NEWS

Zigbee adapter stopped working FIXED


  • Developer

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


  • Starter

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

    Zigbee 9-28-20.jpg

    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
    

  • Most Active

    @ap2017

    lsof /dev/ttyACM1
    

    would be correct.


  • Starter

    @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:~$
    
    

  • Starter

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


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


  • Starter

    @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
    

  • Developer

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


  • Starter

    @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
    

  • Starter

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


Log in to reply
 

Suggested Topics

1.9k
Online

32.2k
Users

38.8k
Topics

526.5k
Posts