Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
11.85k stars 1.65k forks source link

Error while starting zigbee-herdsman #2928

Closed kitopopo closed 4 years ago

kitopopo commented 4 years ago

Bug Report

Hi mr @koenkk,

Every raspberry startup zigbe2mqtt process don't startup, zigbe2mqtt process need three attempts fort startup, in the third attemp starts correctly. after raspberry reboot again the same problem appears I paste the info from logs:

zigbe2mqtt log:


> info  2020-02-10 14:54:31: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-02-10.14-54-31' filename: log.txt
> info  2020-02-10 14:54:31: Starting zigbee2mqtt version 1.10.0-dev (commit #13b996e)
> info  2020-02-10 14:54:31: Starting zigbee-herdsman...
> error 2020-02-10 14:55:21: Error while starting zigbee-herdsman
> 
> feb 10 14:53:27 raspberrypi npm[451]: zigbee2mqtt:info  2020-02-10 14:53:27: Starting zigbee2mqtt version 1.10.0-dev (commit #13b996e)
> feb 10 14:53:27 raspberrypi npm[451]: zigbee2mqtt:info  2020-02-10 14:53:27: Starting zigbee-herdsman...
> feb 10 14:54:29 raspberrypi npm[451]: zigbee2mqtt:error 2020-02-10 14:54:29: Error while starting zigbee-herdsman
> feb 10 14:54:29 raspberrypi npm[451]: zigbee2mqtt:error 2020-02-10 14:54:29: Failed to start zigbee
> feb 10 14:54:29 raspberrypi npm[451]: zigbee2mqtt:error 2020-02-10 14:54:29: Exiting...
> feb 10 14:54:29 raspberrypi npm[451]: zigbee2mqtt:error 2020-02-10 14:54:29: Error: AREQ - SYS - resetInd after 30000ms
> feb 10 14:54:29 raspberrypi npm[451]:     at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24)
> feb 10 14:54:29 raspberrypi npm[451]:     at ontimeout (timers.js:436:11)
> feb 10 14:54:29 raspberrypi npm[451]:     at tryOnTimeout (timers.js:300:5)
> feb 10 14:54:29 raspberrypi npm[451]:     at listOnTimeout (timers.js:263:5)
> feb 10 14:54:29 raspberrypi npm[451]:     at Timer.processTimers (timers.js:223:10)
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! code ELIFECYCLE
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! errno 1
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! zigbee2mqtt@1.10.0-dev start: `node index.js`
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! Exit status 1
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR!
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! Failed at the zigbee2mqtt@1.10.0-dev start script.
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR! A complete log of this run can be found in:
> feb 10 14:54:29 raspberrypi npm[451]: npm ERR!     /home/pi/.npm/_logs/2020-02-10T13_54_29_098Z-debug.log
> feb 10 14:54:29 raspberrypi systemd[1]: zigbee2mqtt.service: Main process exited, code=exited, status=1/FAILURE
> feb 10 14:54:29 raspberrypi systemd[1]: zigbee2mqtt.service: Failed with result 'exit-code'.
> feb 10 14:54:29 raspberrypi systemd[1]: zigbee2mqtt.service: Service RestartSec=100ms expired, scheduling restart.
> feb 10 14:54:29 raspberrypi systemd[1]: zigbee2mqtt.service: Scheduled restart job, restart counter is at 1.
> feb 10 14:54:29 raspberrypi systemd[1]: Stopped zigbee2mqtt.
> feb 10 14:54:29 raspberrypi systemd[1]: Started zigbee2mqtt.
> feb 10 14:54:30 raspberrypi npm[1137]: > zigbee2mqtt@1.10.0-dev start /opt/zigbee2mqtt
> feb 10 14:54:30 raspberrypi npm[1137]: > node index.js
> feb 10 14:54:31 raspberrypi npm[1137]: zigbee2mqtt:info  2020-02-10 14:54:31: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-02-10.14-54-31' filename: log.txt
> feb 10 14:54:31 raspberrypi npm[1137]: zigbee2mqtt:info  2020-02-10 14:54:31: Starting zigbee2mqtt version 1.10.0-dev (commit #13b996e)
> feb 10 14:54:31 raspberrypi npm[1137]: zigbee2mqtt:info  2020-02-10 14:54:31: Starting zigbee-herdsman...
> feb 10 14:55:21 raspberrypi npm[1137]: zigbee2mqtt:error 2020-02-10 14:55:21: Error while starting zigbee-herdsman
> feb 10 14:55:21 raspberrypi npm[1137]: zigbee2mqtt:error 2020-02-10 14:55:21: Failed to start zigbee
> feb 10 14:55:21 raspberrypi npm[1137]: zigbee2mqtt:error 2020-02-10 14:55:21: Exiting...
> feb 10 14:55:21 raspberrypi npm[1137]: zigbee2mqtt:error 2020-02-10 14:55:21: Error: AREQ - SYS - resetInd after 30000ms
> feb 10 14:55:21 raspberrypi npm[1137]:     at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24)
> 

Log from .npm, folder


0 info it worked if it ends with ok
1 verbose cli [ '/usr/bin/node', '/usr/bin/npm', 'start' ]
2 info using npm@6.13.4
3 info using node@v10.19.0
4 verbose run-script [ 'prestart', 'start', 'poststart' ]
5 info lifecycle zigbee2mqtt@1.10.0-dev~prestart: zigbee2mqtt@1.10.0-dev
6 info lifecycle zigbee2mqtt@1.10.0-dev~start: zigbee2mqtt@1.10.0-dev
7 verbose lifecycle zigbee2mqtt@1.10.0-dev~start: unsafe-perm in lifecycle true
8 verbose lifecycle zigbee2mqtt@1.10.0-dev~start: PATH: /usr/lib/node_modules/npm/node_modules/npm-lifecycle/node-gyp-bin:/opt/zigbee2mqtt/node_modules/.bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
9 verbose lifecycle zigbee2mqtt@1.10.0-dev~start: CWD: /opt/zigbee2mqtt
10 silly lifecycle zigbee2mqtt@1.10.0-dev~start: Args: [ '-c', 'node index.js' ]
11 silly lifecycle zigbee2mqtt@1.10.0-dev~start: Returned: code: 1  signal: null
12 info lifecycle zigbee2mqtt@1.10.0-dev~start: Failed to exec start script
13 verbose stack Error: zigbee2mqtt@1.10.0-dev start: `node index.js`
13 verbose stack Exit status 1
13 verbose stack     at EventEmitter.<anonymous> (/usr/lib/node_modules/npm/node_modules/npm-lifecycle/index.js:332:16)
13 verbose stack     at EventEmitter.emit (events.js:198:13)
13 verbose stack     at ChildProcess.<anonymous> (/usr/lib/node_modules/npm/node_modules/npm-lifecycle/lib/spawn.js:55:14)
13 verbose stack     at ChildProcess.emit (events.js:198:13)
13 verbose stack     at maybeClose (internal/child_process.js:982:16)
13 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:259:5)
14 verbose pkgid zigbee2mqtt@1.10.0-dev
15 verbose cwd /opt/zigbee2mqtt
16 verbose Linux 4.19.97-v7l+
17 verbose argv "/usr/bin/node" "/usr/bin/npm" "start"
18 verbose node v10.19.0
19 verbose npm  v6.13.4
20 error code ELIFECYCLE
21 error errno 1
22 error zigbee2mqtt@1.10.0-dev start: `node index.js`
22 error Exit status 1
23 error Failed at the zigbee2mqtt@1.10.0-dev start script.
23 error This is probably not a problem with npm. There is likely additional logging output above.
24 verbose exit [ 1, true ]

Log from opt-->zigbe-->data

i``` nfo 2020-02-10 14:54:31: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-02-10.14-54-31' filename: log.txt info 2020-02-10 14:54:31: Starting zigbee2mqtt version 1.10.0-dev (commit #13b996e) info 2020-02-10 14:54:31: Starting zigbee-herdsman... error 2020-02-10 14:55:21: Error while starting zigbee-herdsman



How i can solve this problem? thanks in advanced- best regards

## What happened

After reboot raspberry Zigbee2mqtt service doesn't startup in the first attempt

## What did you expect to happen

Should be start in the firtst attempt after raspberry reset

## How to reproduce it (minimal and precise)

Make a reset to the raspberrypi

## Debug Info
zigbee2mqtt version: version 1.10.0 Lastet dev brach
CC2531 firmware version: 20190608.zip
benjaminreede commented 4 years ago

Got the same issue, only mine doesn't start at all. Happend after upgrading to 1.10.0

HoekieN commented 4 years ago

Same here, also running zigbee2mqtt version: version 1.10.0 and happens at random times when it is running, need to stop zigbee2mqtt and unplug the usb and plug in it and start zigbee2mqtt to get it to work again.

CodeFinder2 commented 4 years ago

Already tried the stuff in the FAQ?

Koenkk commented 4 years ago

Duplicate of #2899

kitopopo commented 4 years ago

Hi @Koenkk ,

I apologize for reopening a repeated issue, I was looking before opening it but I didn't find it. You were right, with the tests I was doing I put the zigbe2mqtt dongle in another usb port. Thank you very much for all the support you are giving to everyone with problems that are coming out, it is very kind. Best regards

rikki78 commented 4 years ago

For anyone coming here with this issue when running the IOTstack zigbee2mqtt docker image, change the docker-compose.yml to use a different port. By default the port mapping is - /dev/ttyAMA0:/dev/ttyACM0 but changing it to - /dev/ttyACM0:/dev/ttyACM0 solved this issue for me.

as described here

https://github.com/gcgarner/IOTstack/wiki/Zigbee2MQTT

JCaminada commented 4 years ago

Hi,

Sorry to react on a repeated issue, but I tried everything discussed before. Keep getting error with starting zigbee-herdsman.

Started with a CC2531 USB stick and initially all ok. After updating zigbee2mqtt the issue started with the zigbee-herdman not starting up.

Since I also had an issue with the limited number of devices and the range of the CC2531 USB stick, I bought a Texas Instruments CC26X2R1. Also in the hope this would solve the issue with the zigbee-herdsman.

At first connection the new adapter worked, but after trying to connect the third device (xiaomi plug) it stopped working.

Trying to restart the zigbee2mqtt gave again the error with the zigbee-herdsman.

This is what I get when trying to start:

pi@DOMOTICZ:/opt/zigbee2mqtt $ DEBUG=zigbee-herdsman* npm start

zigbee2mqtt@1.12.0 start /opt/zigbee2mqtt node index.js

zigbee2mqtt:info 2020-04-08 00:49:32: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-04-08.00-49-32' filename: log.txt zigbee2mqtt:debug 2020-04-08 00:49:32: Loaded state from file /opt/zigbee2mqtt/data/state.json zigbee2mqtt:info 2020-04-08 00:49:32: Starting zigbee2mqtt version 1.12.0 (commit #840b9d9) zigbee2mqtt:info 2020-04-08 00:49:32: Starting zigbee-herdsman... zigbee2mqtt:debug 2020-04-08 00:49:32: Using zigbee-herdsman with settings: '{"network":{"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11],"networkKey":"HIDDEN"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyACM0"}}' zigbee-herdsman:adapter Path '/dev/ttyACM0' is valid for 'ZStackAdapter' +0ms zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyACM0"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json"}' +0ms zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyACM0 and {"baudRate":115200,"rtscts":true,"autoOpen":false} +0ms zigbee2mqtt:error 2020-04-08 00:49:32: Error while starting zigbee-herdsman zigbee2mqtt:error 2020-04-08 00:49:32: Failed to start zigbee zigbee2mqtt:error 2020-04-08 00:49:32: Exiting... zigbee2mqtt:error 2020-04-08 00:49:32: Error: Error while opening serialport 'Error: Error Resource temporarily unavailable Cannot lock port' at Znp. (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:113:32) at Generator.next () at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:8:71 at new Promise () at __awaiter (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:4:12) at SerialPort. (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:111:49) at SerialPort._error (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/node_modules/@serialport/stream/lib/index.js:198:14) at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/node_modules/@serialport/stream/lib/index.js:242:12 npm ERR! code ELIFECYCLE npm ERR! errno 1 npm ERR! zigbee2mqtt@1.12.0 start: node index.js npm ERR! Exit status 1 npm ERR! npm ERR! Failed at the zigbee2mqtt@1.12.0 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/2020-04-07T22_49_32_661Z-debug.log

Really hope that this makes sense and there is support.

Thanks a lot!

Koenkk commented 4 years ago

Error: Error while opening serialport 'Error: Error Resource temporarily unavailable Cannot lock port' means that a different application on your pc is locking the port. You can find out which with ls -l /proc/[0-9]/fd/ | grep /dev/ttyACM0

JCaminada commented 4 years ago

Hi Koen,

Thanks for your very quick reply.

I'm running Domoticz on a Pi. I was not able to understand what is blocking the port.

I did find out that the zigbee-herdsman is not working, but when connecting the Pi to wired connection and not wifi, I'm able to add devices.

When connected to only wifi, connecting devices is not an option.

In both connection methods I keep getting the message that zigbee-herdsman is not working as explained above.

Hope this makes some sense to you.

Mads commented 4 years ago

For what it is worth... Changing the port to use by-id symlinks worked for me. serial: port: >- /dev/serial/by-id/usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B000BE97D64-if0

qwerk commented 4 years ago

the duebug option helped me. i found out that some optional items that I left out are the issue. I had to add the baudrate and the rtscts to the configuration.yaml after that it started without issue.

baudrate: 115200 rtscts: false

hernanif1 commented 3 years ago

Still no success:

Config

data_path: /config/zigbee2mqtt
external_converters: []
devices: devices.yaml
groups: groups.yaml
homeassistant: true
permit_join: false
mqtt:
  base_topic: zigbee2mqtt
  user: __redacted__
  password: __redacted__
serial:
  port: /dev/ttyACM0
advanced:
  log_level: warn
  pan_id: 6754
  channel: 11
  network_key:
    - 1
    - 3
    - 5
    - 7
    - 9
    - 11
    - 13
    - 15
    - 0
    - 2
    - 4
    - 6
    - 8
    - 10
    - 12
    - 13
  availability_blocklist: []
  availability_passlist: []
device_options: {}
blocklist: []
passlist: []
queue: {}
frontend:
  port: 8099
experimental: {}
socat:
  enabled: false
  master: 'pty,raw,echo=0,link=/tmp/ttyZ2M,mode=777'
  slave: 'tcp-listen:8485,keepalive,nodelay,reuseaddr,keepidle=1,keepintvl=1,keepcnt=5'
  options: '-d -d'
  log: false
zigbee_herdsman_debug: true

Error log:

2021-05-18T10:46:20.680Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT'
2021-05-18T10:46:20.686Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2421204-if00"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"concurrent":null,"delay":null}}'
2021-05-18T10:46:20.689Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2421204-if00 and {"baudRate":115200,"rtscts":false,"autoOpen":false}
2021-05-18T10:46:20.700Z zigbee-herdsman:adapter:zStack:znp:log Serialport opened
2021-05-18T10:46:21.169Z zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload
2021-05-18T10:46:21.170Z zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239]
2021-05-18T10:46:22.181Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1}
2021-05-18T10:46:22.189Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32]

I tried to change:

I'm using a sd card running the homeassistant auto launch and via ssh has not a lot commands available and it is hard to test the suggested errors from https://www.zigbee2mqtt.io/information/FAQ.html#help-zigbee2mqtt-fails-to-start

Suggestions from zigbee2mqtt:

  1. The port of your serial adapter changed. Check this to find out the port of your adapter. I see the log in the system tab so my id seems to be okay

    21-05-18 10:57:55 INFO (MainThread) [supervisor.hardware.monitor] Detecting HardwareAction.REMOVE usb hardware /dev/bus/usb/001/032
    21-05-18 10:57:57 INFO (MainThread) [supervisor.hardware.monitor] Detecting HardwareAction.ADD usb hardware /dev/bus/usb/001/033
    21-05-18 10:57:57 INFO (MainThread) [supervisor.hardware.monitor] Detecting HardwareAction.ADD serial hardware /dev/ttyACM0 - /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2421204-if00
  2. If you are using a CC2530 or CC2531; it is a common issue for this adapter to crash... No I'm not, I'm using Conbee 2

  3. Verify that you put the correct port in configuration.yaml: I ran ls -l /dev/serial/by-id -> output: sh usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2421204-if00 -> ../../ttyACM0 In this example the correct port would be /dev/ttyACM0 and it is ../../ttyACM0 but I don't know if this is the problem

  4. Verify that the user you run Zigbee2MQTT as has write access to the port I ran test -w /dev/ttyACM0 && echo success || echo failure -> success

There are other suggestions but none of them seems to apply to my case, they are usually a different device.

I just installed the hassio so I have nothing installed that could have conflict

Screenshot 2021-05-18 at 13 16 30

Screenshot 2021-05-18 at 13 18 09

Let me know please what I'm missing.

hernanif1 commented 3 years ago

For next generations, I fixed the error above adding the property below (because I'm using conbee 2)

serial:
  port: /dev/ttyAMA0
  adapter: deconz
Kaveendra commented 3 years ago

For next generations, I fixed the error above adding the property below (because I'm using conbee 2)

serial:
  port: /dev/ttyAMA0
  adapter: deconz

This worked!

LaHoshi commented 3 years ago

@hernanif1 I also use ConBee II, but your fix didnt work for me.

I dont understand why port: /dev/ttyAMA0 works for you?!?

you have written that ConBee II shows up as /dev/ttyACM0

only adding adapter: deconz didnt work for me.

hernanif1 commented 3 years ago

@hernanif1 I also use ConBee II, but your fix didnt work for me.

I dont understand why port: /dev/ttyAMA0 works for you?!?

you have written that ConBee II shows up as /dev/ttyACM0

only adding adapter: deconz didnt work for me.

It's depende on your usb drive Id name. You can check it in your system logs removing and inserting the usb pendrive.

I don't remember the exact name of the page to see it but it's should be easy to find.

mcavallo-git commented 3 years ago

For next generations, I fixed the error above adding the property below (because I'm using conbee 2)

serial:
  port: /dev/ttyAMA0
  adapter: deconz

Thank you very much, @hernanif1 - this worked for me as well, using a ConBee II on HomeAssistant OS (running on an ESXi VM with USB device shared down into the VM).

Humorously enough, I had literally troubleshooted the items you listed previous to that line, with none working except the solution you gave with the "adapter: deconz" property under the "serial" property. Fun

grant66 commented 2 years ago

Had the same issue. For whatever reason the coordinator (sonoff 3.0) had moved to /dev/ttyUSB0.

ESPHome, if you have it installed, will tell you this without having to mess about with docker containers.

Changed the serial port config in the add-on (supervisor -> add-ons -> zigbee2mqtt -> configuration) to /dev/USB0 and everything good.

StarFox2873 commented 2 years ago

For next generations, I fixed the error above adding the property below (because I'm using conbee 2)

serial:
  port: /dev/ttyAMA0
  adapter: deconz

This did the trick for me!!! Thank you..

Mx7733 commented 2 years ago

For next generations, I fixed the error above adding the property below (because I'm using conbee 2)

serial:
  port: /dev/ttyAMA0
  adapter: deconz

Would that also work for a Sonoff zigbee 3.0 ? Im getting the same error and follwed every instruction, but no dice. And shoul it be adapter: sonoff?

So nevermind. I added the bautrate ( baudrate: 115200) and now it works. Leaving my comment for other users.

It worked only once. now the error is back.