Zigbee adapter stopped working FIXED

[Asgothian]

@ap2017 I apologise. I should have put quotes around the "npm list", as that was the command i wanted you to check.

As you can see, there is an extra serialport library installed, but each adapter has (should have) a usable version, so you should be able to remove the extra one.

npm prune should get rid of it.

A.

[ap2017]

@Asgothian No problem. I run the following, but still have same extraneous serial library 6..2.2 when run "npm list serialport"

cd /opt/iobroker
npm prune --dry-run
sudo reboot

[ap2017]

@Asgothian As previously, keep getting these errors:

zigbee.0 2020-09-24 10:39:10.082 error (2461) Error: Error while opening serialport 'Error: Error: Device or resource busy, cannot open /dev/ttyACM1' at Znp.<anonymous> (/opt/iobroker/node_modules/iobroker.zigbee/node_modules/zigbee-he
zigbee.0 2020-09-24 10:39:10.081 error (2461) Failed to start Zigbee
zigbee.0 2020-09-24 10:39:09.975 info (2461) Starting Zigbee...
zigbee.0 2020-09-24 10:39:09.974 info (2461) Try to reconnect. 1 attempts left
zigbee.0 2020-09-24 10:38:59.972 error (2461) Error: Failed to connect to the adapter (Error: Cannot request when znp has not been initialized yet) at ZStackAdapter.<anonymous> (/opt/iobroker/node_modules/iobroker.zigbee/node_modules/z
zigbee.0 2020-09-24 10:38:59.972 error (2461) Failed to start Zigbee

[Asgothian]

@ap2017
Of course.. the "npm prune --dry-run" only lists what it would do. This is to ensure that it doesn't get rid of something you want to keep
once you checked the list, you can do "npm prune" (without the dry run)

a Reboot is not needed..

A.

[ap2017]

@Asgothian The unwanted serial driver 6.2.2 disappeared after pruning, but it did not help to resolve the main issue, see errors below. I rebooted controller after pruning, just in case.

[Asgothian]

@ap2017
Unfortunately, that is what i expected. Now you should no longer get any errors on an npm rebuild, but i have the feeling that is not the error. I am starting to think that the firmware on the Zigbee Board / Stick is not responding correctly.

As long as there is a message that the zigbee library cannot be initialized, the issue is most likely hardware related.

A.

[Thomas Braun]

@ap2017
Please stop the zwave Adapater and reboot. I may happen that the zwo adapters do block the port.
And I see a duplicate entry in the zwave entry. I think that only one entry should show there.

[ap2017]

@Thomas-Braun I stopped both zwave and zigbee and rebooted, here is list of serial ports:

As I mentioned before, when zigbee is off, zwave works fine on both ports ACM0 and ACM1, so it looks like system works properly with ports.

What would be next step, try to uninstall and reinstall zigbee adapter again? Re-flash CC2531 dongle? Thank you.

[Asgothian]

@ap2017
No.

Please verify if the Zigbee Adapter will start when

• no zwave sticks are connected to the system
• no zwave adapter is running.

A.

[ap2017]

@Asgothian Sorry, how do I check if zigbee adapter started?

[Asgothian]

@ap2017 Watch the log for an entry that the zigbee adapter started successfully, alternatively, watch the green light in the instance list.

[ap2017]

@Asgothian Of course, I did not pay attention that you asked to disable zwave, not zigbee. Unplugging zwave dongle and disabling zwave adapter did not help. FYI, zigbee behaves same way for ACM0 and ACM1 ports

[ap2017]

@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)

[Asgothian]

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

[ap2017]

@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]

@ap2017

lsof /dev/ttyACM1

would be correct.

[ap2017]

@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]

@ap2017 Here is response to "npm list serialport"
if it helps

ap@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$

[mickym]

@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, stopping

this is the crash of the adapter - all other messages are in my opinion a result of the adapter crash, but not the root cause.

mickym2 created this issue in ioBroker/ioBroker.zigbee

closed Version 1.2.x is not stable #792

[ap2017]

@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