Lidl Zigbee Gateway v3.6.0 - RCP - Still having crashes -> potential rouge device identified? #112
|
Dear jnilo1, I did everything as you wrote in
I started with pairing routers and few end devices. Except of few I was able to crash multiple times with device 0xccccccfffe58fb16 which is Ikea tradfri remote E1743. After pairing it and sending commands (on, off, brightness up, brightness down) multiple times it would crash and it was repeatable. I'm adding full logs of Z2M and CPCD from start, if you are interested in troubleshooting further we can try. Thank you |
Replies: 26 comments 2 replies
|
Hi @sipe — thanks for the clean reproduction and the full logs. Let me first explain what's actually happening, because it changes what's worth doing next, then propose something concrete you can run on your side. What's crashing — and what isn'tThe title asks whether this is a rogue device. It isn't — and the gateway isn't crashing either. Here's the chain your setup runs: From
Why it's not the E1743The remote interviews perfectly ( And because you did the full fresh setup this time (clean NVM3, everything re-paired from scratch), we can now rule out the "stale keys / orphan devices" explanation we were chasing in #96. That leaves the conclusion that this is a defect inside How you can help pin it downThe one thing that would let us escalate this to Silabs is a backtrace from zigbeed at the instant it dies — and since we compile zigbeed ourselves, you can produce that on your side. Three small edits under 1. Keep the symbols — in # before: RUN strip /install/usr/local/bin/zigbeed /install/usr/local/bin/cpcd
RUN strip /install/usr/local/bin/cpcd(zigbeed is built into 2. Add 3. Run zigbeed under gdb — in [program:zigbeed]
command=/bin/sh -c 'while [ ! -e /tmp/ttyZigbeed ]; do sleep 1; done; \
exec env MALLOC_CHECK_=3 gdb -batch \
-ex "handle SIGPIPE nostop noprint pass" \
-ex run \
-ex "echo \n===== ZIGBEED BACKTRACE =====\n" \
-ex "bt full" -ex "thread apply all bt" \
--args /usr/local/bin/zigbeed -r "spinel+cpc://%(ENV_CPCD_INSTANCE)s?iid=1&iid-list=0" -p /tmp/ttyZigbeed -d %(ENV_ZIGBEED_DEBUG)s'Then build and run the image locally so it uses your edits: docker compose build cpcd-zigbeed
docker compose upReproduce the same way (E1743, on/off + brightness in a burst) with If you'd rather just have a working coordinator in the meantime, the supervisor already auto-restarts zigbeed within a couple of seconds, so the network does recover on its own — it's just noisy. |
|
An obvious alternative would be to switch to NCP-UART running EmberZnet 7.5.1 and which is rock solid on EFR1 chips ... |
|
Hello @jnilo1 Thank you for further steps to troubleshoot. I was able to produce 2 crashes, but nothing informative in logs I played with Claude for a bit of futher toubleshooting, maybe this saves you a few steps to try out with me so we can get ahead what else to troubleshoot. I'm attaching markdown, if you need other format let me know. Yes I can use EmberZnet 7.5.1 but I'm interested in bleeding edge and to get this issue resolved if possible. As always, thank you. |
|
Hi @sipe, thanks for the logs and for the extra troubleshooting notes. Your new logs are useful even though they do not contain the expected backtrace. They show that That last line is gdb telling us that the inferior process called execve(). So this is not a normal native crash; zigbeed is taking an internal restart path and replacing itself. That also explains why the I would not treat Could you try one more gdb wrapper, this time catching the restart before execve() replaces the process? Then please attach only:
If the stop reason is |
|
Dear @jnilo1 Here is crash from cpcd. Crash happened at [31/05/2026, 22:53:54] Here is full log it is not long. Thank you. |
|
Hi @sipe, thanks, this log is much more useful. This is still not a So the order is:
That means this is an intentional/self restart path inside The The remaining problem is that the backtrace still has no source-level symbols: So we now know the failure mode, but not the exact I attached a debug version of the multiarch Dockerfile for that. It does the following:
Please replace your current docker compose -f docker-compose-zigbee.yml build cpcd-zigbeed
docker compose -f docker-compose-zigbee.yml up cpcd-zigbeedIf the symbols are present, the next backtrace should show something like: That line is the useful part. It should tell us whether the restart is caused by CPC reset handling, EZSP/ASH state, or another explicit restart branch in |
|
I was able to get crash at 15.06 Before that I updated Docker.multiarch with Claude help because of this error This is updated Dockerfile.multiarch CPCD crash There was crash? or disconnect before at 15:01, not sure if this is providing any additional information. Attaching full Z2M and CPCD logs Thank you |
|
Hi @sipe, I tested this locally and found why the previous debug image still did not give a useful gdb backtrace. The generated file is indeed: in the generated project root, not under But there was a second issue: the generated makefile uses: C_FLAGS += ...whereas the previous I attached a corrected multi-arch Dockerfile as With this Dockerfile, I verified on my host that the resulting and that gdb can resolve source lines: The relevant fix is that the Dockerfile now patches generated makefiles using a pattern that matches RUN find . -maxdepth 2 -type f \( -name '*.mak' -o -name '*Makefile*' \) -print0 | \
xargs -0 sed -i -E \
-e 's/[[:space:]]-O[0-3s]([[:space:]]|$)/ /g' \
-e 's/(^C_FLAGS[[:space:]]*[+:?]?=[[:space:]]*)/\1-g -O0 -fno-omit-frame-pointer /' \
-e 's/(^CFLAGS[[:space:]]*[+:?]?=[[:space:]]*)/\1-g -O0 -fno-omit-frame-pointer /' \
-e 's/(^CPPFLAGS[[:space:]]*[+:?]?=[[:space:]]*)/\1-g -O0 -fno-omit-frame-pointer /' && \
make -f zigbeed.Makefile -j$(nproc) && \
readelf -S build/debug/zigbeed | grep -E '\.debug_(info|line|str)'It also keeps Could you rebuild with the attached Dockerfile and rerun the same gdb catchpoint test? The command I used for a local amd64 test was: docker buildx build --network=host --progress=plain \
--build-arg TARGETARCH=amd64 \
-t zigbeed-debug-clean-test:latest \
-f Dockerfile.multiarch-zigbeed-debug.txt \
.For your normal compose setup, just use the attached file as the Dockerfile used by the Once the image has real debug symbols, the same |
|
New crash but I don't see any info [01/06/2026, 21:54:38] zh:ember:ezsp: Fatal error, status=ERROR_SERIAL_INIT. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=29 Len=10] Full log Thank you |
|
Hi @sipe, Thanks, this confirms that the Docker image starts, but this log is not yet the useful debug run. The important difference is that gdb did not stop on In this new log we only have: That means gdb is following the So the Dockerfile/debug-symbol part may now be fixed, but the -ex "catch syscall execve"Could you please confirm that your -ex "set pagination off" \
-ex "set print thread-events off" \
-ex "handle SIGPIPE nostop noprint pass" \
-ex "handle SIGTERM stop print nopass" \
-ex "catch syscall execve" \
-ex "catch syscall exit" \
-ex "catch syscall exit_group" \
-ex run \
-ex "echo \n===== ZIGBEED STOP/RESTART BACKTRACE =====\n" \
-ex "bt full" \
-ex "thread apply all bt" \
-ex "echo ===== END BACKTRACE =====\n"What we need from the next run is not the full log, only the block that starts with: If the new Dockerfile is really being used, that block should now show a source line like: Without the |
|
My fault, wrong file edited. Crash at 01/06/2026, 23:18:45 Full log |
|
Hi @sipe, Great, this time the debug symbols are working. This is the important new line: So the Dockerfile part is now fixed. However, the The relevant flow is: if (setjmp(gResetJump)) {
fprintf(stderr, "Restarting\n");
execvp(argv[0], argv);
}and the restart is triggered from: void halReboot(void)
{
longjmp(gResetJump, 1);
}So by the time gdb stops at The next useful test is to stop earlier, before the Could you please replace the gdb wrapper with the same one as before, but add this before -ex "break halReboot" \So the important part becomes: -ex "handle SIGPIPE nostop noprint pass" \
-ex "handle SIGTERM stop print nopass" \
-ex "break halReboot" \
-ex "catch syscall execve" \
-ex "catch syscall exit" \
-ex "catch syscall exit_group" \
-ex run \
-ex "echo \n===== ZIGBEED REBOOT BACKTRACE =====\n" \
-ex "bt full" \
-ex "thread apply all bt" \
-ex "echo ===== END BACKTRACE =====\n"If |
|
Hello @jnilo1 new crash 02/06/2026, 23:05:15 Full log Another one caught |
|
Hi @sipe, Great, this is the useful backtrace we needed. The key part is: In #define TYPE_RST 4So the restart is now explained: That means this is not a CPC/RCP-triggered reboot. The CPC reset thread is only sitting in The actual path is: So the next question is no longer "why does zigbeed crash?", but "why is the ASH host side sending an RST frame?" Could you please attach the Zigbee2MQTT log around At this point, the evidence says:
One more thing worth testing: you are currently running the CPC UART link at |
|
Dear @jnilo1 Here is log 1 minute before I left it overnight, there were multiple crashes, here is the log of all and 1 minute before, maybe there is an pattern that can help. I already tried other bauds including 115200 I can try again with different bauds. |
|
Hi @sipe, Thanks, these Z2M logs are useful. I went through the whole sequence again from the beginning, and these logs make the interpretation more precise. The So the restart mechanism is now understood. It is not a native crash, and it is not However, the Z2M logs do not show an explicit outgoing So I would not say yet that Z2M is intentionally sending an ASH What the logs show is:
but not always. For example the The strongest visible pattern is traffic bursts shortly before the restart. The first reproduced event follows the IKEA remote/button burst, and several later overnight events happen after many incoming reports from At this point we know: The missing piece is whether Could you run one more capture at the same Please add these gdb commands just before -ex "echo \n===== ASH RX STATE =====\n" \
-ex "frame 1" \
-ex "p/x rxBuffer[0]" \
-ex "p rxLen" \
-ex "x/32xb rxBuffer" \I am using So the useful part becomes: -ex "break halReboot" \
-ex "catch syscall execve" \
-ex "catch syscall exit" \
-ex "catch syscall exit_group" \
-ex run \
-ex "echo \n===== ASH RX STATE =====\n" \
-ex "frame 1" \
-ex "p/x rxBuffer[0]" \
-ex "p rxLen" \
-ex "x/32xb rxBuffer" \
-ex "echo \n===== ZIGBEED REBOOT BACKTRACE =====\n" \
-ex "bt full" \
-ex "thread apply all bt" \
-ex "echo ===== END BACKTRACE =====\n"If this shows If the buffer looks odd, truncated, or inconsistent, then the problem is more likely stream corruption/desynchronization somewhere in the TCP/PTY/socat/ASH path. About baudrate: thanks for the reminder that you already tested other baudrates in #96. Given these Z2M logs, I would not focus only on |
|
Me again, Quick recap of where we are, then one combined capture that should finally tell us who puts the RST on zigbeed's input — and that's the only open question left. The I mapped the exact path your bytes take between Z2M and zigbeed, from That's two socat hops plus a PTY-to-PTY pair, none of it flow-controlled. So the RST is one of:
The To separate A from B we need to see, in the same run, both the raw ASH bytes crossing the link and what zigbeed actually has in its receive buffer when it reboots. Two small changes: 1. Hex-log the ASH stream at the TCP edge (the decisive capture)In [program:socat-zigbeed]
command=/bin/sh -c 'while [ ! -e /tmp/ttyZigbeedHost ]; do sleep 1; done; \
exec socat -x -v tcp-listen:%(ENV_ZIGBEED_PORT)s,reuseaddr,fork file:/tmp/ttyZigbeedHost,raw,echo=0,nonblock'
(No-rebuild alternative, only if your 2. Keep the gdb
|
|
Hello @jnilo1 Crash at 04/06/2026, 00:58:03 CPCD SOCAT |
|
Hi @sipe, This run closes the question I raised last time — is It's a genuine, CRC-valid ASH RST — corruption is ruled outYour dump: That is exactly the decoded form of a valid RST, for three reasons in the ASH source:
The hex capture agrees: the The timeline points at that RST as the triggerReading the capture in order: So the simplest reading that fits every line is: the Either way the conclusion is the same: a deliberate RST from Z2M's The one open question: why does
|
|
Dear @jnilo1 Attached 1 minute before crash Z2M log. Topology I'm running cpcd+zigbeed and Z2M are running on same host, but 2 separate containers. For host ASH path I will test today/tomorrow and report back. |
|
Hi @sipe, This targeted Z2M sees a port close, not an ASH timeout/faultReading the 30-60 s before The counter dump also does not show an ASH link collapsing before the close: So this event does not look like Z2M/ember resetting because it exceeded an ASH ACK-timeout threshold or detected an obvious ASH protocol failure. The previous "ember reset after ACK timeout" hypothesis is weakened here: the timeout counter is literally zero, and the last EZSP transaction completed successfully. What the Z2M log shows is simpler: the serial/TCP port closes underneath Z2M while the link still looks mostly healthy from Z2M's point of view. The RST is real, but likely part of reconnect/initThe previous gdb + As checked in the Silicon Labs ASH decoder, decodes exactly to: So this is not a random Cross-reading the There is still a small timing caveat because the gdb and socat timestamps are not perfectly correlated, but nothing in the Z2M log shows an ember-side protocol decision before the close. The RST looks more like reconnect/init behavior after the transport dropped than a mid-session reset triggered by an ASH timeout. The likely weak point is now the host transport bridgeYour confirmed topology is important: Since Z2M and cpcd+zigbeed are two separate containers, direct PTY access is not straightforward. A symlink to The suspect is therefore the TCP/PTY bridge, especially the are consistent with the forked bridge/reconnect path around the failure. Note the two different PIDs ( Test 1: serialize the bridge to one client (
|
|
Dear @jnilo1 Sorry for late reply 08/06/2026, 23:38:59 crash for test 1 cpcd socat Second test will run now and see if it's crashes. Thanks |
|
Hi @sipe, Thanks — and this Test 1 result is genuinely useful, even though it crashed again. It rules a hypothesis out, which is exactly what a clean single-variable test is for. Test 1 tells us the socat serialization is not the trigger
The The new signal this run points upstream, at the CPC linkThis is the line that's new and interesting: That is CPC, not ASH: the EFR32 secondary is telling That hop is exactly the one carried today by the What I'd like you to test next: v3.8.0v3.8.0 is now released. It gives A pre-built multi-arch image (amd64 + arm64) is published: Pin it in your cpcd-zigbeed:
image: ghcr.io/jnilo1/cpcd-zigbeed:3.8.0
environment:
- RCP_HOST=192.168.178.xx # your gateway IPdocker compose -f docker-compose-zigbee.yml pull cpcd-zigbeed
docker compose -f docker-compose-zigbee.yml up -d
To answer your direct question: you do not need v3.8.0 for the Test 2 you already have queued (Docker-internal |
|
Dear @jnilo1 As I have :latest image already set, overnight test was done with latest image. If needed to repeat, I can repeat with older image. Settings I can report that there were no crashes during the night. This is the full cpcd log overnight - there are few invalid checksums and one reconnect Full log In Z2M at that timeline nothing in logs. I run this with "productive" environment overnight so no socat and gdb. All last runs overnight crash always happened, multiple times. I can troubleshoot further if needed. Thanks. |
|
Hi @sipe, This is the result we were after — a full night with no Why it held — the TCP bus absorbed the event that used to crash itThe key line is at the end of your log: The Please move to v3.8.1 and let that soakRather than soak on 3.8.0, I'd like you to move straight to v3.8.1 and soak there. It's the same In 3.8.0 are exactly those timed-out health probes being reaped, and it would matter if anything in your setup restarts containers on docker logs cpcd-zigbeed 2>&1 | grep -c "reaped unknown pid" # should stop growing on v3.8.1To update: docker compose -f docker-compose-zigbee.yml pull cpcd-zigbeed
docker compose -f docker-compose-zigbee.yml up -dOne important detail: a Compose-level healthcheck:
# $$ escapes Compose interpolation so the container shell sees a literal $
test: ["CMD-SHELL", "p=$$(printf '%04X' \"$$ZIGBEED_PORT\"); grep -qiE \":$$p [0-9A-F:]+ 0A \" /proc/net/tcp /proc/net/tcp6 2>/dev/null"]
interval: 30s
timeout: 10s
start_period: 60s
retries: 3Then just leave it running for a few days (no gdb/ One easy thing that would help: the transport statsThe link is now self-healing, but it would be very useful to know how often it actually has to heal. Every day or two during the soak, could you send these two counts from the docker logs cpcd-zigbeed 2>&1 | grep -c "invalid checksum" # CPC packets corrupted on the host<->gateway path
docker logs cpcd-zigbeed 2>&1 | grep -c "dropped, reconnecting" # times the TCP bus had to reconnectBoth are now harmless (CPC retransmits the corrupt packet; Thanks again — this is a really useful confirmation. |
|
Dear @jnilo1 Thank you for help. v3.8.1 Stats I will report back again after few days with stats. If there is anything else to test let me know. |
|
Update Up 38 hours (healthy) Everything is working normally. I think we can mark this issue as resolved. Thank you very much for helping. |
|
Hi @sipe, That's the confirmation we needed — 38 hours What the stats tell usBoth numbers are exactly what a healthy link looks like:
So the picture is consistent: the link occasionally hiccups (as any LAN link does), and v3.8.x now rides through it instead of crashing. ResolutionThe root cause was the host-side transport, not the RCP firmware, cpcd, or any Zigbee device: Two changes fixed it, both in v3.8.x:
Please do keep an eye on those two counters over the coming days — if Thank you for the patient, disciplined testing — the single-variable runs and the gdb/ |
Hi @sipe,
That's the confirmation we needed — 38 hours
healthy, zerozigbeedreboots, where every night used to crash multiple times. I'm happy to mark this resolved.What the stats tell us
Both numbers are exactly what a healthy link looks like:
zigbeed. Harmless — it's a quality gauge, not a fault.driver_tcpbus re-dials the gateway in a few milliseconds and the CPC s…