`ramses_cc.send_packet` creates invalid address sets

[Onl1ne1373]

`ramses_cc.send_packet` creates invalid address sets

[zxdavb]

Full fix will be in 0.31.10 (and 0.41.10)

[Onl1ne1373]

I added fake timestamps and tried "client.py parse" on

Onl1ne1373@DebianRamses:~/src/ramses_rf$ cat usb-01ff.log 
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 072 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 073 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 072 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 054 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 055 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 054 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 065 RQ --- 21:051294 21:051294 --:------ 01FF 026 008028282AD0008000243028320000C10280800280FF80040020
2024-02-05T18:38:45.319438 066 RQ --- 21:051294 21:051294 --:------ 01FF 026 008028282AD0008000243028320000C10280800280FF80040020
2024-02-05T18:38:45.319438 065 RQ --- 21:051294 21:051294 --:------ 01FF 026 008028282AD0008000243028320000C10280800280FF80040020
2024-02-05T18:38:45.319438 092 RQ --- 21:033619 21:033619 --:------ 01FF 026 008028282AD0008000243028320000C10280800280FF80040020
2024-02-05T18:38:45.319438 092 RQ --- 21:033619 21:033619 --:------ 01FF 026 008028282AD0008000243028320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 045 RQ --- 21:041873 18:010547 --:------ 01FF 026 00802A2A2CD0008000243028320000440280800280FF800400A4
2024-02-05T18:38:45.319438 073 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 073 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 074 RQ --- 21:033620 18:010547 --:------ 01FF 026 0080292729D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 053 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 054 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020
2024-02-05T18:38:45.319438 053 RQ --- 21:033394 21:033394 --:------ 01FF 026 008029282AD0008000143C28320000C10280800280FF80040020

And the result also did not show the packages and not error messages:

Onl1ne1373@DebianRamses:~/src/ramses_rf$ cat usb-01ff.log | python3 client.py parse

client.py: Starting ramses_rf...
18:45:14.958 Best practice is exactly one gateway (HGI) in the known_list: []
18:45:14.958 It is strongly recommended to provide a known_list, and use it as a whitelist (device_id filter), configure: enforce_known_list = True

client.py: Starting engine...
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:041873 |  18:010547 | RQ | message_01ff     |      || {'temperature': 21.0, 'setpoint_bounds': (21.0, 22.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
18:38:45.319 ||  21:033620 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (19.5, 20.5), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}

client.py: Engine stopped: ended without error (e.g. EOF)
 - finished ramses_rf.

So it is not ramses_cc related, but something in the parser.

[Onl1ne1373]

It also happens with a W 22C9:

045  W --- 21:033618 21:033618 --:------ 22C9 006 00073A07D001

It is not visible in the packet.log, only on serial direct. So it seems it has something to do with the addressing.

15 minutes later....
There was indeed something wrong with the addressing. This was caused by a binding error, giving the wrong address in the reply.
But while debugging the problem it would have been nice to have a packet.log to see the problem.

[zxdavb]

There was indeed something wrong with the addressing. This was caused by a binding error, giving the wrong address in the reply.

One of those cases, where things are obvious in retrospect:

RQ --- 21:033618 18:010547 --:------ 01FF 026 0080292428D00...  # addr set is valid
RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D00...  # addr set is invalid
RQ --- 21:033618 --:------ 21:033618 01FF 026 0080292428D00...  # addr set *should be* invalid
 I --- 21:033618 --:------ 21:033618 01FF 026 0080292428D00...  # addr set is valid

But while debugging the problem it would have been nice to have a packet.log to see the problem.

I agree. You shoudl have gotten an error message: Bad frame: invalid address set

I often deprecate some logging to reduce log spam. In this case, I believe I went too far. I will put it back. For the four packets above, we have:

22:39:02.001 ||  21:033618 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
22:39:02.003 ||  21:033618 |            | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
22:39:02.004 ||  21:033618 |            |  I | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}

... but I will make it do this:

22:39:02.001 ||  21:033618 |  18:010547 | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
11:43:25.698 045 RQ --- 21:033618 21:033618 --:------ 01FF 026 0080292428D0008000143C28320000C10280800280FF80040020  # addr set is invalid
 < PacketInvalid(Bad frame: invalid address set)
22:39:02.003 ||  21:033618 |            | RQ | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}
22:39:02.004 ||  21:033618 |            |  I | message_01ff     |      || {'temperature': 20.5, 'setpoint_bounds': (18.0, 20.0), 'time_planning': False, 'temp_adjusted': False, '_flags_10': 'D0'}

[zxdavb]

Worse that that:

• rather than wait to receive the invalid echo of the command you sent,
• it should warn you that the command you are sending is potentially invalid

If I can do the above, then maybe I can remove the PacketInvalid(... warnings sometime in future

[zxdavb]

See:

• cb2cf323
• fd3abb0b

[zxdavb]

So:

ramses_tx.command:command.py:259 RQ --- 04:240790 --:------ 04:240790 1060 003 006401             < Command potentially invalid: wrong verb or dst addr should not be src
ramses_tx.command:command.py:259 RP --- 04:240790 --:------ 04:240790 1060 003 006401             < Command potentially invalid: wrong verb or dst addr should not be src
ramses_tx.command:command.py:259  W --- 04:240790 --:------ 04:240790 1060 003 006401             < Command potentially invalid: wrong verb or dst addr should not be src
ramses_tx.command:command.py:259 RQ --- --:------ --:------ 12:106131 313F 009 00380128CF110A07E5 < Command potentially invalid: wrong verb or dst addr should be present
ramses_tx.command:command.py:259 RP --- --:------ --:------ 12:106131 313F 009 00380128CF110A07E5 < Command potentially invalid: wrong verb or dst addr should be present
ramses_tx.command:command.py:259  W --- --:------ --:------ 12:106131 313F 009 00380128CF110A07E5 < Command potentially invalid: wrong verb or dst addr should be present
ramses_tx.command:command.py:259 RQ --- 21:033618 --:------ 21:033618 01FF 026 0080292428D0008... < Command potentially invalid: wrong verb or dst addr should not be src

[Onl1ne1373]

Thanks for taking your time to enhance the logging! Those warnings look good.