Skip to content
This repository has been archived by the owner on Dec 14, 2022. It is now read-only.

"Handshake" suddenly stopped working - AC2889 #15

Open
ronaldt80 opened this issue Jan 4, 2021 · 24 comments
Open

"Handshake" suddenly stopped working - AC2889 #15

ronaldt80 opened this issue Jan 4, 2021 · 24 comments

Comments

@ronaldt80
Copy link

ronaldt80 commented Jan 4, 2021

The plugin has been running successfully over the weekend; all services work. Last night however the plugin stopped updating its status in home assistant ("handshake") - below the last log record which occurred at 22.46 last night (prior to this the "handshake" occurred at least once per 3 minutes).

2021-01-03 22:46:55 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xa4e2deb0: Type.NON 2.05 Content (MID 2131, token ba0d) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 3 option(s), 1128 byte(s) payload>
2021-01-03 22:46:55 DEBUG (MainThread) [coap] New unique message received
2021-01-03 22:46:55 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xa4e2deb0: Type.NON 2.05 Content (MID 2131, token ba0d) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 3 option(s), 1128 byte(s) payload>
2021-01-03 22:46:55 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xa4e2deb0: Type.NON 2.05 Content (MID 2131, token ba0d) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xa7a9aa90>
2021-01-03 22:46:55 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-01-03 22:46:55 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-01-03 22:46:55 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"0","pwr":"0","cl":false,"aqil":100,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":320,"fltsts1":4348,"fltsts2":1948,"range":"Comfort","Runtime":170510082,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}

Since last night the status is no longer updated, the purifier responds to commands given but (for example) the toggle does not move. Below output upon turning on and off this afternoon, note, machine was on, toggle showed off - log shows 2 times command on and once off (rapid clicking to get to the desired status).

2021-01-04 17:40:11 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "1"}}}
2021-01-04 17:40:11 DEBUG (MainThread) [coap] Sending request - Token: ba1a, Remote: <UDP6EndpointAddress xxx.xxx.x.x>
2021-01-04 17:40:11 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0xa58d7148: Type.NON POST (MID 52481, token ba1a) remote <UDP6EndpointAddress xxx.xxx.x.x>, 2 option(s), 264 byte(s) payload>
2021-01-04 17:40:11 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xa4e5d250: Type.NON 2.05 Content (MID 52481, token ba1a) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:11 DEBUG (MainThread) [coap] New unique message received
2021-01-04 17:40:11 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xa4e5d250: Type.NON 2.05 Content (MID 52481, token ba1a) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:11 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xa4e5d250: Type.NON 2.05 Content (MID 52481, token ba1a) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 1 option(s), 20 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xa553d0e8>
2021-01-04 17:40:11 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"success"}'
2021-01-04 17:40:21 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "1"}}}
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Sending request - Token: ba1b, Remote: <UDP6EndpointAddress xxx.xxx.x.x >
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0x9fdde310: Type.NON POST (MID 52482, token ba1b) remote <UDP6EndpointAddress xxx.xxx.x.x >, 2 option(s), 264 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0x9fdde730: Type.NON 2.05 Content (MID 52482, token ba1b) remote <UDP6EndpointAddress xxx.xxx.x.x  with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] New unique message received
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0x9fdde730: Type.NON 2.05 Content (MID 52482, token ba1b) remote <UDP6EndpointAddress xxx.xxx.x.x  with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0x9fdde730: Type.NON 2.05 Content (MID 52482, token ba1b) remote <UDP6EndpointAddress xxx.xxx.x.x  with local address>, 1 option(s), 20 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0x9fddefe8>
2021-01-04 17:40:21 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"success"}'
2021-01-04 17:40:21 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "0"}}}
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Sending request - Token: ba1c, Remote: <UDP6EndpointAddress xxx.xxx.x.x >
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0x9fdde988: Type.NON POST (MID 52483, token ba1c) remote <UDP6EndpointAddress xxx.xxx.x.x >, 2 option(s), 264 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xa50255c8: Type.NON 2.05 Content (MID 52483, token ba1c) remote <UDP6EndpointAddress xxx.xxx.x.x  with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] New unique message received
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xa50255c8: Type.NON 2.05 Content (MID 52483, token ba1c) remote <UDP6EndpointAddress xxx.xxx.x.x  with local address>, 1 option(s), 20 byte(s) payload>
2021-01-04 17:40:21 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xa50255c8: Type.NON 2.05 Content (MID 52483, token ba1c) remote <UDP6EndpointAddress xxx.xxx.x.x with local address>, 1 option(s), 20 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xa5025f58>
2021-01-04 17:40:21 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"success"}'

A homeassistant restart solves the issue temporarily. Any thoughts what could be the issue? Let me know if more information is required.

thanks for any guidance given!

Ronald

@tunip
Copy link

tunip commented Jan 8, 2021

Same behavior on my AC2889.

I see also this message in the debug log:

2021-01-08 10:10:26 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0x7f8358ae3f10: Type.NON 2.05 Content (MID 55817, token bf58) remote <UDP6EndpointAddress 192.168.5.19 with local address>, 1 option(s), 19 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0x7f8358ae3040>
2021-01-08 10:10:26 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"failed"}'
2021-01-08 10:10:26 DEBUG (MainThread) [aioairctrl.coap.client] set_control_value failed. resyncing...
2021-01-08 10:10:26 DEBUG (MainThread) [aioairctrl.coap.client] syncing
2021-01-08 10:10:26 DEBUG (MainThread) [coap] Sending request - Token: bf59, Remote: <UDP6EndpointAddress 192.168.5.19>
2021-01-08 10:10:26 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0x7f8358ae3d30: Type.NON POST (MID 55818, token bf59) remote <UDP6EndpointAddress 192.168.5.19>, 2 option(s), 8 byte(s) payload>

@o0v7r0o
Copy link

o0v7r0o commented Jan 31, 2021

I just started digging into the code but my assumption is that the issue pops up when the 'server' (purifier) restarts, but 'client' (philips-airpurifier -> aioairctrl -> aiocoap) is not requesting a new observation.
Here are the diagrams how it should look like:
https://tools.ietf.org/html/draft-ietf-core-observe-08#appendix-A

So ideally max-age should be taken into account and the client have to start from scratch if max-age is overdue or an exception from aiocoap is raised.
BTW there is similar issue with tradfri integration, chrysn/aiocoap#224, it might be useful to look how it is solved there.

@betaboon
Copy link
Owner

@ronaldt80 @tunip i just released a new version which might help adressing your issues

if you find the time please test and report back :)

@o0v7r0o thank you for digging into this. i think the reconnection issue is somewhat unrelated but should indeed be taken a look at. I'll try to reproduce that locally and if that is indeed a problem open an issue for it and mention you :)

@ronaldt80
Copy link
Author

ronaldt80 commented Mar 17, 2021 via email

@tunip
Copy link

tunip commented Mar 17, 2021

Started testing now... will also report the next few days. Thx for your work!

@tunip
Copy link

tunip commented Mar 18, 2021

Tested it just now and it is not solved. Need to enable debug logging and provide logs later.

@ronaldt80
Copy link
Author

ronaldt80 commented Mar 18, 2021 via email

@betaboon
Copy link
Owner

thank you guys for testing. can you provide me with more comprehensive debug-logs ?

@tunip
Copy link

tunip commented Mar 19, 2021

@betaboon

Attached you will find my logs.

SWITCHING ON (Turning the switch in HA to on. Air Purifier is running, while the switch in HA goes back to off from alone):

2021-03-19 17:16:21,435 - aioairctrl.coap.client - DEBUG - REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "1"}}}
2021-03-19 17:16:21,441 - coap - DEBUG - Sending request - Token: e6e0, Remote: <UDP6EndpointAddress 192.168.18.177>
2021-03-19 17:16:21,442 - coap - DEBUG - Sending message <aiocoap.Message at 0x7ffa21eb04c0: Type.NON POST (MID 64892, token e6e0) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload>
2021-03-19 17:16:21,755 - coap - DEBUG - Incoming message <aiocoap.Message at 0x7ffa2a077fd0: Type.NON 2.05 Content (MID 64892, token e6e0) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 19 byte(s) payload>
2021-03-19 17:16:21,759 - coap - DEBUG - Received Response: <aiocoap.Message at 0x7ffa2a077fd0: Type.NON 2.05 Content (MID 64892, token e6e0) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 19 byte(s) payload>
2021-03-19 17:16:21,761 - coap - DEBUG - Response <aiocoap.Message at 0x7ffa2a077fd0: Type.NON 2.05 Content (MID 64892, token e6e0) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 19 byte(s) payload> matched to request <PlumbingRequest at 0x7ffa21dc8190 around <aiocoap.Message at 0x7ffa21eb04c0: Type.NON POST (MID 64892, token e6e0) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload> with 2 callbacks>
2021-03-19 17:16:21,764 - aioairctrl.coap.client - DEBUG - RESPONSE: b'{"status":"failed"}'
2021-03-19 17:16:21,767 - aioairctrl.coap.client - DEBUG - set_control_value failed. resyncing...
2021-03-19 17:16:21,767 - aioairctrl.coap.client - DEBUG - syncing
2021-03-19 17:16:21,774 - coap - DEBUG - Sending request - Token: e6e1, Remote: <UDP6EndpointAddress 192.168.18.177>
2021-03-19 17:16:21,775 - coap - DEBUG - Sending message <aiocoap.Message at 0x7ffa28ec1040: Type.NON POST (MID 64893, token e6e1) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 8 byte(s) payload>
2021-03-19 17:16:21,781 - coap - DEBUG - Incoming message <aiocoap.Message at 0x7ffa21dc8f10: Type.NON 2.05 Content (MID 64893, token e6e1) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 8 byte(s) payload>
2021-03-19 17:16:21,783 - coap - DEBUG - Received Response: <aiocoap.Message at 0x7ffa21dc8f10: Type.NON 2.05 Content (MID 64893, token e6e1) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 8 byte(s) payload>
2021-03-19 17:16:21,784 - coap - DEBUG - Response <aiocoap.Message at 0x7ffa21dc8f10: Type.NON 2.05 Content (MID 64893, token e6e1) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 8 byte(s) payload> matched to request <PlumbingRequest at 0x7ffa21dac430 around <aiocoap.Message at 0x7ffa28ec1040: Type.NON POST (MID 64893, token e6e1) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 8 byte(s) payload> with 2 callbacks>
2021-03-19 17:16:21,786 - aioairctrl.coap.client - DEBUG - synced: 3B3A7727
2021-03-19 17:16:21,787 - aioairctrl.coap.client - DEBUG - set_control_value failed. retrying...
2021-03-19 17:16:21,787 - aioairctrl.coap.client - DEBUG - REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "1"}}}
2021-03-19 17:16:21,790 - coap - DEBUG - Sending message <aiocoap.Message at 0x7ffa23fb6f40: Type.NON POST (MID 64894, token e6e2) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload>
2021-03-19 17:16:21,797 - coap - DEBUG - Incoming message <aiocoap.Message at 0x7ffa28ec10d0: Type.NON 2.05 Content (MID 64894, token e6e2) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:16:21,798 - coap - DEBUG - Received Response: <aiocoap.Message at 0x7ffa28ec10d0: Type.NON 2.05 Content (MID 64894, token e6e2) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:16:21,799 - coap - DEBUG - Response <aiocoap.Message at 0x7ffa28ec10d0: Type.NON 2.05 Content (MID 64894, token e6e2) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload> matched to request <PlumbingRequest at 0x7ffa21eb0340 around <aiocoap.Message at 0x7ffa23fb6f40: Type.NON POST (MID 64894, token e6e2) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload> with 2 callbacks>
2021-03-19 17:16:21,800 - aioairctrl.coap.client - DEBUG - RESPONSE: b'{"status":"success"}'

SWITCHING OFF (Turning the switch in HA to on and immediately to off. Air Purifier is switching off):

2021-03-19 17:19:16,443 - aioairctrl.coap.client - DEBUG - REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "1"}}}
2021-03-19 17:19:16,449 - coap - DEBUG - Sending request - Token: e6e3, Remote: <UDP6EndpointAddress 192.168.18.177>
2021-03-19 17:19:16,451 - coap - DEBUG - Sending message <aiocoap.Message at 0x7ffa23fb49d0: Type.NON POST (MID 64895, token e6e3) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload>
2021-03-19 17:19:16,470 - coap - DEBUG - Incoming message <aiocoap.Message at 0x7ffa21ea94f0: Type.NON 2.05 Content (MID 64895, token e6e3) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:19:16,471 - coap - DEBUG - Received Response: <aiocoap.Message at 0x7ffa21ea94f0: Type.NON 2.05 Content (MID 64895, token e6e3) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:19:16,473 - coap - DEBUG - Response <aiocoap.Message at 0x7ffa21ea94f0: Type.NON 2.05 Content (MID 64895, token e6e3) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload> matched to request <PlumbingRequest at 0x7ffa21ea9b80 around <aiocoap.Message at 0x7ffa23fb49d0: Type.NON POST (MID 64895, token e6e3) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload> with 2 callbacks>
2021-03-19 17:19:16,476 - aioairctrl.coap.client - DEBUG - RESPONSE: b'{"status":"success"}'
2021-03-19 17:19:17,324 - aioairctrl.coap.client - DEBUG - REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "0"}}}
2021-03-19 17:19:17,329 - coap - DEBUG - Sending request - Token: e6e4, Remote: <UDP6EndpointAddress 192.168.18.177>
2021-03-19 17:19:17,333 - coap - DEBUG - Sending message <aiocoap.Message at 0x7ffa333df850: Type.NON POST (MID 64896, token e6e4) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload>
2021-03-19 17:19:17,341 - coap - DEBUG - Incoming message <aiocoap.Message at 0x7ffa23ef29a0: Type.NON 2.05 Content (MID 64896, token e6e4) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:19:17,342 - coap - DEBUG - Received Response: <aiocoap.Message at 0x7ffa23ef29a0: Type.NON 2.05 Content (MID 64896, token e6e4) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload>
2021-03-19 17:19:17,344 - coap - DEBUG - Response <aiocoap.Message at 0x7ffa23ef29a0: Type.NON 2.05 Content (MID 64896, token e6e4) remote <UDP6EndpointAddress 192.168.18.177 (locally 192.168.8.40%eth0)>, 1 option(s), 20 byte(s) payload> matched to request <PlumbingRequest at 0x7ffa23ef2d00 around <aiocoap.Message at 0x7ffa333df850: Type.NON POST (MID 64896, token e6e4) remote <UDP6EndpointAddress 192.168.18.177>, 1 option(s), 264 byte(s) payload> with 2 callbacks>
2021-03-19 17:19:17,346 - aioairctrl.coap.client - DEBUG - RESPONSE: b'{"status":"success"}'

@betaboon
Copy link
Owner

@tunip thank you for the logs.

could you please provide logs with more "context" (aka logs before and after) ?
it seems like there is no status-update coming from the device.

it would be nice to have a log with like 1sec before 5secs after (in a gist)

@ronaldt80
Copy link
Author

ronaldt80 commented Mar 19, 2021 via email

@tunip
Copy link

tunip commented Mar 19, 2021

Maybe this is the issue... There are no log entries before and after I switch the device on and off (on/off).

@betaboon
Copy link
Owner

Maybe this is the issue... There are no log entries before and after I switch the device on and off (on/off).

@tunip can you try to using aioairctrl as described here but run aioairctrl -D -H $DEVICE_IP status-observe --json and then fiddle around with the official app? just so we're sure the observations work at all

@ronaldt80
Copy link
Author

Regular behavior observed in the log since 11pm 18 March (last HA restart), log is filled with regular "handshakes" this suddenly stops at 12.45pm CET (no error message in the log)

2021-03-19 12:40:20 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7ca977f0: Type.NON 2.05 Content (MID 5501, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:40:20 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:40:20 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7ca977f0: Type.NON 2.05 Content (MID 5501, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:40:20 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7ca977f0: Type.NON 2.05 Content (MID 5501, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:40:20 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:40:20 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:40:20 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204078180,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:41:21 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7bf47d00: Type.NON 2.05 Content (MID 5502, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:41:21 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:41:21 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7bf47d00: Type.NON 2.05 Content (MID 5502, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:41:21 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7bf47d00: Type.NON 2.05 Content (MID 5502, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:41:21 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:41:21 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:41:21 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204139240,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:42:15 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7bf69940: Type.NON 2.05 Content (MID 5503, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:15 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:42:15 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7bf69940: Type.NON 2.05 Content (MID 5503, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:15 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7bf69940: Type.NON 2.05 Content (MID 5503, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:42:15 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:42:15 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:42:15 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204192745,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:42:26 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7eef4a30: Type.NON 2.05 Content (MID 5504, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:26 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:42:26 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7eef4a30: Type.NON 2.05 Content (MID 5504, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:26 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7eef4a30: Type.NON 2.05 Content (MID 5504, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:42:26 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:42:26 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:42:26 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204204527,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:42:28 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7deac6d0: Type.NON 2.05 Content (MID 5505, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:28 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:42:28 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7deac6d0: Type.NON 2.05 Content (MID 5505, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:42:28 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7deac6d0: Type.NON 2.05 Content (MID 5505, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:42:28 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:42:28 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:42:28 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204205609,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:43:16 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff2e851880: Type.NON 2.05 Content (MID 5506, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:16 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:43:16 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff2e851880: Type.NON 2.05 Content (MID 5506, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:16 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff2e851880: Type.NON 2.05 Content (MID 5506, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:43:16 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:43:16 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:43:16 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204253767,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:43:18 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xfffec700b910: Type.NON 2.05 Content (MID 5507, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:18 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:43:18 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xfffec700b910: Type.NON 2.05 Content (MID 5507, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:18 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xfffec700b910: Type.NON 2.05 Content (MID 5507, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:43:18 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:43:18 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:43:18 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204255921,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:43:22 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7b1b48b0: Type.NON 2.05 Content (MID 5508, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:22 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:43:22 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7b1b48b0: Type.NON 2.05 Content (MID 5508, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:22 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7b1b48b0: Type.NON 2.05 Content (MID 5508, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:43:22 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:43:22 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:43:22 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204260214,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:43:48 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff807ba370: Type.NON 2.05 Content (MID 5509, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:48 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:43:48 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff807ba370: Type.NON 2.05 Content (MID 5509, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:48 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff807ba370: Type.NON 2.05 Content (MID 5509, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:43:48 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:43:48 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:43:48 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204285908,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:43:52 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xfffec713a340: Type.NON 2.05 Content (MID 5510, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:52 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:43:52 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xfffec713a340: Type.NON 2.05 Content (MID 5510, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:43:52 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xfffec713a340: Type.NON 2.05 Content (MID 5510, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:43:52 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:43:52 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:43:52 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":3,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204290202,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:44:49 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7d89d6d0: Type.NON 2.05 Content (MID 5511, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:44:49 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:44:49 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7d89d6d0: Type.NON 2.05 Content (MID 5511, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:44:49 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7d89d6d0: Type.NON 2.05 Content (MID 5511, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:44:49 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:44:49 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:44:49 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":2,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204346927,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}
2021-03-19 12:44:52 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7da4e430: Type.NON 2.05 Content (MID 5512, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:44:52 DEBUG (MainThread) [coap] New unique message received
2021-03-19 12:44:52 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7da4e430: Type.NON 2.05 Content (MID 5512, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload>
2021-03-19 12:44:52 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7da4e430: Type.NON 2.05 Content (MID 5512, token c5b4) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 3 option(s), 1128 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f1d9160>
2021-03-19 12:44:52 DEBUG (MainThread) [coap.blockwise-requester] Notification received
2021-03-19 12:44:52 DEBUG (MainThread) [coap.blockwise-requester] Reporting completed notification
2021-03-19 12:44:52 DEBUG (MainThread) [aioairctrl.coap.client] observation status: {"state":{"reported":{"name":"Office","type":"AC2889","modelid":"AC2889/10","swversion":"1.0.7","om":"1","pwr":"1","cl":false,"aqil":20,"uil":"2","dt":0,"dtrs":0,"mode":"A","pm25":1,"iaql":1,"aqit":4,"ddp":"0","err":0,"fltt1":"A3","fltt2":"C7","fltsts0":244,"fltsts1":3873,"fltsts2":1473,"range":"Comfort","Runtime":204350149,"WifiVersion":"[email protected]","ProductId":"be10acb2e62411e8a1e3061302926720","DeviceId":"ae703a000f9b11eb86326a05de4f87e8","StatusType":"localcontrol","ConnectType":"Localcontrol"}}}

Schedule off automation through "service call"

2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "0"}}}
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending request - Token: c5c5, Remote: <UDP6EndpointAddress 192.168.xxx.xxx>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0xffff6c67c460: Type.NON POST (MID 43446, token c5c5) remote <UDP6EndpointAddress 192.168.xxx.xxx>, 2 option(s), 264 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7c2fec40: Type.NON 2.05 Content (MID 43446, token c5c5) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 19 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] New unique message received
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7c2fec40: Type.NON 2.05 Content (MID 43446, token c5c5) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 19 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7c2fec40: Type.NON 2.05 Content (MID 43446, token c5c5) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 19 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7c2fea60>
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"failed"}'
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] set_control_value failed. resyncing...
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] syncing
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending request - Token: c5c6, Remote: <UDP6EndpointAddress 192.168.xxx.xxx>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0xffff7d755d30: Type.NON POST (MID 43447, token c5c6) remote <UDP6EndpointAddress 192.168.xxx.xxx>, 2 option(s), 8 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7b179a60: Type.NON 2.05 Content (MID 43447, token c5c6) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 8 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] New unique message received
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7b179a60: Type.NON 2.05 Content (MID 43447, token c5c6) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 8 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7b179a60: Type.NON 2.05 Content (MID 43447, token c5c6) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 8 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xfffec6ff42b0>
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] synced: 5851F42E
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] set_control_value failed. retrying...
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "0"}}}
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending request - Token: c5c7, Remote: <UDP6EndpointAddress 192.168.xxx.xxx>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0xfffec70c87f0: Type.NON POST (MID 43448, token c5c7) remote <UDP6EndpointAddress 192.168.xxx.xxx>, 2 option(s), 264 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xfffea9e172e0: Type.NON 2.05 Content (MID 43448, token c5c7) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] New unique message received
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xfffea9e172e0: Type.NON 2.05 Content (MID 43448, token c5c7) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload>
2021-03-19 16:30:00 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xfffea9e172e0: Type.NON 2.05 Content (MID 43448, token c5c7) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7f8bc340>
2021-03-19 16:30:00 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"success"}'

Manual on/off command in HA (switch "flips" back)

2021-03-19 18:51:40 DEBUG (MainThread) [aioairctrl.coap.client] REQUEST: {"state": {"desired": {"CommandType": "app", "DeviceId": "", "EnduserId": "", "pwr": "0"}}}
2021-03-19 18:51:40 DEBUG (MainThread) [coap] Sending request - Token: c5c8, Remote: <UDP6EndpointAddress 192.168.xxx.xxx>
2021-03-19 18:51:40 DEBUG (MainThread) [coap] Sending message <aiocoap.Message at 0xffff7d38e7c0: Type.NON POST (MID 43449, token c5c8) remote <UDP6EndpointAddress 192.168.xxx.xxx>, 2 option(s), 264 byte(s) payload>
2021-03-19 18:51:40 DEBUG (MainThread) [coap] Incoming message <aiocoap.Message at 0xffff7e4c7c70: Type.NON 2.05 Content (MID 43449, token c5c8) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload>
2021-03-19 18:51:40 DEBUG (MainThread) [coap] New unique message received
2021-03-19 18:51:40 DEBUG (MainThread) [coap] Received Response: <aiocoap.Message at 0xffff7e4c7c70: Type.NON 2.05 Content (MID 43449, token c5c8) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload>
2021-03-19 18:51:40 DEBUG (MainThread) [coap] Response <aiocoap.Message at 0xffff7e4c7c70: Type.NON 2.05 Content (MID 43449, token c5c8) remote <UDP6EndpointAddress 192.168.xxx.xxx with local address>, 1 option(s), 20 byte(s) payload> matched to request <aiocoap.tokenmanager.PlumbingRequest object at 0xffff7d4c7cd0>
2021-03-19 18:51:40 DEBUG (MainThread) [aioairctrl.coap.client] RESPONSE: b'{"status":"success"}'

@ronaldt80
Copy link
Author

ronaldt80 commented Mar 19, 2021

Happy to also try the aioairctrl command but I run HassOS - not sure how to run aioairctrl manually; tried through SSH cli but that does not work. Any tips?

@betaboon
Copy link
Owner

Happy to also try the aioairctrl command but I run HassOS - not sure how to run aioairctrl manually; tried through SSH cli but that does not work. Any tips?

you can just clone the repository on your local machine and run the stuff there :)

@tunip
Copy link

tunip commented Mar 19, 2021

@ronaldt80 I run the official Home Assistant docker container. I installed aioairctrl in /tmp inside the container. Will test later the "observations" with aioairctrl and the official app.

@tunip
Copy link

tunip commented Mar 20, 2021

aioairctrl output

Using the "Clean Home+" app (ON/OF, Speeds, Light, Mode, etc.):
https://gist.github.com/tunip/bc85881a6306975b9cead2b28edf2639

Interval output (every few minutes) without manual action:
https://gist.github.com/tunip/87df2b14f9332b7e7f87923cb2b737b6

@kolomiichenko
Copy link

same problem on ac2729

@betaboon
Copy link
Owner

hey guys. I'm sorry but currently i dont have the time to look further into it.
I'll try to find some time in the future ;)

@pasce
Copy link

pasce commented May 6, 2021

just curious: does anyone already know why this could happen?

@smhagit
Copy link

smhagit commented May 13, 2021

I've also bought a Philips (AC2889/10; swversion:1.0.7; [email protected]).

The integration stops sending data after about 50 to 70 hours but will still react to commands like turning on or control the fan.
After restarting the HA Core, the data comes in again immediately and it runs for the next few days.

I ran Homeassistant on a Raspberry and executed the following command in the homeassistant container right after I restarted the core.
nohup aioairctrl -D -H 192.168.2.92 status-observe --json > /config/aioairctrl_logs/debug_13_05_-16_52.nohup &

Will wait the next few days until it's broken again. Then I will have a complete log and will try to dive deeper from this starting point.

Any ideas what it could be?

EDIT

After restarting the HA Core, the data comes in again immediately and it runs for the next few days.

...mhhh not completely correct. just for a few hours...

@kongo09
Copy link

kongo09 commented May 13, 2021

After restarting the HA Core, the data comes in again immediately

The describes pretty much what I observe with my two devices. Strange thing is, after all the work of @betaboon including his monkeycode fixing of the upstream python library for coap, the devices used to work without a problem. Now they just stopped, but a reboot of HA fixes this. I've now set HA to reboot automatically every night. Surely not a nice workaround.

@mhetzi mhetzi mentioned this issue Aug 17, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

9 participants