Restart Loop when Weather Station disconnects

[mrfenyx]

Describe the bug
For some reason, during the night my Weather station (WS3500) disconnects. I presume the batteries are not ok and it runs out of solar power. At this point, the adapter shuts down with the following errors:

2023-01-17 04:20:33.478 - error: sainlogic.0 (2586388) uncaught exception: undefined
2023-01-17 04:20:33.508 - error: sainlogic.0 (2586388) undefined
2023-01-17 04:20:34.187 - error: host.smarthome instance system.adapter.sainlogic.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
2023-01-17 04:20:34.188 - info: host.smarthome Restart adapter system.adapter.sainlogic.0 because enabled
2023-01-17 04:21:04.339 - info: host.smarthome instance system.adapter.sainlogic.0 started with pid 3517595
2023-01-17 04:22:34.559 - error: sainlogic.0 (3517595) uncaught exception: undefined
2023-01-17 04:22:34.562 - error: sainlogic.0 (3517595) undefined
2023-01-17 04:22:35.519 - error: host.smarthome instance system.adapter.sainlogic.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
2023-01-17 04:22:35.521 - info: host.smarthome Restart adapter system.adapter.sainlogic.0 because enabled
2023-01-17 04:23:05.676 - info: host.smarthome instance system.adapter.sainlogic.0 started with pid 3518057
2023-01-17 04:23:34.225 - error: sainlogic.0 (3518057) uncaught exception: undefined
2023-01-17 04:23:34.227 - error: sainlogic.0 (3518057) undefined
2023-01-17 04:23:34.871 - error: host.smarthome instance system.adapter.sainlogic.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
2023-01-17 04:23:34.871 - info: host.smarthome Restart adapter system.adapter.sainlogic.0 because enabled
2023-01-17 04:23:34.871 - warn: host.smarthome Do not restart adapter system.adapter.sainlogic.0 because restart loop detected

Due to another issue (https://github.com/phifogg/ioBroker.sainlogic/issues/145) I can't enable any log level above error as my log will be spammed with warnings but the time stamp of the above error coincides with the time when I stop receiving data from the station.

Versions:

• Adapter version: 0.10.0
• JS-Controller version: 4.0.24
• Node version: 16.19.0
• Operating system: Raspberry Pi OS

[phifogg]

It sounds like your adapter receives some illegal / bad data from the station and hence crashes. Not good and something I would be keen to find.

Without debug log though a bit difficult to trouble shoot. I'll comment on #145 for a potential workaround.

[mrfenyx]

The issue was that the batteries inside the sensor unit (the actual weather station) were not good and thus, the station shut down around 3 am. At this point the adapter lost connection, started restarting itself, cause a restart loop and eventually shut down.

[phifogg]

Good to know the batteries solved. Still something the adapter should be better at handling...

[elek76]

I seem to be having a similar issue, filtered debug log: sainlogic-restart-loop.log

This has happened two times in the last 3 days. I must admit that I have been using version 0.10.3 of the adapter, just noticed that 0.10.5 is available. Updated the adapter and will see if any change can be observed. My setup:

• Sainlogic WS3500
• Ecowitt GW1100 + 4 soil moisture sensors WH51 (will be extended with 2 WH31s next week)

The battery of the WS3500 is reported to be good (the station was installed ca. 2 months ago). One of the WH51s is reporting unplausible values, it could be that its battery is low or there is some HW issue. I am not at home now, will check the sensor next week when I get back. ioBroker is running in a Docker container on a Synology DS418Play in case it matters.

Hope this information helps.

[phifogg]

@elek76 : It is probably the unreasonable values:

2023-08-09 08:57:40.402  - debug: sainlogic.0 (8590) Listener received WU update: {"ID":"1","PASSWORD":"__PASSWORD__","tempf":"-9999","humidity":"-9999","dewptf":"-9999","windchillf":"-9999","winddir":"-9999","windspeedmph":"-9999","windgustmph":"-9999","rainin":"-9999","dailyrainin":"-9999","weeklyrainin":"-9999","monthlyrainin":"-9999","yearlyrainin":"-9999","solarradiation":"-9999","UV":"-9999","indoortempf":"72.9","indoorhumidity":"58","absbaromin":"29.749","baromin":"30.253","lowbatt":"0","dateutc":"now","softwaretype":"EasyWeatherPro_V5.1.1","action":"updateraw","realtime":"1","rtfreq":"5"}

there is a lot of -9999 values in here. I can put some checks in place if it still causes issues.

[elek76]

@phifogg Thanks for checking. FYI, the update to 0.10.5 did not fix the issue (which was kind of expected):

It was caused again by unplausible values, apparently all outdoor values are incorrect:

2023-08-10 02:36:41.154 - debug: sainlogic.0 (9844) Listener received WU update: {"ID":"1","PASSWORD":"...","tempf":"-9999","humidity":"-9999","dewptf":"-9999","windchillf":"-9999","winddir":"-9999","windspeedmph":"-9999","windgustmph":"-9999","rainin":"-9999","dailyrainin":"-9999","weeklyrainin":"-9999","monthlyrainin":"-9999","yearlyrainin":"-9999","solarradiation":"-9999","UV":"-9999","indoortempf":"73.0","indoorhumidity":"58","absbaromin":"29.760","baromin":"30.265","lowbatt":"0","dateutc":"now","softwaretype":"EasyWeatherPro_V5.1.1","action":"updateraw","realtime":"1","rtfreq":"5"}

The device seem to send these wrong values to wunderground and ecowitt, too:

The last correct values were reported at 2023-08-10 02:30:33.674, then 3 times wrong values and uncaught exception before the adapter was shut down.

ID 1 is the WS3500. I will also try to find out if there is a fix for the WS3500 to not report incorrect values.

[elek76]

Update: after adjusting the antenna of the GW1100 to better reach the fourth WH51 and adding two new WH31s to the same gateway, the restart loops have disappeared. The events could be unrelated as I haven't changed anything in the WS3500 setup, the bogus updates of which have caused the restart loop. I will continue observing the setup and update here if anything comes up.