total freeze of pi3 on starting

jonesMeUp commented 5 months ago

What happened?

In 9/10 tries zigbee2mqtt freezes my pi3 right after ... "RTS/CTS config is off, enabling flow control." If it starts (via npm start), then i can use it and can pair my 2 Ikea Waterleak sensors. Stopping and starting z2m again is no problem. But when i reboot the raspi, npm start freeze it again.

The serial port and the whole z2m folders are writeable by user pi.
I tried several USB cords and all USB-Ports of the raspi.
I tried several positions of the dongle, near at the raspi and far away
No log file is written on a freeze.
On all tries only the dongle and the power cord is connected to the pi.
It happens with ember and ezsp.
My raspi pico with a 433Mhz sender connected to serial port (echo "sendRf(674647)" > /dev/ttyACM0) has no problems with my raspi3 running on bookworm.
I tried /dev/ttyACM0 and /dev/serial/by-id/........

I have used z2m about 2 month before i updated the raspi to the latest raspian with all updates. The first reboots made no problems, but now its frustrating. I updated the dongle after the first freezes, but it didn't change anything.

npm test shows no problems even before a freezing "npm start"

What can I do to squeeze an error message out of z2m instead of a freeze? Thanks for your time jones

What did you expect to happen?

An error message instead of a full crashed computer

How to reproduce it (minimal and precise)

Reboot raspi on a working config

Zigbee2MQTT version

1.37.0 - 1.38.0 (ember) 1.37.0 - 1.37.1 (ezsp)

Adapter firmware version

7.4.2 [GA] (for ember) and for ezsp the last version shown on https://darkxst.github.io/silabs-firmware-builder/

Adapter

ZBDongle-E

Setup

plain z2m on Raspi3b with fhem

Debug log

no log on freezed raspi, here is a log of a running z2m

[2024-05-31 21:51:07] info: z2m: Logging to console, file (filename: log.log) [2024-05-31 21:51:07] info: z2m: Starting Zigbee2MQTT version 1.37.1 (commit #cda867a) [2024-05-31 21:51:07] info: z2m: Starting zigbee-herdsman (0.46.6) [2024-05-31 21:51:08] info: zh:ember: ======== Ember Adapter Starting ======== [2024-05-31 21:51:08] info: zh:ember:ezsp: ======== EZSP starting ======== [2024-05-31 21:51:08] info: zh:ember:uart:ash: ======== ASH NCP reset ======== [2024-05-31 21:51:08] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. [2024-05-31 21:51:08] info: zh:ember:uart:ash: Serial port opened [2024-05-31 21:51:08] info: zh:ember:uart:ash: ======== ASH starting ======== [2024-05-31 21:51:09] info: zh:ember:uart:ash: ======== ASH connected ======== [2024-05-31 21:51:09] info: zh:ember:uart:ash: ======== ASH started ======== [2024-05-31 21:51:09] info: zh:ember:ezsp: ======== EZSP started ======== [2024-05-31 21:51:10] info: zh:ember: [STACK STATUS] Network up. [2024-05-31 21:51:10] info: zh:ember: [INIT TC] NCP network matches config. [2024-05-31 21:51:10] info: zh:ember: [CONCENTRATOR] Started source route discovery. 1248ms until next broadcast. [2024-05-31 21:51:10] info: zh:controller: Wrote coordinator backup to '/opt/zigbee2mqtt/data/coordinator_backup.json' [2024-05-31 21:51:10] info: z2m: zigbee-herdsman started (resumed) [2024-05-31 21:51:10] info: z2m: Coordinator firmware version: '{"meta":{"build":0,"ezsp":13,"major":7,"minor":4,"patch":2,"revision":"7.4.2 [GA]","special":0,"type":170},"type":"EmberZNet"}' [2024-05-31 21:51:10] info: z2m: Currently 0 devices are joined: [2024-05-31 21:51:10] warning: z2m: permit_join set to true in configuration.yaml. [2024-05-31 21:51:10] warning: z2m: Allowing new devices to join. [2024-05-31 21:51:10] warning: z2m: Set permit_join to false once you joined all devices. [2024-05-31 21:51:10] info: z2m: Zigbee: allowing new devices to join. [2024-05-31 21:51:10] info: zh:ember: [STACK STATUS] Network opened. [2024-05-31 21:51:10] info: z2m: Connecting to MQTT server at mqtt://localhost [2024-05-31 21:51:10] info: z2m: Connected to MQTT server [2024-05-31 21:51:10] info: z2m: Zigbee2MQTT started! [2024-05-31 21:53:21] info: z2m: Disconnecting from MQTT server [2024-05-31 21:53:21] info: z2m: Stopping zigbee-herdsman... [2024-05-31 21:53:21] info: zh:controller: Wrote coordinator backup to '/opt/zigbee2mqtt/data/coordinator_backup.json' [2024-05-31 21:53:21] info: zh:ember:uart:ash: ASH COUNTERS since last clear: [2024-05-31 21:53:21] info: zh:ember:uart:ash: Total frames: RX=76, TX=143 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: DATA frames : RX=75, TX=67 [2024-05-31 21:53:21] info: zh:ember:uart:ash: DATA bytes : RX=794, TX=731 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Retry frames: RX=0, TX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: ACK frames : RX=0, TX=75 [2024-05-31 21:53:21] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: CRC errors : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Comm errors : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Length < minimum: RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Length > maximum: RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Bad controls : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Bad lengths : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Bad ACK numbers : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Out of buffers : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Retry dupes : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: Out of sequence : RX=0 [2024-05-31 21:53:21] info: zh:ember:uart:ash: ACK timeouts : RX=0 [2024-05-31 21:53:21] info: zh:ember: [STACK STATUS] Network closed. [2024-05-31 21:53:21] info: zh:ember:uart:ash: Port closed. Error? no [2024-05-31 21:53:21] info: zh:ember:uart:ash: ======== ASH stopped ======== [2024-05-31 21:53:21] info: zh:ember:ezsp: ======== EZSP stopped ======== [2024-05-31 21:53:21] info: zh:ember: ======== Ember Adapter Stopped ======== [2024-05-31 21:53:21] info: z2m: Stopped zigbee-herdsman [2024-05-31 21:53:21] info: z2m: Stopped Zigbee2MQTT

Nerivec commented 5 months ago

From the logs, seems like it's starting properly when it starts. So I guess there must be something messing with it outside of Z2M. Did you try plugging the adapter in a powered USB hub (a hub with an external power adapter to avoid drawing from the PI)?

jonesMeUp commented 5 months ago

thx for your answer. no, i don't have a powered USB hub. But why it was running about 2 month without any problems?

Nerivec commented 5 months ago

The update could have change internal power settings. It could also be the power adapter of the PI showing signs of trouble. I'm no PI expert though, could be something else entirely, but power is often a source of weird issues on the PI...

jonesMeUp commented 5 months ago

Ok, i will buy a powered USB and keep you informed. Thx, again

nono20004 commented 5 months ago

Hello I have the same problem with zwave2mqtt have update your raspberry firmware ? If you have update, downgrade your raspberry pi 3 b model and your problème solved. Sorry for my bad English

jonesMeUp commented 5 months ago

@nono20004 thx, yes i have the latest firmware on my pi. i can`t wait to test your hint (when i am back home in the night or tomorrow). @Nerivec the powered usb-switch will arrive in about 3 days, then i will test it with both firmawares.

nono20004 commented 5 months ago

Ok your are welcome I wait your final result

jonesMeUp commented 5 months ago

So... you are both right:

its not a z2m problem
raspi is the enemy

I tested a bunch of firmware verisons and thats the result: Pi3_ZBDongle-E__test

All firmwares above 6.1.77 didnt't work. I leave this issue open until i checked the last rpi firmware with an aktive USB-Hub. This should help desperate raspi users to fix the problem.

Without your help i didn't know where to search, because the dongle says max 100mA and Raspi3b says a sum of 1,2A is given to USB, so i took this as a fact and searched for days on my z2m settings, USB-Cords, dongle position, etc and also killed a 32GB SD-Card which was degraded to a 30MB Card, after cutting power on each try, while green LED says disc activity forever.

nono20004 commented 5 months ago

Hello thank you for your response. I wish that USB hub solve the problem but for me with zwave aotec gen 5 I didn't Good luck

JacekKac commented 5 months ago

@jonesMeUp how did you downgrade pi firmware?

JacekKac commented 5 months ago

ok i did a rpi-update to the newst firmware and it's working ok, in the meantime i disabled bt to save energy (not sure if this is necessary

jonesMeUp commented 5 months ago

For all that need an info how to update: On the picture above, you see the correct file (6.1.77) on the right you can copy the hash. then sudo rpi-update hash example for 6.1.77 sudo rpi-update 5fc4f643d2e9c5aa972828705a902d184527ae3f

@JacekKac all firmwares > 6.1.77 didn't work for me. make 1 or 2 reboot and look if it still works

jonesMeUp commented 5 months ago

With my new active USB-Hub i have tested 2 of the newer firmwares and all worked well. As the max_usb_current=1 is meanwhile ignored by the raspi, i can see 2 solutions:

downgrade the raspi tp 6.1.77
use an aktive USB-Hub

jonesMeUp commented 5 months ago

update: the problem seems to be solved in the upcoming 6.7.y kernel patch info

clauso commented 3 weeks ago

I am so happy I found this after trying to debug these crashes for weeks. So to sum it up:

If I am on raspberry OS I do not have the option to go for a 6.7 kernel (yet), right? So I just downgrade to kernel 6.1 ( rpi-update 5fc4f643d2e9c5aa972828705a902d184527ae3f ) and that's it for now, correct?

jonesMeUp commented 3 weeks ago

yep, z2m works for some time now with kernel 6.1.77 on my raspi3

Koenkk / zigbee2mqtt