Everything unavailable when z2m restarts/crashes

[copystring]

What happened?

It looks like z2m crashed and restarted. When this happens every device is marked as unavailable and only sometimes return to available.

What did you expect to happen?

Maybe it makes more sense to automatically restart the adapter when there's a connection loss instead of endlessly trying to reconnect?
Also as you can see in the third screenshot of the logs it seems like iobroker.zigbee2mqtt behaves different than a restart when the connection ist lost which seems to be the reason the devices do not always turn back to being available.

How to reproduce it (minimal and precise)

Wait for z2m to restart for example be connection loss of the adapter.

Adapter version

2.4.4

Log

Disconnect:

Eventually z2m works again and iobroker.zigbee2mqtt reconnects:

This is what it looks like when manually restarting iobroker.zigbee2mqtt:

[o0shojo0o]

What happened?

It looks like z2m crashed and restarted. When this happens every device is marked as unavailable and only sometimes return to available.

I have now tried so several things, but do not get this behavior readjusted, then z2m always sends all available states on a new connection.

Maybe it makes more sense to automatically restart the adapter when there's a connection loss instead of endlessly trying to reconnect?

The websocket connection is completely reinitialized, as with an adapter restart, that would make no difference.
Also a full adapter restart would be a problem for users using the 'dummy MQTT server' from the adapter, for them it would end in an endless loop.

Also as you can see in the third screenshot of the logs it seems like iobroker.zigbee2mqtt behaves different than a restart when the connection ist lost which seems to be the reason the devices do not always turn back to being available.

No this is only because I suppress the log when an adapter is running and reconnects.
https://github.com/o0shojo0o/ioBroker.zigbee2mqtt/blob/ea52abe240a43fe729f7236773281f92b27264d0/main.js#L142-L146

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[o0shojo0o]

I assume from your other issues (#148) that you are using the MQTT connection type here.
Please switch to the websocket connection.

[copystring]

I do still have this Problem.
For example this device:

As you can see it's clearly available in z2m but not in the ioBroker adapter.
A few seconds later everything is online again.

🤷‍♂️

I will try to get a log when this happens the next time.

[copystring]

I have not been able to get a good log for this, but I'm still confident it has something to do with the websocket connection reconnecting.

For example, this light:

All the other devices have the same available timestamp as this light, which is roughly 10 seconds after websocket reconnected.

Here's a log with the time range https://pastebin.com/XNcRB09a

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[tonez18]

Same issue here. After restarting zigbee2mqtt and adapter everything is working fine for 3-4 days. After this period the problem comes back :/

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[copystring]

Issue still persists.

[o0shojo0o]

Sorry, but no matter what I try, I do not get the problem readjusted.
I am at a loss as to why a few users have this kind of problem.

[o0shojo0o]

What else I could offer is the connection via mqtt, can you test that?
Possibly also the dev branch if you need authentication.
https://github.com/o0shojo0o/ioBroker.zigbee2mqtt/tree/external-mqtt-credentials-%23148

[copystring]

Yes, I was just thinking about that yesterday evening.
I don't need authentication so the normal release should work.
Sure, if it works this is fine. However it feels like a workaround rather than finding the actual reason. Having said that, I understand the difficulty finding the issue when it's not possible to reproduce.
Just yesterday I was thinking maybe additional logging for each device could help. Debug logging the availability for each device when the availability changes might give a clue when this happens.

[o0shojo0o]

I get a message for each change of availability on my Zigbee devices.
And I actually only get messages that make sense since one battery is dead.

[copystring]

What does a message like this look like? I could not find one in my logs.
I will test the adapter via MQTT for the next days and report back. For testing, is the latest release ok or install via GitHub for latest changes?

[copystring]

I get errors via MQTT.

z2m_log1.txt

[o0shojo0o]

Ok... that was of course not with me.
But tonight it goes away for a week on vacation, I will look at it afterwards.

[o0shojo0o]

z2m_log1

I looked at the log, but what's totally weird is that it's banging at the JSON.Pars() in the websocket even though you have MQTT enabled?!
Totally wild ...

2023-07-31 21:01:39.862 - error: zigbee2mqtt.0 (240608) Unexpected token 'o', ...""payload":online,"to"... is not valid JSON
2023-07-31 21:01:39.862 - error: zigbee2mqtt.0 (240608) Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch().
2023-07-31 21:01:39.862 - error: zigbee2mqtt.0 (240608) unhandled promise rejection: Unexpected token 'o', ...""payload":online,"to"... is not valid JSON
2023-07-31 21:01:39.863 - error: zigbee2mqtt.0 (240608) SyntaxError: Unexpected token 'o', ...""payload":online,"to"... is not valid JSON
at JSON.parse ()
at Zigbee2mqtt.messageParse (/opt/iobroker/node_modules/iobroker.zigbee2mqtt/main.js:135:33)

https://github.com/o0shojo0o/ioBroker.zigbee2mqtt/blob/2ba7ce53c19213400299221405d61c1bcc7b07ae/main.js#L126-L142

Can you test the current git version?

[o0shojo0o]

@Eistee82 are you by any chance online in Discord today?

[o0shojo0o]

I have already found you ;)

[copystring]

I want to try this later. Does the PR mean it's fixed?

[o0shojo0o]

No, the PR was for the problem of @Eistee82

[copystring]

I've been using 2.10.1 for a few days now and the issue has since been resolved using mqtt instead of websocket.
So the issue must be with websocket.

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days