Hassio-zigbee2mqtt: Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms

[ghost]

Hello alltogether from Germany,

my Zigbee Devices suddenly stopped working yesterday afternoon.
Anyone got an Idea what could have happened?
Could it be the update from zigbee2mqtt 1.5.1 to 1.6.0 within the add on?

More Informations below - thanks in advance!

zigbee2mqtt add-on version (if edge, please report commit hash):
1.6.0 stable

Operating environment (HassOS, Virtual Machine, Device/platform running Hass.io):
Raspberry Pi 3B+
HassOS 2.12
Hass IO Supervisor 187
CC2531 Stick with Firmware CC2531_DEFAULT_20190608

Description of problem:
Add-On starts and runs, but all linked Devices are in "unavailable" State.
On September 13, at 03:18 PM all Devices became unavailable without any action made by myself.
Add-On Auto Update is enabled in Hass-IO
Error pasted in Logging Section below repeats every 60-90 seconds.

Troubleshooting steps:
Rebooted the Pi twice
replugged CC2531 stick multiple times

Your entire configuration from the frontend (with sensitive fields redacted):

{
  "data_path": "/share/zigbee2mqtt",
  "devices": "devices.yaml",
  "groups": "groups.yaml",
  "homeassistant": true,
  "permit_join": false,
  "mqtt": {
    "base_topic": "zigbee2mqtt",
    "server": "mqtt://homeassistant",
    "user": "zigbee2mqtt",
    "password": "censored"
  },
  "serial": {
    "port": "/dev/ttyACM0"
  },
  "advanced": {
    "pan_id": 6754,
    "channel": 11,
    "network_key": [censored],
    "availability_blacklist": [],
    "log_level": "debug"
  },
  "ban": [],
  "whitelist": [],
  "queue": {}
}

Your logs from Hass.io

2019-09-14T15:02:35: PM2 log: App [npm:0] starting in -fork mode-
2019-09-14T15:02:35: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.6.0
> node index.js
  zigbee2mqtt:info 9/14/2019, 3:02:41 PM Logging to directory: '/share/zigbee2mqtt/log/2019-09-14.15-02-39'
  zigbee2mqtt:debug 9/14/2019, 3:02:41 PM Removing old log directory '/share/zigbee2mqtt/log/2019-09-14.14-39-10'
  zigbee2mqtt:debug 9/14/2019, 3:02:41 PM Loaded state from file /share/zigbee2mqtt/state.json
  zigbee2mqtt:debug 9/14/2019, 3:02:41 PM Saving state to file /share/zigbee2mqtt/state.json
  zigbee2mqtt:info 9/14/2019, 3:02:41 PM Starting zigbee2mqtt version 1.6.0 (commit #unknown)
  zigbee2mqtt:info 9/14/2019, 3:02:41 PM Starting zigbee-shepherd
  zigbee2mqtt:debug 9/14/2019, 3:02:41 PM Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":"HIDDEN"},"dbPath":"/share/zigbee2mqtt/database.db","coordBackupPath":"/share/zigbee2mqtt/coordinator_backup.json","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:info 9/14/2019, 3:02:59 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds) (Error: SRSP - SYS - osalNvRead after 6000ms)
  zigbee2mqtt:info 9/14/2019, 3:03:59 PM Starting zigbee-shepherd
  zigbee2mqtt:error 9/14/2019, 3:04:17 PM Error while starting zigbee-shepherd! (Error: SRSP - SYS - osalNvRead after 6000ms)
  zigbee2mqtt:error 9/14/2019, 3:04:17 PM Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 9/14/2019, 3:04:17 PM Failed to start
    {"message":"SRSP - SYS - osalNvRead after 6000ms","stack":"Error: SRSP - SYS - osalNvRead after 6000ms\n    at Timeout.object.timer.setTimeout [as _onTimeout] (/zigbee2mqtt-1.6.0/node_modules/zigbee-herdsman/dist/znp/znp.js:227:24)\n    at ontimeout (timers.js:436:11)\n    at tryOnTimeout (timers.js:300:5)\n    at listOnTimeout (timers.js:263:5)\n    at Timer.processTimers (timers.js:223:10)"}
  zigbee2mqtt:error 9/14/2019, 3:04:17 PM Exiting...

[jamesawebb]

Also seeing this following the 1.6.0 upgrade. Host system is an Intel NUC running Debian 10.

[brendanmullan]

Experiencing the same issue. Raspberry Pi 3B+, CC2531.

[OlegMB]

The same. Raspberry Pi 3B+, CC2531. Zigbee2mqtt Hass.io Add-on

[mattclar]

Same here, raspberry pi 3B+ running hassos 3.5

[ghost]

Any way to perform a Add-On downgrade to 1.5.1.x within HassIO?

[mattclar]

Yep I just did.
Use the restore function to selectively restore only the zigbee2mqtt add-on
to the previous version
Apparently there's a way to do it with the cli but I couldn't find it

On Mon., 16 Sep. 2019, 5:48 pm MiGrAt0r, [e-mail] wrote:

Any way to perform a Add-On downgrade to 1.5.1.x within HassIO?

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/danielwelch/hassio-zigbee2mqtt/issues/226?email_source=notifications&email_token=AAGNYDZYP2FYKXI5OBZYTCDQJ423HA5CNFSM4IWXAT52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD6YLF5A#issuecomment-531673844,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAGNYD4CY3TTBAXMSNBE7N3QJ423HANCNFSM4IWXAT5Q
.

[brendanmullan]

Yep I just did. Use the restore function to selectively restore only the zigbee2mqtt add-on to the previous version Apparently there's a way to do it with the cli but I couldn't find it

Is this only if you had previously saved a snapshot before upgrading? Or is there another way to downgrade the addon?

[mattclar]

I believe you need a previous backup :/
You could Google further about the cli, but the few threads I saw hadn't
found out how to do it

On Mon., 16 Sep. 2019, 9:40 pm Brendan Mullan, [e-mail]
wrote:

Yep I just did. Use the restore function to selectively restore only the
zigbee2mqtt add-on to the previous version Apparently there's a way to do
it with the cli but I couldn't find it

Is this only if you had previously saved a snapshot before upgrading? Or
is there another way to downgrade the addon?

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/danielwelch/hassio-zigbee2mqtt/issues/226?email_source=notifications&email_token=AAGNYD76RNFPGNK3P6RFYZDQJ5WEDA5CNFSM4IWXAT52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD6Y3XWI#issuecomment-531741657,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAGNYD5Y4JMCXAXSNMUT35TQJ5WEDANCNFSM4IWXAT5Q
.

[danielwelch]

https://github.com/Koenkk/zigbee2mqtt/issues/1980 looks related to this issue?

If that's the case, it will require an update from zigbee2mqtt.

[rwit-ormer]

Same problem here:
Raspberry Pi 3B+, Home Assistant 0.99.0, CC2531 Stick with Firmware CC2531_DEFAULT_20190608

[hawaltie]

Same problem here:
Intel NUc, Hass.io, Home Assistant 0.99.2, CC2531 Stick with Firmware CC2531_DEFAULT_20190608

[cconde]

Another CC2531 Stick with Firmware CC2531_DEFAULT_20190608 with the same problem

[vstoms]

Same problem here:
Synology NAS, Hass.Io, Home Assistant 0.99.3, CC2531 Stick with Firmware CC2531_DEFAULT_20190608

[jonnyrider]

I also have this problem.

Intel NUC, Hass.io, Home Assistant 0.99.2, CC2531 Stick with Firmware CC2531_DEFAULT_20190608

Any update?

[sliepie]

Reflash of stick solved problem for me

[vstoms]

Did a reflash and it worked! (At first I still got the error messages, but after some minutes the stick got online again).

./run.sh: line 16: [Info] Configuration backup found in /share/zigbee2mqtt/.configuration.yaml.bk. Skipping config backup.: No such file or directory
2019-10-02T14:37:01: PM2 log: Launching in no daemon mode
2019-10-02T14:37:01: PM2 log: App [npm:0] starting in -fork mode-
2019-10-02T14:37:01: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.6.0
> node index.js
  zigbee2mqtt:info 10/2/2019, 2:37:09 PM Logging to directory: '/share/zigbee2mqtt/log/2019-10-02.14-37-07'
  zigbee2mqtt:info 10/2/2019, 2:37:09 PM Starting zigbee2mqtt version 1.6.0 (commit #unknown)
  zigbee2mqtt:info 10/2/2019, 2:37:09 PM Starting zigbee-shepherd
  zigbee2mqtt:info 10/2/2019, 2:37:22 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds) (Error: SRSP - SYS - osalNvRead after 6000ms)
  zigbee2mqtt:info 10/2/2019, 2:38:22 PM Starting zigbee-shepherd
  zigbee2mqtt:error 10/2/2019, 2:38:29 PM Error while starting zigbee-shepherd! (Error: SRSP - SYS - osalNvRead after 6000ms)
  zigbee2mqtt:error 10/2/2019, 2:38:29 PM Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 10/2/2019, 2:38:29 PM Failed to start
    {"message":"SRSP - SYS - osalNvRead after 6000ms","stack":"Error: SRSP - SYS - osalNvRead after 6000ms\n    at Timeout.object.timer.setTimeout [as _onTimeout] (/zigbee2mqtt-1.6.0/node_modules/zigbee-herdsman/dist/znp/znp.js:227:24)\n    at ontimeout (timers.js:436:11)\n    at tryOnTimeout (timers.js:300:5)\n    at listOnTimeout (timers.js:263:5)\n    at Timer.processTimers (timers.js:223:10)"}
  zigbee2mqtt:error 10/2/2019, 2:38:29 PM Exiting...
npm
 ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! [email protected] start: `node index.js`
npm ERR! Exit status 1
npm ERR! 
npm ERR!
 Failed at the [email protected] start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
npm ERR! A complete log of this run can be found in:
npm ERR!     /root/.npm/_logs/2019-10-02T12_38_29_399Z-debug.log
2019-10-02T14:38:31: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-10-02T14:38:31: PM2 log: App [npm:0] starting in -fork mode-
2019-10-02T14:38:31: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.6.0
> node index.js
  zigbee2mqtt:info 10/2/2019, 2:38:34 PM Logging to directory: '/share/zigbee2mqtt/log/2019-10-02.14-38-34'
  zigbee2mqtt:info 10/2/2019, 2:38:35 PM Starting zigbee2mqtt version 1.6.0 (commit #unknown)
  zigbee2mqtt:info 10/2/2019, 2:38:35 PM Starting zigbee-shepherd
  zigbee2mqtt:info 10/2/2019, 2:38:41 PM zigbee-shepherd started
  zigbee2mqtt:info 10/2/2019, 2:38:41 PM Coordinator firmware version: '20190608'

[ghost]

I can confirm that it is running again fine on 1.6.0:

Steps done:

• Updated to 1.6.0 - Breakdown
• Rollback to 1.5.1.2 - still broken
• Stick re-flashed with 20190608 via Raspberry Pi
• Version 1.5.1.2 was running again
• Updated to 1.6.0 - Runs fine!

[daveonkels]

Confirmed it's working using a similar process - re-flashed using CC debugger, didn't work on the first try, then mapped to device by name and it fired up correctly (v1.6.0). Does this suggest that 1.6.0 update wrote bad data to the stick?

[crazyquark]

I have this too, just reflashed the stick to see if it helps.

[GitOnHub]

I can confirm that it is running again fine on 1.6.0:

Steps done:

• Updated to 1.6.0 - Breakdown
• Rollback to 1.5.1.2 - still broken
• Stick re-flashed with 20190608 via Raspberry Pi
• Version 1.5.1.2 was running again
• Updated to 1.6.0 - Runs fine!

The issue surfaced on both my CC2530 and CC2531; above procedure solved it.

• v1.6.0
• CC2530 on CC2530_CC2591_SOURCE_ROUTING_20190619
• CC2531 on version that was most recent in march 2019.

Both of these developed the problem after Z2M crashed in a way that has happened in my setup many times already with v1.6.0, as seen in attached logs. (debug-level logs have been recycled already, sorry)

log.txt

[Export33]

Same problem here.
Raspberry 3b+, CC2531_DEFAULT_20190608, zigbee2mqtt on docker.
Reflashing did the trick.

[Export33]

I had this error several times in the last days. Reflashing always helped, but the waf -> 0.

Today the devices wouldn´t reconnect after reflashing:

Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.

Disconnecting them from power/ using the real switch helped.

[GilbyDettori]

Just migrated from IKEA to the cc2531, failed twice in a week, pending it's second reflash now.

VMware based Debian 9
CC2531_DEFAULT_20190608
Has 0.99.3

Happy to do whatever triage is asked of me.

EDIT: It just dawned on me that it failed upon a couple of has restarts. For the first time in a while.

Not sure why this could bring about instability in a product hass is merely consuming info from though. And not even directly.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[vincnetas]

running on koenkk/zigbee2mqtt:1.6.0-arm32v6 docker image on RPI 3.
Had same error. Re flashed stick, everything works again.