UPDATE 31.10.: Amazon Alexa - ioBroker Skill läuft aus ?

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

[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

[Asgothian]

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

[ap2017]

@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

[ap2017]

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