Closed ouaibe closed 2 months ago
A fix is currently being tested for that issue. Waiting on the issue to re-appear to confirm fix is working before merging in main.
Issue is more complex than anticipated, UART frames seem to be coming in somewhat split, from one MCU (not repeatable on mutliple fans).
After a few fix attempts playing with what I thought were leading 0x00 bytes, turns out it probably was a buffer error and commands were misparsted by the UART protocol in the 1st place. Increasing the buffer size to 512 seems to improve the situation dramatically for the MCU that suffered from that issue. Seeing that some messages are > 40 bytes (320bits) it would make sense that the buffer be bigger than the default 256bits.
Fix worked for a while, but the situation re-appeared. It looks like we'll need to do a manual bytes rotation when the UART message arrives dis-ordered. The testing cycles are really long because it takes at least a few days for the situation to appear (some memory overflow in the MCU?), will report later.
More samples of the MCU's messages:
[07:12:22][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00c\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x85"
[07:12:22][D][main:256]: Unknown UART Command received from MCU
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x40
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x1B
[07:12:22][D][main:258]: 0x02
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0xF9
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x63
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x00
[07:12:22][D][main:258]: 0x85
[07:12:22][W][component:237]: Component uart took a long time for an operation (202 ms).
[07:12:22][W][component:238]: Components should block for at most 30 ms.
[07:12:27][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:27][D][main:262]: We sent 11 bytes.
[07:12:27][D][main:264]: 0xAA
[07:12:27][D][main:264]: 0x0A
[07:12:27][D][main:264]: 0xFA
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x00
[07:12:27][D][main:264]: 0x03
[07:12:27][D][main:264]: 0xF9
[07:12:27][W][component:237]: Component uart took a long time for an operation (68 ms).
[07:12:27][W][component:238]: Components should block for at most 30 ms.
[07:12:27][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:27][D][main:256]: Unknown UART Command received from MCU
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x40
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x1B
[07:12:27][D][main:258]: 0x02
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0xF9
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x21
[07:12:27][D][main:258]: 0x02
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x51
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x40
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x1B
[07:12:27][D][main:258]: 0x02
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0x00
[07:12:27][D][main:258]: 0xF9
[07:12:27][W][component:237]: Component uart took a long time for an operation (198 ms).
[07:12:27][W][component:238]: Components should block for at most 30 ms.
[07:12:32][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:32][D][main:262]: We sent 11 bytes.
[07:12:32][D][main:264]: 0xAA
[07:12:32][D][main:264]: 0x0A
[07:12:32][D][main:264]: 0xFA
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x00
[07:12:32][D][main:264]: 0x03
[07:12:32][D][main:264]: 0xF9
[07:12:32][W][component:237]: Component uart took a long time for an operation (68 ms).
[07:12:32][W][component:238]: Components should block for at most 30 ms.
[07:12:32][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:32][D][main:256]: Unknown UART Command received from MCU
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x40
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x1B
[07:12:32][D][main:258]: 0x02
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0xF9
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x21
[07:12:32][D][main:258]: 0x02
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x51
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x40
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x1B
[07:12:32][D][main:258]: 0x02
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0x00
[07:12:32][D][main:258]: 0xF9
[07:12:32][W][component:237]: Component uart took a long time for an operation (204 ms).
[07:12:32][W][component:238]: Components should block for at most 30 ms.
[07:12:37][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:37][D][main:262]: We sent 11 bytes.
[07:12:37][D][main:264]: 0xAA
[07:12:37][D][main:264]: 0x0A
[07:12:37][D][main:264]: 0xFA
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x00
[07:12:37][D][main:264]: 0x03
[07:12:37][D][main:264]: 0xF9
[07:12:37][W][component:237]: Component uart took a long time for an operation (66 ms).
[07:12:37][W][component:238]: Components should block for at most 30 ms.
[07:12:37][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:37][D][main:256]: Unknown UART Command received from MCU
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x40
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x1B
[07:12:37][D][main:258]: 0x02
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0xF9
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x21
[07:12:37][D][main:258]: 0x02
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x51
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x40
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x1B
[07:12:37][D][main:258]: 0x02
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0x00
[07:12:37][D][main:258]: 0xF9
[07:12:37][W][component:237]: Component uart took a long time for an operation (200 ms).
[07:12:37][W][component:238]: Components should block for at most 30 ms.
[07:12:42][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:42][D][main:262]: We sent 11 bytes.
[07:12:42][D][main:264]: 0xAA
[07:12:42][D][main:264]: 0x0A
[07:12:42][D][main:264]: 0xFA
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x00
[07:12:42][D][main:264]: 0x03
[07:12:42][D][main:264]: 0xF9
[07:12:42][W][component:237]: Component uart took a long time for an operation (70 ms).
[07:12:42][W][component:238]: Components should block for at most 30 ms.
[07:12:42][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:42][D][main:256]: Unknown UART Command received from MCU
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x40
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x1B
[07:12:42][D][main:258]: 0x02
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0xF9
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x21
[07:12:42][D][main:258]: 0x02
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x51
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x40
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x1B
[07:12:42][D][main:258]: 0x02
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0x00
[07:12:42][D][main:258]: 0xF9
[07:12:42][W][component:237]: Component uart took a long time for an operation (200 ms).
[07:12:42][W][component:238]: Components should block for at most 30 ms.
[07:12:47][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:47][D][main:262]: We sent 11 bytes.
[07:12:47][D][main:264]: 0xAA
[07:12:47][D][main:264]: 0x0A
[07:12:47][D][main:264]: 0xFA
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x00
[07:12:47][D][main:264]: 0x03
[07:12:47][D][main:264]: 0xF9
[07:12:47][W][component:237]: Component uart took a long time for an operation (68 ms).
[07:12:47][W][component:238]: Components should block for at most 30 ms.
[07:12:47][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:47][D][main:256]: Unknown UART Command received from MCU
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x40
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x1B
[07:12:47][D][main:258]: 0x02
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0xF9
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x21
[07:12:47][D][main:258]: 0x02
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x51
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x40
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x1B
[07:12:47][D][main:258]: 0x02
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0x00
[07:12:47][D][main:258]: 0xF9
[07:12:47][W][component:237]: Component uart took a long time for an operation (200 ms).
[07:12:47][W][component:238]: Components should block for at most 30 ms.
[07:12:52][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:52][D][main:262]: We sent 11 bytes.
[07:12:52][D][main:264]: 0xAA
[07:12:52][D][main:264]: 0x0A
[07:12:52][D][main:264]: 0xFA
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x00
[07:12:52][D][main:264]: 0x03
[07:12:52][D][main:264]: 0xF9
[07:12:52][W][component:237]: Component uart took a long time for an operation (66 ms).
[07:12:52][W][component:238]: Components should block for at most 30 ms.
[07:12:52][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:52][D][main:256]: Unknown UART Command received from MCU
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x40
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x1B
[07:12:52][D][main:258]: 0x02
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0xF9
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x21
[07:12:52][D][main:258]: 0x02
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x51
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x40
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x1B
[07:12:52][D][main:258]: 0x02
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0x00
[07:12:52][D][main:258]: 0xF9
[07:12:52][W][component:237]: Component uart took a long time for an operation (198 ms).
[07:12:52][W][component:238]: Components should block for at most 30 ms.
[07:12:57][D][uart_debug:158]: >>> "\xAA\n\xFA\x00\x00\x00\x00\x00\x00\x03\xF9"
[07:12:57][D][main:262]: We sent 11 bytes.
[07:12:57][D][main:264]: 0xAA
[07:12:57][D][main:264]: 0x0A
[07:12:57][D][main:264]: 0xFA
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x00
[07:12:57][D][main:264]: 0x03
[07:12:57][D][main:264]: 0xF9
[07:12:57][W][component:237]: Component uart took a long time for an operation (66 ms).
[07:12:57][W][component:238]: Components should block for at most 30 ms.
[07:12:57][D][uart_debug:158]: <<< "\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9\x00\x00!\x02\x00\x00\x00Q\x00\x00\x00\x00\x00@\x00\x00\e\x02\x00\x00\x00\x00\x00\xF9"
[07:12:57][D][main:256]: Unknown UART Command received from MCU
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x40
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x1B
[07:12:57][D][main:258]: 0x02
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0xF9
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x21
[07:12:57][D][main:258]: 0x02
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x51
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x40
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x1B
[07:12:57][D][main:258]: 0x02
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0x00
[07:12:57][D][main:258]: 0xF9
[07:12:57][W][component:237]: Component uart took a long time for an operation (204 ms).
[07:12:57][W][component:238]: Components should block for at most 30 ms.
This looks more and more like a memory management issue on the MCU side. Will try a few techniques: when this happens, turn off the settings probe every 5 seconds, and see if it improves when it's turned back on (manually). If it does, then a cooldown mechanism will have to be implemented. Other areas of investigation are with flushing the UART connection and restarting it (if possible from ESPhome) when this happens.
After some testing, and consulting the original firmware logs, the settings probe command every X seconds is not needed and likely the cause of a memleak in the MCU :cry: . The only time this settings probe command is used in the original firmware is when settings are changed by the BL2028N, in order to validate they have been effectively changed on the fan via an MCU settings check. This is not implemented currently in the HA integration. Either way, as soon as the settings are changed on the fan using the buttons, the MCU immediately sends an update via the UART which we grab in the HA integration. In addition the MCU sends an update every minute or so. All in all, less code, less bugs :clap: .
It's been days and the memleak hasn't re-appeared. Considering this solved at the moment.
Is there an existing issue for this?
Is this question already covered by the FAQ?
Are you trying to run ESPHome on another Dreo Fan than the DR-HTF004S?
This is a DR-HTF004S.
Your Fan Model (ONLY the DR-HTF004S is supported at the moment).
DR-HTF004S
Your Fan Firmware Version.
ESPHome
Your Fan MCU Version.
003
Current Behavior
Usually the response to read-settings rceived from the MCU is as follows:
[12:39:24][W][component:237]: Component uart took a long time for an operation (70 ms). [12:39:24][W][component:238]: Components should block for at most 30 ms.
[12:39:24][D][main:104]: We read 0x4E temperature. [12:39:24][D][sensor:093]: 'Air Temperature': Sending state 25.55556 °C with 1 decimals of accuracy [12:39:24][D][main:117]: We read 'Sound Off' [12:39:24][D][main:122]: Not changing Fan Beeper settings. [12:39:24][D][main:128]: We read 'Adaptive Display On' [12:39:24][D][main:133]: Not changing Adaptive Display settings. [12:39:24][D][main:163]: We read Fan Mode:'Normal' [12:39:24][D][main:168]: Not changing Fan Mode settings. [12:39:24][D][main:190]: We read Fan Speed: '10' [12:39:24][D][main:195]: Not changing Fan Speed settings. [12:39:24][D][main:200]: We read Oscillation:'30 Degrees' [12:39:24][D][main:205]: Not changing Oscillation settings.
But from time to time the MCU will crash and send a leading series of 0x00 bytes with a 0x85 checksum:
[12:39:24][W][component:237]: Component uart took a long time for an operation (70 ms). [12:39:24][W][component:238]: Components should block for at most 30 ms.
This causes the ESPHome code not to recognize the command response and thus not update the settings in HA.
Expected Behavior
We should treat this by trimming leading 0x00 bytes and the checksum and then process the command response starting with 0xAA.
Steps To Reproduce, including errors you've seen.
Let the fan run for a while, it seems it happens after a certain amount of time (days).
Extra information about the steps taken.
Information about your browser environment.