Zigbee adapter stopped working FIXED
-
@Asgothian Here is the latest debug log when trying to restart zigbee adapter. Anything comes to mind? Thank you for your time.
zigbee.0 2020-09-27 17:53:02.239 error (4926) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM1' at Znp.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/z
zigbee.0 2020-09-27 17:53:02.239 error (4926) Failed to start Zigbee
zigbee.0 2020-09-27 17:53:02.138 debug (4926) Starting zigbee-herdsman...
zigbee.0 2020-09-27 17:53:02.137 info (4926) Starting Zigbee...
zigbee.0 2020-09-27 17:53:02.137 info (4926) Try to reconnect. 1 attempts left
zigbee.0 2020-09-27 17:52:52.136 error (4926) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM1' at Znp.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/z
zigbee.0 2020-09-27 17:52:52.135 error (4926) Failed to start Zigbee
zigbee.0 2020-09-27 17:52:52.061 debug (4926) Backup /opt/iobroker/iobroker-data/zigbee_0/backup_2020_09_27-17_52_51.tar.gz success
zigbee.0 2020-09-27 17:52:52.004 debug (4926) Starting zigbee-herdsman...
zigbee.0 2020-09-27 17:52:52.003 info (4926) Starting Zigbee...
zigbee.0 2020-09-27 17:52:51.977 debug (4926) Using zigbee-herdsman with settings: {"network":{"panID":6754,"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"extenedPanID":[221,221,221,221,221,221,221,221]},"database
zigbee.0 2020-09-27 17:52:51.960 info (4926) starting. Version 1.2.1 in /opt/iobroker/node_modules/iobroker.zigbee, node: v12.18.4, js-controller: 3.1.6
host.AP-Tiny 2020-09-27 17:52:51.188 info instance system.adapter.zigbee.0 started with pid 4926
host.AP-Tiny 2020-09-27 17:52:48.684 info instance system.adapter.zigbee.0 terminated with code 11 (ADAPTER_REQUESTED_TERMINATION)
zigbee.0 2020-09-27 17:52:48.172 error at stop (/opt/iobroker/node_modules/iobroker.js-controller/lib/adapter.js:8270:22)
zigbee.0 2020-09-27 17:52:48.172 error at Zigbee.emit (events.js:315:20)
zigbee.0 2020-09-27 17:52:48.172 error at Zigbee.onUnload (/opt/iobroker/node_modules/iobroker.zigbee/main.js:442:41)
zigbee.0 2020-09-27 17:52:48.172 error at ZigbeeController.stop (/opt/iobroker/node_modules/iobroker.zigbee/lib/zigbeecontroller.js:304:20)
zigbee.0 2020-09-27 17:52:48.172 error at ZigbeeController.callExtensionMethod (/opt/iobroker/node_modules/iobroker.zigbee/lib/zigbeecontroller.js:187:42)
zigbee.0 2020-09-27 17:52:48.172 error at DeviceAvailability.stop (/opt/iobroker/node_modules/iobroker.zigbee/lib/zbDeviceAvailability.js:118:43)
zigbee.0 2020-09-27 17:52:48.172 error at ZigbeeController.getClients (/opt/iobroker/node_modules/iobroker.zigbee/lib/zigbeecontroller.js:201:49)
zigbee.0 2020-09-27 17:52:48.172 error at Controller.getDevices (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:252:31)
zigbee.0 2020-09-27 17:52:48.172 error at Function.all (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/model/device.js:234:16)
zigbee.0 2020-09-27 17:52:48.172 error at Function.loadFromDatabaseIfNecessary (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/model/device.js:214:55)
zigbee.0 2020-09-27 17:52:48.172 error (4705) TypeError: Cannot read property 'getEntries' of null
zigbee.0 2020-09-27 17:52:48.171 error (4705) unhandled promise rejection: Cannot read property 'getEntries' of null
Unhandled 2020-09-27 17:52:48.170 error promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch().
zigbee.0 2020-09-27 17:52:48.170 info (4705) Terminated (ADAPTER_REQUESTED_TERMINATION): Without reason
zigbee.0 2020-09-27 17:52:48.169 info (4705) terminating
zigbee.0 2020-09-27 17:52:48.169 error at ZigbeeController.stop (/opt/iobroker/node_modules/iobroker.zigbee/lib/zigbeecontroller.js:308:33))
zigbee.0 2020-09-27 17:52:48.169 error at Controller.stop (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:199:16)
zigbee.0 2020-09-27 17:52:48.169 error at __awaiter (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:23:12)
zigbee.0 2020-09-27 17:52:48.169 error at new Promise (<anonymous>)
zigbee.0 2020-09-27 17:52:48.169 error at /opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:27:71
zigbee.0 2020-09-27 17:52:48.169 error at Generator.next (<anonymous>)
zigbee.0 2020-09-27 17:52:48.169 error at Controller.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:200:18)
zigbee.0 2020-09-27 17:52:48.169 error at Controller.databaseSave (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/controller.js:219:45)
zigbee.0 2020-09-27 17:52:48.169 error at Function.all (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/model/group.js:88:15)
zigbee.0 2020-09-27 17:52:48.169 error at Function.loadFromDatabaseIfNecessary (/opt/iobroker/node_modules/zigbee-herdsman/dist/controller/model/group.js:76:55)
zigbee.0 2020-09-27 17:52:48.169 error (4705) Failed to stop zigbee (TypeError: Cannot read property 'getEntries' of null
zigbee.0 2020-09-27 17:52:48.168 info (4705) Zigbee: disabling joining new devices.
zigbee.0 2020-09-27 17:52:48.166 info (4705) cleaned everything up...
zigbee.0 2020-09-27 17:52:48.165 info (4705) Got terminate signal TERMINATE_YOURSELF
host.AP-Tiny 2020-09-27 17:52:48.163 info stopInstance system.adapter.zigbee.0 send kill signal
host.AP-Tiny 2020-09-27 17:52:48.159 info stopInstance system.adapter.zigbee.0 (force=false, process=true) -
@ap2017 Things that come to mind:
- Put the log in code tags, makes it more readable
- The serial port is still locked.
- This is not the first entry after trying to start the adapter. It shows a restart attempt.
Please follow these steps, and post the resulting log (in code tags)
- Disable the zigbee instance
- stop the iobroker
- verify that no process has the serial device open
lsof /def/ttyACM1- If no process has the serial device open, start iobroker
- check again if any process has the serial port open
- delete the current log (Delete, not clear, in the log view)
- attempt to start the zigbee adapter. If it does not start, disable it again, then post the log file.
A.
-
@Asgothian said in Zigbee adapter stopped working:
lsof /def/ttyACM1
When iobroker stopped and started same status of serial port is reported (hopefully there is no error in command):
Here is log after zigbee adapter started
zigbee.0 2020-09-28 23:23:31.400 error (26678) Error: Failed to connect to the adapter (Error: Cannot request when znp has not been initialized yet) at ZStackAdapter.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/ zigbee.0 2020-09-28 23:23:31.399 error (26678) Failed to start Zigbee zigbee.0 2020-09-28 23:23:23.829 debug (26678) Starting zigbee-herdsman... zigbee.0 2020-09-28 23:23:23.829 info (26678) Starting Zigbee... zigbee.0 2020-09-28 23:23:23.828 info (26678) Try to reconnect. 1 attempts left zigbee.0 2020-09-28 23:23:13.828 error at /opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:242:12 zigbee.0 2020-09-28 23:23:13.828 error at SerialPort._error (/opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:198:14) zigbee.0 2020-09-28 23:23:13.828 error at SerialPort.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:134:49) zigbee.0 2020-09-28 23:23:13.828 error at __awaiter (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:23:12) zigbee.0 2020-09-28 23:23:13.828 error at new Promise (<anonymous>) zigbee.0 2020-09-28 23:23:13.828 error at /opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:27:71 zigbee.0 2020-09-28 23:23:13.828 error at Generator.next (<anonymous>) zigbee.0 2020-09-28 23:23:13.828 error at Znp.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:136:32) zigbee.0 2020-09-28 23:23:13.828 error (26678) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM1' zigbee.0 2020-09-28 23:23:13.827 error (26678) Failed to start Zigbee zigbee.0 2020-09-28 23:23:13.744 debug (26678) Backup /opt/iobroker/iobroker-data/zigbee_0/backup_2020_09_28-23_23_13.tar.gz success zigbee.0 2020-09-28 23:23:13.666 debug (26678) Starting zigbee-herdsman... zigbee.0 2020-09-28 23:23:13.665 info (26678) Starting Zigbee... zigbee.0 2020-09-28 23:23:13.628 debug (26678) Using zigbee-herdsman with settings: {"network":{"panID":6754,"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"extenedPanID":[221,221,221,221,221,221,221,221]},"databa zigbee.0 2020-09-28 23:23:13.611 info (26678) starting. Version 1.2.1 in /opt/iobroker/node_modules/iobroker.zigbee, node: v12.18.4, js-controller: 3.1.6 zigbee.0 2020-09-28 23:23:13.150 debug (26678) statesDB connected zigbee.0 2020-09-28 23:23:13.150 debug (26678) States connected to redis: 127.0.0.1:9000 zigbee.0 2020-09-28 23:23:13.146 debug (26678) States create System PubSub Client zigbee.0 2020-09-28 23:23:13.145 debug (26678) States create User PubSub Client zigbee.0 2020-09-28 23:23:13.142 debug (26678) Redis States: Use Redis connection: 127.0.0.1:9000 zigbee.0 2020-09-28 23:23:13.141 debug (26678) objectDB connected zigbee.0 2020-09-28 23:23:13.138 debug (26678) Objects connected to redis: 127.0.0.1:9001 zigbee.0 2020-09-28 23:23:13.129 debug (26678) Objects client initialize lua scripts zigbee.0 2020-09-28 23:23:13.128 debug (26678) Objects create User PubSub Client zigbee.0 2020-09-28 23:23:13.128 debug (26678) Objects create System PubSub Client zigbee.0 2020-09-28 23:23:13.126 debug (26678) Objects client ready ... initialize now zigbee.0 2020-09-28 23:23:13.105 debug (26678) Redis Objects: Use Redis connection: 127.0.0.1:9001 host.AP-Tiny 2020-09-28 23:23:12.547 info instance system.adapter.zigbee.0 started with pid 26678 -
-
@Thomas-Braun Here is response for lsof /dev/ttyACM1 Not sure what it means, is port being used or not? Getting same response with ioBroker on or off
ap@AP-Tiny:~$ lsof /dev/ttyACM1 ap@AP-Tiny:~$ -
@ap2017 Here is response to "npm list serialport"
if it helpsap@AP-Tiny:/opt/iobroker$ npm list serialport iobroker.inst@2.0.3 /opt/iobroker ├─┬ iobroker.discovery@2.3.11 │ └── serialport@8.0.8 ├─┬ iobroker.mysensors@2.0.1 │ └── serialport@7.1.5 ├─┬ iobroker.zigbee@1.2.1 │ └─┬ zigbee-herdsman@0.13.8 │ └── serialport@9.0.1 └─┬ iobroker.zwave2@1.7.0-alpha.2 └─┬ zwave-js@5.0.0-alpha.3 ├─┬ @zwave-js/serial@5.0.0-alpha.0 │ └── serialport@9.0.1 └── serialport@9.0.1 ap@AP-Tiny:/opt/iobroker$ -
@ap2017 I had problems to understand why this version of the adapter reached the status to be in the default repository. I have now 2 threads open
https://github.com/ioBroker/ioBroker.zigbee/issues/792
https://forum.iobroker.net/topic/37147/zigbee-adapter-1-2-1-nicht-stable
... and I hope there will be a solution provided by the experts.meanwhile everything is running in debug mode - and I hope that there will be help by the experts.
I would not complain if this adapter is still only in the latest repository - but I had to learn that you need to be careful expressing your personal opinion if you are not an expert and only a silly end user.What I can see in your log - that all theses errors are consecutive errors of a previous crash. you should have a look if you have an error like:
Adapter disconnected, stoppingthis is the crash of the adapter - all other messages are in my opinion a result of the adapter crash, but not the root cause.
closed Version 1.2.x is not stable #792
-
@mickym Here is my error log after starting adapter in debug mode. Do not see error that you mentioned. I am not clear what do you mean by "be careful expressing your personal opinion if you are not an expert and only a silly end user"
zigbee.0 2020-09-29 23:37:01.205 error (22022) Error: Failed to connect to the adapter (Error: Cannot request when znp has not been initialized yet) at ZStackAdapter.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/ zigbee.0 2020-09-29 23:37:01.204 error (22022) Failed to start Zigbee zigbee.0 2020-09-29 23:36:53.649 debug (22022) Starting zigbee-herdsman... zigbee.0 2020-09-29 23:36:53.648 info (22022) Starting Zigbee... zigbee.0 2020-09-29 23:36:53.647 info (22022) Try to reconnect. 1 attempts left zigbee.0 2020-09-29 23:36:43.647 error at /opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:242:12 zigbee.0 2020-09-29 23:36:43.647 error at SerialPort._error (/opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:198:14) zigbee.0 2020-09-29 23:36:43.647 error at SerialPort.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:134:49) zigbee.0 2020-09-29 23:36:43.647 error at __awaiter (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:23:12) zigbee.0 2020-09-29 23:36:43.647 error at new Promise (<anonymous>) zigbee.0 2020-09-29 23:36:43.647 error at /opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:27:71 zigbee.0 2020-09-29 23:36:43.647 error at Generator.next (<anonymous>) zigbee.0 2020-09-29 23:36:43.647 error at Znp.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:136:32) zigbee.0 2020-09-29 23:36:43.647 error (22022) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM1' zigbee.0 2020-09-29 23:36:43.646 error (22022) Failed to start Zigbee zigbee.0 2020-09-29 23:36:43.500 debug (22022) Starting zigbee-herdsman... zigbee.0 2020-09-29 23:36:43.499 info (22022) Starting Zigbee... zigbee.0 2020-09-29 23:36:43.498 debug (22022) Using zigbee-herdsman with settings: {"network":{"panID":6754,"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"extenedPanID":[221,221,221,221,221,221,221,221]},"databa zigbee.0 2020-09-29 23:36:43.483 info (22022) starting. Version 1.2.1 in /opt/iobroker/node_modules/iobroker.zigbee, node: v12.18.4, js-controller: 3.1.6 zigbee.0 2020-09-29 23:36:43.369 debug (22022) statesDB connected zigbee.0 2020-09-29 23:36:43.368 debug (22022) States connected to redis: 127.0.0.1:9000 zigbee.0 2020-09-29 23:36:43.365 debug (22022) States create System PubSub Client zigbee.0 2020-09-29 23:36:43.364 debug (22022) States create User PubSub Client zigbee.0 2020-09-29 23:36:43.360 debug (22022) Redis States: Use Redis connection: 127.0.0.1:9000 zigbee.0 2020-09-29 23:36:43.359 debug (22022) objectDB connected zigbee.0 2020-09-29 23:36:43.356 debug (22022) Objects connected to redis: 127.0.0.1:9001 zigbee.0 2020-09-29 23:36:43.347 debug (22022) Objects client initialize lua scripts zigbee.0 2020-09-29 23:36:43.347 debug (22022) Objects create User PubSub Client zigbee.0 2020-09-29 23:36:43.346 debug (22022) Objects create System PubSub Client zigbee.0 2020-09-29 23:36:43.344 debug (22022) Objects client ready ... initialize now zigbee.0 2020-09-29 23:36:43.327 debug (22022) Redis Objects: Use Redis connection: 127.0.0.1:9001 host.AP-Tiny 2020-09-29 23:36:42.857 info instance system.adapter.zigbee.0 started with pid 22022 -
@ap2017 the log clearly shows that the Adapter is unable to open the serial port. I have to admit that I am at a loss as to why this is.
Can you try to flash the Firmware in your zigbee device ? It is possible that the Firmware does not work properly and as such does not allow opening the port.Also - do you have an Alternative System to try and connect to the zigbee device to ensure the serial port works ?
A.
-
@Asgothian I configured zigbee to work with ACM0 (the port normally used by zwave adapter, but for this test zwave adapter is disabled). Just in case, swapped physical ports and connecting cables. Here is log from fresh system start. It seems to me that unable to open com port is secondary error, error log always start with other errors, see below.
I will re-flash the adapter and placed an order for another one.
zigbee.0 2020-09-30 08:42:36.675 debug (1964) system.adapter.admin.0: logging true zigbee.0 2020-09-30 08:42:02.506 error at /opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:242:12 zigbee.0 2020-09-30 08:42:02.506 error at SerialPort._error (/opt/iobroker/node_modules/serialport/node_modules/@serialport/stream/lib/index.js:198:14) zigbee.0 2020-09-30 08:42:02.506 error at SerialPort.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:134:49) zigbee.0 2020-09-30 08:42:02.506 error at __awaiter (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:23:12) zigbee.0 2020-09-30 08:42:02.506 error at new Promise (<anonymous>) zigbee.0 2020-09-30 08:42:02.506 error at /opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:27:71 zigbee.0 2020-09-30 08:42:02.506 error at Generator.next (<anonymous>) zigbee.0 2020-09-30 08:42:02.506 error at Znp.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:136:32) zigbee.0 2020-09-30 08:42:02.506 error (1964) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM0' zigbee.0 2020-09-30 08:42:02.506 error (1964) Failed to start Zigbee zigbee.0 2020-09-30 08:42:02.411 debug (1964) Starting zigbee-herdsman... zigbee.0 2020-09-30 08:42:02.411 info (1964) Starting Zigbee... zigbee.0 2020-09-30 08:42:02.410 info (1964) Try to reconnect. 1 attempts left zigbee.0 2020-09-30 08:41:52.409 error at rejected (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:25:65) zigbee.0 2020-09-30 08:41:52.409 error at Generator.throw (<anonymous>) zigbee.0 2020-09-30 08:41:52.409 error at ZStackAdapter.<anonymous> (/opt/iobroker/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:89:31) zigbee.0 2020-09-30 08:41:52.409 error (1964) Error: Failed to connect to the adapter (Error: Cannot request when znp has not been initialized yet) zigbee.0 2020-09-30 08:41:52.408 error (1964) Failed to start Zigbee zigbee.0 2020-09-30 08:41:44.793 debug (1964) Starting zigbee-herdsman... zigbee.0 2020-09-30 08:41:44.792 info (1964) Starting Zigbee... zigbee.0 2020-09-30 08:41:44.791 debug (1964) Using zigbee-herdsman with settings: {"network":{"panID":6754,"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"extenedPanID":[221,221,221,221,221,221,221,221]},"databas zigbee.0 2020-09-30 08:41:44.776 info (1964) starting. Version 1.2.1 in /opt/iobroker/node_modules/iobroker.zigbee, node: v12.18.4, js-controller: 3.1.6 zigbee.0 2020-09-30 08:41:44.623 debug (1964) statesDB connected zigbee.0 2020-09-30 08:41:44.623 debug (1964) States connected to redis: 127.0.0.1:9000 zigbee.0 2020-09-30 08:41:44.620 debug (1964) States create System PubSub Client zigbee.0 2020-09-30 08:41:44.619 debug (1964) States create User PubSub Client zigbee.0 2020-09-30 08:41:44.616 debug (1964) Redis States: Use Redis connection: 127.0.0.1:9000 zigbee.0 2020-09-30 08:41:44.615 debug (1964) objectDB connected zigbee.0 2020-09-30 08:41:44.612 debug (1964) Objects connected to redis: 127.0.0.1:9001 zigbee.0 2020-09-30 08:41:44.601 debug (1964) Objects client initialize lua scripts zigbee.0 2020-09-30 08:41:44.600 debug (1964) Objects create User PubSub Client zigbee.0 2020-09-30 08:41:44.599 debug (1964) Objects create System PubSub Client zigbee.0 2020-09-30 08:41:44.597 debug (1964) Objects client ready ... initialize now zigbee.0 2020-09-30 08:41:44.576 debug (1964) Redis Objects: Use Redis connection: 127.0.0.1:9001 host.AP-Tiny 2020-09-30 08:41:44.042 info instance system.adapter.zigbee.0 started with pid 1964 -
@Asgothian Thank you for your help, re-flashing zigbee adapter helped, I no longer have error messages and my zigbee devices are operational. I am wondering what went wrong, adapter flash memory got corrupted?
