Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge πŸŒ‰, get rid of your proprietary Zigbee bridges πŸ”¨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.08k stars 1.68k forks source link

Z2M fails to start after: Updated Zigbee2MQTT to version 1.40.1 #23901

Closed afkdk closed 3 weeks ago

afkdk commented 1 month ago

What happened?

I simply upgraded and Z2M devices were not available. When I check, the X2M dis not start - CPU/... flashes briefly when started in HA but stops <2 sec. On a black screen, HA displays 502: Bad Gateway.

NOTHING was changed - and Z2M had worked flawlessly up till this upgrade - it was (AFAIK set up by default values by HA/Z2M directives) - and MQTT is working for other integrations...

And no hints in the reference web page seems relevant πŸ₯΄

HA has of course been restarted plenty of times - just-in-case something needed a restart...


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


[2024-09-08 11:33:41] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:33:41] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:33:44] info: zh:zstack:znp: Socket error [2024-09-08 11:33:44] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:33:44] error: z2m: Failed to start zigbee [2024-09-08 11:33:44] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:33:44] error: z2m: Exiting... [2024-09-08 11:33:44] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21) /app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12) [11:33:44] INFO: Preparing to start... [11:33:44] INFO: Socat not enabled [11:33:45] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-08 11:33:46] info: z2m: Logging to console, file (filename: log.log) [2024-09-08 11:33:46] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-09-08 11:33:46] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-08 11:33:46] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-08 11:33:46] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":6754,\"extendedPanID\":[221,221,221,221,221,221,221,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://10.100.100.223:6638\"},\"adapter\":{\"concurrent\":null,\"delay\":null,\"disableLED\":false,\"transmitPower\":9}}"' [2024-09-08 11:33:46] debug: zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT' [2024-09-08 11:33:46] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:33:46] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:33:47] info: zh:zstack:znp: Socket error [2024-09-08 11:33:47] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:33:47] error: z2m: Failed to start zigbee [2024-09-08 11:33:47] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:33:47] error: z2m: Exiting... [2024-09-08 11:33:47] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21) /app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12) [11:33:47] INFO: Preparing to start... [11:33:48] INFO: Socat not enabled [11:33:48] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-08 11:33:49] info: z2m: Logging to console, file (filename: log.log) [2024-09-08 11:33:49] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-09-08 11:33:49] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-08 11:33:49] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-08 11:33:49] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":6754,\"extendedPanID\":[221,221,221,221,221,221,221,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://10.100.100.223:6638\"},\"adapter\":{\"concurrent\":null,\"delay\":null,\"disableLED\":false,\"transmitPower\":9}}"' [2024-09-08 11:33:49] debug: zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT' [2024-09-08 11:33:49] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:33:49] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:33:52] info: zh:zstack:znp: Socket error [2024-09-08 11:33:52] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:33:52] error: z2m: Failed to start zigbee [2024-09-08 11:33:52] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:33:52] error: z2m: Exiting... [2024-09-08 11:33:52] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21) /app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12)

What did you expect to happen?

It simply upgraded, restarted, and then worked...

How to reproduce it (minimal and precise)

The Z2M simply never starts πŸ˜–

Zigbee2MQTT version

1.40.1

Adapter firmware version

not found - possibly due to tubesz coordinator by web

Adapter

tubesz

Setup

HA BT on proxmox

Debug log

[2024-09-08 11:33:46] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:33:46] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:33:47] info: zh:zstack:znp: Socket error [2024-09-08 11:33:47] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:33:47] error: z2m: Failed to start zigbee [2024-09-08 11:33:47] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:33:47] error: z2m: Exiting... [2024-09-08 11:33:47] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21)

/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12) [11:33:47] INFO: Preparing to start... [11:33:48] INFO: Socat not enabled [11:33:48] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-08 11:33:49] info: z2m: Logging to console, file (filename: log.log) [2024-09-08 11:33:49] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-09-08 11:33:49] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-08 11:33:49] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-08 11:33:49] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":6754,\"extendedPanID\":[221,221,221,221,221,221,221,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://10.100.100.223:6638\"},\"adapter\":{\"concurrent\":null,\"delay\":null,\"disableLED\":false,\"transmitPower\":9}}"' [2024-09-08 11:33:49] debug: zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT' [2024-09-08 11:33:49] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:33:49] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:33:52] info: zh:zstack:znp: Socket error [2024-09-08 11:33:52] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:33:52] error: z2m: Failed to start zigbee [2024-09-08 11:33:52] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:33:52] error: z2m: Exiting... [2024-09-08 11:33:52] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21)

/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12) [11:55:52] INFO: Preparing to start... [11:55:52] INFO: Socat not enabled [11:55:52] INFO: Starting Zigbee2MQTT... Starting Zigbee2MQTT without watchdog. [2024-09-08 11:55:53] info: z2m: Logging to console, file (filename: log.log) [2024-09-08 11:55:53] debug: z2m: Loaded state from file /config/zigbee2mqtt/state.json [2024-09-08 11:55:53] info: z2m: Starting Zigbee2MQTT version 1.40.1 (commit #unknown) [2024-09-08 11:55:53] info: z2m: Starting zigbee-herdsman (0.57.3) [2024-09-08 11:55:53] debug: z2m: Using zigbee-herdsman with settings: '"{\"network\":{\"panID\":6754,\"extendedPanID\":[221,221,221,221,221,221,221,221],\"channelList\":[25],\"networkKey\":\"HIDDEN\"},\"databasePath\":\"/config/zigbee2mqtt/database.db\",\"databaseBackupPath\":\"/config/zigbee2mqtt/database.db.backup\",\"backupPath\":\"/config/zigbee2mqtt/coordinator_backup.json\",\"serialPort\":{\"path\":\"tcp://10.100.100.223:6638\"},\"adapter\":{\"concurrent\":null,\"delay\":null,\"disableLED\":false,\"transmitPower\":9}}"' [2024-09-08 11:55:53] debug: zh:adapter: Failed to validate path: 'Error: spawn udevadm ENOENT' [2024-09-08 11:55:53] debug: zh:controller: Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"tcp://10.100.100.223:6638"},"adapter":{"disableLED":false,"concurrent":null,"delay":null,"transmitPower":9},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json"}' [2024-09-08 11:55:53] info: zh:zstack:znp: Opening TCP socket with 10.100.100.223:6638 [2024-09-08 11:55:57] info: zh:zstack:znp: Socket error [2024-09-08 11:55:57] error: z2m: Error while starting zigbee-herdsman [2024-09-08 11:55:57] error: z2m: Failed to start zigbee [2024-09-08 11:55:57] error: z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions [2024-09-08 11:55:57] error: z2m: Exiting... [2024-09-08 11:55:57] error: z2m: Error: Error while opening socket at Socket. (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:178:24) at Socket.emit (node:events:529:35) at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at processTicksAndRejections (node:internal/process/task_queues:82:21)

/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264 var er = new ERR_STREAM_WRITE_AFTER_END(); ^ Error: write after end at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12) at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21) at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12) at Logger.log (/app/lib/util/logger.ts:189:25) at Logger.info (/app/lib/util/logger.ts:202:14) at Znp.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/z-stack/znp/znp.ts:108:16) at Object.onceWrapper (node:events:632:26) at Socket.emit (node:events:517:28) at TCP. (node:net:350:12)

sven-borden commented 1 month ago

Similar issue on my side :(

harvindhillon commented 1 month ago

Did you try resetting the zigbee dongle itself?

Shutdown z2m. Restart dongle, once restarted see if it can be reachable. Then start z2m

From the error it looks like it cant connect to the dongle.

afkdk commented 1 month ago

Thanks for your time investigating this problem πŸ‘

I had already tried this but I have now retried it by disconnecting the PoE unit, waiting 5+ sec, and then repowering... And then Start Z2M again - No change, still red light after a short time...

sΓΈn. 8. sep. 2024 22.16 skrev harvindhillon @.***>:

Did you try resetting the zigbee dongle itself?

Shutdown z2m. Restart dongle, once restarted see if it can be reachable. Then start z2m

From the error it looks like it cant connect to the dongle.

β€” Reply to this email directly, view it on GitHub https://github.com/Koenkk/zigbee2mqtt/issues/23901#issuecomment-2336812081, or unsubscribe https://github.com/notifications/unsubscribe-auth/APBXV5FRZCNZ7FMZOZ6YHHTZVSWC5AVCNFSM6AAAAABN2224JCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDGMZWHAYTEMBYGE . You are receiving this because you authored the thread.Message ID: @.***>

aantonelloborges commented 1 month ago

If you are using a slzb-06 coordinator via POE, in its settings, make sure that you only have Ethernet mode enabled. I had this same problem yesterday and it was solved. Now I have a problem with panId.

image
afkdk commented 1 month ago

I am using the TubesZB PoE coordinator - and I have just installed a HA PyCLI tool for gathering some more information for possibly i identifikation of the bug culprit. The nice color coding of the text has vanished by the copy-paste so I may try some better media if necessary for interpretation...


s6-rc: info: service s6rc-oneshot-runner: stopping s6-rc: info: service s6rc-oneshot-runner successfully stopped s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service banner: starting


Add-on: TubesZB Zigpy-CLI Tools TubesZB Zigpy-CLI Toolsadd-on

Add-on version: 0.2.3.4 You are running the latest version of this add-on. System: Home Assistant OS 13.1 (amd64 / qemux86-64) Home Assistant Core: 2024.9.1 Home Assistant Supervisor: 2024.08.0

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

s6-rc: info: service banner successfully started s6-rc: info: service zigpy-cli: starting [01:47:39] INFO: Directoty Exists [01:47:40] INFO: Running zigpy - info on /dev/ttyS3 Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 398, in _reconfigure_port orig_attr = termios.tcgetattr(self.fd) ^^^^^^^^^^^^^^^^^^^^^^^^^^ termios.error: (5, 'I/O error')

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/bin/zigpy", line 8, in sys.exit(cli()) ^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1157, in call return self.main(args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1078, in main rv = self.invoke(ctx) ^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1688, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1688, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1434, in invoke return ctx.invoke(self.callback, ctx.params) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 783, in invoke return __callback(args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/decorators.py", line 45, in new_func return f(get_current_context().obj, *args, *kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy_cli/cli.py", line 20, in inner return loop.run_until_complete(cmd(args, kwargs)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 654, in run_until_complete return future.result() ^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy_cli/radio.py", line 82, in info await app.connect() File "/usr/local/lib/python3.11/site-packages/zigpy_znp/zigbee/application.py", line 103, in connect await znp.connect() File "/usr/local/lib/python3.11/site-packages/zigpy_znp/api.py", line 731, in connect self._uart = await uart.connect(self._config[conf.CONF_DEVICE], self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpyznp/uart.py", line 171, in connect , protocol = await zigpy.serial.create_serial_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/serial.py", line 69, in create_serial_connection transport, protocol = await pyserial_asyncio.create_serial_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/serial_asyncio/init.py", line 448, in create_serial_connection serial_instance = serial.serial_for_url(*args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/serial/init.py", line 90, in serial_for_url instance.open() File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 332, in open self._reconfigure_port(force_update=True) File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 401, in _reconfigure_port raise SerialException("Could not configure port: {}".format(msg)) serial.serialutil.SerialException: Could not configure port: (5, 'I/O error') [01:47:40] INFO: zigpy-cli-up script exited with code 1 s6-rc: warning: unable to start service zigpy-cli: command exited 1 s6-rc: info: service banner: stopping /run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information. /run/s6/basedir/scripts/rc.init: fatal: stopping the container. s6-rc: info: service banner successfully stopped s6-rc: info: service legacy-cont-init: stopping s6-rc: info: service legacy-cont-init successfully stopped s6-rc: info: service fix-attrs: stopping s6-rc: info: service fix-attrs successfully stopped s6-rc: info: service s6rc-oneshot-runner: stopping s6-rc: info: service s6rc-oneshot-runner successfully stopped

man. 9. sep. 2024 00.18 skrev aantonelloborges @.***>:

If you are using a slzb-06 coordinator via POE, in its settings, make sure that you only have Ethernet mode enabled. I had this same problem yesterday and it was solved. Now I have a problem with panId.

β€” Reply to this email directly, view it on GitHub https://github.com/Koenkk/zigbee2mqtt/issues/23901#issuecomment-2336843001, or unsubscribe https://github.com/notifications/unsubscribe-auth/APBXV5DH7YEYB2GXSKU72RTZVTELNAVCNFSM6AAAAABN2224JCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDGMZWHA2DGMBQGE . You are receiving this because you authored the thread.Message ID: @.***>

afkdk commented 1 month ago

BTW., I just noticed that it refered to HA 2024.9.1 - it also failed in the last 2024.8.x version. i just updated to version 2024.9.1 in case that this Z2M problem may originate in some unintentional bindings to this newer HA version...

man. 9. sep. 2024 01.51 skrev Anders Kjaersgaard (via GMAIL) < @.***>:

I am using the TubesZB PoE coordinator - and I have just installed a HA PyCLI tool for gathering some more information for possibly i identifikation of the bug culprit. The nice color coding of the text has vanished by the copy-paste so I may try some better media if necessary for interpretation...


s6-rc: info: service s6rc-oneshot-runner: stopping s6-rc: info: service s6rc-oneshot-runner successfully stopped s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service banner: starting


Add-on: TubesZB Zigpy-CLI Tools TubesZB Zigpy-CLI Toolsadd-on

Add-on version: 0.2.3.4 You are running the latest version of this add-on. System: Home Assistant OS 13.1 (amd64 / qemux86-64) Home Assistant Core: 2024.9.1 Home Assistant Supervisor: 2024.08.0

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

s6-rc: info: service banner successfully started s6-rc: info: service zigpy-cli: starting [01:47:39] INFO: Directoty Exists [01:47:40] INFO: Running zigpy - info on /dev/ttyS3 Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 398, in _reconfigure_port orig_attr = termios.tcgetattr(self.fd) ^^^^^^^^^^^^^^^^^^^^^^^^^^ termios.error: (5, 'I/O error')

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/bin/zigpy", line 8, in sys.exit(cli()) ^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1157, in call return self.main(args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1078, in main rv = self.invoke(ctx) ^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1688, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1688, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 1434, in invoke return ctx.invoke(self.callback, ctx.params) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/core.py", line 783, in invoke return __callback(args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/click/decorators.py", line 45, in new_func return f(get_current_context().obj, *args, *kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy_cli/cli.py", line 20, in inner return loop.run_until_complete(cmd(args, kwargs)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 654, in run_until_complete return future.result() ^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy_cli/radio.py", line 82, in info await app.connect() File "/usr/local/lib/python3.11/site-packages/zigpy_znp/zigbee/application.py", line 103, in connect await znp.connect() File "/usr/local/lib/python3.11/site-packages/zigpy_znp/api.py", line 731, in connect self._uart = await uart.connect(self._config[conf.CONF_DEVICE], self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpyznp/uart.py", line 171, in connect , protocol = await zigpy.serial.create_serial_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/serial.py", line 69, in create_serial_connection transport, protocol = await pyserial_asyncio.create_serial_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/serial_asyncio/init.py", line 448, in create_serial_connection serial_instance = serial.serial_for_url(*args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/serial/init.py", line 90, in serial_for_url instance.open() File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 332, in open self._reconfigure_port(force_update=True) File "/usr/local/lib/python3.11/site-packages/serial/serialposix.py", line 401, in _reconfigure_port raise SerialException("Could not configure port: {}".format(msg)) serial.serialutil.SerialException: Could not configure port: (5, 'I/O error') [01:47:40] INFO: zigpy-cli-up script exited with code 1 s6-rc: warning: unable to start service zigpy-cli: command exited 1 s6-rc: info: service banner: stopping /run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information. /run/s6/basedir/scripts/rc.init: fatal: stopping the container. s6-rc: info: service banner successfully stopped s6-rc: info: service legacy-cont-init: stopping s6-rc: info: service legacy-cont-init successfully stopped s6-rc: info: service fix-attrs: stopping s6-rc: info: service fix-attrs successfully stopped s6-rc: info: service s6rc-oneshot-runner: stopping s6-rc: info: service s6rc-oneshot-runner successfully stopped

man. 9. sep. 2024 00.18 skrev aantonelloborges @.***>:

If you are using a slzb-06 coordinator via POE, in its settings, make sure that you only have Ethernet mode enabled. I had this same problem yesterday and it was solved. Now I have a problem with panId.

β€” Reply to this email directly, view it on GitHub https://github.com/Koenkk/zigbee2mqtt/issues/23901#issuecomment-2336843001, or unsubscribe https://github.com/notifications/unsubscribe-auth/APBXV5DH7YEYB2GXSKU72RTZVTELNAVCNFSM6AAAAABN2224JCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDGMZWHA2DGMBQGE . You are receiving this because you authored the thread.Message ID: @.***>

harvindhillon commented 1 month ago

Did you try reaching out to TubeZ ?

Seems like the serial connection to the zigbee radio is not opening

afkdk commented 1 month ago

Not yet as it has (AFAIK) not changed - as the other reports also seem to indicate: it "only" this Z2M upgrade is the action/change that breaks the Zigbee integration... But I'll try til reach out πŸ‘

afkdk commented 1 month ago

Link til Tubes coordinator integration issue:

https://github.com/tube0013/tube_gateways/issues/205

Please add/supplement my notes where appropriate...

Irix0 commented 1 month ago

I think my issue #23950 is related to this.

afkdk commented 1 month ago

Agree - some similar start-up issues seem to appear on the issues list...

Most surprisingly, the Z2M sprung into action the other day and worked for 1+ days - so GREAT to see it all back LIVE and working πŸ˜ƒ It worked flawlessly without any errors - and I could get to the TubesZB web interface again...

It happened much to my surprise after a "total power cut", i.e., I have some PV batteries installed so all power had to be cut to the house - and surprisingly, the Z2M was back up and running afterward! Despite that, I have tried shutdowns and power cuts of both the coordinator and HA... Likely, the startup has in some way been "just right" - like https://github.com/Koenkk/zigbee2mqtt/issues/23950 and others have reported...

But as expected (as Master in computer science I know that computers work deterministic so eventually I expected to fail again), this Morning at 7 AM, it suddenly failed again πŸ˜₯

Now it is back to the "failed state" - somehow the Z2M <-> TubesZB interaction locks each other up and only be coincidence, it may work again (for a short time...)

Later today, the power has to be cut again and I may be lucky that circumstances are right again so the start timing is _just _right__ so I have some more time to enjoy the great integration as long as it works 🀞

afkdk commented 1 month ago

I have updated https://github.com/tube0013/tube_gateways/issues/205 as well with link...

afkdk commented 3 weeks ago

Now it seems that I almost with certainty can circumvent this problem by 1) switching off-wait-on PoE switch (powering TubesZB ESP), 2) restart Z2M by restarting HA. So my guess is some intricate tcp timing/queue issue locks up the network between HA and the TubesZP dongle (the remaining ports on switch and other HA network comm work fine when this happens.)

afkdk commented 3 weeks ago

Closed