search

zxdavb / ramses_rf

An interface for the RAMSES RF protocol, as used by Honeywell-compatible HVAC & CH/DHW systems.
MIT License
55 stars 15 forks source link

3EF0 parser: ValueError: Invalid result: ... is > 1 #77

Closed JeroenTogt closed 1 year ago

JeroenTogt commented 1 year ago

I see multiple times the following error:

Pretty clear whats happening as it expects 00 - 64 at that location, but there are a lot of these errors. Could it be that 64 is not the max value?

Attached logfile as well, hope this gives some info: 2023.txt

Thanks for looking into this and the great work you do on this

2023-03-21 18:19:43.768 ERROR (MainThread) [ramses_rf.protocol.message]  I --- 10:057706 --:------ 10:057706 3EF0 009 008F100A00FF032600 < Coding error: ValueError(Invalid result: 1.43 (0x8F) is > 1)
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/ramses_rf/protocol/message.py", line 331, in _validate
    result = PAYLOAD_PARSERS.get(self.code, parser_unknown)(
  File "/usr/local/lib/python3.10/site-packages/ramses_rf/protocol/parsers.py", line 141, in wrapper
    result = fnc(payload, msg, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ramses_rf/protocol/parsers.py", line 2478, in parser_3ef0
    mod_level = percent_from_hex(payload[2:4], high_res=False)  # 00-64 (or FF)
  File "/usr/local/lib/python3.10/site-packages/ramses_rf/protocol/helpers.py", line 27, in wrapper
    return fnc(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ramses_rf/protocol/helpers.py", line 252, in percent_from_hex
    raise ValueError(f"Invalid result: {result} (0x{value}) is > 1")
ValueError: Invalid result: 1.43 (0x8F) is > 1

I

zxdavb commented 1 year ago

Hello @JeroenTogt, thanks for your submission.

Before I can look at this, I require (unedited) packet logs, rather than HA logs please (I need to compare the 3EF0 packets against the 0008, 10E0, 3220, 3EF1 packets).

The contents of these log files look like this:

2023-02-17T13:27:10.287127 # ramses_rf 0.22.40
2023-02-17T13:27:10.333671 000  I --- 18:123456 63:262142 --:------ 7FFF 016 001001865F57BA5976302E32322E3430
2023-02-17T13:28:15.762861 058  I --- 04:033244 --:------ 04:033244 30C9 003 02076B
   ...
zxdavb commented 1 year ago

Regarding the log you did provide me, these messages are very unusual:

No response for task(000C|RP|01:007149|0000): throttling to 1/6h

So, could you kindly provide the make/model of your controller, opentherm bridge, and of your boiler?

JeroenTogt commented 1 year ago

Hey David,

Here my setup Evotouch controller ATC928G3000 ( firmware 02.00.19.33) Openterm bridge R8810A1018 OTGW ( openterm gateway version 6.2) in gateway mode. http://otgw.tclcode.com/ hardware from nodoshop ( this gateway is used to look at the openterm communication between the bridge and the boiler, it is mounted in between the bridge and the boiler) Boiler Remeha Calenta Ace 40c In zone 0 6x HR92 and the evotouch controller as sensor in zone 1 2x Hr92 and T87RF as sensor

Hope this is enough info! If you need more pls let me know

home-assistant.log packet.log otgw log.txt

zxdavb commented 1 year ago

Your setup is largely the same as mine:

Give me a few minutes to review your logs and have a think about next steps.

zxdavb commented 1 year ago

I should start by saying your log files are unhelpfully short - 24h log files (or longer) would be more useful.

In your OTGW log, we have:

18:52:41.077956  T900E6400  Write-Data  Maximum relative modulation level: 100.00
18:52:41.227004  B500E6400  Write-Ack   Maximum relative modulation level: 100.00
   ...
18:52:45.074154  T00110000  Read-Data   Relative modulation level: 0.00
18:52:45.176620  BC0110000  Read-Ack    Relative modulation level: 0.00
   ...
18:52:51.074133  T00110000  Read-Data   Relative modulation level: 0.00
18:52:51.175826  B40117C00  Read-Ack    Relative modulation level: 124.00
   ...
18:52:57.063794  T00110000  Read-Data   Relative modulation level: 0.00
18:52:57.176817  BC0111B00  Read-Ack    Relative modulation level: 27.00

The above is the only example in that log file where the RelModLevel was > 100%. Note it is above the MaxRelModLevel, 100%.

The equivalent RelModLevel messages in the ramses_rf packet log look like this:

2023-03-22T18:41:48.689945 ... RP --- 10:057706 01:007149 --:------ 3220 005 00C0110000
2023-03-22T18:43:47.676770 039 RP --- 10:057706 01:007149 --:------ 3220 005 00C0110000
2023-03-22T18:48:49.517022 040 RP --- 10:057706 01:007149 --:------ 3220 005 00C0110000
2023-03-22T18:53:51.364044 039 RP --- 10:057706 01:007149 --:------ 3220 005 00C0110000

Note the above all have a RelModLevel of 0% (0x00). I am not sure if it is always 0x00 (possible), or just was so for these specific 4 instances (most likely) - again, the logs you sent me need to be > 24h for us to be really sure.

Unfortunately, the MaxRelModLevel equivalents are not present in the log files you sent me.

... and we also have:

2023-03-22T18:41:48.659395 ...  I --- 10:057706 --:------ 10:057706 3EF0 009 0000100200FF033000
2023-03-22T18:41:48.723650 ... RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033064
2023-03-22T18:42:08.655261 040 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:43:08.859960 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:44:09.078718 040 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:45:09.283947 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:46:09.486870 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:47:09.700928 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033000
2023-03-22T18:47:29.041563 039  I --- 10:057706 --:------ 10:057706 3EF0 009 0000100200FF033000
2023-03-22T18:48:09.908041 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100200FF033000
2023-03-22T18:49:10.135176 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100200FF033000
2023-03-22T18:50:10.338308 040 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100200FF033064
2023-03-22T18:51:12.543741 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100200FF033064
2023-03-22T18:52:12.744112 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100200FF033064
2023-03-22T18:52:55.600908 040  I --- 10:057706 --:------ 10:057706 3EF0 009 007C100A00FF033064
2023-03-22T18:53:12.966539 040 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033064
2023-03-22T18:54:13.165774 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033064
2023-03-22T18:55:13.376427 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033064
2023-03-22T18:56:13.585155 039 RP --- 10:057706 01:007149 --:------ 3EF0 009 0000100A00FF033064

Note for the above, all the RelModLevels are 0x00, except for the one which is 0x7C (124%), matching the entry from the OTGW log entry of about the same datetime.

zxdavb commented 1 year ago

The challenge we have is this...

For all other OTB/boiler combinations I've seen, the OT (3220) RelModLevel is reported as a percentage from 0x00 to 0x64 (0-100 decimal) (actually, it's a f8.8, so it's from 0x0000 to 0x6400).

I do know some boilers can modulate above 100%, say 125%, but I've never seen such values.

Most importantly, I have access to the OT specification, and it only permits values from 0 to 100.

So, on that basis, this is returning an invalid value (the 7C in the payload):

18:52:51.175826  B40117C00  Read-Ack    Relative modulation level: 124.00

The above is the root cause of the issue - the 'bad' 3EF0 packet is simply reflecting what the OT value is (0x7C):

2023-03-22T18:52:55.600908 040  I --- 10:057706 --:------ 10:057706 3EF0 009 007C100A00FF033064
zxdavb commented 1 year ago

So I wonder if - in your specific case - the value is from 0-200 and you need to divide by 200 to get the percentage (i.e. 0.0 to 1.0) rather than 100?

What I mean is that the boiler/gateway aren't following the protocol specification? (I have seen this sort of behaviour before)

As a first step, maybe you could remove the OTGW and connect the OTB direct to the boiler and see what happens. Is the bad value from the boiler itself, or is it caused by the OTGW?

Or simply check your OTGW has the latest FW?

Or ask for help on the OTGW forums, or the boiler forums?

JeroenTogt commented 1 year ago

Hi David, All clear, root cause is that the rel modulation level is outside the 0-100 range as per the OT specification. When I look at the log, this indeed happens ( this one is this morning and included in the ramses logs, unfortunately not completely in the OTGW log) ill post them later today so they can gather some more...:-)

otgw1 This also shows that most of the time the boiler runs at minimum capacity. ( it is just heating the attic). Also the max capacity of the boiler is limited as well( with parameters in the boiler, you see that as well in this log. ( but it sometimes goes to 101 %...).

See here an old graph were you see relative mod level even go negative...and well above 100 otgw 2

Here a sort of a typical run otgw3

My guess is that the boiler is producing the bad numbers.

Ill switch the OTGW to monitor mode, it is not supposed to do anything with the data and see if this still happens Then ill upgrade the FW ( current one is of oktober 2022) there is a new version, but don't see anything related to this in the changelog... Then ill hook it up direct...

Ill post the question of relative mod level on the OTGW forum as well, to see if someone else notices this as well...

Ill post the longer logfiles at the end of the day.

Anything on the throttling to 1/6h thing you picked up as unusual?

zxdavb commented 1 year ago

Anything on the throttling to 1/6h thing you picked up as unusual?

There are no RPs from the controller to the HGI-compatible gateway in the packet logs you sent me.

Maybe the RF signal strength between the HGI-compatible gateway and the controller is off? Can you tune it (some of the evofw3 devices can be tuned), or put it in a better location?

I am closing this issue - I don't believe I can provide a fix, and I don't think any possible workaround would be useful.

JeroenTogt commented 1 year ago

Hi David,

Here the longer logs. Just see if usefull for future reference. If I find some on the relative modulation level not in between 0 -100 dec then Ill let you know.

otlog-20230323.txt packet.log home-assistant.log

JeroenTogt commented 1 year ago

packet.log.2023-03-22.log first bit of the packet log till midnight