Device not reachable in phoscon still receiving data in domoticz

[niawag]

Hi, I've been using this plugin for a long time and it's great, thanks for your work on it.

I noticed that some of my sensors (xiaomi aqara T/H/P) are reported as "not reachable" in Phoscon App but the deCONZ plugin keep getting the same values and the sensors are not reported as timed out in domoticz, as you can see for this device:

curl -s 'http://192.168.0.44:8080/json.htm?type=devices&rid=104'
{
        "ActTime" : 1649081872,
        "AstrTwilightEnd" : "22:01",
        "AstrTwilightStart" : "05:25",
        "CivTwilightEnd" : "20:44",
        "CivTwilightStart" : "06:41",
        "DayLength" : "13:00",
        "NautTwilightEnd" : "21:21",
        "NautTwilightStart" : "06:04",
        "ServerTime" : "2022-04-04 16:17:52",
        "SunAtSouth" : "13:43",
        "Sunrise" : "07:12",
        "Sunset" : "20:13",
        "app_version" : "2022.1 (build 14294)",
        "result" :
        [
                {
                        "AddjMulti" : 1.0,
                        "AddjMulti2" : 1.0,
                        "AddjValue" : 0.0,
                        "AddjValue2" : 0.0,
                        "BatteryLevel" : 95,
                        "CustomImage" : 0,
                        "Data" : "19.8 C",
                        "Description" : "",
                        "Favorite" : 1,
                        "HardwareDisabled" : false,
                        "HardwareID" : 16,
                        "HardwareName" : "deCONZ",
                        "HardwareType" : "deCONZ plugin",
                        "HardwareTypeVal" : 94,
                        "HaveTimeout" : false,
                        "ID" : "00:15:8d:00:05:88:92:52-01-0402",
                        "LastUpdate" : "2022-04-04 10:10:35",
                        "Name" : "Bureau Ju",
                        "Notifications" : "false",
                        "PlanID" : "0",
                        "PlanIDs" :
                        [
                                0
                        ],
                        "Protected" : false,
                        "ShowNotifications" : true,
                        "SignalLevel" : "-",
                        "SubType" : "LaCrosse TX3",
                        "Temp" : 19.809999999999999,
                        "Timers" : "false",
                        "Type" : "Temp",
                        "TypeImg" : "temperature",
                        "Unit" : 30,
                        "Used" : 1,
                        "XOffset" : "0",
                        "YOffset" : "0",
                        "idx" : "104",
                        "trend" : 0
                }
        ],
        "status" : "OK",
        "title" : "Devices"
}

As you can see, the status is "OK", the Temp value is also set. In the domoticz log I can read that: 2022-04-04 16:27:40.329 deCONZ: ### Device > 25 Name:Bureau Ju Type:ZHATemperature Details:{'lastupdated': '2022-03-27T12:36:55.318', 'temperature': 1981} and {'battery': 95, 'offset': 0, 'on': True, 'reachable': False}

But "reachable: false" or the "'lastupdated': '2022-03-27T12:36:55.318'" does not seem to result in a timeout in domoticz.

Is it a normal behaviour ? Is there something I can do to troubleshoot it ?

[Smanar]

Hello, sorry I have notification problem, haven't see your post. I have tried yesterday to make a device disconnect with puting a sensor in a metal box, and have failed, still connected, so making another try.

And no, it's not normal. Can you show the debug line just after this one ? The one starting by ### Update device

On a normal way this debug log is producted at start, so you need to have "TimedOut : 1" in the previous debug line. After that even you receive notification as the value don't change, you need to stay in TimedOut.

Edit: I have updated the code on the beta, can you make a try with the new version ? On the plugin folder ...

git pull
git checkout beta
git pull

I think at start the sensor is marked in TimedOut, but this state is removed immedialtly.

[niawag]

Hi and thanks for your help!

As I've re-paired the failing sensors it may take some time to test. I've put the battery out of on of them and I'll check from time to time how it appears in Phoscon and in Domoticz. As of now, phoscon is still reporting it as "last seen 20 minutes ago" and domoticz keep getting data every 5 minutes (I removed the battery at 14h35):

I've updated to beta after the screenshot, I'll report as soon as the device is not reachable in Phoscon

Is it the debug lines you want to see ?

2022-04-09 15:04:29.413  deCONZ: ### Device > 20 Name:Bureau Gawain Type:ZHATemperature Details:{'lastupdated': '2022-04-09T12:34:45.627', 'temperature': 2022} and {'battery': 100, 'offset': 0, 'on': True, 'reachable': True}
2022-04-09 15:04:29.414  deCONZ: ### Update  device (Bureau Gawain) : {'nValue': 0, 'sValue': '20.22', 'BatteryLevel': 100}, IGNORED , no changes !

I'll add this line asap

[Smanar]

Yep, it s this one, but like you have said need some time for the sensor be displayed as unreacheable. I m making same on my side, 18h it was not reacheable, still 6h to wait for.

[Smanar]

Ok, 2 days without zigbee notifications, but the device is still reachable on my side on phosocn.

Edit: Ok so was the lastupdated time, the lastseen is good, have failed to make the sensor leave again, serioulsy how thoses device can leave on some users ... In a metal box, 10m from the closer router.

[niawag]

It's only been 20h for me so still a bit of time to wait...

As of now the log does not show other information about the sensor and there is no data logged, the domoticz report ends at 15:40. On my initial post my Pi3 was under too much load and was frequently restarting, it seems the failing sensors were updated on each Domoticz and/or Deconz restart. I reduced the Pi3 load now so let's see how it works !

[niawag]

Hi, I'm not sure what is going on, for now Domoticz keeps showing the timed out device as ok, and even added data. The log seems to be ok as you can see:

2022-04-09 15:04:29.413  deCONZ: ### Device > 20 Name:Bureau Gawain Type:ZHATemperature Details:{'lastupdated': '2022-04-09T12:34:45.627', 'temperature': 2022} and {'battery': 100, 'offset': 0, 'on': True, 'reachable': True}
2022-04-09 15:04:29.414  deCONZ: ### Update  device (Bureau Gawain) : {'nValue': 0, 'sValue': '20.22', 'BatteryLevel': 100}, IGNORED , no changes !
2022-04-09 15:04:29.414  deCONZ: ### Device > 21 Name:Bureau Gawain Type:ZHAHumidity Details:{'humidity': 6726, 'lastupdated': '2022-04-09T12:34:45.665'} and {'battery': 100, 'offset': 0, 'on': True, 'reachable': True}
2022-04-09 15:04:29.415  deCONZ: ### Update  device (Bureau Gawain) : {'nValue': 67, 'sValue': '1', 'BatteryLevel': 100}, IGNORED , no changes !
2022-04-09 15:04:29.415  deCONZ: ### Device > 24 Name:Bureau Gawain Type:ZHAPressure Details:{'lastupdated': '2022-04-09T12:29:33.680', 'pressure': 990} and {'battery': 100, 'offset': 0, 'on': True, 'reachable': True}
2022-04-09 15:04:29.416  deCONZ: ### Update  device (Bureau Gawain) : {'nValue': 0, 'sValue': '990;4', 'BatteryLevel': 100}, IGNORED , no changes !
2022-04-10 14:37:34.481  deCONZ: ### Update  device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 67, 'sValue': '1'}
2022-04-10 14:37:34.481  (Bureau Gawain) Updating device from 67:'1' to have values 67:'1'.
2022-04-10 14:37:34.495  deCONZ: ### Update  device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '20.22'}
2022-04-10 14:37:34.495  (Bureau Gawain) Updating device from 0:'20.22' to have values 0:'20.22'.
2022-04-10 14:37:34.506  deCONZ: ### Update  device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '990;4'}
2022-04-10 14:37:34.507  (Bureau Gawain) Updating device from 0:'990;4' to have values 0:'990;4'.

The first couples of lines (2022-04-09 15:04:29) are the last one before removing the battery, the others are when Deconz report the device as TimedOut (2022-04-10 14:37:34). And here is the csv of temperature data:

09/04/2022 15:35 | 20,22
09/04/2022 15:40 | 20,22
10/04/2022 14:40 | 20,22
10/04/2022 14:45 | 20,22
10/04/2022 14:50 | 20,22
10/04/2022 14:55 | 20,22
10/04/2022 15:00 | 20,22
10/04/2022 15:05 | 20,22
10/04/2022 15:10 | 20,22
10/04/2022 15:15 | 20,22
10/04/2022 15:20 | 20,22
10/04/2022 15:25 | 20,22
10/04/2022 15:30 | 20,22
10/04/2022 15:35 | 20,22

As you can see, there is an hour of data from 14:40 to 15:35 (10/04), I don't know why. The sensor timeout in domoticz is set at 60 minutes so the device should be marked as timed out in domoticz.

[Smanar]

I think you had thoses line only 1 time ?

2022-04-10 14:37:34.495  deCONZ: ### Update  device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '20.22'}
2022-04-10 14:37:34.495  (Bureau Gawain) Updating device from 0:'20.22' to have values 0:'20.22'.

Because the plugin update sensor only if there is new value.

2022-04-10 14:37:34.495 (Bureau Gawain) Updating device from 0:'20.22' to have values 0:'20.22'.

I think here it was updated for the TimedOut value, because values are sames, you will have in logs ", IGNORED , no changes !" for the next ones.

As you can see, there is an hour of data from 14:40 to 15:35 (10/04), I don't know why.

For me it's normal, it's domoticz itself that wrote the last value every 5 mn, even you don't update the device.

The sensor timeout in domoticz is set at 60 minutes so the device should be marked as timed out in domoticz.

At wich one moment ? On deconz a sensor is marked as unreachable after 24h, so deconz can send notification during 24h after the disconnection for this device (but wich one ? there is no new values, no battery , .... ). After that, it have the unreachable state {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 67, 'sValue': '1'} and was marked as unreachable in domoticz. And the plugin stop update the widget if there is no new values and a reachable = true.

But yes If you use the sensor timeout feature from domoticz, without update during 60 min, the device need to be set in error too. You are seing the plugin updating the sensor during this period ? On the "device panel" you have too the "lastseen" for domoticz.

[niawag]

I have three (x2) lines because this sensors sends Temp, Hum and Pression information. I didn't know that domoticz writes the same value every 5 minutes when there is no change, ok for that too.

The device in domoticz shows "last seen a day ago" so it's working but the device does not show "timed out" as it should (because the 60 min timeout is way gone). Here is the result of this command curl -s 'http://192.168.0.44:8080/json.htm?type=devices&rid=101' :

{
        "ActTime" : 1649691767,
        "AstrTwilightEnd" : "22:14",
        "AstrTwilightStart" : "05:08",
        "CivTwilightEnd" : "20:54",
        "CivTwilightStart" : "06:27",
        "DayLength" : "13:24",
        "NautTwilightEnd" : "21:32",
        "NautTwilightStart" : "05:49",
        "ServerTime" : "2022-04-11 17:42:47",
        "SunAtSouth" : "13:41",
        "Sunrise" : "06:59",
        "Sunset" : "20:23",
        "app_version" : "2022.1 (build 14294)",
        "result" :
        [
                {
                        "AddjMulti" : 1.0,
                        "AddjMulti2" : 1.0,
                        "AddjValue" : 0.0,
                        "AddjValue2" : 0.0,
                        "BatteryLevel" : 100,
                        "CustomImage" : 0,
                        "Data" : "20.2 C",
                        "Description" : "",
                        "Favorite" : 1,
                        "HardwareDisabled" : false,
                        "HardwareID" : 16,
                        "HardwareName" : "deCONZ",
                        "HardwareType" : "deCONZ plugin",
                        "HardwareTypeVal" : 94,
                        "HaveTimeout" : false,
                        "ID" : "00:15:8d:00:05:8a:61:15-01-0402",
                        "LastUpdate" : "2022-04-10 14:37:34",
                        "Name" : "Bureau Gawain",
                        "Notifications" : "false",
                        "PlanID" : "0",
                        "PlanIDs" :
                        [
                                0
                        ],
                        "Protected" : false,
                        "ShowNotifications" : true,
                        "SignalLevel" : "-",
                        "SubType" : "LaCrosse TX3",
                        "Temp" : 20.219999999999999,
                        "Timers" : "false",
                        "Type" : "Temp",
                        "TypeImg" : "temperature",
                        "Unit" : 27,
                        "Used" : 1,
                        "XOffset" : "0",
                        "YOffset" : "0",
                        "idx" : "101",
                        "trend" : 0
                }
        ],
        "status" : "OK",
        "title" : "Devices"
}

As you can see, it returned "HaveTimeout" : false,, is that normal?

[Smanar]

"LastUpdate" : "2022-04-10 14:37:34", The sensor timeout in domoticz is set at 60 minutes

Seriously I m making test on my side, I will ask on domoticz forum how this feature, because I have set the minimum value, and only 1 sensor have been impacted by this setting (on the whole domoticz)

But your device is "unreachable" in phoscon too ? No logs with 'TimedOut': 1, for this device ?

[niawag]

Yes, device unreachable in Phoscon after 24h without battery in the sensor:

I have 'TimedOut': 1 in the log as shown here: 2022-04-10 14:37:34.495 deCONZ: ### Update device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '20.22'} But the device does not show that in Domoticz.

[Smanar]

Ok, I remake a try on my side with an ikea remote. You can see some websocket return for this device ? (that can re-enable it). If I m right the newt one will be deCONZ: ### Update device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '20.22'}, IGNORED , no changes !

But as you have "LastUpdate" : "2022-04-10 14:37:34", if we have missed a websocket notification, long time we have missed it ...

The only possible issue I m seing is

• you receive a notification with config/reacheable = false > timedout = 1
• you receive a notification with state/anything > timeout = 0

but on m y logic if the device is unreachable in deconz (and since 24h) , you can't have the second notification ....

[niawag]

Here is the last websocket data domoticz received:

2022-04-10 14:37:34.506  deCONZ: ### WebSocket Data : {'config': {'battery': 100, 'offset': 0, 'on': True, 'reachable': False}, 'e': 'changed', 'id': '24', 'r': 'sensors', 't': 'event', 'uniqueid': '00:15:8d:00:05:8a:61:15-01-0403'}
2022-04-10 14:37:34.506  deCONZ: ### Update  device (Bureau Gawain) : {'BatteryLevel': 100, 'TimedOut': 1, 'nValue': 0, 'sValue': '990;4'}

So I received a websocket notification saying 'reachable': False and the device in domoticz were update to 'TimedOut': 1

[niawag]

I got a connection problem (don't know why):

2022-04-12 14:56:37.789  Status: deCONZ: Stop directive received.
2022-04-12 14:56:37.789  deCONZ: Acquiring GIL for 'deCONZ'
2022-04-12 14:56:37.792  deCONZ: Pushing 'DisconnectDirective' on to queue
2022-04-12 14:56:37.792  deCONZ: Processing 'DisconnectDirective' message
2022-04-12 14:56:37.795  deCONZ: Acquiring GIL for 'DisconnectDirective'
2022-04-12 14:56:37.797  deCONZ: Disconnect directive received for '192.168.0.44:8088'.
2022-04-12 14:56:37.800  deCONZ: Handling TCP disconnect, socket (192.168.0.44:8088) is connected
2022-04-12 14:56:37.800  deCONZ: Acquiring GIL for 'CPluginTransportTCP::handleRead'
2022-04-12 14:56:37.806  deCONZ: Acquiring GIL for 'DisconnectDirective'
2022-04-12 14:56:37.806  Queued asynchronous read aborted (192.168.0.44:8088), [2] End of file.
2022-04-12 14:56:37.813  deCONZ: Pushing 'DisconnectedEvent' on to queue
2022-04-12 14:56:37.813  deCONZ: Processing 'DisconnectedEvent' message
2022-04-12 14:56:37.814  deCONZ: Acquiring GIL for 'DisconnectedEvent'
2022-04-12 14:56:37.814  deCONZ: Disconnect event received for '192.168.0.44:8088'.
2022-04-12 14:56:37.815  deCONZ: Pushing 'onDisconnectCallback' on to queue
2022-04-12 14:56:37.815  deCONZ: Pushing 'onStopCallback' on to queue
2022-04-12 14:56:37.815  deCONZ: Acquiring GIL for 'DisconnectedEvent'
2022-04-12 14:56:37.815  deCONZ: Processing 'onDisconnectCallback' message
2022-04-12 14:56:37.815  deCONZ: Acquiring GIL for 'onDisconnectCallback'
2022-04-12 14:56:37.815  deCONZ: Calling message handler 'onDisconnect' on 'module' type object.
2022-04-12 14:56:37.816  Status: deCONZ: onDisconnect called for deCONZ_WebSocket
2022-04-12 14:56:37.816  deCONZ: Acquiring GIL for 'onDisconnectCallback'
2022-04-12 14:56:37.816  deCONZ: Processing 'onStopCallback' message
2022-04-12 14:56:37.816  deCONZ: Acquiring GIL for 'onStopCallback'
2022-04-12 14:56:37.816  deCONZ: Calling message handler 'onStop' on 'module' type object.
2022-04-12 14:56:37.816  deCONZ: onStop called
2022-04-12 14:56:37.816  Error: deCONZ: CConnection_disconnect, disconnection request from 'deCONZ' ignored. Transport does not exist.

and, after that, domoticz updated the sensor with the same valueas before:

2022-04-12 14:56:49.177  deCONZ: ### Device > 20 Name:Bureau Gawain Type:ZHATemperature Details:{'lastupdated': '2022-04-09T12:34:45.627', 'temperature': 2022} and {'battery': 100, 'offset': 0, 'on': True, 'reachable': False}
2022-04-12 14:56:49.177  deCONZ: ### Update  device (Bureau Gawain) : {'nValue': 0, 'sValue': '20.22', 'BatteryLevel': 100, 'TimedOut': 1}

[Smanar]

Lol serioulsy, it's terrific ^^. You are not alone with this issue, so I have asked to another user how it's for him now with the last beta.

And it seem it's not possible to change this setting using JSON, or it haven't worked on my side.

[niawag]

The other user with this problem wrote an issue? Do you have the link?

I think I'll put the battery back when I get home but if needed I can remove it again to troubleshoot this.

[Smanar]

It's a french forum https://easydomoticz.com/forum/viewtopic.php?f=30&t=7593&start=820 But yes, I have removed a battery on my side too, so for the moment I need to make tries on my side.

[niawag]

No problem, I'm french ;) I'll have a look on easydomoticz

[Smanar]

Ok so I m making a test with an ikea remote, the device is marked in red here, I m waiting to see if a notification can change the state to remove it.

HaveTimeout true
LastUpdate  "2022-04-13 12:30:03"

[niawag]

Problem solved ! Hooray!

https://github.com/domoticz/domoticz/issues/5218