Container keeps restarting with version 1.23 #11545

avakarev · 2022-02-21T16:23:02Z

What happened?

Docker container of image koenkk/zigbee2mqtt:latest-dev constantly restarts.
Same configurations works just fine with latest release koenkk/zigbee2mqtt:1.23.0

What did you expect to happen?

I expect container to keep running, connects to mqtt server and publishes / consumes messages.

How to reproduce it (minimal and precise)

Pull and run latest koenkk/zigbee2mqtt:latest-dev image (I found the following version in logs: 1.23.0-dev (commit #a345181)

Zigbee2MQTT version

1.23.0-dev (commit #a345181)

Adapter firmware version

20211217

Adapter

Electrolama zzh! CC2652R

Debug log

zigbee2mqtt | Using '/app/data' as data directory
zigbee2mqtt | Zigbee2MQTT:debug 2022-02-21 17:22:14: Loaded state from file /app/data/state.json
zigbee2mqtt | Zigbee2MQTT:info 2022-02-21 17:22:14: Logging to console only'
zigbee2mqtt | Zigbee2MQTT:info 2022-02-21 17:22:14: Starting Zigbee2MQTT version 1.23.0-dev (commit #a345181)
zigbee2mqtt | Zigbee2MQTT:info 2022-02-21 17:22:14: Starting zigbee-herdsman (0.14.17)
zigbee2mqtt | Zigbee2MQTT:debug 2022-02-21 17:22:14: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":true},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[25],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6755},"serialPort":{"path":"/dev/ttyUSB0"}}'

The text was updated successfully, but these errors were encountered:

avakarev · 2022-02-21T16:30:20Z

Here is content of configuration.yaml:

serial:
  port: /dev/ttyUSB0
  disable_led: true

mqtt:
  server: mqtt://my-server:1883
  base_topic: zigbee2mqtt-home
  user: '!secret user'
  password: '!secret password'
  client_id: zigbee2mqtt-home
  include_device_information: true

permit_join: false

frontend:
  port: 8080
  host: 0.0.0.0

devices: devices.yaml
groups: groups.yaml

ota:
  ikea_ota_use_test_url: false
  update_check_interval: 3600
  disable_automatic_update_check: true

availability:
  active:
    timeout: 20
  passive:
    timeout: 720

homeassistant: false

advanced:
  log_level: debug
  log_output: ['console']
  pan_id: 6755
  channel: 25
  last_seen: ISO_8601_local
  legacy_api: false

Here is content of devices.yaml:

'0x000d6ffffe4b4615':
  friendly_name: hallway-wall-light
  availability: true
'0x847127fffebea049':
  friendly_name: mailbox-motion
'0x14b457fffe693ef6':
  friendly_name: storeroom-motion
'0xa4c138a63ca36dd1':
  friendly_name: '0xa4c138a63ca36dd1'

Here is content of groups.yaml:

{}

Koenkk · 2022-02-21T16:38:36Z

Please provide the debug log of the crash

See https://www.zigbee2mqtt.io/guide/usage/debug.html on how to enable debug logging.

avakarev · 2022-02-21T16:49:46Z

Here we go:

zigbee2mqtt    | Using '/app/data' as data directory
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 17:48:07: Loaded state from file /app/data/state.json
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:07: Logging to console only'
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:07: Starting Zigbee2MQTT version 1.23.0-dev (commit #0fdbb91)
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:07: Starting zigbee-herdsman (0.14.18)
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 17:48:07: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":true},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[25],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6755},"serialPort":{"path":"/dev/ttyUSB0"}}'
zigbee2mqtt    | 2022-02-21T16:48:08.919Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6755,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":true,"concurrent":null,"delay":null}}'
zigbee2mqtt    | 2022-02-21T16:48:08.924Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with {"baudRate":115200,"rtscts":false,"autoOpen":false,"path":"/dev/ttyUSB0"}
zigbee2mqtt    | Using '/app/data' as data directory
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 17:48:19: Loaded state from file /app/data/state.json
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:20: Logging to console only'
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:20: Starting Zigbee2MQTT version 1.23.0-dev (commit #0fdbb91)
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 17:48:20: Starting zigbee-herdsman (0.14.18)
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 17:48:20: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":true},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[25],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6755},"serialPort":{"path":"/dev/ttyUSB0"}}'
zigbee2mqtt    | 2022-02-21T16:48:21.026Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6755,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":true,"concurrent":null,"delay":null}}'
zigbee2mqtt    | 2022-02-21T16:48:21.031Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with {"baudRate":115200,"rtscts":false,"autoOpen":false,"path":"/dev/ttyUSB0"}

Koenkk · 2022-02-21T20:08:55Z

I don't see any crash in this log. Can you provide the STDOUT when running with env variable DEBUG=*?

avakarev · 2022-02-21T20:29:38Z

Here we go:

zigbee2mqtt    | Using '/app/data' as data directory
zigbee2mqtt    | winston:create-logger: Define prototype method for "error"
zigbee2mqtt    | winston:create-logger: Define prototype method for "warn"
zigbee2mqtt    | winston:create-logger: Define prototype method for "info"
zigbee2mqtt    | winston:create-logger: Define prototype method for "http"
zigbee2mqtt    | winston:create-logger: Define prototype method for "verbose"
zigbee2mqtt    | winston:create-logger: Define prototype method for "debug"
zigbee2mqtt    | winston:create-logger: Define prototype method for "silly"
zigbee2mqtt    | winston:create-logger: Define prototype method for "emerg"
zigbee2mqtt    | winston:create-logger: Define prototype method for "alert"
zigbee2mqtt    | winston:create-logger: Define prototype method for "crit"
zigbee2mqtt    | winston:create-logger: Define prototype method for "error"
zigbee2mqtt    | winston:create-logger: Define prototype method for "warning"
zigbee2mqtt    | winston:create-logger: Define prototype method for "notice"
zigbee2mqtt    | winston:create-logger: Define prototype method for "info"
zigbee2mqtt    | winston:create-logger: Define prototype method for "debug"
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 21:25:35: Loaded state from file /app/data/state.json
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 21:25:35: Logging to console only'
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 21:25:35: Starting Zigbee2MQTT version 1.23.0-dev (commit #9e35f22)
zigbee2mqtt    | Zigbee2MQTT:info  2022-02-21 21:25:35: Starting zigbee-herdsman (0.14.18)
zigbee2mqtt    | Zigbee2MQTT:debug 2022-02-21 21:25:35: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":true},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[25],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6755},"serialPort":{"path":"/dev/ttyUSB0"}}'
zigbee2mqtt    | 2022-02-21T20:25:35.488Z serialport/bindings-cpp loading LinuxBinding
zigbee2mqtt    | 2022-02-21T20:25:35.878Z serialport/bindings-cpp list
zigbee2mqtt    | 2022-02-21T20:25:36.113Z serialport/bindings-cpp list
zigbee2mqtt    | 2022-02-21T20:25:36.292Z serialport/bindings-cpp list
zigbee2mqtt    | 2022-02-21T20:25:36.401Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":"HIDDEN","panID":6755,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[25]},"serialPort":{"path":"/dev/ttyUSB0"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":true,"concurrent":null,"delay":null}}'
zigbee2mqtt    | 2022-02-21T20:25:36.405Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with {"baudRate":115200,"rtscts":false,"autoOpen":false,"path":"/dev/ttyUSB0"}
zigbee2mqtt    | 2022-02-21T20:25:36.411Z serialport/stream opening path: /dev/ttyUSB0
zigbee2mqtt    | 2022-02-21T20:25:36.413Z serialport/bindings-cpp open
zigbee2mqtt    | 2022-02-21T20:30:30.284Z serialport/stream _read queueing _read for after open
zigbee2mqtt exited with code 139

This log doesn't seem to be very useful too. Just switching image between koenkk/zigbee2mqtt:latest-dev and koenkk/zigbee2mqtt:1.23.0 in docker-compose.yml either breaks it or fixes it respectively.

Just in case, here is my docker-compose.yml:

version: "3.7"

services:
  zigbee2mqtt:
    image: koenkk/zigbee2mqtt:latest-dev
    # image: koenkk/zigbee2mqtt:1.23.0
    container_name: zigbee2mqtt
    restart: unless-stopped
    ports:
      - "8080:8080/tcp"
    volumes:
      - ./data:/app/data
      - /run/udev:/run/udev:ro
    devices:
      - /dev/ttyUSB0:/dev/ttyUSB0
    environment:
      - TZ=Europe/Berlin
      - DEBUG=*
    privileged: true

Koenkk · 2022-02-21T20:31:12Z

Still no crash, it just stop working right? Can you do a npm ci in the z2m folder? (not applicable when you run in docker/ha addon)

avakarev · 2022-02-21T20:36:23Z

yes, I run it in the docker, but can run interactively from the shell. Which node to take 14 or 16?

Koenkk · 2022-02-21T20:49:33Z

What system are you running on?

avakarev · 2022-02-21T20:59:26Z

Took 14. npm ci seems to be fine.

$:> cat /sys/firmware/devicetree/base/model
Raspberry Pi 3 Model B Rev 1.2

$:> lsb_release -a
No LSB modules are available.
Distributor ID:	Raspbian
Description:	Raspbian GNU/Linux 11 (bullseye)
Release:	11
Codename:	bullseye

$:> arch
armv7l

$:> uname -a
Linux raspberrypi 5.10.92-v7+ #1514 SMP Mon Jan 17 17:36:39 GMT 2022 armv7l GNU/Linux

$:> node -v
v14.19.0

$:> npm -v
6.14.16

$:> git clone https://github.com/Koenkk/zigbee2mqtt.git
remote: Total 21079 (delta 717), reused 735 (delta 526), pack-reused 20079
Receiving objects: 100% (21079/21079), 87.04 MiB | 2.32 MiB/s, done.
Resolving deltas: 100% (15776/15776), done.

$:> git checkout dev
Branch 'dev' set up to track remote branch 'dev' from 'origin'.
Switched to a new branch 'dev'

$:> git rev-parse HEAD
9e35f22ac4862103abe1c41678ab0de5c1f0051c

$:> npm ci
added 922 packages in 116.529s

$:> echo $?
0

avakarev · 2022-02-21T21:12:17Z

I did npm run build && npm start z2m starts just fine outside the container.

avakarev · 2022-02-21T21:26:30Z

I think it worth to take a look in direction of serialport. What can I see from the end of the log, herdsman call serialport and then it explodes. Will try to downgrade herdsman to 0.14.16, before serialport's version bump https://github.com/Koenkk/zigbee-herdsman/pull/504/files. Then build a local image and try to run it.

qp68 · 2022-02-21T21:44:15Z

Don't know if this will help but with the addon on Home Assistant OS, I get the same problem. Starting of zigbee2mqtt is on infinite loop and it "breaks" on same line as @avakarev. Everything was working fine on 1.23.0-dev commit f6f507c

[cont-init.d] executing container initialization scripts...
[cont-init.d] socat.sh: executing... 
[22:29:26] INFO: Socat not enabled, marking service as down
[cont-init.d] socat.sh: exited 0.
[cont-init.d] zigbee2mqtt.sh: executing... 
[cont-init.d] zigbee2mqtt.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[22:29:27] INFO: Zigbee Herdsman debug logging enabled
[22:29:29] INFO: Handing over control to Zigbee2mqtt Core ...
> zigbee2mqtt@1.23.0-dev start
> node index.js
Zigbee2MQTT:debug 2022-02-21 22:29:37: Loaded state from file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2022-02-21 22:29:37: Logging to console and directory: '/config/zigbee2mqtt/log/2022-02-21.22-29-34' filename: log.txt
Zigbee2MQTT:debug 2022-02-21 22:29:37: Removing old log directory '/config/zigbee2mqtt/log/2022-02-21.22-23-41'
Zigbee2MQTT:info  2022-02-21 22:29:37: Starting Zigbee2MQTT version 1.23.0-dev (commit #caafc64)
Zigbee2MQTT:info  2022-02-21 22:29:37: Starting zigbee-herdsman (0.14.18)
Zigbee2MQTT:debug 2022-02-21 22:29:37: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_22_98_92_6B-if00-port0"}}'
2022-02-21T21:29:38.352Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_22_98_92_6B-if00-port0"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2022-02-21T21:29:38.354Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with {"baudRate":115200,"rtscts":false,"autoOpen":false,"path":"/dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_22_98_92_6B-if00-port0"}
[22:29:40] INFO: Zigbee Herdsman debug logging enabled
[22:29:42] INFO: Handing over control to Zigbee2mqtt Core ...

avakarev · 2022-02-21T21:54:56Z

@Koenkk I can confirm now that downgrading herdsman to 0.14.16, basically reverting Koenkk/zigbee-herdsman#504 fixes the issue with container. WDYT of reverting Koenkk/zigbee-herdsman#504 for now, fix the dev branch and then take a closer look on serialport 9 => 10 migration?

avakarev · 2022-02-21T22:09:43Z

I also noticed that z2m's dockerfile referencing quite old version of alpine: 3.12. I assume serialport is quite sensitive to musl, so it might be that new serialport@10 doesn't like older alpines. I am about to try to build z2m image with latest dev branch (so latest herdsman) but different alpine versions.

avakarev · 2022-02-21T22:16:29Z

Ok, image based on node:14-alpine3.12 with latest dev branch fails same ways as node:14-alpine3.14 and node:14-alpine3.15.

Koenkk · 2022-02-22T15:40:54Z

@avakarev I think this issue is specific to rpi/arm, latest-dev works fine om my intel nuc.

avakarev · 2022-02-22T16:00:00Z

@Koenkk weird that it's only reproducible in docker container. And only with serialport@10.

@qp68 do you run z2m in docker too? What's your hardware?

qp68 · 2022-02-22T16:49:26Z

@qp68 do you run z2m in docker too? What's your hardware?

I run zigbee2mqtt as HA addon on Home Assistant OS 7.4. Hardware : Raspberry Pi 4 B 8 Go

BudBundi · 2022-02-22T17:40:02Z

Same problem here with a Raspberry Pi 4 B 4 GB with the arm64 image.
The docker container says Build: Docker on linux, arm64

avakarev · 2022-02-22T23:03:26Z

@Koenkk can you please bump zigbee-herdsman pkg in zigbee-herdsman-converters from 0.14.16 to >= 0.14.18?
Not sure if it can cause any issues, but it worth to avoid using both serialport v9 and v10 cause v10 has breaking changes (NAPI).

z2m-> zigbee-herdsman@0.14.18 -> serialport@10.3.0
z2m -> zigbee-herdsman-converters@14.0.430 -> zigbee-herdsman@0.14.16 -> serialport@9.2.8

Minims · 2022-02-23T12:39:18Z

Same problem with a Raspberry Pi 4 2 GB with the arm64 image with the zigbee2mqtt-edge version.

avakarev · 2022-02-23T17:48:40Z

JFYI I reproduced the issue with just serialport at https://github.com/avakarev/serialport-docker-rpi, so z2m could be fixed by just temporary rollback to serialport v9. I created an issue for serialport at serialport/node-serialport#2438

Koenkk · 2022-02-23T18:17:02Z

@avakarev thanks for the investigation!

I've reverted to serialport 9 for the time being, lets keep this issue open until serialport/node-serialport#2438 is fixed.

github-actions · 2022-03-26T00:02:15Z

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

avakarev added the problem Something isn't working label Feb 21, 2022

avakarev mentioned this issue Feb 23, 2022

serialport@10.3.0 fails in docker container on rpi serialport/node-serialport#2438

Closed

lukeallister mentioned this issue Feb 23, 2022

[New device support]: Sylvania BR30 TW (advertising as LEDVANCE) #11578

Closed

github-actions bot added the stale Stale issues label Mar 26, 2022

github-actions bot closed this as completed Apr 3, 2022

Koenkk mentioned this issue May 22, 2022

Bump serialport version to 10.4.0 Koenkk/zigbee-herdsman#540

Closed

Koenkk mentioned this issue Nov 10, 2022

Bump serialport from 9.2.8 to 10.4.0 Koenkk/zigbee-herdsman#607

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Container keeps restarting with version 1.23 #11545

Container keeps restarting with version 1.23 #11545

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

qp68 commented Feb 21, 2022

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

Koenkk commented Feb 22, 2022

avakarev commented Feb 22, 2022

qp68 commented Feb 22, 2022

BudBundi commented Feb 22, 2022

avakarev commented Feb 22, 2022 •

edited

Loading

Minims commented Feb 23, 2022

avakarev commented Feb 23, 2022

Koenkk commented Feb 23, 2022

github-actions bot commented Mar 26, 2022

Container keeps restarting with version 1.23 #11545

Container keeps restarting with version 1.23 #11545

Comments

avakarev commented Feb 21, 2022

What happened?

What did you expect to happen?

How to reproduce it (minimal and precise)

Zigbee2MQTT version

Adapter firmware version

Adapter

Debug log

avakarev commented Feb 21, 2022

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

Koenkk commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

qp68 commented Feb 21, 2022

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022

avakarev commented Feb 21, 2022 • edited Loading

Koenkk commented Feb 22, 2022

avakarev commented Feb 22, 2022

qp68 commented Feb 22, 2022

BudBundi commented Feb 22, 2022

avakarev commented Feb 22, 2022 • edited Loading

Minims commented Feb 23, 2022

avakarev commented Feb 23, 2022

Koenkk commented Feb 23, 2022

github-actions bot commented Mar 26, 2022

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 21, 2022 •

edited

Loading

avakarev commented Feb 22, 2022 •

edited

Loading