Hello,
On Friday morning I woke up and my lights did not turn on as I moved around the house. Upon further digging I found that my zigbee2mqtt add-on was not working.
I have HA (0.103.0) installed on a Linux VM (Ubuntu 18 LTE) within Proxmox (proxmox-ve: 6.1-2 (running kernel: 5.3.13-1-pve)).
First I tested that Proxmox could see the USB stick:
root@pve:~$ ls -l /dev/serial/by-id
total 0
lrwxrwxrwx 1 root root 13 Dec 15 11:18 usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B0018E1F5E8-if00 -> ../../ttyACM0
root@pve:~$ test -w /dev/ttyACM0 && echo success || echo failure
success
I then checked within the HA VM with the same test:
ls -l /dev/serial/by-id
total 0
lrwxrwxrwx 1 root root 13 Dec 15 11:13 usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B0018E1F5E8-if00 -> ../../ttyACM0
root@home_assistant_server:~$ test -w /dev/ttyACM0 && echo success || echo failure
success
It all looked fine so I started the zigbee2mqtt add-on, my config is:
{
"data_path": "/share/zigbee2mqtt",
"devices": "devices.yaml",
"groups": "groups.yaml",
"homeassistant": true,
"permit_join": false,
"mqtt": {
"base_topic": "zigbee2mqtt",
"server": "mqtt://10.10.20.221:1883",
"user": "mqtt_broker",
"password": "Password"
},
"serial": {
"port": "/dev/ttyACM0"
},
"advanced": {
"pan_id": 6754,
"channel": 11,
"network_key": [
9,
8,
3,
11,
9,
13,
15,
1,
2,
4,
6,
4,
11,
16,
13
],
"availability_blacklist": [],
"log_level": "debug",
"baudrate": 115200
},
"ban": [],
"whitelist": [],
"queue": {},
"socat": {
"enabled": false,
"master": "pty,raw,echo=0,link=/dev/ttyZ2M,mode=777",
"slave": "tcp-listen:8485,keepalive,nodelay,reuseaddr,keepidle=1,keepintvl=1,keepcnt=5",
"restartdelay": 1,
"initialdelay": 1,
"options": "-d -d",
"log": false
}
}
I got the following error:
./run.sh: line 16: [Info] Configuration backup found in /share/zigbee2mqtt/.configuration.yaml.bk. Skipping config backup.: No such file or directory
[Info] Socat is DISABLED and not started
2019-12-15T11:51:39: PM2 log: Launching in no daemon mode
2019-12-15T11:51:39: PM2 log: App [npm:0] starting in -fork mode-
2019-12-15T11:51:39: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.7.1
> node index.js
zigbee2mqtt:info 2019-12-15T11:51:41: Logging to directory: '/share/zigbee2mqtt/log/2019-12-15.11-51-40'
zigbee2mqtt:debug 2019-12-15T11:51:41: Removing old log directory '/share/zigbee2mqtt/log/2019-12-14.23-31-31'
zigbee2mqtt:debug 2019-12-15T11:51:41: Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 2019-12-15T11:51:41: Starting zigbee2mqtt version 1.7.1 (commit #unknown)
zigbee2mqtt:info 2019-12-15T11:51:41: Starting zigbee-herdsman...
zigbee2mqtt:debug 2019-12-15T11:51:41: Using zigbee-herdsman with settings: '{"network":{"panID":"HIDDEN","extendedPanID":["HIDDEN"],"channelList":[11],"networkKey":"HIDDEN"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyACM0"}}'
zigbee2mqtt:error 2019-12-15T11:51:41: Error while starting zigbee-herdsman
zigbee2mqtt:error 2019-12-15T11:51:41: Failed to start zigbee
zigbee2mqtt:error 2019-12-15T11:51:41: Exiting...
zigbee2mqtt:error 2019-12-15T11:51:41: Error: Error while opening serialport 'Error: Error: No such device, cannot open /dev/ttyACM0'
at Znp.<anonymous> (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:109:32)
at Generator.next (<anonymous>)
at /zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:8:71
at new Promise (<anonymous>)
at __awaiter (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:4:12)
at SerialPort.serialPort.open (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:107:49)
at SerialPort._error (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/node_modules/@serialport/stream/stream.js:197:14)
at binding.open.then.err (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/node_modules/@serialport/stream/stream.js:241:12)
npm
ERR! code ELIFECYCLE
npm ERR! errno 1
npm
ERR! [email protected] start: `node index.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the [email protected] start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
2019-12-15T11:51:42: PM2 log: App [npm:0] exited with code [1] via signal [SIGINT]
2019-12-15T11:51:42: PM2 log: App [npm:0] starting in -fork mode-
2019-12-15T11:51:42: PM2 log: App [npm:0] online
> [email protected] start /zigbee2mqtt-1.7.1
> node index.js
zigbee2mqtt:info 2019-12-15T11:51:43: Logging to directory: '/share/zigbee2mqtt/log/2019-12-15.11-51-43'
zigbee2mqtt:debug 2019-12-15T11:51:43: Removing old log directory '/share/zigbee2mqtt/log/2019-12-14.23-31-34'
zigbee2mqtt:debug 2019-12-15T11:51:43: Loaded state from file /share/zigbee2mqtt/state.json
zigbee2mqtt:info 2019-12-15T11:51:43: Starting zigbee2mqtt version 1.7.1 (commit #unknown)
zigbee2mqtt:info 2019-12-15T11:51:43: Starting zigbee-herdsman...
zigbee2mqtt:debug 2019-12-15T11:51:43: Using zigbee-herdsman with settings: '{"network":{"panID":"HIDDEN","extendedPanID":["HIDDEN"],"channelList":[11],"networkKey":"HIDDEN"},"databasePath":"/share/zigbee2mqtt/database.db","databaseBackupPath":"/share/zigbee2mqtt/database.db.backup","backupPath":"/share/zigbee2mqtt/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":true,"path":"/dev/ttyACM0"}}'
zigbee2mqtt:error 2019-12-15T11:51:50: Error while starting zigbee-herdsman
zigbee2mqtt:error 2019-12-15T11:51:50: Failed to start zigbee
zigbee2mqtt:error 2019-12-15T11:51:50: Exiting...
zigbee2mqtt:error 2019-12-15T11:51:50: Error: SRSP - SYS - version after 6000ms
at Timeout.object.timer.setTimeout [as _onTimeout] (/zigbee2mqtt-1.7.1/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24)
at ontimeout (timers.js:436:11)
at tryOnTimeout (timers.js:300:5)
at listOnTimeout (timers.js:263:5)
at Timer.processTimers (timers.js:223:10)
npm
ERR! code ELIFECYCLE
npm ERR! errno 1cl
npm
ERR! [email protected] start: `node index.js`
npm ERR! Exit status 1
npm
ERR!
npm ERR! Failed at the [email protected] start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
npm ERR! A complete log of this run can be found in:
npm ERR! /root/.npm/_logs/2019-12-15T11_51_50_939Z-debug.log
I then ran the test again to see if the stick was still avaliable to the linux VM and it was not:
root@home_assistant_server:~# ls -l /dev/serial/by-id
ls: cannot access '/dev/serial/by-id': No such file or directory
root@home_assistant_server:~# test -w /dev/ttyACM0 && echo success || echo failure
failure
I then ran the tests on Proxmox again and it was still avaliable:
root@pve:~# ls -l /dev/serial/by-id
total 0
lrwxrwxrwx 1 root root 13 Dec 15 11:36 usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B0018E1F5E8-if00 -> ../../ttyACM0
root@pve:~# test -w /dev/ttyACM0 && echo success || echo failure
success
I checked the Proxmox syslog and I found that the USB stick is constantly disconnecting and reconnecting while the addon is active but if I stop the addon then it stays attached:
Dec 15 11:50:00 pve systemd[1]: Starting Proxmox VE replication runner...
Dec 15 11:50:01 pve systemd[1]: pvesr.service: Succeeded.
Dec 15 11:50:01 pve systemd[1]: Started Proxmox VE replication runner.
Dec 15 11:50:36 pve kernel: usb 5-1.2: USB disconnect, device number 45
Dec 15 11:50:36 pve kernel: usb 5-1.2: new full-speed USB device number 46 using xhci_hcd
Dec 15 11:50:36 pve kernel: usb 5-1.2: New USB device found, idVendor=0451, idProduct=16a8, bcdDevice= 0.09
Dec 15 11:50:36 pve kernel: usb 5-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 15 11:50:36 pve kernel: usb 5-1.2: Product: TI CC2531 USB CDC
Dec 15 11:50:36 pve kernel: usb 5-1.2: Manufacturer: Texas Instruments
Dec 15 11:50:36 pve kernel: usb 5-1.2: SerialNumber: __0X00124B0018E1F5E8
Dec 15 11:50:36 pve kernel: cdc_acm 5-1.2:1.0: ttyACM0: USB ACM device
Dec 15 11:50:38 pve kernel: usb 5-1.2: reset full-speed USB device number 46 using xhci_hcd
Dec 15 11:51:00 pve systemd[1]: Starting Proxmox VE replication runner...
Dec 15 11:51:01 pve systemd[1]: pvesr.service: Succeeded.
Dec 15 11:51:01 pve systemd[1]: Started Proxmox VE replication runner.
Dec 15 11:51:37 pve kernel: usb 5-1.2: USB disconnect, device number 46
Dec 15 11:51:37 pve kernel: usb 5-1.2: new full-speed USB device number 47 using xhci_hcd
Dec 15 11:51:38 pve kernel: usb 5-1.2: New USB device found, idVendor=0451, idProduct=16a8, bcdDevice= 0.09
Dec 15 11:51:38 pve kernel: usb 5-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 15 11:51:38 pve kernel: usb 5-1.2: Product: TI CC2531 USB CDC
Dec 15 11:51:38 pve kernel: usb 5-1.2: Manufacturer: Texas Instruments
Dec 15 11:51:38 pve kernel: usb 5-1.2: SerialNumber: __0X00124B0018E1F5E8
Dec 15 11:51:38 pve kernel: cdc_acm 5-1.2:1.0: ttyACM0: USB ACM device
Dec 15 11:51:41 pve kernel: usb 5-1.2: reset full-speed USB device number 47 using xhci_hcd
Dec 15 11:51:45 pve kernel: usb 5-1.2: USB disconnect, device number 47
Dec 15 11:51:45 pve kernel: usb 5-1.2: new full-speed USB device number 48 using xhci_hcd
Dec 15 11:51:45 pve kernel: usb 5-1.2: New USB device found, idVendor=0451, idProduct=16a8, bcdDevice= 0.09
Dec 15 11:51:45 pve kernel: usb 5-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 15 11:51:45 pve kernel: usb 5-1.2: Product: TI CC2531 USB CDC
Dec 15 11:51:45 pve kernel: usb 5-1.2: Manufacturer: Texas Instruments
Dec 15 11:51:45 pve kernel: usb 5-1.2: SerialNumber: __0X00124B0018E1F5E8
Dec 15 11:51:45 pve kernel: cdc_acm 5-1.2:1.0: ttyACM0: USB ACM device
Dec 15 11:51:50 pve kernel: usb 5-1.2: reset full-speed USB device number 48 using xhci_hcd
Dec 15 11:51:54 pve kernel: usb 5-1.2: USB disconnect, device number 48
Dec 15 11:51:54 pve kernel: usb 5-1.2: new full-speed USB device number 49 using xhci_hcd
Dec 15 11:51:54 pve kernel: usb 5-1.2: New USB device found, idVendor=0451, idProduct=16a8, bcdDevice= 0.09
Dec 15 11:51:54 pve kernel: usb 5-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 15 11:51:54 pve kernel: usb 5-1.2: Product: TI CC2531 USB CDC
Dec 15 11:51:54 pve kernel: usb 5-1.2: Manufacturer: Texas Instruments
Dec 15 11:51:54 pve kernel: usb 5-1.2: SerialNumber: __0X00124B0018E1F5E8
Dec 15 11:51:54 pve kernel: cdc_acm 5-1.2:1.0: ttyACM0: USB ACM device
Dec 15 11:51:56 pve kernel: usb 5-1.2: reset full-speed USB device number 49 using xhci_hcd
Dec 15 11:52:00 pve systemd[1]: Starting Proxmox VE replication runner...
Dec 15 11:52:01 pve systemd[1]: pvesr.service: Succeeded.
Dec 15 11:52:01 pve systemd[1]: Started Proxmox VE replication runner.
Dec 15 11:52:03 pve kernel: usb 5-1.2: USB disconnect, device number 49
I followed all the guides I could find and made sure modemmanager was not installed in the VM or Proxmox:
root@home_assistant_server:~# systemctl |grep Modem
root@home_assistant_server:~#
root@pve:~# systemctl |grep Modem
root@pve:~#
I have run out of ideas of where to look next, has anyone got any ideas?
Many thanks