search

smar000 / evoGateway

Python script for listening in and responding to evohome heating control radio messages
46 stars 17 forks source link

What looks like failing requests? #37

Closed Hendersonm66 closed 2 years ago

Hendersonm66 commented 2 years ago

Hi

Yesterday I built a Nano CUL with 868 Radio and installed evofw3. I then installed Evogateway on a Raspberry PI running Ubuntu Server 20.04.

I think I've managed to get it all up and running even as far as having values via MQTT to an EmonPI system. So it seems to be collecting and decoding packets correctly.

Here is what looks like normal operation.

2021-10-05 08:41:37 |064| CTL Controller -> | I| system_sync | _next_sync: 08:44:08, remaining_seconds: 151.0 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 18.00°C @ Office [Zone 00 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 18.00°C @ Hall [Zone 01 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 16.00°C @ Games room [Zone 02 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 15.00°C @ Bedroom 1 [Zone 03 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 18.00°C @ Kitchen [Zone 04 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 18.00°C @ Toilet [Zone 05 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| setpoint | 19.00°C @ Livingroom [Zone 06 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 18.45°C @ Office [Zone 00 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 18.92°C @ Hall [Zone 01 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 17.00°C @ Games room [Zone 02 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 21.23°C @ Bedroom 1 [Zone 03 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 18.46°C @ Kitchen [Zone 04 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 17.81°C @ Toilet [Zone 05 ] 2021-10-05 08:41:37 |065| CTL Controller -> | I| temperature | 20.25°C @ Livingroom [Zone 06 ] 2021-10-05 08:41:53 |075| TRV Zone_06 TRV:13... -> | I| temperature | 18.90°C 2021-10-05 08:41:55 |075| TRV Zone_01 TRV:13... -> CTL Controller | I| heat_demand | 0% 2021-10-05 08:42:29 |070| TRV Zone_02 TRV:13... -> CTL Controller | I| heat_demand | 0%

However, I'm hoping someone could have a look at this log file section from startup. Are these constant RE-SENT entries showing a failure to send a command to the Controller? These lines also show up later during operation but infrequently.

ubuntu@ubuntu:~/evoGateway$ python3 evogateway.py 2021-10-05 08:11:19 | 2021-10-05 08:11:19 | ------------------------------------------------------------------------------------------ 2021-10-05 08:11:19 | Devices loaded from 'devices.json' file: 2021-10-05 08:11:19 | CTL 01:196480 - Controller 2021-10-05 08:11:19 | TRV 04:133207 - Zone_06 TRV:133207 2021-10-05 08:11:19 | TRV 04:133209 - Zone_06 TRV:133209 2021-10-05 08:11:19 | TRV 04:133211 - Zone_05 TRV:133211 2021-10-05 08:11:19 | TRV 04:133361 - Zone_01 TRV:133361 2021-10-05 08:11:19 | TRV 04:133363 - Zone_02 TRV:133363 2021-10-05 08:11:19 | TRV 04:133365 - Zone_03 TRV:133365 2021-10-05 08:11:19 | TRV 04:133367 - Zone_00 TRV:133367 - Zone 00 2021-10-05 08:11:19 | BDR 13:194054 - BDR:194054 2021-10-05 08:11:19 | HGI 18:000730 - evoGateway 2021-10-05 08:11:19 | STA 34:213191 - T87RF2033 2021-10-05 08:11:19 | ------------------------------------------------------------------------------------------ 2021-10-05 08:11:19 | 2021-10-05 08:11:19 | # evogateway 3.0.6 An empty block_list was enabled, so will be ignored

Using an allow_list: ['01:196480', '04:133207', '04:133209', '04:133211', '04:133361', '04:133363', '04:133365', '04:133367', '13:194054', '18:000730', '34:213191']

2021-10-05T08:11:19.953467 # ramses_rf 0.11.0

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.068822: RE-SENT (1/24)

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.129623: RE-SENT (2/24)

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.191126: RE-SENT (3/24)

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.252522: RE-SENT (4/24)

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.313658: RE-SENT (5/24)

2021-10-05T08:11:20.277410 # evofw3 0.7.0

PktProtocolQos.send_data( I|63:262142|7FFF): boff=0, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.373184: RE-SENT (6/24)

2021-10-05 08:11:20 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

2021-10-05 08:11:20 |000| HGI evoGateway -> CTL Controller |RQ| system_sync | REQUEST: system_sync

PktProtocolQos.send_data(RQ|01:196480|1F09): boff=1, want=RQ|01:196480|1F09, tout=2021-10-05 08:11:20.574637: RE-SENT (1/5)

2021-10-05 08:11:20 |000| HGI evoGateway -> CTL Controller |RQ| system_sync | REQUEST: system_sync

PktProtocolQos.send_data( I|63:262142|7FFF): boff=2, want= I|63:262142|7FFF, tout=2021-10-05 08:11:20.807278: RE-SENT (2/5)

PktProtocolQos.send_data(RQ|01:196480|1F09): boff=3, want=RQ|01:196480|1F09, tout=2021-10-05 08:11:21.209418: RE-SENT (3/5)

2021-10-05 08:11:20 |000| HGI evoGateway -> CTL Controller |RQ| system_sync | REQUEST: system_sync

PktProtocolQos.send_data(RQ|01:196480|1F09): boff=3, want=RQ|01:196480|1F09, tout=2021-10-05 08:11:21.657621: RE-SENT (4/5)

2021-10-05 08:11:21 |000| HGI evoGateway -> CTL Controller |RQ| system_sync | REQUEST: system_sync

PktProtocolQos.send_data( I|63:262142|7FFF): boff=3, want= I|63:262142|7FFF, tout=2021-10-05 08:11:22.099585: RE-SENT (5/5)

2021-10-05 08:11:21 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

PktProtocolQos.send_data(RQ|01:196480|1F09): boff=3, want=RP|01:196480|1F09, tout=2021-10-05 08:11:22.140281: EXPIRED (5/5)

2021-10-05 08:11:22 |000| HGI evoGateway -> CTL Controller |RQ| zone_devices | REQUEST: device_class: heating_control, domain_id: FC

PktProtocolQos.send_data( I|63:262142|7FFF): boff=1, want= I|63:262142|7FFF, tout=2021-10-05 08:11:22.341005: RE-SENT (1/2)

2021-10-05 08:11:22 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

PktProtocolQos.send_data(RQ|01:196480|000C|000F): boff=2, want=RQ|01:196480|000C|000F, tout=2021-10-05 08:11:22.606893: RE-SENT (2/2)

2021-10-05 08:11:22 |000| HGI evoGateway -> CTL Controller |RQ| zone_devices | REQUEST: device_class: heating_control, domain_id: FC

PktProtocolQos.send_data(RQ|01:196480|000C|000F): boff=2, want=RP|01:196480|000C|000F, tout=2021-10-05 08:11:22.641269: EXPIRED (2/2)

2021-10-05 08:11:22 |000| HGI evoGateway -> CTL Controller |RQ| zone_devices | REQUEST: device_class: hotwater_sensor, domain_id: FA

PktProtocolQos.send_data( I|63:262142|7FFF): boff=1, want= I|63:262142|7FFF, tout=2021-10-05 08:11:22.845021: RE-SENT (1/2)

2021-10-05 08:11:22 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

PktProtocolQos.send_data(RQ|01:196480|000C|000D): boff=2, want=RQ|01:196480|000C|000D, tout=2021-10-05 08:11:23.112799: RE-SENT (2/2)

2021-10-05 08:11:22 |000| HGI evoGateway -> CTL Controller |RQ| zone_devices | REQUEST: device_class: hotwater_sensor, domain_id: FA

PktProtocolQos.send_data(RQ|01:196480|000C|000D): boff=2, want=RP|01:196480|000C|000D, tout=2021-10-05 08:11:23.147261: EXPIRED (2/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> CTL Controller |RQ| tpi_params | REQUEST: tpi_params

PktProtocolQos.send_data( I|63:262142|7FFF): boff=1, want= I|63:262142|7FFF, tout=2021-10-05 08:11:23.350763: RE-SENT (1/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

PktProtocolQos.send_data(RQ|01:196480|1100): boff=2, want=RQ|01:196480|1100, tout=2021-10-05 08:11:23.617840: RE-SENT (2/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> CTL Controller |RQ| tpi_params | REQUEST: tpi_params

PktProtocolQos.send_data(RQ|01:196480|1100): boff=2, want=RP|01:196480|1100, tout=2021-10-05 08:11:23.650624: EXPIRED (2/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> CTL Controller |RQ| datetime | REQUEST: datetime

PktProtocolQos.send_data( I|63:262142|7FFF): boff=1, want= I|63:262142|7FFF, tout=2021-10-05 08:11:23.852058: RE-SENT (1/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> UNBOUND | I| puzzle_packet | ramses_rf: v0.11.0

PktProtocolQos.send_data(RQ|01:196480|313F): boff=2, want=RQ|01:196480|313F, tout=2021-10-05 08:11:24.118437: RE-SENT (2/2)

2021-10-05 08:11:23 |000| HGI evoGateway -> CTL Controller |RQ| datetime | REQUEST: datetime

PktProtocolQos.send_data( I|63:262142|7FFF): boff=2, want=RP|01:196480|313F, tout=2021-10-05 08:11:24.154319: EXPIRED (2/2)

2021-10-05 08:11:24 |000| HGI evoGateway -> CTL Controller |RQ| system_zones | REQUEST: zone_type: radiator_valve

PktProtocolQos.send_data(RQ|01:196480|0005|0008): boff=1, want=RQ|01:196480|0005|0008, tout=2021-10-05 08:11:24.376842: RE-SENT (1/2)

2021-10-05 08:11:24 |000| HGI evoGateway -> CTL Controller |RQ| system_zones | REQUEST: zone_type: radiator_valve

PktProtocolQos.send_data(RQ|01:196480|0005|0008): boff=2, want=RQ|01:196480|0005|0008, tout=2021-10-05 08:11:24.631599: RE-SENT (2/2)

2021-10-05 08:11:24 |000| HGI evoGateway -> CTL Controller |RQ| system_zones | REQUEST: zone_type: radiator_valve

PktProtocolQos.send_data(RQ|01:196480|0005|0008): boff=2, want=RP|01:196480|0005|0008, tout=2021-10-05 08:11:24.664674: EXPIRED (2/2)

smar000 commented 2 years ago

> However, I'm hoping someone could have a look at this log file section from startup. Are these constant RE-SENT entries showing a failure to send a command to the Controller? These lines also show up later during operation but infrequently.

I see these as well, but don't really worry about them. I think these are just the system retrying when it does not get a response within a certain time, but not 100% sure. As these are directly from the ramses_rf libraries, you could ask there if you wanted to understand better.

sveco86 commented 2 years ago

I had the same issue. It stopped when I updated evofw3 in my CC1101