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.

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

Improve amount of decoded frames #51

Closed
ich777 opened this issue Aug 13, 2024 · 12 comments
Closed

Improve amount of decoded frames #51

ich777 opened this issue Aug 13, 2024 · 12 comments

Comments

@ich777
Copy link

ich777 commented Aug 13, 2024

Hi, just a quick question, I get eight invalid headers every time, is this something that can be maybe fixed or is this something that I can just safely ignore?
I mean it also complains about taking too long but I assume that's how it is.

Here is a snippet from my log:

[12:55:35][D][sensor:094]: 'votronic battery voltage': Sending state 12.25000 V with 2 decimals of accuracy
[12:55:36][D][sensor:094]: 'votronic pv voltage': Sending state 12.26000 V with 2 decimals of accuracy
[12:55:36][D][sensor:094]: 'votronic pv current': Sending state 0.40000 A with 1 decimals of accuracy
[12:55:36][D][sensor:094]: 'votronic pv power': Sending state 4.90400 W with 1 decimals of accuracy
[12:55:36][D][sensor:094]: 'votronic pv controller temperature': Sending state 22.00000 °C with 0 decimals of accuracy
[12:55:36][D][sensor:094]: 'votronic charging mode setting id': Sending state 53.00000  with 0 decimals of accuracy
[12:55:36][D][text_sensor:064]: 'votronic charging mode setting': Sending state 'Lead Gel'
[12:55:36][D][sensor:094]: 'votronic pv battery status bitmask': Sending state 0.00000  with 0 decimals of accuracy
[12:55:36][D][text_sensor:064]: 'votronic pv battery status': Sending state 'Standby'
[12:55:36][D][sensor:094]: 'votronic pv controller status bitmask': Sending state 8.00000  with 0 decimals of accuracy
[12:55:36][D][text_sensor:064]: 'votronic pv controller status': Sending state 'Active'
[12:55:36][W][component:237]: Component votronic took a long time for an operation (154 ms).
[12:55:36][W][component:238]: Components should block for at most 30 ms.
[12:55:38][W][votronic:097]: Invalid header (0x00)
[12:55:38][W][votronic:097]: Invalid header (0x00)
[12:55:38][W][votronic:097]: Invalid header (0x00)
[12:55:38][W][votronic:097]: Invalid header (0x16)
[12:55:38][W][votronic:097]: Invalid header (0x35)
[12:55:38][W][votronic:097]: Invalid header (0x00)
[12:55:38][W][votronic:097]: Invalid header (0x08)
[12:55:38][W][votronic:097]: Invalid header (0x35)
[12:55:38][I][votronic:173]: Solar charger data received

I'm using the Votronic SR 140 Duo (should be model: SR1610) via the Display Link interface.

Keep up the good work!

Cheers,
Christoph

@syssi
Copy link
Owner

syssi commented Aug 13, 2024

Could you enable the debug mode of the uart component? I'm interested in some raw traffic (printed to the log) to replay your traffic locally to poke around: https://github.com/syssi/esphome-votronic/blob/main/votronic_display_link.md#debugging

@ich777
Copy link
Author

ich777 commented Aug 13, 2024

Sure thing, I hope this is what you where after: debug.txt

I put it in a file to not bloat the Issue.

@syssi
Copy link
Owner

syssi commented Aug 13, 2024

$ cat debug.txt | grep 'uart_debug:'
[19:35:38][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:40][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:42][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:43][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:45][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:47][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00
[19:35:49][D][uart_debug:114]: <<< 00:00:00:00:00:00:00:00:00:00:00

This doesn't look good. This isn't valid display link traffic.

@ich777
Copy link
Author

ich777 commented Aug 13, 2024

Give me a sec, I just noticed that it doesn't report data correctly since uploading the debug firmware.elf

@ich777
Copy link
Author

ich777 commented Aug 13, 2024

I really don't know what broke, I'm now only receiving invalid headers for whatever reason.
I have to look into that tomorrow.

@syssi
Copy link
Owner

syssi commented Aug 13, 2024

Just reboot the ESP a few times. Does it fix it (temporary)?

@ich777
Copy link
Author

ich777 commented Aug 13, 2024

Just reboot the ESP a few times. Does it fix it (temporary)?

Nope, already tried that a few times.

@ich777
Copy link
Author

ich777 commented Aug 14, 2024

@syssi new file attached, it seems my controller doesn't report values when the Solar side is too low or it has to do because my Battery is almost dead (new will arrive soon).

debug.txt

@syssi
Copy link
Owner

syssi commented Aug 16, 2024

This log messages does explain the issue probably:

[08:25:33][VV][votronic:070]: Buffer cleared due to timeout: AA.1A
[08:25:33][D][uart_debug:114]: <<< 00:0C:35:00:08:61:AA:1A:58:04:11:07:00:00:00:00:00:0C:35:00:08:61:AA:1A:58:04:11:07:00:00:00:00:00:0C:35:00:08:61:AA:1A:58:04:11:07:00:00:00:00:00:0C:35:00:08:61:AA:1A:58:04:11:07:00:00:00:00:00:0C:35:00:08:61:AA:1A:58:04:11:07:00:00:00:00:00:0C:35:00:08:61:AA:1A:59:04:11:07:00:00:00:00:00:0C:35:00:08:60:AA:1A:59:04:11:07:00:00:00:00:00:0C:35:00:08:60:AA:1A
[08:25:33][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:33][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:33][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:34][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:34][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:34][VV][votronic:070]: Buffer cleared due to timeout: 
[08:25:34][W][votronic:097]: Invalid header (0x59)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 59
[08:25:34][W][votronic:097]: Invalid header (0x04)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 04
[08:25:34][W][votronic:097]: Invalid header (0x11)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 11
[08:25:34][W][votronic:097]: Invalid header (0x07)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 07
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x0C)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 0C
[08:25:34][W][votronic:097]: Invalid header (0x35)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 35
[08:25:34][W][votronic:097]: Invalid header (0x00)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 00
[08:25:34][W][votronic:097]: Invalid header (0x08)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 08
[08:25:34][W][votronic:097]: Invalid header (0x60)
[08:25:34][VV][votronic:082]: Buffer cleared due to reset: 60

It looks like the firmware of your device has a pretty bad behavior. This is happening:

  1. The device transmits 2 bytes (the start of frame (0xAA 0x1A)) and waits a second
  2. The rx_timeout kicks in and clears the buffer
  3. The remaining bytes are received now. Because the buffer content doesn't start with 0xAA 0x1A anymore the gets discarded too.

This issue can be resolved by increasing the rx_timeout:

substitutions:
  # ...
  rx_timeout: 1000ms

Please start with 1s decrease the setting step by step to identify a good threshold.

@ich777
Copy link
Author

ich777 commented Aug 16, 2024

Please start with 1s decrease the setting step by step to identify a good threshold.

Thanks, I've now set rx_timeout to 1300ms (1200ms are not enough it seems) and it seems way better:

[09:01:15][D][sensor:094]: 'votronic battery voltage': Sending state 11.89000 V with 2 decimals of accuracy
[09:01:15][D][sensor:094]: 'votronic pv voltage': Sending state 11.88000 V with 2 decimals of accuracy
[09:01:15][D][sensor:094]: 'votronic pv current': Sending state 0.30000 A with 1 decimals of accuracy
[09:01:15][D][sensor:094]: 'votronic pv power': Sending state 3.56400 W with 1 decimals of accuracy
[09:01:15][D][sensor:094]: 'votronic pv controller temperature': Sending state 12.00000 °C with 0 decimals of accuracy
[09:01:15][D][sensor:094]: 'votronic charging mode setting id': Sending state 53.00000  with 0 decimals of accuracy
[09:01:15][D][text_sensor:064]: 'votronic charging mode setting': Sending state 'Lead Gel'
[09:01:15][D][sensor:094]: 'votronic pv battery status bitmask': Sending state 0.00000  with 0 decimals of accuracy
[09:01:15][D][text_sensor:064]: 'votronic pv battery status': Sending state 'Standby'
[09:01:15][D][sensor:094]: 'votronic pv controller status bitmask': Sending state 8.00000  with 0 decimals of accuracy
[09:01:15][D][text_sensor:064]: 'votronic pv controller status': Sending state 'Active'
[09:01:15][W][component:237]: Component votronic took a long time for an operation (110 ms).
[09:01:15][W][component:238]: Components should block for at most 30 ms.
[09:01:17][I][votronic:173]: Solar charger data received
[09:01:17][D][sensor:094]: 'votronic battery voltage': Sending state 11.89000 V with 2 decimals of accuracy
[09:01:17][D][sensor:094]: 'votronic pv voltage': Sending state 11.88000 V with 2 decimals of accuracy
[09:01:17][D][sensor:094]: 'votronic pv current': Sending state 0.30000 A with 1 decimals of accuracy
[09:01:17][D][sensor:094]: 'votronic pv power': Sending state 3.56400 W with 1 decimals of accuracy
[09:01:17][D][sensor:094]: 'votronic pv controller temperature': Sending state 12.00000 °C with 0 decimals of accuracy
[09:01:17][D][sensor:094]: 'votronic charging mode setting id': Sending state 53.00000  with 0 decimals of accuracy
[09:01:17][D][text_sensor:064]: 'votronic charging mode setting': Sending state 'Lead Gel'
[09:01:17][D][sensor:094]: 'votronic pv battery status bitmask': Sending state 0.00000  with 0 decimals of accuracy
[09:01:17][D][text_sensor:064]: 'votronic pv battery status': Sending state 'Standby'
[09:01:17][D][sensor:094]: 'votronic pv controller status bitmask': Sending state 8.00000  with 0 decimals of accuracy
[09:01:17][D][text_sensor:064]: 'votronic pv controller status': Sending state 'Active'
[09:01:17][W][component:237]: Component votronic took a long time for an operation (117 ms).
[09:01:17][W][component:238]: Components should block for at most 30 ms.
[09:01:20][I][votronic:173]: Solar charger data received
[09:01:20][D][sensor:094]: 'votronic battery voltage': Sending state 11.89000 V with 2 decimals of accuracy
[09:01:20][D][sensor:094]: 'votronic pv voltage': Sending state 11.88000 V with 2 decimals of accuracy
[09:01:20][D][sensor:094]: 'votronic pv current': Sending state 0.30000 A with 1 decimals of accuracy
[09:01:20][D][sensor:094]: 'votronic pv power': Sending state 3.56400 W with 1 decimals of accuracy
[09:01:20][D][sensor:094]: 'votronic pv controller temperature': Sending state 12.00000 °C with 0 decimals of accuracy
[09:01:20][D][sensor:094]: 'votronic charging mode setting id': Sending state 53.00000  with 0 decimals of accuracy
[09:01:20][D][text_sensor:064]: 'votronic charging mode setting': Sending state 'Lead Gel'
[09:01:20][D][sensor:094]: 'votronic pv battery status bitmask': Sending state 0.00000  with 0 decimals of accuracy
[09:01:20][D][text_sensor:064]: 'votronic pv battery status': Sending state 'Standby'
[09:01:20][D][sensor:094]: 'votronic pv controller status bitmask': Sending state 8.00000  with 0 decimals of accuracy
[09:01:20][D][text_sensor:064]: 'votronic pv controller status': Sending state 'Active'
[09:01:20][W][component:237]: Component votronic took a long time for an operation (111 ms).
[09:01:20][W][component:238]: Components should block for at most 30 ms.
[09:01:22][I][votronic:173]: Solar charger data received

Appreciate the time and response!

@ich777 ich777 closed this as completed Aug 16, 2024
@syssi syssi changed the title Question Improve amount of decoded frames Aug 16, 2024
@syssi
Copy link
Owner

syssi commented Aug 16, 2024

Could you do me a favor and very your device is already listed as supported device here?

https://github.com/syssi/esphome-votronic/blob/main/votronic_display_link.md#supported-devices

I would like to extend the list if possible.

@ich777
Copy link
Author

ich777 commented Aug 16, 2024

@syssi yes it is, it‘s model number is SR1610 as mentioned in the first post (at the very bottom).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants