Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error while starting zigbee-shepherd - request timeout at CcZnp #118

Closed
Klumper opened this issue Feb 28, 2019 · 53 comments
Closed

Error while starting zigbee-shepherd - request timeout at CcZnp #118

Klumper opened this issue Feb 28, 2019 · 53 comments
Labels

Comments

@Klumper
Copy link

Klumper commented Feb 28, 2019

I've just recieved a CC2531 Zigbee stick which had the latest firmware on it. I plugged it in to my Home Assistant (RPi 3 - v0.88.1) but I can't get it to work. I've tried pushing the 'debug' button on the stick but it didn't do much. Tried looking up the error but couldn't find a solution

Config

{
  "data_path": "/share/zigbee2mqtt",
  "homeassistant": true,
  "permit_join": true,
  "mqtt_base_topic": "zigbee2mqtt",
  "mqtt_server": "mqtt://192.168.1.14",
  "serial_port": "/dev/ttyACM1",
  "devices": [],
  "network_key": [],
  "zigbee_shepherd_debug": true,
  "log_level": "debug",
  "mqtt_user": "removed",
  "mqtt_pass": "removed"
}

Log

2/28/2019, 7:14:03 PM - info: Logging to directory: '/share/zigbee2mqtt/log/2019-02-28.19-14-03'
2/28/2019, 7:14:04 PM - debug: Using zigbee-shepherd with settings: '{"net":{"panId":6754,"channelList":[11],"precfgkey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"dbPath":"/share/zigbee2mqtt/database.db","sp":{"baudRate":115200,"rtscts":true}}'
2/28/2019, 7:14:04 PM - debug: Loaded state from file /share/zigbee2mqtt/state.json
2/28/2019, 7:14:04 PM - info: Starting zigbee2mqtt version 1.1.1 (commit #unknown)
2/28/2019, 7:14:04 PM - info: Starting zigbee-shepherd
2/28/2019, 7:14:08 PM - info: Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
2/28/2019, 7:15:08 PM - info: Starting zigbee-shepherd
2/28/2019, 7:15:11 PM - error: Error while starting zigbee-shepherd!
2/28/2019, 7:15:11 PM - error: Press the reset button on the stick (the one closest to the USB) and start again
2/28/2019, 7:15:11 PM - error: Failed to start Error: request timeout
    at CcZnp.<anonymous> (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:255:22)
    at Object.onceWrapper (events.js:273:13)
    at CcZnp.emit (events.js:182:13)
    at Timeout.<anonymous> (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:234:18)
    at ontimeout (timers.js:436:11)
    at tryOnTimeout (timers.js:300:5)
    at listOnTimeout (timers.js:263:5)
    at Timer.processTimers (timers.js:223:10)
2/28/2019, 7:19:04 PM - debug: Saving state to file /share/zigbee2mqtt/state.json

I've tried pushing the 'debug' button on the stick but it didn't do much.

@LennartIsHigh
Copy link

LennartIsHigh commented Mar 4, 2019

Same problem here, flashed the USB again but with the same result.
It gets stuck at starting of the Zigbee-shepherd...

I'm using Hassio and tried both versions of Zigbee2MQTT (regular and edge). This made no difference.

@masterful
Copy link

I have the same issue - I think it stems from my stick being on /dev/ttyACM1 and for some reason the configuration.yaml file keeps it at /dev/ttyACM0 (and so can't find it). Manually editing that configuration file seemed to do the trick (.../share/zigbee2mqtt/configuration.yaml)

@LennartIsHigh
Copy link

I have tried all USB ports of the RPi but that didn't work. Like you said I changed them in the configuration.yaml file of /share/zigbee2mqtt/. Any other suggestions?

@LennartIsHigh
Copy link

My next guess was to delete my configuration.yaml file every time to create a new one.
{ "data_path": "/share/zigbee2mqtt", "homeassistant": false, "permit_join": false, "mqtt_base_topic": "zigbee2mqtt", "mqtt_server": "mqtt://homeassistant", "serial_port": "/dev/ttyACM0", "devices": [], "network_key": [], "rtscts": false, "zigbee_shepherd_debug": true, "log_level": "debug", "mqtt_pass": "removed", "mqtt_user": "removed" }

Still with the same result:

zigbee2mqtt:info 3/5/2019, 12:38:35 PM Starting zigbee-shepherd
2019-03-05T11:38:36.002Z zigbee-shepherd:init zigbee-shepherd booting...
2019-03-05T11:38:36.047Z zigbee-shepherd:request REQ --> SYS:osalNvRead
2019-03-05T11:38:39.068Z zigbee-shepherd:request RSP <-- SYS:osalNvRead
2019-03-05T11:38:39.079Z zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
at CcZnp. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:255:22)
at Object.onceWrapper (events.js:273:13)
at CcZnp.emit (events.js:182:13)
at Timeout. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:234:18)
at ontimeout (timers.js:436:11)
at tryOnTimeout (timers.js:300:5)
at listOnTimeout (timers.js:263:5)
at Timer.processTimers (timers.js:223:10)
zigbee2mqtt:info 3/5/2019, 12:38:39 PM Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)

@masterful
Copy link

🤔 the way I'd discovered the issue was by using the test release, docker exec (actually did a docker commit, docker run + device) and seeing what step it was failing on by manually invoking lines of the run.sh - and then seeing the configuration.yaml file get saved with the wrong serial port.

I have two USB sticks plugged in, a Z-Wave, and a Zigbee - the Z-Wave took /dev/ttyACM0, so the zigbee was /dev/ttyACM1 for me. You might be able to tell which one is which if you have more than one by looking at the ids:

ls -al /dev/serial/by-id/

@LennartIsHigh
Copy link

I'm using Hassio with the SSH add-on. This terminal command is not usable for me. Or can someone explain me how to make this command executable?

@LennartIsHigh
Copy link

OK, found it. In the end I think it has to do with load shedding of my RPi. I had 4 devices connected. And at that moment the Zigbee thingy did not work. I disconnected all deviced, rebooted the RPi and started putting in the devices one by one. I verified every input in the HASSIO HARDWARE page to see which USB port showed up and edited the configuration.yaml file to the corresponding port. And at that moment the Zigbee Thingy started working. Problem solved...

@h4nc
Copy link

h4nc commented Mar 11, 2019

I have the same issue. Yesterday I updated to 1.2.1 .
Everything worked fine before, but now I get the same errors as in the first post and zigbee won't start.
I pressed the reset button ad advised in the log but that did not help. I also reinstalled the add-on.

I'm on hassio (lastest release).
The stick is on dev/ttyACM0 in hassio and and I also have that in the config.

@supoeric
Copy link

I have the same issue.
After I delete "zigbee_shepherd_devices: true" and restart the service, it work again, but cannot add new devices.

@h4nc
Copy link

h4nc commented Mar 13, 2019

Looks like you have a crashed stick, see here:
Koenkk/zigbee2mqtt#1235

Also I don't have or had "zigbee_shepherd_devices: true" in my config. What does it stand for?

EDIT: Nevermind found it

If set to true, the add-on will look for a custom devices.js file within data_path. If this file is present, the add-on will replace the zigbee2mqtt devices.js file with this file. Used to experiment with and/or add support for new devices.

@marinoraffaele
Copy link

hi, I too have the problem if I try to restart the zigbee2mqtt haddon continually gives me the error :)

zigbee2mqtt:info 3/14/2019, 4:50:48 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-14.16-50-48'
zigbee2mqtt:info 3/14/2019, 4:50:49 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/14/2019, 4:50:49 PM Starting zigbee-shepherd
zigbee2mqtt:info 3/14/2019, 4:50:51 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
zigbee2mqtt:info 3/14/2019, 4:51:51 PM Starting zigbee-shepherd
zigbee2mqtt:error 3/14/2019, 4:51:53 PM Error while starting zigbee-shepherd!
zigbee2mqtt:error 3/14/2019, 4:51:53 PM Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 3/14/2019, 4:51:53 PM Failed to start
{"message":"request timeout","stack":"Error: request timeout\n at CcZnp. (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:261:22)\n at Object.onceWrapper (events.js:273:13)\n at CcZnp.emit (events.js:182:13)\n at Timeout. (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:240:18)\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 3/14/2019, 4:51:53 PM Exiting...
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm
ERR! zigbee2mqtt@1.2.1 start: node index.js
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-03-14T15_51_53_199Z-debug.log
2019-03-14T16:51:56: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-03-14T16:51:56: PM2 log: App [npm:0] starting in -fork mode-
2019-03-14T16:51:56: PM2 log: App [npm:0] online

zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
node index.js
zigbee2mqtt:info 3/14/2019, 4:51:59 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-14.16-51-59'
zigbee2mqtt:info 3/14/2019, 4:52:00 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/14/2019, 4:52:00 PM Starting zigbee-shepherd
zigbee2mqtt:info 3/14/2019, 4:52:02 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 15, 2019

@marinoraffaele what is the output of ls /dev?

@marinoraffaele
Copy link

marinoraffaele commented Mar 15, 2019

@Koenkk below the result of the command:
core-ssh:# ls /dev
fd mqueue pts stderr tty urandom
full null random stdin ttyACM0 zero
init ptmx shm stdout ttyAMA0
core-ssh:
#

@aXecuter
Copy link

I have the same issues, can't seem to get zigbee2mqtt to work reliably anymore after flashing the latest firmware (20190223) on my CC2531 stick, in combination with updating Zigbee2MQTT.

sometimes, I can get it to work by manually starting Zigbee2MQTT and resetting / reinserting the usb stick. Most of the times it doesn't help

@Koenkk don't know what you are looking for, but here's my output of " ls /dev "
image

pi@hassbian:/opt/zigbee2mqtt $ npm start

> zigbee2mqtt@1.2.1 start /opt/zigbee2mqtt
> node index.js

  zigbee2mqtt:info 3/15/2019, 3:55:56 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-03-15.15-55-56'
  zigbee2mqtt:info 3/15/2019, 3:55:57 PM Starting zigbee2mqtt version 1.2.1 (commit #f54f3bd)
  zigbee2mqtt:info 3/15/2019, 3:55:57 PM Starting zigbee-shepherd
  zigbee2mqtt:info 3/15/2019, 3:56:04 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
  zigbee2mqtt:info 3/15/2019, 3:57:04 PM Starting zigbee-shepherd
  zigbee2mqtt:error 3/15/2019, 3:57:11 PM Error while starting zigbee-shepherd!
  zigbee2mqtt:error 3/15/2019, 3:57:11 PM Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 3/15/2019, 3:57:11 PM Failed to start
        {"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:261:22)\n    at Object.onceWrapper (events.js:277:13)\n    at CcZnp.emit (events.js:189:13)\n    at Timeout.<anonymous> (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:240:18)\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 3/15/2019, 3:57:11 PM Exiting...
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! zigbee2mqtt@1.2.1 start: `node index.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the zigbee2mqtt@1.2.1 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!     /home/pi/.npm/_logs/2019-03-15T14_57_46_295Z-debug.log
pi@hassbian:/opt/zigbee2mqtt $

@marinoraffaele
Copy link

marinoraffaele commented Mar 15, 2019

@Koenkk below the result of the command:

i have flashing Firmware CC2531ZNP-Prod_20190223.zip on my CC2531 stick, in combination with updating Zigbee2MQTT.

hassio

-------1---------
[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-03-14T16:37:02: PM2 log: Launching in no daemon mode
2019-03-14T16:37:03: PM2 log: App [npm:0] starting in -fork mode-
2019-03-14T16:37:03: PM2 log: App [npm:0] online

zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
node index.js
zigbee2mqtt:info 3/14/2019, 4:37:07 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-14.16-37-07'
zigbee2mqtt:debug 3/14/2019, 4:37:07 PM Removing old log directory '/share/zigbee2mqtt/log/2019-03-14.08-45-49'
zigbee2mqtt:debug 3/14/2019, 4:37:09 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","sp":{"baudRate":115200,"rtscts":true}}'
zigbee2mqtt:debug 3/14/2019, 4:37:09 PM Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:debug 3/14/2019, 4:37:09 PM Saving state to file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 3/14/2019, 4:37:09 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/14/2019, 4:37:09 PM Starting zigbee-shepherd
zigbee2mqtt:info 3/14/2019, 4:37:11 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
zigbee2mqtt:info 3/14/2019, 4:38:11 PM Starting zigbee-shepherd
zigbee2mqtt:error 3/14/2019, 4:38:12 PM Error while starting zigbee-shepherd!
zigbee2mqtt:error 3/14/2019, 4:38:12 PM Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 3/14/2019, 4:38:12 PM Failed to start
{"message":"request timeout","stack":"Error: request timeout\n at CcZnp. (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:261:22)\n at Object.onceWrapper (events.js:273:13)\n at CcZnp.emit (events.js:182:13)\n at Timeout. (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:240:18)\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 3/14/2019, 4:38:12 PM Exiting...
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR!
zigbee2mqtt@1.2.1 start: node index.js
npm ERR!
Exit status 1
npm
ERR!
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-03-14T15_38_12_800Z-debug.log
2019-03-14T16:38:14: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-03-14T16:38:14: PM2 log: App [npm:0] starting in -fork mode-
2019-03-14T16:38:14: PM2 log: App [npm:0] online
zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
node index.js
zigbee2mqtt:info 3/14/2019, 4:38:17 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-14.16-38-17'
zigbee2mqtt:debug 3/14/2019, 4:38:17 PM Removing old log directory '/share/zigbee2mqtt/log/2019-03-14.08-46-55'
zigbee2mqtt:debug 3/14/2019, 4:38:18 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","sp":{"baudRate":115200,"rtscts":true}}'
zigbee2mqtt:debug 3/14/2019, 4:38:18 PM Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:debug 3/14/2019, 4:38:18 PM Saving state to file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 3/14/2019, 4:38:18 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/14/2019, 4:38:18 PM Starting zigbee-shepherd

-------2---------

Log
[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-03-15T17:05:54: PM2 log: Launching in no daemon mode
2019-03-15T17:05:54: PM2 log: App [npm:0] starting in -fork mode-
2019-03-15T17:05:54: PM2 log: App [npm:0] online

zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
node index.js
zigbee2mqtt:info 3/15/2019, 5:05:59 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-15.17-05-59'
zigbee2mqtt:debug 3/15/2019, 5:05:59 PM Removing old log directory '/share/zigbee2mqtt/log/2019-03-15.08-40-27'
zigbee2mqtt:debug 3/15/2019, 5:06:01 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","sp":{"baudRate":115200,"rtscts":true}}'
zigbee2mqtt:debug 3/15/2019, 5:06:02 PM Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:debug 3/15/2019, 5:06:02 PM Saving state to file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 3/15/2019, 5:06:02 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/15/2019, 5:06:02 PM Starting zigbee-shepherd
zigbee2mqtt:info 3/15/2019, 5:06:02 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
zigbee2mqtt:info 3/15/2019, 5:07:02 PM Starting zigbee-shepherd
zigbee2mqtt:error 3/15/2019, 5:07:02 PM Error while starting zigbee-shepherd!
zigbee2mqtt:error 3/15/2019, 5:07:02 PM Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 3/15/2019, 5:07:02 PM Failed to start
{"message":"Error: No such file or directory, cannot open /dev/ttyACM0","stack":"Error: Error: No such file or directory, cannot open /dev/ttyACM0"}
zigbee2mqtt:error 3/15/2019, 5:07:02 PM Exiting...
npm
ERR! code ELIFECYCLE
npm ERR! errno 1
npm
ERR! zigbee2mqtt@1.2.1 start: node index.js
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-03-15T16_07_02_796Z-debug.log
2019-03-15T17:07:06: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-03-15T17:07:06: PM2 log: App [npm:0] starting in -fork mode-
2019-03-15T17:07:06: PM2 log: App [npm:0] online
zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
node index.js
zigbee2mqtt:info 3/15/2019, 5:07:09 PM Logging to directory: '/share/zigbee2mqtt/log/2019-03-15.17-07-09'
zigbee2mqtt:debug 3/15/2019, 5:07:09 PM Removing old log directory '/share/zigbee2mqtt/log/2019-03-15.08-41-38'
zigbee2mqtt:debug 3/15/2019, 5:07:10 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","sp":{"baudRate":115200,"rtscts":true}}'
zigbee2mqtt:debug 3/15/2019, 5:07:11 PM Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:debug 3/15/2019, 5:07:11 PM Saving state to file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 3/15/2019, 5:07:11 PM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
zigbee2mqtt:info 3/15/2019, 5:07:11 PM Starting zigbee-shepherd
zigbee2mqtt:info 3/15/2019, 5:07:11 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 15, 2019

@marinoraffaele did it work before? Can you try re-flashing your stick?

@marinoraffaele
Copy link

I tried to flash the zigbee pen again but the problem persists. if I restart the Raspberry everything works perfectly, at the first restart of hassio the addon zegebemqtt shows the error.

@supoeric
Copy link

I have the same issue.
After I delete "zigbee_shepherd_devices: true" and restart the service, it work again, but cannot add new devices.

I reflash the stick to latest firmware, but still get error.
screencapture-192-168-0-225-8123-hassio-addon-7ad98f9c_zigbee2mqtt-2019-03-16-22_39_14

Here is my config.
screencapture-192-168-0-225-8123-hassio-addon-7ad98f9c_zigbee2mqtt-2019-03-16-22_39_40

But after I deleted "zigbee_shepherd_devices: true" and restart zigbee2mqtt, It return normal.

@marinoraffaele
Copy link

I don't have the zigbee_shepherd_devices configuration: true but it doesn't work. I repeat the addon works if I restart Raspberry.

@Michaelnorge
Copy link

Same issue here...

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 19, 2019

@Michaelnorge did it ever work, or did it stop working after some time?

@marinoraffaele
Copy link

guys is not able to help me to solve this error when starting the add-on zigbee2mqtt? I do not know what to do. if I try to flash the pen cc2531 as soon as I insert it and the add-on works everything works, if I try to restart it has stopped working with the same error.

@Spitfire69
Copy link

Exactly the same issue here...on a Rpi3

@Michaelnorge
Copy link

@Koenkk
Using: ioBroker/Raspberry Pi3/CC2531/Trådfri/Xiaomi

It is working, but after a restart the USB-dongle wont start again. Its light is turning off while booting and the log shows "info: zigbee.0 Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)" and after 60 seconds "error: zigbee.0 Error while starting zigbee-shepherd!. Error: request timeout"

I need to restart raspberry three times to get the zigbee-dongle in work again.
(strange but really three times everytime)

I´m updated everything and made a reflash as well, but it did not help.

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 25, 2019

For all hasio users, can you check with the latest edge?

@colmben
Copy link

colmben commented Mar 26, 2019

I was getting this error on a fresh hassio install, redid the whole thing to hassbian and I'm still getting the same error. Restarting multiple times isn't helping. Pressing the reset button isn't helping.

Full debug of startup:

zigbee2mqtt:info 3/26/2019, 11:39:21 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-03-26.23-39-21'
serialport/bindings loading LinuxBinding +0ms
zigbee2mqtt:debug 3/26/2019, 11:39:22 PM Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":"HIDDEN"},"dbPath":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
zigbee2mqtt:debug 3/26/2019, 11:39:22 PM Loaded state from file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:debug 3/26/2019, 11:39:22 PM Saving state to file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:info 3/26/2019, 11:39:22 PM Starting zigbee2mqtt version 1.2.1 (commit #4048cb8)
zigbee2mqtt:info 3/26/2019, 11:39:22 PM Starting zigbee-shepherd
zigbee-shepherd:init zigbee-shepherd booting... +0ms
cc-znp Initialize, opening serial port +0ms
serialport/stream opening path: /dev/ttyACM0 +0ms
serialport/binding-abstract open +0ms
serialport/stream _read queueing _read for after open +8ms
serialport/bindings/poller Creating poller +0ms
serialport/stream opened path: /dev/ttyACM0 +5s
cc-znp The serialport /dev/ttyACM0 is opened. +5s
serialport/stream _read reading +8ms
serialport/binding-abstract read +5s
serialport/bindings/unixRead Starting read +0ms
zigbee-shepherd:request REQ --> SYS:osalNvRead +0ms
cc-znp:SREQ --> SYS:osalNvRead, { id: 3840, offset: 0, len: 1, value: [ 85 ] } +0ms
serialport/stream _write 8 bytes of data +68ms
serialport/binding-abstract write 8 bytes +66ms
serialport/bindings/unixWrite Starting write 8 bytes offset 0 bytesToWrite 8 +0ms
serialport/bindings/unixRead waiting for readable because of code: EAGAIN +67ms
serialport/bindings/poller Polling for "readable" +90ms
serialport/bindings/unixWrite write returned null 8 +8ms
serialport/bindings/unixWrite wrote 8 bytes +0ms
serialport/bindings/unixWrite Finished writing 8 bytes +1ms
serialport/stream binding.write write finished +17ms
cc-znp:SRSP <-- SYS:osalNvRead, timeout +0ms
zigbee-shepherd:request RSP <-- SYS:osalNvRead +2s
zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
at CcZnp. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:261:22)
at Object.onceWrapper (events.js:277:13)
at CcZnp.emit (events.js:189:13)
at Timeout. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:240:18)
at ontimeout (timers.js:436:11)
at tryOnTimeout (timers.js:300:5)
at listOnTimeout (timers.js:263:5)
at Timer.processTimers (timers.js:223:10) +0ms
zigbee2mqtt:info 3/26/2019, 11:39:29 PM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
serialport/stream #flush +1s
serialport/binding-abstract flush +2s
serialport/stream binding.flush finished +4ms
serialport/stream #close +2ms
serialport/binding-abstract close +6ms
serialport/bindings/poller Stopping poller +2s
serialport/bindings/poller Destroying poller +2ms
serialport/stream binding.read error { Error: Canceled
at Poller.emitCanceled (/opt/zigbee2mqtt/node_modules/@serialport/bindings/lib/poller.js:101:17)
at Poller.stop (/opt/zigbee2mqtt/node_modules/@serialport/bindings/lib/poller.js:91:10)
at close.then (/opt/zigbee2mqtt/node_modules/@serialport/bindings/lib/linux.js:48:19) canceled: true } +6ms
serialport/stream _read queueing _read for after open +2ms
serialport/stream binding.close finished +36s
cc-znp The serialport /dev/ttyACM0 is closed. +37s
zigbee2mqtt:info 3/26/2019, 11:40:29 PM Starting zigbee-shepherd
zigbee-shepherd:init zigbee-shepherd booting... +1m
cc-znp Initialize, opening serial port +24s
serialport/stream opening path: /dev/ttyACM0 +24s
serialport/binding-abstract open +1m
serialport/stream _read queueing _read for after open +2ms
serialport/bindings/poller Creating poller +1m
serialport/stream opened path: /dev/ttyACM0 +5s
cc-znp The serialport /dev/ttyACM0 is opened. +5s
serialport/stream _read reading +3ms
serialport/binding-abstract read +5s
serialport/bindings/unixRead Starting read +1m
zigbee-shepherd:request REQ --> SYS:osalNvRead +1m
cc-znp:SREQ --> SYS:osalNvRead, { id: 3840, offset: 0, len: 1, value: [ 85 ] } +1m
serialport/stream _write 8 bytes of data +10ms
serialport/binding-abstract write 8 bytes +11ms
serialport/bindings/unixWrite Starting write 8 bytes offset 0 bytesToWrite 8 +1m
serialport/bindings/unixRead waiting for readable because of code: EAGAIN +13ms
serialport/bindings/poller Polling for "readable" +18ms
serialport/bindings/unixWrite write returned null 8 +2ms
serialport/bindings/unixWrite wrote 8 bytes +1ms
serialport/bindings/unixWrite Finished writing 8 bytes +0ms
serialport/stream binding.write write finished +7ms
cc-znp:SRSP <-- SYS:osalNvRead, timeout +1m
zigbee-shepherd:request RSP <-- SYS:osalNvRead +2s
zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
at CcZnp. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:261:22)
at Object.onceWrapper (events.js:277:13)
at CcZnp.emit (events.js:189:13)
at Timeout. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:240:18)
at ontimeout (timers.js:436:11)
at tryOnTimeout (timers.js:300:5)
at listOnTimeout (timers.js:263:5)
at Timer.processTimers (timers.js:223:10) +1m
zigbee2mqtt:error 3/26/2019, 11:40:35 PM Error while starting zigbee-shepherd!
zigbee2mqtt:error 3/26/2019, 11:40:35 PM Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 3/26/2019, 11:40:35 PM Failed to start
{"message":"request timeout","stack":"Error: request timeout\n at CcZnp. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:261:22)\n at Object.onceWrapper (events.js:277:13)\n at CcZnp.emit (events.js:189:13)\n at Timeout. (/opt/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:240:18)\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 3/26/2019, 11:40:35 PM Exiting...
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! zigbee2mqtt@1.2.1 start: node index.js
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the zigbee2mqtt@1.2.1 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! /home/pi/.npm/_logs/2019-03-26T23_41_11_467Z-debug.log

@colmben
Copy link

colmben commented Mar 27, 2019

Note I am seeing this in dmesg, this is taking the usb out, (reflashing), putting it back in and then getting a failed start. The last two error lines appear after the failed start...

usb 1-1.2: USB disconnect, device number 4
[ 2158.363117] usb 1-1.2: new full-speed USB device number 5 using dwc_otg
[ 2158.510861] usb 1-1.2: New USB device found, idVendor=0451, idProduct=16a8
[ 2158.510875] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2158.510884] usb 1-1.2: Product: TI CC2531 USB CDC
[ 2158.510893] usb 1-1.2: Manufacturer: Texas Instruments
[ 2158.510901] usb 1-1.2: SerialNumber: __0X9C1D5813563EFFFF
[ 2158.513431] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
[ 2272.323670] cdc_acm 1-1.2:1.0: failed to set dtr/rts
[ 2278.883684] cdc_acm 1-1.2:1.0: failed to set dtr/rts

@colmben
Copy link

colmben commented Mar 27, 2019

Could someone take a minute to describe what led on the stick should do in a correct startup? Currently the led on my stick comes on when you first plug it in, goes out when the "npm start" command is given and stays off as the start fails. In a normal start should the led come back on?

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 27, 2019

@colmben the procedure should be:

  • Stop zigbee2mqtt
  • re-plug stick (green light should go ON) and press reset button on the stick (the one close to the usb port), green light should go OFF
  • start zigbee2mqtt, green light should go ON

@colmben
Copy link

colmben commented Mar 27, 2019

Great, thanks.

@colmben
Copy link

colmben commented Mar 27, 2019

So I am getting green light on re-plug, light off on reset but then the start fails with the timeout message and the green stays off.

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 27, 2019

what is the output of ls /dev on your system?

@colmben
Copy link

colmben commented Mar 27, 2019

pi@hassbian:/opt/zigbee2mqtt $ ls /dev
autofs fb0 input loop7 network_latency ram12 ram8 stdin tty15 tty24 tty33 tty42 tty51 tty60 uhid vcs4 vcsm
block fd kmsg loop-control network_throughput ram13 ram9 stdout tty16 tty25 tty34 tty43 tty52 tty61 uinput vcs5 vhci
btrfs-control full log mapper null ram14 random tty tty17 tty26 tty35 tty44 tty53 tty62 urandom vcs6 watchdog
bus fuse loop0 mem ppp ram15 raw tty0 tty18 tty27 tty36 tty45 tty54 tty63 vchiq vcsa watchdog0
cachefiles gpiochip0 loop1 memory_bandwidth ptmx ram2 rfkill tty1 tty19 tty28 tty37 tty46 tty55 tty7 vcio vcsa1 zero
char gpiochip1 loop2 mmcblk0 pts ram3 serial tty10 tty2 tty29 tty38 tty47 tty56 tty8 vc-mem vcsa2
console gpiochip2 loop3 mmcblk0p1 ram0 ram4 serial1 tty11 tty20 tty3 tty39 tty48 tty57 tty9 vcs vcsa3
cpu_dma_latency gpiomem loop4 mmcblk0p2 ram1 ram5 shm tty12 tty21 tty30 tty4 tty49 tty58 ttyACM0 vcs1 vcsa4
cuse hwrng loop5 mqueue ram10 ram6 snd tty13 tty22 tty31 tty40 tty5 tty59 ttyAMA0 vcs2 vcsa5
disk initctl loop6 net ram11 ram7 stderr tty14 tty23 tty32 tty41 tty50 tty6 ttyprintk vcs3 vcsa6
pi@hassbian:/opt/zigbee2mqtt $ lsusb
Bus 001 Device 006: ID 0451:16a8 Texas Instruments, Inc.
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

@colmben
Copy link

colmben commented Mar 27, 2019

Slightly easier format to read...

pi@hassbian:/opt/zigbee2mqtt $ ls -l /dev
total 0
crw-r--r-- 1 root root 10, 235 Mar 27 17:17 autofs
drwxr-xr-x 2 root root 580 Mar 27 17:17 block
crw------- 1 root root 10, 234 Mar 27 17:17 btrfs-control
drwxr-xr-x 3 root root 60 Jan 1 1970 bus
crw------- 1 root root 10, 63 Mar 27 17:17 cachefiles
drwxr-xr-x 2 root root 2460 Mar 27 17:44 char
crw------- 1 root root 5, 1 Mar 27 17:17 console
crw------- 1 root root 10, 62 Mar 27 17:17 cpu_dma_latency
crw------- 1 root root 10, 203 Mar 27 17:17 cuse
drwxr-xr-x 7 root root 140 Mar 27 17:17 disk
crw-rw---- 1 root video 29, 0 Mar 27 17:17 fb0
lrwxrwxrwx 1 root root 13 Nov 3 2016 fd -> /proc/self/fd
crw-rw-rw- 1 root root 1, 7 Mar 27 17:17 full
crw-rw-rw- 1 root root 10, 229 Mar 27 17:17 fuse
crw-rw---- 1 root gpio 254, 0 Mar 27 17:17 gpiochip0
crw-rw---- 1 root gpio 254, 1 Mar 27 17:17 gpiochip1
crw-rw---- 1 root gpio 254, 2 Mar 27 17:17 gpiochip2
crw-rw---- 1 root gpio 248, 0 Mar 27 17:17 gpiomem
crw------- 1 root root 10, 183 Mar 27 17:17 hwrng
lrwxrwxrwx 1 root root 25 Mar 27 17:17 initctl -> /run/systemd/initctl/fifo
drwxr-xr-x 2 root root 60 Jan 1 1970 input
crw-r--r-- 1 root root 1, 11 Mar 27 17:17 kmsg
lrwxrwxrwx 1 root root 28 Mar 27 17:17 log -> /run/systemd/journal/dev-log
brw-rw---- 1 root disk 7, 0 Mar 27 17:17 loop0
brw-rw---- 1 root disk 7, 1 Mar 27 17:17 loop1
brw-rw---- 1 root disk 7, 2 Mar 27 17:17 loop2
brw-rw---- 1 root disk 7, 3 Mar 27 17:17 loop3
brw-rw---- 1 root disk 7, 4 Mar 27 17:17 loop4
brw-rw---- 1 root disk 7, 5 Mar 27 17:17 loop5
brw-rw---- 1 root disk 7, 6 Mar 27 17:17 loop6
brw-rw---- 1 root disk 7, 7 Mar 27 17:17 loop7
crw-rw---- 1 root disk 10, 237 Mar 27 17:17 loop-control
drwxr-xr-x 2 root root 60 Mar 27 17:17 mapper
crw-r----- 1 root kmem 1, 1 Mar 27 17:17 mem
crw------- 1 root root 10, 59 Mar 27 17:17 memory_bandwidth
brw-rw---- 1 root disk 179, 0 Mar 27 17:17 mmcblk0
brw-rw---- 1 root disk 179, 1 Mar 27 17:17 mmcblk0p1
brw-rw---- 1 root disk 179, 2 Mar 27 17:17 mmcblk0p2
drwxrwxrwt 2 root root 40 Jan 1 1970 mqueue
drwxr-xr-x 2 root root 60 Mar 27 17:17 net
crw------- 1 root root 10, 61 Mar 27 17:17 network_latency
crw------- 1 root root 10, 60 Mar 27 17:17 network_throughput
crw-rw-rw- 1 root root 1, 3 Mar 27 17:17 null
crw------- 1 root root 108, 0 Mar 27 17:17 ppp
crw-rw-rw- 1 root tty 5, 2 Mar 27 18:10 ptmx
drwxr-xr-x 2 root root 0 Nov 3 2016 pts
brw-rw---- 1 root disk 1, 0 Mar 27 17:17 ram0
brw-rw---- 1 root disk 1, 1 Mar 27 17:17 ram1
brw-rw---- 1 root disk 1, 10 Mar 27 17:17 ram10
brw-rw---- 1 root disk 1, 11 Mar 27 17:17 ram11
brw-rw---- 1 root disk 1, 12 Mar 27 17:17 ram12
brw-rw---- 1 root disk 1, 13 Mar 27 17:17 ram13
brw-rw---- 1 root disk 1, 14 Mar 27 17:17 ram14
brw-rw---- 1 root disk 1, 15 Mar 27 17:17 ram15
brw-rw---- 1 root disk 1, 2 Mar 27 17:17 ram2
brw-rw---- 1 root disk 1, 3 Mar 27 17:17 ram3
brw-rw---- 1 root disk 1, 4 Mar 27 17:17 ram4
brw-rw---- 1 root disk 1, 5 Mar 27 17:17 ram5
brw-rw---- 1 root disk 1, 6 Mar 27 17:17 ram6
brw-rw---- 1 root disk 1, 7 Mar 27 17:17 ram7
brw-rw---- 1 root disk 1, 8 Mar 27 17:17 ram8
brw-rw---- 1 root disk 1, 9 Mar 27 17:17 ram9
crw-rw-rw- 1 root root 1, 8 Mar 27 17:17 random
drwxr-xr-x 2 root root 60 Jan 1 1970 raw
crw-rw-r-- 1 root netdev 10, 58 Mar 27 17:17 rfkill
drwxr-xr-x 4 root root 80 Mar 27 17:44 serial
lrwxrwxrwx 1 root root 7 Mar 27 17:17 serial1 -> ttyAMA0
drwxrwxrwt 2 root root 40 Nov 3 2016 shm
drwxr-xr-x 3 root root 160 Mar 27 17:17 snd
lrwxrwxrwx 1 root root 15 Nov 3 2016 stderr -> /proc/self/fd/2
lrwxrwxrwx 1 root root 15 Nov 3 2016 stdin -> /proc/self/fd/0
lrwxrwxrwx 1 root root 15 Nov 3 2016 stdout -> /proc/self/fd/1
crw-rw-rw- 1 root tty 5, 0 Mar 27 17:17 tty
crw--w---- 1 root tty 4, 0 Mar 27 17:17 tty0
crw--w---- 1 root tty 4, 1 Mar 27 17:17 tty1
crw--w---- 1 root tty 4, 10 Mar 27 17:17 tty10
crw--w---- 1 root tty 4, 11 Mar 27 17:17 tty11
crw--w---- 1 root tty 4, 12 Mar 27 17:17 tty12
crw--w---- 1 root tty 4, 13 Mar 27 17:17 tty13
crw--w---- 1 root tty 4, 14 Mar 27 17:17 tty14
crw--w---- 1 root tty 4, 15 Mar 27 17:17 tty15
crw--w---- 1 root tty 4, 16 Mar 27 17:17 tty16
crw--w---- 1 root tty 4, 17 Mar 27 17:17 tty17
crw--w---- 1 root tty 4, 18 Mar 27 17:17 tty18
crw--w---- 1 root tty 4, 19 Mar 27 17:17 tty19
crw--w---- 1 root tty 4, 2 Mar 27 17:17 tty2
crw--w---- 1 root tty 4, 20 Mar 27 17:17 tty20
crw--w---- 1 root tty 4, 21 Mar 27 17:17 tty21
crw--w---- 1 root tty 4, 22 Mar 27 17:17 tty22
crw--w---- 1 root tty 4, 23 Mar 27 17:17 tty23
crw--w---- 1 root tty 4, 24 Mar 27 17:17 tty24
crw--w---- 1 root tty 4, 25 Mar 27 17:17 tty25
crw--w---- 1 root tty 4, 26 Mar 27 17:17 tty26
crw--w---- 1 root tty 4, 27 Mar 27 17:17 tty27
crw--w---- 1 root tty 4, 28 Mar 27 17:17 tty28
crw--w---- 1 root tty 4, 29 Mar 27 17:17 tty29
crw--w---- 1 root tty 4, 3 Mar 27 17:17 tty3
crw--w---- 1 root tty 4, 30 Mar 27 17:17 tty30
crw--w---- 1 root tty 4, 31 Mar 27 17:17 tty31
crw--w---- 1 root tty 4, 32 Mar 27 17:17 tty32
crw--w---- 1 root tty 4, 33 Mar 27 17:17 tty33
crw--w---- 1 root tty 4, 34 Mar 27 17:17 tty34
crw--w---- 1 root tty 4, 35 Mar 27 17:17 tty35
crw--w---- 1 root tty 4, 36 Mar 27 17:17 tty36
crw--w---- 1 root tty 4, 37 Mar 27 17:17 tty37
crw--w---- 1 root tty 4, 38 Mar 27 17:17 tty38
crw--w---- 1 root tty 4, 39 Mar 27 17:17 tty39
crw--w---- 1 root tty 4, 4 Mar 27 17:17 tty4
crw--w---- 1 root tty 4, 40 Mar 27 17:17 tty40
crw--w---- 1 root tty 4, 41 Mar 27 17:17 tty41
crw--w---- 1 root tty 4, 42 Mar 27 17:17 tty42
crw--w---- 1 root tty 4, 43 Mar 27 17:17 tty43
crw--w---- 1 root tty 4, 44 Mar 27 17:17 tty44
crw--w---- 1 root tty 4, 45 Mar 27 17:17 tty45
crw--w---- 1 root tty 4, 46 Mar 27 17:17 tty46
crw--w---- 1 root tty 4, 47 Mar 27 17:17 tty47
crw--w---- 1 root tty 4, 48 Mar 27 17:17 tty48
crw--w---- 1 root tty 4, 49 Mar 27 17:17 tty49
crw--w---- 1 root tty 4, 5 Mar 27 17:17 tty5
crw--w---- 1 root tty 4, 50 Mar 27 17:17 tty50
crw--w---- 1 root tty 4, 51 Mar 27 17:17 tty51
crw--w---- 1 root tty 4, 52 Mar 27 17:17 tty52
crw--w---- 1 root tty 4, 53 Mar 27 17:17 tty53
crw--w---- 1 root tty 4, 54 Mar 27 17:17 tty54
crw--w---- 1 root tty 4, 55 Mar 27 17:17 tty55
crw--w---- 1 root tty 4, 56 Mar 27 17:17 tty56
crw--w---- 1 root tty 4, 57 Mar 27 17:17 tty57
crw--w---- 1 root tty 4, 58 Mar 27 17:17 tty58
crw--w---- 1 root tty 4, 59 Mar 27 17:17 tty59
crw--w---- 1 root tty 4, 6 Mar 27 17:17 tty6
crw--w---- 1 root tty 4, 60 Mar 27 17:17 tty60
crw--w---- 1 root tty 4, 61 Mar 27 17:17 tty61
crw--w---- 1 root tty 4, 62 Mar 27 17:17 tty62
crw--w---- 1 root tty 4, 63 Mar 27 17:17 tty63
crw--w---- 1 root tty 4, 7 Mar 27 17:17 tty7
crw--w---- 1 root tty 4, 8 Mar 27 17:17 tty8
crw--w---- 1 root tty 4, 9 Mar 27 17:17 tty9
crw-rw---- 1 root dialout 166, 0 Mar 27 17:46 ttyACM0
crw-rw---- 1 root dialout 204, 64 Mar 27 17:17 ttyAMA0
crw------- 1 root root 5, 3 Mar 27 17:17 ttyprintk
crw------- 1 root root 10, 239 Mar 27 17:17 uhid
crw------- 1 root root 10, 223 Mar 27 17:17 uinput
crw-rw-rw- 1 root root 1, 9 Mar 27 17:17 urandom
crw-rw---- 1 root video 245, 0 Mar 27 17:17 vchiq
crw-rw---- 1 root video 249, 0 Mar 27 17:17 vcio
crw------- 1 root root 250, 0 Mar 27 17:17 vc-mem
crw-rw---- 1 root tty 7, 0 Mar 27 17:17 vcs
crw-rw---- 1 root tty 7, 1 Mar 27 17:17 vcs1
crw-rw---- 1 root tty 7, 2 Mar 27 17:17 vcs2
crw-rw---- 1 root tty 7, 3 Mar 27 17:17 vcs3
crw-rw---- 1 root tty 7, 4 Mar 27 17:17 vcs4
crw-rw---- 1 root tty 7, 5 Mar 27 17:17 vcs5
crw-rw---- 1 root tty 7, 6 Mar 27 17:17 vcs6
crw-rw---- 1 root tty 7, 128 Mar 27 17:17 vcsa
crw-rw---- 1 root tty 7, 129 Mar 27 17:17 vcsa1
crw-rw---- 1 root tty 7, 130 Mar 27 17:17 vcsa2
crw-rw---- 1 root tty 7, 131 Mar 27 17:17 vcsa3
crw-rw---- 1 root tty 7, 132 Mar 27 17:17 vcsa4
crw-rw---- 1 root tty 7, 133 Mar 27 17:17 vcsa5
crw-rw---- 1 root tty 7, 134 Mar 27 17:17 vcsa6
crw-rw---- 1 root video 246, 0 Mar 27 17:17 vcsm
crw------- 1 root root 10, 137 Mar 27 17:17 vhci
crw------- 1 root root 10, 130 Mar 27 17:17 watchdog
crw------- 1 root root 252, 0 Mar 27 17:17 watchdog0
crw-rw-rw- 1 root root 1, 5 Mar 27 17:17 zero

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 27, 2019

you arent using hassio, right? can you verify write access: http://www.zigbee2mqtt.io/information/zigbee2mqtt_fails_to_start.html

@colmben
Copy link

colmben commented Mar 27, 2019

I tried hassio first but had this issue, found it very confusing to confirm anything re usb/serial ports in hassio so I did a fresh hassbian install and that is what I am showing now. Write access looks ok...

pi@hassbian:/opt/zigbee2mqtt $ test -w /dev/ttyACM0 && echo success || echo failure
success

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 27, 2019

can you try re-flashing the stick? As you also have tried a different os/system, I wouldnt know what to do next (there is a chance that the stick itself is broken though).

@colmben
Copy link

colmben commented Mar 27, 2019

I've reflashed with max stability and an old one from last July, both failed with same error. I'll try on an ubuntu laptop and see how it goes.

@colmben
Copy link

colmben commented Mar 27, 2019

Same issue on the unbuntu laptop. Oh dear :( I waited months for that CC2531 from AliExpress, arrgggg!

@h4nc
Copy link

h4nc commented Mar 27, 2019

The cable going from the debugger to the cc2531 could be plugged in incorrect.

Did you check that?

Do you get a confirmation that the firmware was flashed correctly?

@colmben
Copy link

colmben commented Mar 27, 2019

I double checked the connections against the picture in https://www.zigbee2mqtt.io/getting_started/flashing_the_cc2531.html

The flash seems to go fine. The led comes on in green once the flash has finished:

colm@colm-XPS-13-9350:~/cc-tool$ sudo ./cc-tool -e -w CC2531ZNP-Prod.hex 
 assword for colm:  Programmer: CC Debugger
  Target: CC2540
  Erasing flash...
  Completed       
  Writing flash (241 KB)...
  Completed (17.96 s.)
colm@colm-XPS-13-9350:~/cc-tool$ 

Having said that, I'm just seeing that line re Target: CC 2540 - is that normal? Could I have bought the wrong thing?

@h4nc
Copy link

h4nc commented Mar 27, 2019

Look it up in your Aliexpress order. Does it say cc2540?

@colmben
Copy link

colmben commented Mar 27, 2019

CC2531 CC2540 Zigbee Sniffer Wireless Board Bluetooth BLE 4.0 Dongle Capture Module USB Programmer Downloader Cable Connector

[Transaction Screenshot]

€ 4,26 X1

Product properties: CC2540

Oh Dear Lord! That Aliexpress page is very confusing, the two pictures for the CC2531 and CC2540 are the same!

Anyways, in Irish parlance, I am an ejit, sorry for confusing the thread (though I suspect I wouldn't be the only person to do this so at least it is now one documented possibility for the timeout error).

@h4nc
Copy link

h4nc commented Mar 27, 2019

Glad you found the issue. Hopefully your new cc2531 will arrive faster.

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 28, 2019

@colmben it this something that can be also verified visually? Is CC2540 written on the chip of the USB?

@aXecuter
Copy link

@colmben the procedure should be:

* Stop zigbee2mqtt

* re-plug stick (green light should go ON) and press reset button on the stick (the one close to the usb port), green light should go OFF

* start zigbee2mqtt, green light should go ON

I have the same problems (hassbian) since I updated the cc2531 firmware to the (20190223) version. Before that (can't remember the fw version) everything worked without major issues for may be half a year.

the stick is on /dev/ttyACM0 just like in the config, and there's write access to the serial port
after reinserting the stick and pressing the reset button, most of the times the led stays off and I can manage to start Zigbee2mqtt manually via npm start.

But I cant get Zigbee2mqtt to run as a daemon anymore, output:

pi@hassbian:/dev $ systemctl status zigbee2mqtt.service
● zigbee2mqtt.service - zigbee2mqtt
   Loaded: loaded (/etc/systemd/system/zigbee2mqtt.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Sun 2019-03-24 14:31:57 CET; 3 days ago
  Process: 1058 ExecStart=/usr/bin/npm start (code=exited, status=203/EXEC)
 Main PID: 1058 (code=exited, status=203/EXEC)

Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Unit entered failed state.
Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Failed with result 'exit-code'.
Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Service hold-off time over, scheduling restart.
Mar 24 14:31:57 hassbian systemd[1]: Stopped zigbee2mqtt.
Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Start request repeated too quickly.
Mar 24 14:31:57 hassbian systemd[1]: Failed to start zigbee2mqtt.
Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Unit entered failed state.
Mar 24 14:31:57 hassbian systemd[1]: zigbee2mqtt.service: Failed with result 'exit-code'.
pi@hassbian:/dev $

Also after a while, it looks like the cc2531 stick can't be reset anymore, led goes on immediately after a reset. Only option then is to reflash, and I have to repair almost all devices (18 of them). At the moment I'm using the fw from 20190315.

@Koenkk
Copy link
Collaborator

Koenkk commented Mar 28, 2019

can you provide the log at the moment it crashes?

@colmben
Copy link

colmben commented Mar 28, 2019

@colmben it this something that can be also verified visually? Is CC2540 written on the chip of the USB?

The stick is marked as CC25xx which isn't very helpful! The chip itself is very faint, but I think I see a CC2540 on it. Either way, if you look at the AliExpress order summary I posted, it has the line "Product Properties: CC2540", this indicates I chose the wrong one. Why sellers do multiple different items in one listing like that I don't know, it is very confusing![
closeup
20190328_140429

](url)

Koenkk added a commit to Koenkk/zigbee2mqtt.io that referenced this issue Mar 28, 2019
@moejetz
Copy link

moejetz commented Apr 9, 2019

I had the exact same issue, however with older version/firmware combinations too.
I use a LattePanda Delta as my hardware running a standard ubuntu 18.04.
My problem was that the hardware has an Arduino interface built-in which sometimes after boot takes ttyACM0 or ttyACM1 if the CC2531 is plugged in too, so zigbee2mqtt looks at the wrong tty port and therefore cannot start.

To fix this, I have to change the port NOT over the hassio web ui, BUT manually in /usr/share/hassio/share/zigbee2mqtt/configuration.yaml respectively /share/zigbee2mqtt/configuration.yaml. After that, I don't even need to restart the add-on, it just works with the next restarting iteration. Below are the logs while I change the tty port in the config:

  zigbee2mqtt:error 4/9/2019, 8:41:31 AM Failed to start
	{"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:261:22)\n    at Object.onceWrapper (events.js:273:13)\n    at CcZnp.emit (events.js:182:13)\n    at Timeout.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:240:18)\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 4/9/2019, 8:41:31 AM Exiting...
npm
 ERR! code ELIFECYCLE
npm ERR! errno
 1
npm
 ERR! zigbee2mqtt@1.2.1 start: `node index.js`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-04-09T06_41_31_215Z-debug.log
2019-04-09T08:41:31: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-04-09T08:41:31: PM2 log: App [npm:0] starting in -fork mode-
2019-04-09T08:41:31: PM2 log: App [npm:0] online
> zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
> node index.js
  zigbee2mqtt:info 4/9/2019, 8:41:32 AM Logging to directory: '/share/zigbee2mqtt/log/2019-04-09.08-41-32'
  zigbee2mqtt:info 4/9/2019, 8:41:33 AM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
  zigbee2mqtt:info 4/9/2019, 8:41:33 AM Starting zigbee-shepherd
  zigbee2mqtt:info 4/9/2019, 8:41:34 AM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
  zigbee2mqtt:info 4/9/2019, 8:42:34 AM Starting zigbee-shepherd
  zigbee2mqtt:error 4/9/2019, 8:42:36 AM Error while starting zigbee-shepherd!
  zigbee2mqtt:error 4/9/2019, 8:42:36 AM Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 4/9/2019, 8:42:36 AM Failed to start
	{"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:261:22)\n    at Object.onceWrapper (events.js:273:13)\n    at CcZnp.emit (events.js:182:13)\n    at Timeout.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:240:18)\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 4/9/2019, 8:42:36 AM Exiting...
npm
 ERR! code ELIFECYCLE
npm ERR! errno
 1
npm ERR! zigbee2mqtt@1.2.1 start: `node index.js`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-04-09T06_42_36_335Z-debug.log
2019-04-09T08:42:37: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-04-09T08:42:37: PM2 log: App [npm:0] starting in -fork mode-
2019-04-09T08:42:37: PM2 log: App [npm:0] online
> zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
> node index.js
  zigbee2mqtt:info 4/9/2019, 8:42:38 AM Logging to directory: '/share/zigbee2mqtt/log/2019-04-09.08-42-38'
  zigbee2mqtt:info 4/9/2019, 8:42:38 AM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
  zigbee2mqtt:info 4/9/2019, 8:42:38 AM Starting zigbee-shepherd
  zigbee2mqtt:info 4/9/2019, 8:42:39 AM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
  zigbee2mqtt:info 4/9/2019, 8:43:40 AM Starting zigbee-shepherd
  zigbee2mqtt:error 4/9/2019, 8:43:41 AM Error while starting zigbee-shepherd!
  zigbee2mqtt:error 4/9/2019, 8:43:41 AM Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 4/9/2019, 8:43:41 AM Failed to start
	{"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:261:22)\n    at Object.onceWrapper (events.js:273:13)\n    at CcZnp.emit (events.js:182:13)\n    at Timeout.<anonymous> (/zigbee2mqtt-1.2.1/node_modules/cc-znp/lib/ccznp.js:240:18)\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 4/9/2019, 8:43:41 AM Exiting...
npm
 ERR! code ELIFECYCLE
npm ERR! errno
 1
npm ERR! zigbee2mqtt@1.2.1 start: `node index.js`
npm ERR! Exit status 1
npm ERR!
 
npm ERR! Failed at the zigbee2mqtt@1.2.1 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-04-09T06_43_41_570Z-debug.log
2019-04-09T08:43:42: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-04-09T08:43:42: PM2 log: App [npm:0] starting in -fork mode-
2019-04-09T08:43:42: PM2 log: App [npm:0] online
> zigbee2mqtt@1.2.1 start /zigbee2mqtt-1.2.1
> node index.js
  zigbee2mqtt:info 4/9/2019, 8:43:43 AM Logging to directory: '/share/zigbee2mqtt/log/2019-04-09.08-43-43'
  zigbee2mqtt:info 4/9/2019, 8:43:43 AM Starting zigbee2mqtt version 1.2.1 (commit #unknown)
  zigbee2mqtt:info 4/9/2019, 8:43:43 AM Starting zigbee-shepherd
  zigbee2mqtt:info 4/9/2019, 8:43:45 AM zigbee-shepherd started
  zigbee2mqtt:info 4/9/2019, 8:43:45 AM Coordinator firmware version: '20190223'
  zigbee2mqtt:info 4/9/2019, 8:43:45 AM Currently 5 devices are joined:

.......

@moejetz
Copy link

moejetz commented Apr 9, 2019

So @danielwelch you may want to check out if config changes over the hass.io addon web ui do still work, or just don't work for me because I'm using stock ubuntu instead of a RPI with the pre-configured hass.io image. Maybe the point is that ubuntu has a complete file system, so the config path for me is /usr/share/hassio/share/zigbee2mqtt/configuration.yaml instead of just /share/zigbee2mqtt/configuration.yaml . Just my 2 cents...

@danielwelch
Copy link
Owner

danielwelch commented Apr 9, 2019 via email

@miquelbotanch
Copy link

miquelbotanch commented Apr 17, 2019

Same problem here (CC2531), I've been able to operate with aqara devices and tradfi lamps and another CC2531 as a router, after docker upgrade, nothing works, permissions are ok,port is correctly asssigned and I've done all the combinations of button press, unplug restart zigbee2mqtt container...

Last Docker version, and stable coordinator firmware.
Using debug the last line is

"cc-znp The serialport /dev/ttyACM1 is closed."

but I've verified that zigbee2mqtt has write access to the port.

Completely stuck, any clue what else to try ?

UPDATE: reflashing the CC2531 concentrator with stability firmware has solved it.

@stale
Copy link

stale bot commented Jun 16, 2019

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.

@stale stale bot added the stale label Jun 16, 2019
@stale stale bot closed this as completed Jun 23, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests