Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

kostal: more debug output to get better understanding of temporal behaviour #644

Merged
merged 2 commits into from
Jan 12, 2025
Merged

kostal: more debug output to get better understanding of temporal behaviour #644

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
bdf6551
kostal: more tracing with timestamps
lewurm Jan 8, 2025
61f5bc6
contactors control: add tracing with timestamps
lewurm Jan 8, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 13 additions & 0 deletions Software/src/communication/contactorcontrol/comm_contactorcontrol.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -105,6 +105,15 @@ void init_contactors() {
#endif //PERIODIC_BMS_RESET
}

static void dbg_contactors(const char* state) {
#ifdef DEBUG_LOG
logging.print("[");
logging.print(millis());
logging.print(" ms] contactors control: ");
logging.println(state);
#endif
}

// Main functions of the handle_contactors include checking if inverter allows for closing, checking battery 2, checking BMS power output, and actual contactor closing/precharge via GPIO
void handle_contactors() {
#if defined(SMA_BYD_H_CAN) || defined(SMA_BYD_HVS_CAN) || defined(SMA_TRIPOWER_CAN)
Expand Down Expand Up @@ -173,13 +182,15 @@ void handle_contactors() {
switch (contactorStatus) {
case START_PRECHARGE:
set(NEGATIVE_CONTACTOR_PIN, ON, PWM_ON_DUTY);
dbg_contactors("NEGATIVE");
prechargeStartTime = currentTime;
contactorStatus = PRECHARGE;
break;

case PRECHARGE:
if (currentTime - prechargeStartTime >= NEGATIVE_CONTACTOR_TIME_MS) {
set(PRECHARGE_PIN, ON);
dbg_contactors("PRECHARGE");
negativeStartTime = currentTime;
contactorStatus = POSITIVE;
}
Expand All @@ -188,6 +199,7 @@ void handle_contactors() {
case POSITIVE:
if (currentTime - negativeStartTime >= PRECHARGE_TIME_MS) {
set(POSITIVE_CONTACTOR_PIN, ON, PWM_ON_DUTY);
dbg_contactors("POSITIVE");
prechargeCompletedTime = currentTime;
contactorStatus = PRECHARGE_OFF;
}
Expand All @@ -198,6 +210,7 @@ void handle_contactors() {
set(PRECHARGE_PIN, OFF);
set(NEGATIVE_CONTACTOR_PIN, ON, PWM_HOLD_DUTY);
set(POSITIVE_CONTACTOR_PIN, ON, PWM_HOLD_DUTY);
dbg_contactors("PRECHARGE_OFF");
contactorStatus = COMPLETED;
datalayer.system.status.contactors_engaged = true;
}
Expand Down
52 changes: 37 additions & 15 deletions Software/src/inverter/KOSTAL-RS485.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -117,19 +117,40 @@ void float2frameMSB(byte* arr, float value, byte framepointer) {
arr[framepointer + 1] = g.b[3];
}

void send_kostal(byte* arr, int alen) {
static void dbg_timestamp(void) {
#ifdef DEBUG_KOSTAL_RS485_DATA
logging.print("TX: ");
for (int i = 0; i < alen; i++) {
if (arr[i] < 0x10) {
logging.print("[");
logging.print(millis());
logging.print(" ms] ");
#endif
}

static void dbg_frame(byte* frame, int len, const char* prefix) {
dbg_timestamp();
#ifdef DEBUG_KOSTAL_RS485_DATA
logging.print(prefix);
logging.print(": ");
for (uint8_t i = 0; i < len; i++) {
if (frame[i] < 0x10) {
logging.print("0");
}
logging.print(arr[i], HEX);
logging.print(frame[i], HEX);
logging.print(" ");
}
logging.println("\n");
logging.println("");
#endif
Serial2.write(arr, alen);
}

static void dbg_message(const char* msg) {
dbg_timestamp();
#ifdef DEBUG_KOSTAL_RS485_DATA
logging.println(msg);
#endif
}

static void send_kostal(byte* frame, int len) {
dbg_frame(frame, len, "TX");
Serial2.write(frame, len);
}

byte calculate_longframe_crc(byte* lfc, int lastbyte) {
Expand Down Expand Up @@ -247,6 +268,7 @@ void receive_RS485() // Runs as fast as possible to handle the serial stream
}
if (currentMillis - contactorMillis >= INTERVAL_2_S & !RX_allow) {
RX_allow = true;
dbg_message("RX_allow -> true");
}

if (startupMillis) {
Expand All @@ -255,32 +277,28 @@ void receive_RS485() // Runs as fast as possible to handle the serial stream
// Disconnect allowed only, when curren zero
if (datalayer.battery.status.current_dA == 0) {
datalayer.system.status.inverter_allows_contactor_closing = false;
dbg_message("inverter_allows_contactor_closing -> false");
}
} else if (((currentMillis - startupMillis) >= 7000) &
datalayer.system.status.inverter_allows_contactor_closing == false) {
datalayer.system.status.inverter_allows_contactor_closing = true;
dbg_message("inverter_allows_contactor_closing -> true");
}
}

if (B1_delay) {
if ((currentMillis - B1_last_millis) > INTERVAL_1_S) {
send_kostal(frameB1b, 8);
B1_delay = false;
dbg_message("B1_delay -> false");
}
} else if (Serial2.available()) {
RS485_RXFRAME[rx_index] = Serial2.read();
if (RX_allow) {
rx_index++;
if (RS485_RXFRAME[rx_index - 1] == 0x00) {
if ((rx_index == 10) && (RS485_RXFRAME[0] == 0x09) && register_content_ok) {
#ifdef DEBUG_KOSTAL_RS485_DATA
logging.print("RX: ");
for (uint8_t i = 0; i < 10; i++) {
logging.print(RS485_RXFRAME[i], HEX);
logging.print(" ");
}
logging.println("");
#endif
dbg_frame(RS485_RXFRAME, 10, "RX");
rx_index = 0;
if (check_kostal_frame_crc()) {
incoming_message_counter = RS485_HEALTHY;
Expand All @@ -299,6 +317,7 @@ void receive_RS485() // Runs as fast as possible to handle the serial stream
if (headerB && (RS485_RXFRAME[6] == 0x5E) && (RS485_RXFRAME[7] == 0xFF)) {
send_kostal(frameB1, 10);
B1_delay = true;
dbg_message("B1_delay -> true");
B1_last_millis = currentMillis;
}

Expand Down Expand Up @@ -334,11 +353,14 @@ void receive_RS485() // Runs as fast as possible to handle the serial stream
send_kostal(frame3, 9);
}
}
} else {
dbg_frame(RS485_RXFRAME, 10, "RX (dropped)");
}
rx_index = 0;
}
}
if (rx_index >= 10) {
dbg_frame(RS485_RXFRAME, 10, "RX (!RX_allow)");
rx_index = 0;
}
}
Expand Down
6 changes: 5 additions & 1 deletion Software/src/inverter/KOSTAL-RS485.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,10 @@
#include "../include.h"

#define RS485_INVERTER_SELECTED
//#define DEBUG_KOSTAL_RS485_DATA // Enable this line to get TX / RX printed out via serial
//#define DEBUG_KOSTAL_RS485_DATA // Enable this line to get TX / RX printed out via logging

#if defined(DEBUG_KOSTAL_RS485_DATA) && !defined(DEBUG_LOG)
#error "enable LOG_TO_SD, DEBUG_VIA_USB or DEBUG_VIA_WEB in order to use DEBUG_KOSTAL_RS485_DATA"
#endif
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess we should just drop DEBUG_KOSTAL_RS485_DATA and use DEBUG_VIA_USB for everything.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

While we have still heavy debugging going on, i prefer keeping DEBUG_KOSTAL_RS485_DATA and DEBUG_VIA_USB separated.

But that drop dropped is good, as i just figured out, that we must replace zero bytes of RX frame before rx processing, as otherwise we don't process eg. this: if (RS485_RXFRAME[6] == 0x5E) when RXFRAME[7] is 0x00

Also rx frame length may be more than 10 bytes, as there is sent EPOCH timestamp on one frame (actually never seen that, but seen on BYD code that)

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But that drop dropped is good, as i just figured out, that we must replace zero bytes of RX frame before rx processing, as otherwise we don't process eg. this: if (RS485_RXFRAME[6] == 0x5E) when RXFRAME[7] is 0x00

Yes, I'm handling that in my WIP branch: https://github.com/lewurm/Battery-Emulator/blob/1df27f4444ec0cfac8822256208db3e5ff780c06/Software/src/inverter/KOSTAL-RS485.cpp#L244-L249 and https://github.com/lewurm/Battery-Emulator/blob/1df27f4444ec0cfac8822256208db3e5ff780c06/Software/src/inverter/KOSTAL-RS485.cpp#L492-L497

But I don't want to submit that change just yet, because apparently some people have success with the current state and I want to understand why by adding additional logging. I suspect that it works by chance, because we send the right answer after a timeout:

Battery-Emulator/Software/src/inverter/KOSTAL-RS485.cpp

Lines 266 to 268 in 4232da8

if ((currentMillis - B1_last_millis) > INTERVAL_1_S) {
send_kostal(frameB1b, 8);
B1_delay = false;

Also rx frame length may be more than 10 bytes, as there is sent EPOCH timestamp on one frame (actually never seen that, but seen on BYD code that)

That should be covered by the dump_rs485_data_rx(" (!RX_allow)"); case, at least it would print it in several steps then. But indeed, I haven't seen it in any traces yet.


#endif
Loading