Zigbee2mqtt: zigbee-shepherd does not start up

Created on 25 Jan 2019  路  79Comments  路  Source: Koenkk/zigbee2mqtt

I try to get zigbee2mqtt running on a nuc with docker. (I flashed the lastest firmware " CC2531ZNP-Prod_20181024.zip")
I already tried different usb ports and finally I used the latest-dev version and got the following error
`
Using '/app/data' as data directory,
,

[email protected] start /app,
node index.js,
,
zigbee2mqtt:info 2019-1-25 20:30:29 Logging to directory: '/app/data/log/2019-01-25.20-30-29',
zigbee2mqtt:info 2019-1-25 20:30:29 Starting zigbee2mqtt version 1.0.1 (commit #5718cd0),
zigbee2mqtt:info 2019-1-25 20:30:29 Starting zigbee-shepherd,
zigbee2mqtt:info 2019-1-25 20:30:37 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds),
/app/node_modules/q/q.js:155,
throw e;,
^,
,
TypeError: Cannot read property 'close' of undefined,
at shepherd.start (/app/lib/zigbee.js:45:47),
at /app/node_modules/q/q.js:2059:17,
at runSingle (/app/node_modules/q/q.js:137:13),
at flush (/app/node_modules/q/q.js:125:13),
at _combinedTickCallback (internal/process/next_tick.js:132:7),
at process._tickCallback (internal/process/next_tick.js:181:9),
Using '/app/data' as data directory,
,
[email protected] start /app,
node index.js,
,
zigbee2mqtt:info 2019-1-25 20:32:30 Logging to directory: '/app/data/log/2019-01-25.20-32-30',
zigbee2mqtt:info 2019-1-25 20:32:30 Starting zigbee2mqtt version 1.0.1 (commit #5718cd0),
zigbee2mqtt:info 2019-1-25 20:32:30 Starting zigbee-shepherd,
zigbee2mqtt:info 2019-1-25 20:32:43 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds),
/app/node_modules/q/q.js:155,
throw e;,
^,
,
TypeError: Cannot read property 'close' of undefined,
at shepherd.start (/app/lib/zigbee.js:45:47),
at /app/node_modules/q/q.js:2059:17,
at runSingle (/app/node_modules/q/q.js:137:13),
at flush (/app/node_modules/q/q.js:125:13),
at _combinedTickCallback (internal/process/next_tick.js:132:7),
at process._tickCallback (internal/process/next_tick.js:181:9),
npm ERR! code ELIFECYCLE,
npm ERR! errno 1,
npm ERR! [email protected] start: node index.js,
npm ERR! Exit status 1,
`

stale
Source
picture Ulli2k

All 79 comments

by the way: unplug the stick, reconnect and push the reset button does not work

Ulli2k picture Ulli2k on 25 Jan 2019

I have the same problem. Tried reflashing the stick and reinstalling zigbee2mqtt. If I exit the process right after the error message it says "Not connected to MQTT Server", maybe we did something wrong there?

lennartbecker picture lennartbecker on 26 Jan 2019

What is your setup? hardware/os, etc.

Koenkk picture Koenkk on 26 Jan 2019

Running a cc2531 stick with the latest Firmware linked in the documentation. Tried it on a raspberry pi and on my Ubuntu 18.10 laptop and have the same error message on both. It worked very shortly once.

lennartbecker picture lennartbecker on 27 Jan 2019

@Ulli2k does the green light also turn off when you press the reset button?

@lennartbecker can you post your log?

Koenkk picture Koenkk on 27 Jan 2019

Similar problem, ubuntu 18.04 and 褋褋2531

pi@ubuntumd:~$ node --version
v10.15.0
pi@ubuntumd:~$ npm --version
6.4.1

pi@ubuntumd:~$ ls -l /dev/serial/by-id
懈褌芯谐芯 0
lrwxrwxrwx 1 root root 13 褟薪胁 29 00:06 usb-0658_0200_12345678-9012-3456-7890-123456789012-if00 -> ../../ttyACM0
lrwxrwxrwx 1 root root 13 褟薪胁 29 00:06 usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B000E8967DA-if00 -> ../../ttyACM1

2019-1-29 00:37:12 - info: Logging to directory: '/opt/zigbee2mqtt/data/log/2019-01-29.00-37-11'
2019-1-29 00:37:12 - debug: Removing old log directory '/opt/zigbee2mqtt/data/log/2019-01-29.00-36-24'
2019-1-29 00:37:12 - 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":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
2019-1-29 00:37:12 - debug: Can't load state from file /opt/zigbee2mqtt/data/state.json (doesn't exsist)
2019-1-29 00:37:12 - info: Starting zigbee2mqtt version 1.0.1 (commit #16f3e88)
2019-1-29 00:37:12 - info: Starting zigbee-shepherd
2019-1-29 00:37:15 - info: Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)]

Run manual:

pi@ubuntumd:/opt/zigbee2mqtt$ npm start

> [email protected] start /opt/zigbee2mqtt
> node index.js

  zigbee2mqtt:info 2019-1-29 00:45:16 Logging to directory: '/opt/zigbee2mqtt/data/log/2019-01-29.00-45-16'
  zigbee2mqtt:debug 2019-1-29 00:45:16 Removing old log directory '/opt/zigbee2mqtt/data/log/2019-01-29.00-43-34'
  zigbee2mqtt:debug 2019-1-29 00:45:17 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":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-1-29 00:45:17 Can't load state from file /opt/zigbee2mqtt/data/state.json (doesn't exsist)
  zigbee2mqtt:info 2019-1-29 00:45:17 Starting zigbee2mqtt version 1.0.1 (commit #16f3e88)
  zigbee2mqtt:info 2019-1-29 00:45:17 Starting zigbee-shepherd
  zigbee2mqtt:info 2019-1-29 00:45:20 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
/opt/zigbee2mqtt/node_modules/q/q.js:155
                throw e;
                ^

TypeError: Cannot read property 'close' of undefined
    at shepherd.start (/opt/zigbee2mqtt/lib/zigbee.js:45:47)
    at /opt/zigbee2mqtt/node_modules/q/q.js:2059:17
    at runSingle (/opt/zigbee2mqtt/node_modules/q/q.js:137:13)
    at flush (/opt/zigbee2mqtt/node_modules/q/q.js:125:13)
    at process._tickCallback (internal/process/next_tick.js:61:11)
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!     /home/pi/.npm/_logs/2019-01-28T19_45_20_445Z-debug.log
pi@ubuntumd:/opt/zigbee2mqtt$

configuration.yaml:

homeassistant: false
permit_join: true
advanced:
#  channel: 26
  log_level: debug
mqtt:
  base_topic: zigbee2mqtt
  server: 'mqtt://192.168.1.39'
serial:
  port: /dev/ttyACM1

Such a problem occurs quite often, it helps to flashing the stick, removing the entire project and installing zigbee2mqtt from scratch. And it works for about a week and then the situation repeats. Developers branch needed to support xiaomi light bulbs

Pressing the cc2531 button causes the red LED to light up and solves the startup problem. But this solution requires periodically removing the stick and pressing the button, which can sometimes be very difficult.

directman66 picture directman66 on 28 Jan 2019

Same error, master branch

DEBUG=zigbee-shepherd* node index.js
  zigbee2mqtt:info 2019-1-30 00:03:34 Logging to directory: '/home/ricardo/Documents/develop/zigbee2mqtt/data/log/2019-01-30.00-03-34'
  zigbee2mqtt:debug 2019-1-30 00:03:34 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"channelList":[11]},"dbPath":"/home/ricardo/Documents/develop/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-1-30 00:03:34 Loaded state from file /home/ricardo/Documents/develop/zigbee2mqtt/data/state.json
  zigbee2mqtt:info 2019-1-30 00:03:34 Starting zigbee2mqtt version 1.0.1 (commit #b95dcd0)
  zigbee2mqtt:info 2019-1-30 00:03:34 Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +0ms
  zigbee-shepherd:request REQ --> SYS:osalNvRead +5s
  zigbee-shepherd:request RSP <-- SYS:osalNvRead +3s
  zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
    at CcZnp.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:255:22)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at CcZnp.emit (events.js:211:7)
    at Timeout.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:234:18)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5) +5ms
  zigbee2mqtt:info 2019-1-30 00:03:42 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
  zigbee2mqtt:info 2019-1-30 00:04:42 Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +1m
  zigbee-shepherd:request REQ --> SYS:osalNvRead +5s
  zigbee-shepherd:request RSP <-- SYS:osalNvRead +3s
  zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
    at CcZnp.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:255:22)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at CcZnp.emit (events.js:211:7)
    at Timeout.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:234:18)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5) +1ms
  zigbee2mqtt:error 2019-1-30 00:04:51 Error while starting zigbee-shepherd!
  zigbee2mqtt:error 2019-1-30 00:04:51 Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 2019-1-30 00:04:51 Failed to start
    {"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:255:22)\n    at Object.onceWrapper (events.js:315:30)\n    at emitOne (events.js:116:13)\n    at CcZnp.emit (events.js:211:7)\n    at Timeout.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:234:18)\n    at ontimeout (timers.js:498:11)\n    at tryOnTimeout (timers.js:323:5)\n    at Timer.listOnTimeout (timers.js:290:5)"}
^C  zigbee2mqtt:debug 2019-1-30 00:05:05 Saving state to file /home/ricardo/Documents/develop/zigbee2mqtt/data/state.json
  zigbee2mqtt:error 2019-1-30 00:05:05 Not connected to MQTT server!
  zigbee2mqtt:error 2019-1-30 00:05:05 Cannot send message: topic: 'zigbee2mqtt/bridge/state', payload: 'offline
  zigbee-shepherd zigbee-shepherd is stopping. +15s
  zigbee-shepherd zigbee-shepherd is stopped. +1ms
  zigbee2mqtt:info 2019-1-30 00:05:05 zigbee-shepherd stopped

dev branch

 DEBUG=zigbee-shepherd* node index.js
  zigbee2mqtt:info 2019-1-30 00:08:01 Logging to directory: '/home/ricardo/Documents/develop/zigbee2mqtt/data/log/2019-01-30.00-08-01'
  zigbee2mqtt:debug 2019-1-30 00:08:01 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":"/home/ricardo/Documents/develop/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-1-30 00:08:01 Loaded state from file /home/ricardo/Documents/develop/zigbee2mqtt/data/state.json
  zigbee2mqtt:info 2019-1-30 00:08:01 Starting zigbee2mqtt version 1.0.1 (commit #fd93292)
  zigbee2mqtt:info 2019-1-30 00:08:01 Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +0ms
  zigbee-shepherd:request REQ --> SYS:osalNvRead +0ms
  zigbee-shepherd:request RSP <-- SYS:osalNvRead +3s
  zigbee-shepherd:init Coordinator initialize had an error: Error: request timeout
    at CcZnp.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:255:22)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at CcZnp.emit (events.js:211:7)
    at Timeout.<anonymous> (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/cc-znp/lib/ccznp.js:234:18)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5) +0ms
  zigbee2mqtt:info 2019-1-30 00:08:10 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/q/q.js:155
                throw e;
                ^

TypeError: Cannot read property 'close' of undefined
    at shepherd.start (/home/ricardo/Documents/develop/zigbee2mqtt/lib/zigbee.js:45:47)
    at /home/ricardo/Documents/develop/zigbee2mqtt/node_modules/q/q.js:2059:17
    at runSingle (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/q/q.js:137:13)
    at flush (/home/ricardo/Documents/develop/zigbee2mqtt/node_modules/q/q.js:125:13)
    at _combinedTickCallback (internal/process/next_tick.js:131:7)
    at process._tickCallback (internal/process/next_tick.js:180:9

I use to reboot the machine to make it work sometime, but that doesn't even work now. Everybody is using the latest fw with group support?

subzero79 picture subzero79 on 29 Jan 2019

I can see in the host dmesg

[ 3477.635917] cdc_acm 3-1:1.0: failed to set dtr/rts

changing the adv setting false to true or vice versa doesn't make a change

subzero79 picture subzero79 on 29 Jan 2019

Temporarily for tests, I registered in the config software a stick reset

advanced:
  log_level: debug
  soft_reset_timeout: 3600
directman66 picture directman66 on 30 Jan 2019

@subzero79 what coordinator device do you use?

Koenkk picture Koenkk on 30 Jan 2019

I use the cc2531 naked usb dongle.

subzero79 picture subzero79 on 30 Jan 2019

Can you check if this has been fixed in the latest dev branch? Should be fixed by https://github.com/Koenkk/zigbee2mqtt/commit/30823a5a0cedc5989bf2a689a46ff73e03512f5a

Koenkk picture Koenkk on 31 Jan 2019

Switching to the dev branch and running npm install fixed the issue for me, revealing that the root cause of my issue was the user I was running this as didn't have permission to access /dev/ttyACM1

waldher picture waldher on 1 Feb 2019

Switching to the dev branch and running npm install fixed the issue for me, revealing that the root cause of my issue was the user I was running this as didn't have permission to access /dev/ttyACM1

What Permissions did you change? I tried searching and trying some out but it still does not work.

lennartbecker picture lennartbecker on 1 Feb 2019

@lennartbecker The user that you run zigbee2mqtt as needs read/write permission for this device. You can test by running:
test -w /dev/ttyACM0 && echo success || echo failure
I just ran chown testuser /dev/ttyACM0 where testuser was the user I was running zigbee2mqtt as.

waldher picture waldher on 1 Feb 2019
👍1

@lennartbecker The user that you run zigbee2mqtt as needs read/write permission for this device. You can test by running:
test -w /dev/ttyACM0 && echo success || echo failure
I just ran chown testuser /dev/ttyACM0 where testuser was the user I was running zigbee2mqtt as.

Thank you, it told me "success", seems like I have a different problem now :D Something with a request timeout.

lennartbecker picture lennartbecker on 1 Feb 2019

This issue should be fixed in zigbee2mqtt 1.1.1, can anybody confirm?

Koenkk picture Koenkk on 1 Feb 2019

I can confirm 1.1.1 fixes the issue for me.

djchen picture djchen on 2 Feb 2019
🎉1

i have the same problem, however I can't upgrade since I don't have a debugger, any other fixes?

sultanakaneel picture sultanakaneel on 3 Feb 2019

@sultanakaneel you dont need the debugger to update zigbee2mqtt

Koenkk picture Koenkk on 3 Feb 2019

@sultanakaneel you dont need the debugger to update zigbee2mqtt

I must be retarded, but how would I update through hassio?

sultanakaneel picture sultanakaneel on 3 Feb 2019

@sultanakaneel 1.1.1 isn't available yet. You can use edge for now (but keep in mind this is a development branch). As soon as 1.1.1 for hassio is available switch to 1.1.1.

Koenkk picture Koenkk on 3 Feb 2019

@sultanakaneel 1.1.1 isn't available yet. You can use edge for now (but keep in mind this is a development branch). As soon as 1.1.1 for hassio is available switch to 1.1.1.

ah alright, the edge version somehow grinds my pi to a halt so guess I'll just have to wait for a while

sultanakaneel picture sultanakaneel on 3 Feb 2019

I got 1.1.1 via hassio and I still have this failure. I did a full reboot of hassio.

zigbee2mqtt:info 2019-2-3 09:29:11 Zigbee: allowing new devices to join.
zigbee2mqtt:info 2019-2-3 09:29:11 Connecting to MQTT server at mqtt://homeassistant
/zigbee2mqtt-1.1.1/node_modules/q/q.js:155
throw e;
^
TypeError: Cannot read property 'zigbeeModel' of undefined
at devices.forEach (/zigbee2mqtt-1.1.1/lib/extension/coordinatorGroup.js:24:34)
at Array.forEach ()
at zigbee.getAllClients.forEach (/zigbee2mqtt-1.1.1/lib/extension/coordinatorGroup.js:23:21)
at Array.forEach ()
at CoordinatorGroup.onZigbeeStarted (/zigbee2mqtt-1.1.1/lib/extension/coordinatorGroup.js:22:37)
at extensions.filter.forEach (/zigbee2mqtt-1.1.1/lib/controller.js:98:75)
at Array.forEach ()
at Controller.onZigbeeStarted (/zigbee2mqtt-1.1.1/lib/controller.js:98:58)
at zigbee.start (/zigbee2mqtt-1.1.1/lib/controller.js:149:26)
at shepherd.start (/zigbee2mqtt-1.1.1/lib/zigbee.js:64:17)
npm

mgsb picture mgsb on 3 Feb 2019

@mgsb do you use a custom devices.js?

Koenkk picture Koenkk on 3 Feb 2019

Yes. I have an added GE light switch defined in it since it was not in the shepherd list.

mgsb picture mgsb on 3 Feb 2019

@mgsb can you try without? Perhaps your devices.js is not compatible anymore. It would be the best if you make a PR so this device is natively supported by zigbee2mqtt.

Koenkk picture Koenkk on 3 Feb 2019

Thanks - that worked. I got the latest devices.js and replaced my "custom" version. You had merged the GE switch earlier. Other devices are working, but not the GE switch. The switch is recognized now but when I try to turn it on via HA, I get an error:

zigbee2mqtt:info 2019-2-3 10:11:18 Zigbee publish to device '0x0022a300001c942f', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
zigbee2mqtt:info 2019-2-3 10:11:18 MQTT publish: topic 'zigbee2mqtt/0x0022a300001c942f', payload '{"state":"ON","linkquality":0,"power":0}'
/zigbee2mqtt-1.1.1/lib/extension/deviceReceive.js:71
return c.cid === cid && c.type === message.type;
^
TypeError: Cannot read property 'cid' of undefined
at mappedDevice.fromZigbee.filter (/zigbee2mqtt-1.1.1/lib/extension/deviceReceive.js:71:26)
at Array.filter ()
at DeviceReceive.onZigbeeMessage (/zigbee2mqtt-1.1.1/lib/extension/deviceReceive.js:69:52)
at extensions.filter.forEach (/zigbee2mqtt-1.1.1/lib/controller.js:125:31)
at Array.forEach ()
at Controller.onZigbeeMessage (/zigbee2mqtt-1.1.1/lib/controller.js:125:14)
at Zigbee.onMessage (/zigbee2mqtt-1.1.1/lib/zigbee.js:179:18)
at emitOne (events.js:116:13)
at ZShepherd.emit (events.js:211:7)
at ZShepherd. (/zigbee2mqtt-1.1.1/node_modules/zigbee-shepherd/lib/shepherd.js:158:14)

mgsb picture mgsb on 3 Feb 2019

It's odd that "On" works but "Off" fails. Not sure why the mapping fails for "Off". This is not related to the original issue, so if you prefer, I can take this a different issue.

zigbee2mqtt:info 2019-2-3 10:26:12 Zigbee publish to device '0x0022a300001c942f', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
zigbee2mqtt:info 2019-2-3 10:26:13 MQTT publish: topic 'zigbee2mqtt/0x0022a300001c942f', payload '{"state":"ON","linkquality":0,"power":0}'
zigbee2mqtt:info 2019-2-3 10:26:43 Zigbee publish to device '0x0022a300001c942f', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null
zigbee2mqtt:info 2019-2-3 10:26:43 MQTT publish: topic 'zigbee2mqtt/0x0022a300001c942f', payload '{"state":"OFF","linkquality":0,"power":0}'
/zigbee2mqtt-1.1.1/lib/extension/deviceReceive.js:71
return c.cid === cid && c.type === message.type;
^

mgsb picture mgsb on 3 Feb 2019

@mgsb can you try without using a custom devices.js?

Koenkk picture Koenkk on 3 Feb 2019

Ok, I deleted devices.js and now it works after a restart.

mgsb picture mgsb on 3 Feb 2019

hi
i am having problems running on latest zigbee2mqtt. resetting, restarting and reinstalling did not help
this is the log

2019-2-9 21:02:34 - info: Logging to directory: '/share/zigbee2mqtt/log/2019-02-09.21-02-34'
2019-2-9 21:02:36 - info: Starting zigbee2mqtt version 1.1.1 (commit #unknown)
2019-2-9 21:02:36 - info: Starting zigbee-shepherd
2019-2-9 21:02:44 - info: Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
2019-2-9 21:03:44 - info: Starting zigbee-shepherd
2019-2-9 21:03:52 - error: Error while starting zigbee-shepherd!
2019-2-9 21:03:52 - error: Press the reset button on the stick (the one closest to the USB) and start again
2019-2-9 21:03:52 - error: Failed to start Error: request timeout
at CcZnp. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:255:22)
at Object.onceWrapper (events.js:315:30)
at emitOne (events.js:116:13)
at CcZnp.emit (events.js:211:7)
at Timeout. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:234:18)
at ontimeout (timers.js:498:11)
at tryOnTimeout (timers.js:323:5)
at Timer.listOnTimeout (timers.js:290:5)

chrisrock1984 picture chrisrock1984 on 9 Feb 2019

I got 1.1.1 via hassio and I still have this failure, too.
where can I find the devices.js in hass.io installation?

mschmidt29 picture mschmidt29 on 9 Feb 2019

@chrisrock1984 @mschmidt29

  • What is your setup?
  • What sniffer device do you use?
  • What is your zigbee2mqtt configuration.yaml.
  • What is the output of ls /dev?

Also try to:

  • Stop zigbee2mqtt
  • Re-plug CC2531 stick
  • Press reset button (the one close the to USB port). green light should go off
  • Start zigbee2mqtt.
Koenkk picture Koenkk on 10 Feb 2019

thank you for your help:
It worked for almost a year before, but after the latest updated it stopped.
I am using a Rock64 running hassio in a docker container. The last config I used was the standard when installing zigbee2mqtt. I also checked the correct com port, "ACM1" in my case.
What I tried so far is:

  • rebooting
  • uninstall, reinstall
  • reflashing the FW with the latest hex file
  • trying a second CC2531 stick
  • usb repluging
  • reset the stick
  • repowering the rock64
  • restarting zigbee2mqtt

So, what have I missed in the standard procedure of searching for errors? ;-)

chrisrock1984 picture chrisrock1984 on 11 Feb 2019

@chrisrock1984 when downgrading, does it work again?

Koenkk picture Koenkk on 11 Feb 2019

@Koenkk what is the easiest way to downgrade an hassio add-on? i have never done a downgrade. sorry for asking....

chrisrock1984 picture chrisrock1984 on 11 Feb 2019

@danielwelch is there any way to downgrade addons with hassio?

Koenkk picture Koenkk on 11 Feb 2019

@Koenkk i will try it with snapshots - will let you know if it works and which version it was

chrisrock1984 picture chrisrock1984 on 11 Feb 2019

still, downgrading (full whipe) does not work. it seems that it still runs 1.1.1

Log
[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-02-11T16:16:32: PM2 log: Launching in no daemon mode
2019-02-11T16:16:33: PM2 log: App [npm:0] starting in -fork mode-
2019-02-11T16:16:33: PM2 log: App [npm:0] online

[email protected] start /zigbee2mqtt-1.1.1
node index.js
zigbee2mqtt:info 2019-2-11 16:16:39 Logging to directory: '/share/zigbee2mqtt/log/2019-02-11.16-16-38'
zigbee2mqtt:info 2019-2-11 16:16:40 Starting zigbee2mqtt version 1.1.1 (commit #unknown)
zigbee2mqtt:info 2019-2-11 16:16:40 Starting zigbee-shepherd
zigbee2mqtt:info 2019-2-11 16:16:49 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
zigbee2mqtt:info 2019-2-11 16:17:49 Starting zigbee-shepherd
zigbee2mqtt:error 2019-2-11 16:17:57 Error while starting zigbee-shepherd!
zigbee2mqtt:error 2019-2-11 16:17:57 Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 2019-2-11 16:17:57 Failed to start
{"message":"request timeout","stack":"Error: request timeout\n at CcZnp. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:255:22)\n at Object.onceWrapper (events.js:315:30)\n at emitOne (events.js:116:13)\n at CcZnp.emit (events.js:211:7)\n at Timeout. (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:234:18)\n at ontimeout (timers.js:498:11)\n at tryOnTimeout (timers.js:323:5)\n at Timer.listOnTimeout (timers.js:290:5)"}

chrisrock1984 picture chrisrock1984 on 11 Feb 2019

@chrisrock1984 you are having the same issue as in #1067. What is the output of ls -l /dev/serial/by-id/?

Koenkk picture Koenkk on 11 Feb 2019

Hi Koen,
I have the exact same issue.

My environment:

  • Intel server
  • Debian 9
  • Docker 18.09.1
  • CC2531 USB stick with firmware 20190109
  • zigbee2mqtt image 1.1.1 (also tried latest-dev)

I set everything up 4 days ago with 1.1.1, except for the TRADFRI remote, which I did not get to work, so I switched to latest-dev for that and after that worked, I switched back to 1.1.1.
Everything ran fine for the last 4 days.
Today, I had to reboot the server because of a network issue, the configuration did not change.
No I always get Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds), no matter what I try:

  • 1.1.1 or latest-dev
  • Stop the container, pull the USB stick, plug it back in, DON'T push the button, start the container
  • Stop the container, pull the USB stick, plug it back in, push the button (the green light turns off), start the container
    Also another reboot did not fix the issue.

I use a udev rule to give the CC2531 a unique id (/dev/zigbee), this works fine since years with the Home Assistant Docker image and my Z-Wave stick (/dev/zwave).
I have also tried to map /dev/ttyACM1 directly, or via /dev/serial/by-id/usb-Texas_Instruments...

I have not yet reflashed the stick yet, but I really want to avoid that as pairing all devices again (which are hidden under the kitchen) would be a real pain.

Let me know if I can provide or test anything else

hanzoh picture hanzoh on 11 Feb 2019

@Koenkk : it gives me ->

rock64@rock64:~$ ls -l /dev/serial/by-id/
total 0
lrwxrwxrwx 1 root root 13 Feb 11 15:27 usb-0658_0200-if00 -> ../../ttyACM0
lrwxrwxrwx 1 root root 13 Feb 11 15:27 usb-Texas_Instruments_TI_CC2531_USB_CDC___0X9C1D58897D43FFFF-if00 -> ../../ttyACM1

chrisrock1984 picture chrisrock1984 on 12 Feb 2019

Can you all check with the latest dev branch? (-edge for hassio, should be available within an hour).

Koenkk picture Koenkk on 12 Feb 2019

i assume i can use the update instrctions from the documentation for that?

for me its running again for now:

`pi@rpi3:/opt/zigbee2mqtt/data$ npm start

> [email protected] start /opt/zigbee2mqtt
> node index.js

  zigbee2mqtt:info 2/12/2019, 8:06:42 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-02-12.20-06-42'
  zigbee2mqtt:info 2/12/2019, 8:06:43 PM Starting zigbee2mqtt version 1.1.1 (commit #d9ddce5)
  zigbee2mqtt:info 2/12/2019, 8:06:43 PM Starting zigbee-shepherd
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM zigbee-shepherd started
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM Coordinator firmware version: '20181119'
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM Currently 7 devices are joined:
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0x00158d00029bff93 (0x00158d00029bff93): RTCGQ11LM - Xiaomi Aqara human body movement and illuminance sensor (EndDevice)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0x00158d000252a53d (0x00158d000252a53d): MCCGQ11LM - Xiaomi Aqara door & window contact sensor (EndDevice)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0x00158d000278e797 (0x00158d000278e797): MFKZQ01LM - Xiaomi Mi/Aqara smart home cube (EndDevice)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0x00158d00028b6b2f (0x00158d00028b6b2f): MCCGQ01LM - Xiaomi MiJia door & window contact sensor (EndDevice)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0x00158d000268d9e6 (0x00158d000268d9e6): ZNCZ02LM - Xiaomi Mi power plug ZigBee (Router)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0xd0cf5efffeebda06 (0xd0cf5efffeebda06): 404000/404005/404012 - M眉ller Licht Tint LED bulb GU10/E14/E27 350/470/806 lumen, dimmable, color, opal white (Router)
  zigbee2mqtt:info 2/12/2019, 8:06:45 PM 0xd0cf5efffef919e6 (0xd0cf5efffef919e6): 404000/404005/404012 - M眉ller Licht Tint LED bulb GU10/E14/E27 350/470/806 lumen, dimmable, color, opal white (Router)

`

sander816 picture sander816 on 12 Feb 2019

@Koenkk

  • What is your setup? Hass.io - HassOS 2.8 - Home Assistant 0.87.1 - RaspberryPi B 3+
  • What sniffer device do you use? CC2531 stick
  • What is your zigbee2mqtt configuration.yaml. 
{
  "data_path": "/share/zigbee2mqtt",
  "homeassistant": true,
  "permit_join": false,
  "mqtt_base_topic": "zigbee2mqtt",
  "mqtt_server": "mqtt://192.168.178.41",
  "serial_port": "/dev/ttyACM0",
  "devices": [],
  "network_key": [],
  "mqtt_user": "mqttuser",
  "mqtt_pass": "kennwort"
}
  • What is the output of ls /dev?
core-ssh:~# ls /dev
fd       mqueue   pts      stderr   tty      urandom
full     null     random   stdin    ttyACM0  zero
init     ptmx     shm      stdout   ttyAMA0

Also try to:

  • Stop zigbee2mqtt. - ok
  • Re-plug CC2531 stick - ok
  • Press reset button (the one close the to USB port). green light should go off - ok
  • Start zigbee2mqtt. - ok

`
[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
Traceback (most recent call last):
File "set_config.py", line 159, in
main(args.options_path, args.data_path)
File "set_config.py", line 106, in main
cfg.set_option('homeassistant')
File "set_config.py", line 16, in set_option
if self.get_config(name, category) is not None:
File "set_config.py", line 39, in get_config
return self.config.get(config_name, None)
AttributeError: 'NoneType' object has no attribute 'get'
2019-02-12T20:10:08: PM2 log: Launching in no daemon mode
2019-02-12T20:10:08: PM2 log: App [npm:0] starting in -fork mode-
2019-02-12T20:10:08: PM2 log: App [npm:0] online

[email protected] start /zigbee2mqtt-1.1.1
node index.js
zigbee2mqtt:info 2019-2-12 20:10:13 Logging to directory: '/share/zigbee2mqtt/log/2019-02-12.20-10-12'
zigbee2mqtt:info 2019-2-12 20:10:14 Starting zigbee2mqtt version 1.1.1 (commit #unknown)
zigbee2mqtt:info 2019-2-12 20:10:14 Starting zigbee-shepherd
/zigbee2mqtt-1.1.1/lib/zigbee.js:40
this.shepherd = new ZShepherd(settings.get().serial.port, shepherdSettings);
^
TypeError: Cannot read property 'port' of undefined
at Zigbee.start (/zigbee2mqtt-1.1.1/lib/zigbee.js:40:60)
at startupLogVersion (/zigbee2mqtt-1.1.1/lib/controller.js:145:25)
at git.getLastCommit (/zigbee2mqtt-1.1.1/lib/controller.js:185:13)
at /zigbee2mqtt-1.1.1/node_modules/git-last-commit/source/index.js:44:5
at /zigbee2mqtt-1.1.1/node_modules/git-last-commit/source/index.js:14:4
at ChildProcess.exithandler (child_process.js:283:5)
at emitTwo (events.js:126:13)
at ChildProcess.emit (events.js:214:7)
at maybeClose (internal/child_process.js:915:16)
at Socket.stream.socket.on (internal/child_process.js:336:11)
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-02-12T19_10_14_974Z-debug.log
2019-02-12T20:10:15: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-02-12T20:10:15: PM2 log: App [npm:0] starting in -fork mode-
2019-02-12T20:10:15: PM2 log: App [npm:0] online
[email protected] start /zigbee2mqtt-1.1.1
node index.js
zigbee2mqtt:info 2019-2-12 20:10:19 Logging to directory: '/share/zigbee2mqtt/log/2019-02-12.20-10-19'
zigbee2mqtt:info 2019-2-12 20:10:21 Starting zigbee2mqtt version 1.1.1 (commit #unknown)
zigbee2mqtt:info 2019-2-12 20:10:21 Starting zigbee-shepherd
/zigbee2mqtt-1.1.1/lib/zigbee.js:40
this.shepherd = new ZShepherd(settings.get().serial.port, shepherdSettings);
^
TypeError: Cannot read property 'port' of undefined
at Zigbee.start (/zigbee2mqtt-1.1.1/lib/zigbee.js:40:60)
at startupLogVersion (/zigbee2mqtt-1.1.1/lib/controller.js:145:25)
at git.getLastCommit (/zigbee2mqtt-1.1.1/lib/controller.js:185:13)
at /zigbee2mqtt-1.1.1/node_modules/git-last-commit/source/index.js:44:5
at /zigbee2mqtt-1.1.1/node_modules/git-last-commit/source/index.js:14:4
at ChildProcess.exithandler (child_process.js:283:5)
at emitTwo (events.js:126:13)
at ChildProcess.emit (events.js:214:7)
at maybeClose (internal/child_process.js:915:16)
at Socket.stream.socket.on (internal/child_process.js:336:11)
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-02-12T19_10_21_149Z-debug.log
2019-02-12T20:10:21: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-02-12T20:10:21: PM2 log: App [npm:0] starting in -fork mode-
2019-02-12T20:10:21: PM2 log: App [npm:0] online
[email protected] start /zigbee2mqtt-1.1.1
node index.js
`

mschmidt29 picture mschmidt29 on 12 Feb 2019

For me, it is still the same.
I get these errors in dmesg:
cdc_acm 1-6:1.0: failed to set dtr/rts

And this is the complete log with DEBUG=*
z2m.log

hanzoh picture hanzoh on 12 Feb 2019

never mind, resolved

sander816 picture sander816 on 13 Feb 2019

For me, it is still the same.
I get these errors in dmesg:
cdc_acm 1-6:1.0: failed to set dtr/rts

And this is the complete log with DEBUG=*
z2m.log

Does it work when not running on Docker (bare metal)?

update on my problem:
zigbee2mqtt is running fine again, but, i am not able to add new devices.:

`  zigbee2mqtt:warn 2/13/2019, 8:38:46 AM `permit_join` set to  `true` in configuration.yaml.
  zigbee2mqtt:warn 2/13/2019, 8:38:46 AM Allowing new devices to join.
  zigbee2mqtt:warn 2/13/2019, 8:38:46 AM Set `permit_join` to `false` once you joined all devices.
  zigbee2mqtt:info 2/13/2019, 8:38:46 AM Zigbee: allowing new devices to join.
  zigbee2mqtt:info 2/13/2019, 8:38:46 AM Connecting to MQTT server at mqtt://localhost:1883
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM zigbee-shepherd ready
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM Connected to MQTT server
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/0x00158d00029bff93', payload '{"illuminance":6,"linkquality":47,"occupancy":false,"battery":62,"voltage":2935}'
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000252a53d', payload '{"contact":true,"linkquality":5,"battery":86,"voltage":2975}'
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000278e797', payload '{"battery":100,"voltage":3005,"linkquality":23}'
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/0x00158d00028b6b2f', payload '{"contact":true,"linkquality":60,"battery":100,"voltage":3015}'
  zigbee2mqtt:info 2/13/2019, 8:38:47 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000268d9e6', payload '{"state":"ON","power":92.97,"voltage":227.5,"consumption":2.45,"temperature":27,"linkquality":81}'
  zigbee2mqtt:info 2/13/2019, 8:38:49 AM MQTT publish: topic 'zigbee2mqtt/0x00158d00028b6b2f', payload '{"contact":true,"linkquality":63,"battery":100,"voltage":3015}'
  zigbee2mqtt:info 2/13/2019, 8:39:25 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000278e797', payload '{"battery":100,"voltage":3005,"linkquality":36}'

adding a new device does nothing, on my mihome it works fine

Can you try unplugging your xiaomi hub while pairing? Having 2 zigbee networks can be problematic.

Koenkk picture Koenkk on 13 Feb 2019

pressing the reset button made it discovering new devices again

sander816 picture sander816 on 13 Feb 2019

@Koenkk: I have installed z2m on Debian 9 directly (bare metal) and ran it with the same configuration.yaml, log output is exactly the same as above.
I have also installed npm on my Windows 10 machine and tried the stick there:

  zigbee2mqtt:info 2019-2-13 19:28:01 Logging to directory: 'C:\opt\zigbee2mqtt\data\log\2019-02-13.19-28-01'
  serialport/bindings loading WindowsBinding +0ms
  zigbee2mqtt:debug 2019-2-13 19:28:01 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"dbPath":"C:\\opt\\zigbee2mqtt\\data\\database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-2-13 19:28:02 Can't load state from file C:\opt\zigbee2mqtt\data\state.json (doesn't exsist)
  zigbee2mqtt:info 2019-2-13 19:28:02 Starting zigbee2mqtt version 1.1.1 (commit #54dbb97)
  zigbee2mqtt:info 2019-2-13 19:28:02 Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +0ms
  cc-znp Initialize, opening serial port +0ms
  serialport/stream opening path: COM7 +0ms
  serialport/binding-abstract open +0ms
  serialport/stream _read queueing _read for after open +3ms
  serialport/stream opened path: COM7 +5ms
  cc-znp The serialport COM7 is opened. +10ms
  serialport/stream _read reading +1ms
  serialport/binding-abstract read +9ms
  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 +12ms
  serialport/binding-abstract write 8 bytes +12ms
  serialport/stream binding.write write finished +5ms
  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.<anonymous> (C:\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.<anonymous> (C:\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 2019-2-13 19:28:04 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
  serialport/stream #flush +2s
  serialport/binding-abstract flush +2s
  serialport/stream binding.flush finished +1ms
  serialport/stream #close +1ms
  serialport/binding-abstract close +3ms
  serialport/stream binding.read error { [Error: Reading from COM port (ReadIOCompletion): Operation aborted] canceled: true } +3ms
  serialport/stream _read queueing _read for after open +20ms
  serialport/stream binding.close finished +4ms
  cc-znp The serialport COM7 is closed. +2
hanzoh picture hanzoh on 13 Feb 2019

Sorry, the above was with just the stick plugged in (did not press the button, green light was still on).
Here is the log on Windows 10 with the stick replugged and the button pushed (green light went off):

  zigbee2mqtt:info 2019-2-13 19:34:03 Logging to directory: 'C:\opt\zigbee2mqtt\data\log\2019-02-13.19-34-03'
  serialport/bindings loading WindowsBinding +0ms
  zigbee2mqtt:debug 2019-2-13 19:34:03 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"dbPath":"C:\\opt\\zigbee2mqtt\\data\\database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-2-13 19:34:03 Loaded state from file C:\opt\zigbee2mqtt\data\state.json
  zigbee2mqtt:info 2019-2-13 19:34:04 Starting zigbee2mqtt version 1.1.1 (commit #54dbb97)
  zigbee2mqtt:info 2019-2-13 19:34:04 Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +0ms
  cc-znp Initialize, opening serial port +0ms
  serialport/stream opening path: COM7 +0ms
  serialport/binding-abstract open +0ms
  serialport/stream _read queueing _read for after open +3ms
  serialport/stream opened path: COM7 +7ms
  cc-znp The serialport COM7 is opened. +11ms
  serialport/stream _read reading +2ms
  serialport/binding-abstract read +12ms
  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 +12ms
  serialport/binding-abstract write 8 bytes +12ms
  serialport/stream binding.write write finished +2ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 3,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SYS',
  cc-znp   cmd: 'osalNvRead',
  cc-znp   payload: { status: 0, len: 1, value: <Buffer 55> },
  cc-znp   fcs: 62,
  cc-znp   csum: 62 } +30ms
  serialport/stream _read reading +13ms
  serialport/binding-abstract read +20ms
  cc-znp:SRSP <-- SYS:osalNvRead, { status: 0, len: 1, value: <Buffer 55> } +0ms
  zigbee-shepherd:request RSP <-- SYS:osalNvRead, status: 0 +33ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +11ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 131, len: 2, value: [ 98, 26 ] } +42ms
  serialport/stream _write 6 bytes of data +16ms
  serialport/binding-abstract write 6 bytes +20ms
  serialport/stream binding.write write finished +9ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 5,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload: { status: 0, configid: 131, len: 2, value: <Buffer 62 1a> },
  cc-znp   fcs: 158,
  cc-znp   csum: 158 } +40ms
  serialport/stream _read reading +30ms
  serialport/binding-abstract read +42ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 131, len: 2, value: <Buffer 62 1a> } +63ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +53ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +12ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 45, len: 8, value: [ 221, 221, 221, 221, 221, 221, 221, 221 ] } +65ms
  serialport/stream _write 6 bytes of data +37ms
  serialport/binding-abstract write 6 bytes +39ms
  serialport/stream binding.write write finished +36ms
  serialport/stream binding.read finished +11ms
  cc-znp { sof: 254,
  cc-znp   len: 11,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0,
  cc-znp      configid: 45,
  cc-znp      len: 8,
  cc-znp      value: <Buffer dd dd dd dd dd dd dd dd> },
  cc-znp   fcs: 76,
  cc-znp   csum: 76 } +124ms
  serialport/stream _read reading +18ms
  serialport/binding-abstract read +94ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 45, len: 8, value: <Buffer dd dd dd dd dd dd dd dd> } +133ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +132ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +16ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 132, len: 4, value: [ 0, 8, 0, 0 ] } +165ms
  serialport/stream _write 6 bytes of data +83ms
  serialport/binding-abstract write 6 bytes +74ms
  serialport/stream binding.write write finished +39ms
  serialport/stream binding.read finished +12ms
  cc-znp { sof: 254,
  cc-znp   len: 7,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0, configid: 132, len: 4, value: <Buffer 00 08 00 00> },
  cc-znp   fcs: 237,
  cc-znp   csum: 237 } +159ms
  serialport/stream _read reading +34ms
  serialport/binding-abstract read +77ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 132, len: 4, value: <Buffer 00 08 00 00> } +153ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +131ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +14ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 98, len: 16, value: [ 1, 3, 5, 7, 9, 11, 13, 15, 0, 2, 4, 6, 8, 10, 12, 13 ] } +140ms
  serialport/stream _write 6 bytes of data +61ms
  serialport/binding-abstract write 6 bytes +60ms
  serialport/stream binding.write write finished +17ms
  serialport/stream binding.read finished +19ms
  cc-znp { sof: 254,
  cc-znp   len: 19,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0,
  cc-znp      configid: 98,
  cc-znp      len: 16,
  cc-znp      value: <Buffer 01 03 05 07 09 0b 0d 0f 00 02 04 06 08 0a 0c 0d> },
  cc-znp   fcs: 0,
  cc-znp   csum: 0 } +113ms
  serialport/stream _read reading +16ms
  serialport/binding-abstract read +56ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 98, len: 16, value: <Buffer 01 03 05 07 09 0b 0d 0f 00 02 04 06 08 0a 0c 0d> } +114ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +96ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +19ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 99, len: 1, value: [ 0 ] } +115ms
  serialport/stream _write 6 bytes of data +71ms
  serialport/binding-abstract write 6 bytes +67ms
  serialport/stream binding.write write finished +34ms
  serialport/stream binding.read finished +14ms
  cc-znp { sof: 254,
  cc-znp   len: 4,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload: { status: 0, configid: 99, len: 1, value: <Buffer 00> },
  cc-znp   fcs: 4,
  cc-znp   csum: 4 } +136ms
  serialport/stream _read reading +17ms
  serialport/binding-abstract read +67ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 99, len: 1, value: <Buffer 00> } +134ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +114ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +13ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 0 } +116ms
  serialport/stream _write 6 bytes of data +49ms
  serialport/binding-abstract write 6 bytes +50ms
  serialport/stream binding.write write finished +38ms
  serialport/stream binding.read finished +11ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 0, value: <Buffer 00 01 00 08 00 00 10 00> },
  cc-znp   fcs: 112,
  cc-znp   csum: 112 } +131ms
  serialport/stream _read reading +34ms
  serialport/binding-abstract read +82ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 0, value: <Buffer 00 01 00 08 00 00 10 00> } +132ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +118ms
  zigbee-shepherd:init Start the ZNP as a coordinator... +0ms
  zigbee-shepherd:request REQ --> ZDO:startupFromApp +10ms
  cc-znp:SREQ --> ZDO:startupFromApp, { startdelay: 100 } +126ms
  serialport/stream _write 7 bytes of data +48ms
  serialport/binding-abstract write 7 bytes +45ms
  serialport/stream binding.write write finished +17ms
  cc-znp:SRSP <-- ZDO:startupFromApp, __timeout__ +2s
hanzoh picture hanzoh on 13 Feb 2019

Okay, I just found it is definitely the stick.
I took a friend's stick and flashed it with the latest firmware.
Attached it to Windows 10 laptop, did not press the button and started z2m:

  zigbee2mqtt:info 2019-2-13 19:43:57 Logging to directory: 'C:\opt\zigbee2mqtt\data\log\2019-02-13.19-43-56'
  zigbee2mqtt:debug 2019-2-13 19:43:57 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"dbPath":"C:\\opt\\zigbee2mqtt\\data\\database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-2-13 19:43:57 Loaded state from file C:\opt\zigbee2mqtt\data\state.json
  zigbee2mqtt:info 2019-2-13 19:43:58 Starting zigbee2mqtt version 1.1.1 (commit #54dbb97)
  zigbee2mqtt:info 2019-2-13 19:43:58 Starting zigbee-shepherd
  zigbee2mqtt:info 2019-2-13 19:43:58 zigbee-shepherd started
  zigbee2mqtt:info 2019-2-13 19:43:58 Coordinator firmware version: '20190109'
  zigbee2mqtt:debug 2019-2-13 19:43:58 zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":11,"panId":"0x1a63","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b00014d5501","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190109},"startTime":1550083438,"joinTimeLeft":0}
  zigbee2mqtt:info 2019-2-13 19:43:58 Currently 0 devices are joined:
  zigbee2mqtt:info 2019-2-13 19:43:58 Zigbee: disabling joining new devices.
  zigbee2mqtt:info 2019-2-13 19:43:58 Connecting to MQTT server at mqtt://192.168.1.10
  zigbee2mqtt:info 2019-2-13 19:43:58 zigbee-shepherd ready
  zigbee2mqtt:debug 2019-2-13 19:43:58 Coordinator is already in group 99
  zigbee2mqtt:info 2019-2-13 19:43:58 Connected to MQTT server
  zigbee2mqtt:info 2019-2-13 19:43:58 MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
  zigbee2mqtt:debug 2019-2-13 19:43:58 Mounted the cieApp (epId 11)

Is there any way that I can reuse my friend's stick without repairing everything?
Or can I reflash my first stick again and shield it with tin foil?

hanzoh picture hanzoh on 13 Feb 2019

Other sticks cannot be reused without repairing.

I would go for the flash your own stick again with tin foil option.

Koenkk picture Koenkk on 13 Feb 2019

I have reflashed my own stick with latest firmware again, went outside and started it once with my laptop, PAN ID 0x1a62 was set. Put the stick back in the server, started my docker image with 1.1.1 and everything was fine. I had to power cycle all zigbee devices though, after over an hour only 2 out of 12 were reporting to the coordinator, but did not respond to commands. After power cycling everything is working fine as before.
So I will not update or switch to dev for the foreseeable future if 1.1.1 remains stable.
Then I will see if a simple server reboot will hose the stick again :)

Thanks for the support!

hanzoh picture hanzoh on 14 Feb 2019

Duplicate of #937, can you try with zigbee2mqtt 1.0.0 and report in #937?
How can i downgrade on hassio?

pedrogense picture pedrogense on 14 Feb 2019

@pedrogense that won't solve the problem probably (found that out). Can you upgrade to -edge?

Koenkk picture Koenkk on 14 Feb 2019

@pedrogense that won't solve the problem probably (found that out). Can you upgrade to -edge?

@Koenkk i already tried the edge variant before i posted this.
But what i accidentally found out when i booted without my z-wave sticked in the raspberry zigbee2mqtt started perfectly.
When i replug my z-wave stick zigbee fails.
Maybe something with allocating of the
usb鈥檚.

Sent with GitHawk

pedrogense picture pedrogense on 14 Feb 2019

I鈥檝e noticed for the last few days that pushes to dev and subsequent edge builds are failing due to an npm issue @Koenkk. I鈥檒l try to look into what鈥檚 going on.

danielwelch picture danielwelch on 14 Feb 2019

@pedrogense could it be a power issue?

@danielwelch feel free to contact me on telegram if you need help.

Koenkk picture Koenkk on 15 Feb 2019

@pedrogense could it be a power issue?
Its not a power issue, i just tried the original power supply and its the same when both plugged in zigbee gives the error.
When i unplug the z-wave stick and i restart HA zigbee works, when i replug my z-wave stick and restart HA zigbee gives the error.
In the config the both have different tty.... so that cannot be the problem.

pedrogense picture pedrogense on 15 Feb 2019

I have the same issue with version 1.1.1 and edge. When I boot my Pi3 without the CC2531 USB and plug it in, it works fine. When I reboot the Pi3 it changes the USB order.

Working, when USB is plugged in after booted:

  • /dev/ttyACM0 = ZWave
  • /dev/ttyACM1 = Zigbee

When rebooted:

  • /dev/ttyACM0 = Zigbee
  • /dev/ttyACM1 = ZWave

I have tried to update the serial_port in the configuration, but that doesn't work. Tried unplug and re-plug the USB, but not working. When I remove the debug settings from the configuration it still show debug info.
It looks like the configuration is not updated properly.

Here my output of Zigbee2Mqtt:

[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-02-16T12:49:54: PM2 log: Launching in no daemon mode
2019-02-16T12:49:54: PM2 log: App [npm:0] starting in -fork mode-
2019-02-16T12:49:54: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.1.1
> node index.js
  zigbee2mqtt:info 2019-2-16 12:49:59 Logging to directory: '/share/zigbee2mqtt/log/2019-02-16.12-49-59'
  zigbee2mqtt:debug 2019-2-16 12:49:59 Removing old log directory '/share/zigbee2mqtt/log/2019-02-16.11-25-56'
  zigbee2mqtt:debug 2019-2-16 12:50:00 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"channelList":[11],"precfgkey":[8,2,15,43,128,1,13,96,33,23,81,22,9,5,11,63]},"dbPath":"/share/zigbee2mqtt/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-2-16 12:50:01 Loaded state from file /share/zigbee2mqtt/state.json
  zigbee2mqtt:info 2019-2-16 12:50:01 Starting zigbee2mqtt version 1.1.1 (commit #unknown)
  zigbee2mqtt:info 2019-2-16 12:50:01 Starting zigbee-shepherd
  zigbee2mqtt:info 2019-2-16 12:50:04 Error while starting zigbee-shepherd, attemping to fix... (takes 60 seconds)
  zigbee2mqtt:info 2019-2-16 12:51:04 Starting zigbee-shepherd
  zigbee2mqtt:error 2019-2-16 12:51:07 Error while starting zigbee-shepherd!
  zigbee2mqtt:error 2019-2-16 12:51:07 Press the reset button on the stick (the one closest to the USB) and start again
  zigbee2mqtt:error 2019-2-16 12:51:07 Failed to start
    {"message":"request timeout","stack":"Error: request timeout\n    at CcZnp.<anonymous> (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:255:22)\n    at Object.onceWrapper (events.js:315:30)\n    at emitOne (events.js:116:13)\n    at CcZnp.emit (events.js:211:7)\n    at Timeout.<anonymous> (/zigbee2mqtt-1.1.1/node_modules/cc-znp/lib/ccznp.js:234:18)\n    at ontimeout (timers.js:498:11)\n    at tryOnTimeout (timers.js:323:5)\n    at Timer.listOnTimeout (timers.js:290:5)"}

{
  "data_path": "/share/zigbee2mqtt",
  "homeassistant": true,
  "permit_join": false,
  "mqtt_base_topic": "zigbee2mqtt",
  "mqtt_server": "mqtt://192.168.10.193",
  "serial_port": "/dev/ttyACM0",
  "devices": [],
  "network_key": []
}

board: rpi3
version: "1.13"
version_cli: "8"
version_cli_latest: "8"
version_latest: "2.8"

arch: armhf
boot: true
custom: false
image: homeassistant/raspberrypi3-homeassistant
last_version: 0.87.1
machine: raspberrypi3
port: 8123
ssl: false
version: 0.87.1
wait_boot: 600
watchdog: true
rgruyters picture rgruyters on 16 Feb 2019

Here when I boot WITHOUT the Zigbee USB and plug it later in after booted.

[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-02-16T13:07:29: PM2 log: Launching in no daemon mode
2019-02-16T13:07:30: PM2 log: App [npm:0] starting in -fork mode-
2019-02-16T13:07:30: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.1.1
> node index.js
  zigbee2mqtt:info 2019-2-16 13:07:34 Logging to directory: '/share/zigbee2mqtt/log/2019-02-16.13-07-34'
  zigbee2mqtt:debug 2019-2-16 13:07:34 Removing old log directory '/share/zigbee2mqtt/log/2019-02-16.11-29-03'
  zigbee2mqtt:debug 2019-2-16 13:07:35 Using zigbee-shepherd with settings: '{"net":{"panId":6754,"channelList":[11],"precfgkey":[]},"dbPath":"/share/zigbee2mqtt/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 2019-2-16 13:07:35 Loaded state from file /share/zigbee2mqtt/state.json
  zigbee2mqtt:info 2019-2-16 13:07:36 Starting zigbee2mqtt version 1.1.1 (commit #unknown)
  zigbee2mqtt:info 2019-2-16 13:07:36 Starting zigbee-shepherd
  zigbee2mqtt:info 2019-2-16 13:07:37 zigbee-shepherd started
  zigbee2mqtt:info 2019-2-16 13:07:37 Coordinator firmware version: '20190109'
  zigbee2mqtt:debug 2019-2-16 13:07:37 zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":11,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b001936abac","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190109},"startTime":1550318857,"joinTimeLeft":0}
  zigbee2mqtt:info 2019-2-16 13:07:37 Currently 2 devices are joined:
  zigbee2mqtt:info 2019-2-16 13:07:37 0x001788010202d816 (0x001788010202d816): 9290012607 - Philips Hue motion sensor (EndDevice)
  zigbee2mqtt:info 2019-2-16 13:07:37 0x0017880102026f47 (0x0017880102026f47): 9290012607 - Philips Hue motion sensor (EndDevice)
  zigbee2mqtt:info 2019-2-16 13:07:37 Zigbee: disabling joining new devices.
  zigbee2mqtt:info 2019-2-16 13:07:37 Connecting to MQTT server at mqtt://192.168.10.193
  zigbee2mqtt:debug 2019-2-16 13:07:37 Configuring 0x001788010202d816 (0x001788010202d816) ...
  zigbee2mqtt:debug 2019-2-16 13:07:37 Configuring 0x0017880102026f47 (0x0017880102026f47) ...
  zigbee2mqtt:info 2019-2-16 13:07:38 zigbee-shepherd ready
  zigbee2mqtt:info 2019-2-16 13:07:38 Connected to MQTT server
rgruyters picture rgruyters on 16 Feb 2019

I have viewed the configuration.yaml in /share/zigbee2mqtt/ folder and see that the serial_port still shows /dev/ttyACM1 when the config via frontend stated /dev/ttyACM0.
When I manually update the configuration.yaml file it works fine.

I will post an issue for the add-on of Zigbee2mqtt as well.

But, I still have the issue when rebooting my PI3, Zigbee2Mqtt can't access the USB port. Only when I unplug and re-plug the USB stick.

rgruyters picture rgruyters on 16 Feb 2019

Can you try when using the path return by ls -l /dev/serial/by-id (https://www.zigbee2mqtt.io/getting_started/running_zigbee2mqtt.html#1-determine-location-of-cc2531-usb-sniffer-and-checking-user-permissions)

Koenkk picture Koenkk on 16 Feb 2019

@Koenkk throught hassio add-ons /dev/serial/by-id is not available. (unfortunately)

~ # docker exec addon_7ad98f9c_zigbee2mqtt ls -l /dev/serial/by-id
ls: /dev/serial/by-id: No such file or directory
~ # docker exec addon_7ad98f9c_zigbee2mqtt ls -l /dev/
total 419
lrwxrwxrwx    1 root     root            13 Feb 16 23:46 fd -> /proc/self/fd
crw-rw-rw-    1 root     root        1,   7 Feb 16 23:46 full
-rwxr-xr-x    1 root     root        428228 Nov 21 14:14 init
drwxrwxrwt    2 root     root            40 Feb 16 23:46 mqueue
crw-rw-rw-    1 root     root        1,   3 Feb 16 23:46 null
lrwxrwxrwx    1 root     root             8 Feb 16 23:46 ptmx -> pts/ptmx
drwxr-xr-x    2 root     root             0 Feb 16 23:46 pts
crw-rw-rw-    1 root     root        1,   8 Feb 16 23:46 random
drwxrwxrwt    2 root     root            40 Feb 16 23:46 shm
lrwxrwxrwx    1 root     root            15 Feb 16 23:46 stderr -> /proc/self/fd/2
lrwxrwxrwx    1 root     root            15 Feb 16 23:46 stdin -> /proc/self/fd/0
lrwxrwxrwx    1 root     root            15 Feb 16 23:46 stdout -> /proc/self/fd/1
crw-rw-rw-    1 root     root        5,   0 Feb 16 23:46 tty
crw-rw----    1 root     audio     166,   0 Feb 16 23:47 ttyACM0
crw-rw----    1 root     audio     166,   1 Feb 16 23:46 ttyACM1
crw-rw----    1 root     audio     204,  64 Feb 16 23:46 ttyAMA0
crw-rw----    1 root     audio     188,   0 Feb 16 23:46 ttyUSB0
crw-rw-rw-    1 root     root        1,   9 Feb 16 23:46 urandom
crw-rw-rw-    1 root     root        1,   5 Feb 16 23:46 zero
rgruyters picture rgruyters on 16 Feb 2019

Yep, have been hoping for something like this in Hassio for awhile now

danielwelch picture danielwelch on 17 Feb 2019

I completely deleted the folder share / zigbee2mqtt and then reinstalled it. After that everything was ok.

mschmidt29 picture mschmidt29 on 17 Feb 2019

What i did and seems to solve it for me, when zigbee shepperd starts and comes with the error for trying to fix 60sec. within the period it's "fixing" press then the debug button on the usb stick and it works for me.
It was important for my setup that i pressed the button while zigbee2mqtt is fixing and not when the report comes to press the button nearest the usb stick.
Sorry for my bad english.
iv'e restarted my HA instance and it seems to keep working.

pedrogense picture pedrogense on 18 Feb 2019

My problem has been solved. I had to edit the configuration file under /share/zigbee2mqtt folder to make sure that it points to the right device.

rgruyters picture rgruyters on 25 Feb 2019
👍1

@lennartbecker The user that you run zigbee2mqtt as needs read/write permission for this device. You can test by running:
test -w /dev/ttyACM0 && echo success || echo failure
I just ran chown testuser /dev/ttyACM0 where testuser was the user I was running zigbee2mqtt as.

This fixed the issue for me, thanks!

PabloB94 picture PabloB94 on 22 Mar 2019

I've started on some documentation how to fix zigbee2mqtt not being able to start: http://www.zigbee2mqtt.io/information/zigbee2mqtt_fails_to_start.html

In case you want to contribute to this, please edit https://github.com/Koenkk/zigbee2mqtt.io/blob/master/information/zigbee2mqtt_fails_to_start.md and create a PR.

Koenkk picture Koenkk on 22 Mar 2019

I had it running on my freebsd system. Upgrade from node 11 to node 12 seems to have broken it (one of the dependencies) so uninstalled node 12, and took node10, which they kept for those who don't want to go to 12. Fully reinstalled Zigbee2mqtt including fresh npm and node but fails at zigbee shepherd every time now, regardless of disconnecting/reconnecting, pressing button on usb stick, rebooting etc.
root@plex:~ # cd /usr/local/zigbee2mqtt/
root@plex:/usr/local/zigbee2mqtt # npm start &
[1] 17018
root@plex:/usr/local/zigbee2mqtt #

[email protected] start /usr/local/zigbee2mqtt
node index.js

zigbee2mqtt:info 4/29/2019, 9:51:50 AM Logging to directory: '/usr/local/zigbee2mqtt/data/log/2019-04-29.09-51-49'
zigbee2mqtt:info 4/29/2019, 9:51:51 AM Starting zigbee2mqtt version 1.3.1 (commit #39d6a8e)
zigbee2mqtt:info 4/29/2019, 9:51:51 AM Starting zigbee-shepherd
zigbee2mqtt:info 4/29/2019, 9:51:52 AM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds)
zigbee2mqtt:info 4/29/2019, 9:52:52 AM Starting zigbee-shepherd
zigbee2mqtt:error 4/29/2019, 9:52:54 AM Error while starting zigbee-shepherd!
zigbee2mqtt:error 4/29/2019, 9:52:54 AM Press the reset button on the stick (the one closest to the USB) and start again
zigbee2mqtt:error 4/29/2019, 9:52:54 AM Failed to start
{"message":"request timeout","stack":"Error: request timeout\n at CcZnp. (/usr/local/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. (/usr/local/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 4/29/2019, 9:52:54 AM 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-04-29T08_52_59_392Z-debug.log

gluier picture gluier on 29 Apr 2019

@gluier what firmware were you running? I would recommend trying with the latest dev firmware 20190425 https://github.com/Koenkk/Z-Stack-firmware/tree/dev/coordinator/Z-Stack_Home_1.2/bin

Koenkk picture Koenkk on 29 Apr 2019

Not sure if this is the right place to post but when I try to run zigbee2mqtt docker, it still seems to configure port ACM0 when my cc2531 is on ACM1. Is that why it gives the error of zigbee-shepart unable to start?

How do I fix it?

epicurean70 picture epicurean70 on 31 May 2019

@epicurean70 did you configure it correctly in configuration.yaml (http://www.zigbee2mqtt.io/configuration/configuration.html) and forward the correct port with --device=/dev/ttyACM1 (http://www.zigbee2mqtt.io/information/docker.html)

Koenkk picture Koenkk on 3 Jun 2019

HI.
I'm running hassio with zigbee2mqtt.
I bought a preflashed cc2531 and it wad working.
Since I had some little issue, I chose to update it to last firmware, I took this:
https://github.com/Koenkk/Z-Stack-firmware/tree/master/coordinator/Z-Stack_Home_1.2/bin/default
here I donwloaded CC2530_DEFAULT_20190608.zip, because CC2531_DEFAULT_20190608.zip is marked as source routing firmware, that I don't need.

After flashing, no light comes up on the board.
connecting to Raspberry and starting zigbee2mqtt I get:

[Info] Configuration file found: /share/zigbee2mqtt/configuration.yaml
[Info] Configuration written to /share/zigbee2mqtt/configuration.yaml
2019-06-29T11:11:05: PM2 log: Launching in no daemon mode
2019-06-29T11:11:05: PM2 log: App [npm:0] starting in -fork mode-
2019-06-29T11:11:05: PM2 log: App [npm:0] online
[email protected] start /zigbee2mqtt-1.4.0
node index.js
zigbee2mqtt:info 6/29/2019, 11:11:08 AM Logging to directory: '/share/zigbee2mqtt/log/2019-06-29.11-11-08'
zigbee2mqtt:info 6/29/2019, 11:11:10 AM Starting zigbee2mqtt version 1.4.0 (commit #unknown)
zigbee2mqtt:info 6/29/2019, 11:11:10 AM Starting zigbee-shepherd
zigbee2mqtt:info 6/29/2019, 11:11:10 AM Error while starting zigbee-shepherd, attempting to fix... (takes 60 seconds) (Error: Error: No such file or directory, cannot open /dev/ttyACM0)

If I flash CC2531_DEFAULT_20190608.zip found on http://www.zigbee2mqtt.io/getting_started/flashing_the_cc2531.html, light come back and zigbee2mqtt can start it.

What am I missing?

xalex75 picture xalex75 on 29 Jun 2019

@xalex75 read http://www.zigbee2mqtt.io/information/zigbee2mqtt_fails_to_start.html#verify-that-you-put-the-correct-port-in-configurationyaml

Koenkk picture Koenkk on 1 Jul 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[bot] picture stale[bot] on 30 Aug 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

alwashe picture alwashe  路  4Comments
ophilips picture ophilips  路  4Comments
pepp86 picture pepp86  路  4Comments
jwilling picture jwilling  路  4Comments
tb-killa picture tb-killa  路  3Comments