Koenkk / zigbee-herdsman

A Node.js Zigbee library
MIT License
481 stars 300 forks source link

SONOFF Dongle-E (Firmware 6.10.3_115200) Startup Issues #666

Closed chrislentz closed 1 year ago

chrislentz commented 1 year ago

I recently upgraded my SONOFF Dongle-E with the latest 6.10.3 firmware (ncp-uart-sw_6.10.3_115200.gbl) and I have noticed intermittenant start up issues with zigbee-herdsman. I am using Zigbee2MQTT via Docker with Herdsman logging turned on. Below is a start up log for a failed startup and a successful startup.

I am able to trigger the error with a simple docker compose down followed by docker compose up -d. But if I restart everything again after a failed start, it starts up fine.

Compose Block for Reference:

zigbee2mqtt:
    container_name: zigbee2mqtt
    image: koenkk/zigbee2mqtt
    restart: unless-stopped
    devices:
      - /dev/serial/by-id/usb-ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2_20220810193459-if00:/dev/zigbee
    environment:
      - TZ=America/New_York
      - DEBUG=zigbee-herdsman* npm start
    ports:
      - 8282:8282
    networks:
      - default
      - caddy
    volumes:
      - ./zigbee2mqtt/data:/app/data
      - /run/udev:/run/udev:ro
    labels:
      com.centurylinklabs.watchtower.enable: "true"
      caddy: "zigbee2mqtt.REDACTED.com"
      caddy.reverse_proxy: "{{upstreams 8282}}"
      caddy.tls.dns: "route53"
    depends_on:
      - caddy
      - mosquitto

Success Log: https://gist.github.com/chrislentz/dc7dd0a342e9442544733251618b03cd

Failed Log:

Using '/app/data' as data directory
Zigbee2MQTT:debug 2023-02-15 07:28:44: Loaded state from file /app/data/state.json
Zigbee2MQTT:info  2023-02-15 07:28:44: Logging to console and directory: '/app/data/log/2023-02-15.07-28-44' filename: log.txt
Zigbee2MQTT:debug 2023-02-15 07:28:44: Removing old log directory '/app/data/log/2023-02-15.01-01-25'
Zigbee2MQTT:info  2023-02-15 07:28:44: Starting Zigbee2MQTT version 1.30.1 (commit #eb878d3)
Zigbee2MQTT:info  2023-02-15 07:28:44: Starting zigbee-herdsman (0.14.89)
Zigbee2MQTT:debug 2023-02-15 07:28:45: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/app/data/coordinator_backup.json","databaseBackupPath":"/app/data/database.db.backup","databasePath":"/app/data/database.db","network":{"channelList":[20],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"adapter":"ezsp","path":"/dev/zigbee"}}'
2023-02-15T12:28:45.269Z 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":[20]},"serialPort":{"path":"/dev/zigbee","adapter":"ezsp"},"databasePath":"/app/data/database.db","databaseBackupPath":"/app/data/database.db.backup","backupPath":"/app/data/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2023-02-15T12:28:45.270Z zigbee-herdsman:adapter:ezsp:uart Opening SerialPort with {"path":"/dev/zigbee","baudRate":115200,"rtscts":false,"autoOpen":false}
2023-02-15T12:28:45.274Z zigbee-herdsman:adapter:ezsp:uart Serialport opened
2023-02-15T12:28:45.274Z zigbee-herdsman:adapter:ezsp:uart Uart reseting
2023-02-15T12:28:45.274Z zigbee-herdsman:adapter:ezsp:uart --> Write reset
2023-02-15T12:28:45.275Z zigbee-herdsman:adapter:ezsp:uart --> [1ac038bc7e]
2023-02-15T12:28:45.276Z zigbee-herdsman:adapter:ezsp:uart <-- [7e0c61b5a9902a19c4be7d5d087e1c61b1a9d42abfc4be78627e2c61b5a9902a19c4bedaf47e3c61b1a9d42abfc4bedf9e7ec20251a8bd7e]
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart <-- CRC error: 7e||ffff
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart --> [a0547d3a7e]
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (0,4,1): 0c61b5a9902a19c4be7d087e
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (1)
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart --> [8160597e]
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart Unexpected packet sequence 4 | 0
2023-02-15T12:28:45.277Z zigbee-herdsman:adapter:ezsp:uart Skipping the packet as repeated (1)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (1,4,1): 1c61b1a9d42abfc4be78627e
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (2)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> [82503a7e]
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Unexpected packet sequence 4 | 0
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Skipping the packet as repeated (2)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (2,4,1): 2c61b5a9902a19c4bedaf47e
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (3)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> [83401b7e]
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Unexpected packet sequence 4 | 0
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Skipping the packet as repeated (3)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (3,4,1): 3c61b1a9d42abfc4bedf9e7e
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (4)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> [8430fc7e]
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Unexpected packet sequence 4 | 0
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Skipping the packet as repeated (4)
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart <-- Error: c20251a8bd7e
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart Uart reseting
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> Write reset
2023-02-15T12:28:45.278Z zigbee-herdsman:adapter:ezsp:uart --> [1ac038bc7e]
2023-02-15T12:28:45.391Z zigbee-herdsman:adapter:ezsp:uart <-- [11]
2023-02-15T12:28:46.390Z zigbee-herdsman:adapter:ezsp:uart <-- [c1020b0a527e]
2023-02-15T12:28:46.390Z zigbee-herdsman:adapter:ezsp:uart <-- RSTACK: c1020b0a527e
2023-02-15T12:28:46.391Z zigbee-herdsman:adapter:ezsp:uart RSTACK Version: 2 Reason: RESET_SOFTWARE frame: c1020b0a527e
fuzzy01 commented 1 year ago

Same as https://github.com/Koenkk/zigbee2mqtt/issues/15940

MattWestb commented 1 year ago

Have flashing not recorded 7.X firmware in the dongle ? If yes then you need flashing one new NVM file then its corrupted.

fuzzy01 commented 1 year ago

In my case the original firmware on the dongle was 6.10.3.0 build 297. Since then I updated it to 7.1.1.0 build 273. Much better firmware. But the double restart issue stayed. Every second start hangs.

chrislentz commented 1 year ago

I just tried flashing ncp-uart-sw_7.2.0.0_115200 and the problem persists.

chrislentz commented 1 year ago

The problem persists with ncp-uart-sw_7.1.4.0_115200.gbl as well.

mamrai1 commented 1 year ago

i'm using dev image ( koenkk/zigbee2mqtt:latest-dev) and have no problems with ncp-uart-sw_7.1.4.0_115200.gbl

github-actions[bot] commented 1 year ago

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