Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms #226

ghost · 2019-09-14T13:20:58Z

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...

The text was updated successfully, but these errors were encountered:

jamesawebb · 2019-09-14T13:39:05Z

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

brendanmullan · 2019-09-15T01:47:09Z

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

OlegMB · 2019-09-15T12:31:03Z

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

mattclar · 2019-09-15T21:45:07Z

Same here, raspberry pi 3B+ running hassos 3.5

ghost · 2019-09-16T07:48:02Z

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

mattclar · 2019-09-16T11:36:15Z

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, ***@***.***> 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 <#226?email_source=notifications&email_token=AAGNYDZYP2FYKXI5OBZYTCDQJ423HA5CNFSM4IWXAT52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD6YLF5A#issuecomment-531673844>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAGNYD4CY3TTBAXMSNBE7N3QJ423HANCNFSM4IWXAT5Q> .

brendanmullan · 2019-09-16T11:40:48Z

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 · 2019-09-16T11:59:02Z

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, ***@***.***> 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 <#226?email_source=notifications&email_token=AAGNYD76RNFPGNK3P6RFYZDQJ5WEDA5CNFSM4IWXAT52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD6Y3XWI#issuecomment-531741657>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAGNYD5Y4JMCXAXSNMUT35TQJ5WEDANCNFSM4IWXAT5Q> .

danielwelch · 2019-09-16T23:19:17Z

Koenkk/zigbee2mqtt#1980 looks related to this issue?

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

rwit-ormer · 2019-09-19T19:06:07Z

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

hawaltie · 2019-09-25T18:24:11Z

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

cconde · 2019-09-26T15:58:22Z

Another CC2531 Stick with Firmware CC2531_DEFAULT_20190608 with the same problem

vstoms · 2019-09-27T09:47:51Z

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

jonnyrider · 2019-10-01T08:33:43Z

I also have this problem.

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

Any update?

sliepie · 2019-10-01T20:41:15Z

Reflash of stick solved problem for me

vstoms · 2019-10-02T13:57:57Z

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 · 2019-10-02T14:19:18Z

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 · 2019-10-02T23:02:13Z

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 · 2019-10-04T14:31:11Z

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

GitOnHub · 2019-10-04T20:37:00Z

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 · 2019-10-17T21:44:04Z

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

Export33 · 2019-10-22T18:08:34Z

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 · 2019-10-22T19:28:25Z

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 · 2020-01-26T19:53:19Z

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 · 2020-03-22T13:49:23Z

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

This was referenced Oct 20, 2019

Issues with 1.5.1.2 - Is there a way to rollback? #218

Closed

Coordinator initialize had an error: Error: SRSP - UTIL - getDeviceInfo after 6000ms Koenkk/zigbee2mqtt#2177

Closed

vhristev mentioned this issue Oct 23, 2019

CC2530 CC2591 router modelID undefined Koenkk/zigbee2mqtt#2129

Closed

stale bot added the stale label Jan 26, 2020

stale bot closed this as completed Feb 2, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms #226

Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms #226

ghost commented Sep 14, 2019 •

edited by ciotlosm

Loading

jamesawebb commented Sep 14, 2019

brendanmullan commented Sep 15, 2019 •

edited

Loading

OlegMB commented Sep 15, 2019 •

edited

Loading

mattclar commented Sep 15, 2019

ghost commented Sep 16, 2019

mattclar commented Sep 16, 2019 via email

brendanmullan commented Sep 16, 2019

mattclar commented Sep 16, 2019 via email

danielwelch commented Sep 16, 2019 •

edited

Loading

rwit-ormer commented Sep 19, 2019

hawaltie commented Sep 25, 2019

cconde commented Sep 26, 2019

vstoms commented Sep 27, 2019

jonnyrider commented Oct 1, 2019

sliepie commented Oct 1, 2019

vstoms commented Oct 2, 2019 •

edited by ciotlosm

Loading

ghost commented Oct 2, 2019

daveonkels commented Oct 2, 2019

crazyquark commented Oct 4, 2019

GitOnHub commented Oct 4, 2019

Export33 commented Oct 17, 2019

Export33 commented Oct 22, 2019 •

edited

Loading

GilbyDettori commented Oct 22, 2019 •

edited

Loading

stale bot commented Jan 26, 2020

vincnetas commented Mar 22, 2020

Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms #226

Linked Devices suddenly became unavailable - Error: SRSP - SYS - osalNvRead after 6000ms #226

Comments

ghost commented Sep 14, 2019 • edited by ciotlosm Loading

jamesawebb commented Sep 14, 2019

brendanmullan commented Sep 15, 2019 • edited Loading

OlegMB commented Sep 15, 2019 • edited Loading

mattclar commented Sep 15, 2019

ghost commented Sep 16, 2019

mattclar commented Sep 16, 2019 via email

brendanmullan commented Sep 16, 2019

mattclar commented Sep 16, 2019 via email

danielwelch commented Sep 16, 2019 • edited Loading

rwit-ormer commented Sep 19, 2019

hawaltie commented Sep 25, 2019

cconde commented Sep 26, 2019

vstoms commented Sep 27, 2019

jonnyrider commented Oct 1, 2019

sliepie commented Oct 1, 2019

vstoms commented Oct 2, 2019 • edited by ciotlosm Loading

ghost commented Oct 2, 2019

daveonkels commented Oct 2, 2019

crazyquark commented Oct 4, 2019

GitOnHub commented Oct 4, 2019

Export33 commented Oct 17, 2019

Export33 commented Oct 22, 2019 • edited Loading

GilbyDettori commented Oct 22, 2019 • edited Loading

stale bot commented Jan 26, 2020

vincnetas commented Mar 22, 2020

ghost commented Sep 14, 2019 •

edited by ciotlosm

Loading

brendanmullan commented Sep 15, 2019 •

edited

Loading

OlegMB commented Sep 15, 2019 •

edited

Loading

danielwelch commented Sep 16, 2019 •

edited

Loading

vstoms commented Oct 2, 2019 •

edited by ciotlosm

Loading

Export33 commented Oct 22, 2019 •

edited

Loading

GilbyDettori commented Oct 22, 2019 •

edited

Loading