darkxst / silabs-firmware-builder

Silicon Labs firmware builder
https://darkxst.github.io/silabs-firmware-builder/
261 stars 25 forks source link

After HA monthly update (2024.february), ZBdongle-e start buggy #51

Open gyenesadam opened 4 months ago

gyenesadam commented 4 months ago

Hello!

After the last update, 2024.2.1, the Z2M and the SL Multiprotocol addon start crashing. The SL shows the next logs, I assume this cause the Z2M's error, unable to start.

[15:10:38] INFO: The otbr-agent is disabled. 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 cont-init: info: running /etc/cont-init.d/check-cpcd-shm.sh cont-init: info: /etc/cont-init.d/check-cpcd-shm.sh exited 0 s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service banner: starting ----------------------------------------------------------- Add-on: Silicon Labs Multiprotocol Zigbee and OpenThread multiprotocol add-on ----------------------------------------------------------- Add-on version: 2.4.4 You are running the latest version of this add-on. System: Home Assistant OS 11.5 (amd64 / generic-x86-64) Home Assistant Core: 2024.2.1 Home Assistant Supervisor: 2024.01.1 ----------------------------------------------------------- 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 universal-silabs-flasher: starting 
[15:10:39] INFO: Flashing firmware is disabled s6-rc: info: service universal-silabs-flasher successfully started s6-rc: info: service cpcd-config: starting 
[15:10:40] INFO: Generating cpcd configuration. s6-rc: info: service cpcd-config successfully started s6-rc: info: service cpcd: starting 
[15:10:40] INFO: Starting cpcd... WARNING in function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk. s6-rc: info: service cpcd successfully started s6-rc: info: service zigbeed: starting s6-rc: info: service zigbeed successfully started s6-rc: info: service legacy-services: starting s6-rc: info: service legacy-services successfully started 
[15:10:40] INFO: Starting zigbeed... 
[15:10:40:586628] Info : 
[CPCd v4.3.1.0] 
[Library API v3] 
[RCP Protocol v4] 
[15:10:40:586674] Info : Git commit: 133b29678b3d0bc7578e098d2f46b4d5bcd2ebb4 / branch: 
[15:10:40:586675] Info : Sources hash: ff8300587e7e4ab1def7a89a272c0baef32f9eb3bff9b0ba06b94e655d652367 
[15:10:40:586678] WARNING : In function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk. 
[15:10:40:587078] Info : Reading cli arguments 
[15:10:40:587087] Info : /usr/local/bin/cpcd 
[15:10:40:587353] Info : Reading configuration 
[15:10:40:587356] Info : file_path = /usr/local/etc/cpcd.conf 
[15:10:40:587358] Info : instance_name = cpcd_0 
[15:10:40:587358] Info : socket_folder = /dev/shm 
[15:10:40:587359] Info : operation_mode = MODE_NORMAL 
[15:10:40:587360] Info : use_encryption = false 
[15:10:40:587361] Info : binding_key_file = /etc/binding-key.key 
[15:10:40:587361] Info : stdout_tracing = false 
[15:10:40:587362] Info : file_tracing = false 
[15:10:40:587363] Info : lttng_tracing = false 
[15:10:40:587363] Info : enable_frame_trace = false 
[15:10:40:587364] Info : traces_folder = /dev/shm/cpcd-traces 
[15:10:40:587365] Info : bus = UART 
[15:10:40:587365] Info : uart_baudrate = 460800 
[15:10:40:587366] Info : uart_hardflow = false 
[15:10:40:587367] Info : uart_file = /dev/ttyACM0 
[15:10:40:587367] Info : fu_recovery_pins_enabled = false 
[15:10:40:587368] Info : fu_connect_to_bootloader = false 
[15:10:40:587369] Info : fu_enter_bootloader = false 
[15:10:40:587369] Info : restart_cpcd = false 
[15:10:40:587370] Info : application_version_validation = false 
[15:10:40:587371] Info : print_secondary_versions_and_exit = false 
[15:10:40:587372] Info : use_noop_keep_alive = false 
[15:10:40:587372] Info : reset_sequence = true 
[15:10:40:587373] Info : stats_interval = 0 
[15:10:40:587374] Info : rlimit_nofile = 2000 
[15:10:40:587374] Info : ENCRYPTION IS DISABLED 
[15:10:40:587381] Info : Starting daemon in normal mode 
[15:10:40:598314] Info : Connecting to Secondary... 
[15:10:40:673097] Info : RX capability is 256 bytes 
[15:10:40:673112] Info : Connected to Secondary 
[15:10:40:674477] Info : Secondary Protocol v4 
[15:10:40:677621] Info : Secondary CPC v4.3.1 
[15:10:40:679129] Info : Secondary bus bitrate is 460800 
[15:10:40:682277] Info : Secondary APP vUNDEFINED 
[15:10:40:682341] Info : Daemon startup was successful. Waiting for client connections 
[15:10:42:015711] Info : New client connection using library v4.3.1.0 
[15:10:42:120924] Info : Opened connection socket for ep#12 
[15:10:42:121000] Info : Endpoint socket #12: Client connected. 1 connections Listening on port 9999 for connection... Accepting connection. Accepted connection 7. Restarting 
[15:11:42:578572] Info : Endpoint socket #12: Client disconnected. 0 connections 
[15:11:42:578652] Info : Client disconnected 
[15:11:43:579931] Info : New client connection using library v4.3.1.0 
[15:11:43:609082] Info : Opened connection socket for ep#12 
[15:11:43:609249] Info : Endpoint socket #12: Client connected. 1 connections Reusing socket from previous instance. Socket connection has been closed, restarting... Listening on port 9999 for connection... Accepting connection.
darkxst commented 4 months ago

Had to reformat your logs so I could read them! However everything looks ok on Multiprotocol side. Z2M seemingly disconnects as soon as it connects, Can you get logs from Z2M also.

gyenesadam commented 4 months ago

Sorry, I posted it with hurry, from phone, my mistake. After, i get the error again, i'll send the z2m log.

Now, after reload backup it working, so i updated it again to 2024.2.1, let's see what happening.

gyenesadam commented 4 months ago

Till no error, but there is two logs.

When Z2m starting

[18:00:33] INFO: Preparing to start... [18:00:33] INFO: Socat not enabled [18:00:34] INFO: Starting Zigbee2MQTT... Zigbee2MQTT:debug 2024-02-12 18:00:36: Loaded state from file /config/zigbee2mqtt/state.json Zigbee2MQTT:info 2024-02-12 18:00:36: Logging to console and directory: '/config/zigbee2mqtt/log/2024-02-12.18-00-36' filename: log.txt Zigbee2MQTT:debug 2024-02-12 18:00:36: Removing old log directory '/config/zigbee2mqtt/log/2024-02-06.08-14-45' Zigbee2MQTT:info 2024-02-12 18:00:36: Starting Zigbee2MQTT version 1.35.3 (commit #unknown) Zigbee2MQTT:info 2024-02-12 18:00:36: Starting zigbee-herdsman (0.33.8) Zigbee2MQTT:debug 2024-02-12 18:00:36: 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":[87,4,39,137,215,55,65,33],"networkKey":"HIDDEN","panID":50091},"serialPort":{"adapter":"ezsp","path":"tcp://core-silabs-multiprotocol:9999"}}'

After the Z2M started...well...definately only see the end-devices messages. I post, when the error appears again.

darkxst commented 4 months ago

You probably capture with debug logging enabled, if it occurs again.