home-assistant / addons

:heavy_plus_sign: Docker add-ons for Home Assistant
https://home-assistant.io/hassio/
Apache License 2.0
1.56k stars 1.51k forks source link

deCONZ add-on dumps core #2442

Closed Bert-R closed 2 years ago

Bert-R commented 2 years ago

Describe the issue you are experiencing

Once in a while, the deCONZ add-on enters a period where it constantly dumps core and gets restarted by the supervisor. During that period, the Zigbee devices cannot be controlled. I've reported this issue before as #2289. The problem is intermittent. Over the past 90 days, the deCONZ add-on core dumped 687 times in 7 periods.

The core dumps of deCONZ usually go together with core dumps of wmiir: deCONZ first, then in 15-20 seconds wmiir. The latter has a few more core dumps in the same period: 704.

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

deCONZ

What is the version of the add-on?

Multiple. Currently running 6.12.0

Steps to reproduce the issue

There are no steps. It starts to occur on a random moment,

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

No response

Additional information

No response

katiuskt commented 2 years ago

I think I have the same problem here but not sure how to confirm. Please, could you let me know how can I check if I have those core dumps you mention also in my system?

I mean: in the last two weeks my Zigbee devices stopped to be able to be controlled by HA randomly. The only way to have them back is restarting HA or even the whole Proxmox (HA VM on it). Sometimes it stops to work in 4-5 hours. Others it works during 6-7 days without a hiccup.

Running latest HA OS (even with 8.0rc2 it happens) and deCONZ addon 6.12.

However, as mentioned, not sure if it is the same problem so: can I check past logs to confirm? If so, please, could you point me the path/way to check them? If it is not possible to look back in time, please could you let me know where do you see the core dumps? Do you see them into the addon register/log (sorry, my UI isn't in English so not sure how it is labeled)?

If so, I will be in problem to check it because when the zigbee (controlled by deCONZ) devices hang up, I barely can enter into addon page into HA.

FYI: I have de-selected the "watch" setting for deCONZ core. Do you suggest to turn it on maybe?

Bert-R commented 2 years ago

I think you find this in the supervisor logs, but it could also be the add-on logs. I'm sending my logs to Elastic search. There I get this:

Process 402811 (deCONZ) of user 0 dumped core.

And also:

Process 404873 (wmiir) of user 0 dumped core.

I've the watchedog switched on, so the supervisor immediately starts the addon upon a crash.

katiuskt commented 2 years ago

Thank you @Bert-R It seems I can't check out past logs (or if it is possible I'm not able to find the way) so I'll take a look next time before restart the system. Cross fingers watchdog enabled helps a little bit here because it is a little bit disturbing in home this random situation.

ondrackajan commented 2 years ago

Deconz randomly stopped working today. I suspect I might have the same problem.

mdegat01 commented 2 years ago

FYI logs survive restarts and you can get to them @katiuskt . See this guide for instructions on how to do so.

That being said, I'm not entirely sure what we can do about a sporadic issue. We'll need clear steps to reproduce in order to make progress. It also may not be an issue with the addon, the addon is simply packaging deconz software in a container. Have you tried looking at deconz's support channels to see if any users reported similar issues?

I guess for now collect any logs you can about this issue and what happens leading into it. If it is something caused by supervisor or how the addon deploys the debian package then hopefully we'll be able to determine what. If its an issue with the deconz software itself though then you'll have to report it to them.

katiuskt commented 2 years ago

Thank you @mdegat01 for information/links. Quite useful (and unknown to me)! 👍

Last perceived problem (as I said before, I didn't have enabled the watchdog by then) I had with deCONZ was last friday 22th april: I found out at around 8am that the deCONZ addon was stopped since 6am.

Thank to you I can confirm now what it seems a coredump as suspected:

abr 22 06:09:55 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 06:09:55:495 ZCL attribute report 0xBC33ACFFFEC9941E for cluster: 0x0006, ep: 0x01, frame control: 0x18, mfcode: 0x0000
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state CoreState.RUNNING
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.SECURITY/ContextType.CORE
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.TRUST/ContextType.CORE
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.PWNED/ContextType.ADDON
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.FREE_SPACE/ContextType.SYSTEM
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.TRUST/ContextType.SUPERVISOR
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.TRUST/ContextType.PLUGIN
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.check] System checks complete
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state CoreState.RUNNING
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state CoreState.RUNNING
abr 22 06:09:57 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]: 22-04-22 06:09:57 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
abr 22 06:10:07 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 06:10:07:618 Device TTL 5095 s flags: 0x7
abr 22 06:10:08 homeassistant audit[4669]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=4669 comm="QNetworkAccessM" exe="/usr/bin/deCONZ" sig=11 res=1
abr 22 06:10:08 homeassistant kernel: QNetworkAccessM[6173]: segfault at 0 ip 00007fc20b360b84 sp 00007fc1fcb5a8c8 error 4 in libQt5Network.so.5.11.3[7fc20b303000+113000]
abr 22 06:10:08 homeassistant kernel: Code: 1c 00 00 00 00 48 8b 7b 10 eb df 0f 1f 00 c7 47 1c 00 00 00 00 c6 47 50 00 c3 5b c3 66 2e 0f 1f 84 00 00 00 00 00 48 8b 7f 78 <48> 8b 07 ff 60 20 66 0f 1f 44 00 00 53 48 89 fb bf 18 00 00 00 e8
abr 22 06:10:08 homeassistant kernel: audit: type=1701 audit(1650600608.691:303): auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=4669 comm="QNetworkAccessM" exe="/usr/bin/deCONZ" sig=11 res=1
abr 22 06:10:08 homeassistant audit: BPF prog-id=57 op=LOAD
abr 22 06:10:08 homeassistant audit: BPF prog-id=58 op=LOAD
abr 22 06:10:08 homeassistant kernel: audit: type=1334 audit(1650600608.698:304): prog-id=57 op=LOAD
abr 22 06:10:08 homeassistant kernel: audit: type=1334 audit(1650600608.698:305): prog-id=58 op=LOAD
abr 22 06:10:08 homeassistant systemd[1]: Started Process Core Dump (PID 18915/UID 0).
abr 22 06:10:08 homeassistant systemd-coredump[18916]: Process 4669 (deCONZ) of user 0 dumped core.
abr 22 06:10:08 homeassistant systemd[1]: systemd-coredump@1-18915-0.service: Deactivated successfully.
abr 22 06:10:08 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 22 06:10:08 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 22 06:10:08 homeassistant kernel: audit: type=1334 audit(1650600608.887:306): prog-id=0 op=UNLOAD
abr 22 06:10:08 homeassistant kernel: audit: type=1334 audit(1650600608.887:307): prog-id=0 op=UNLOAD
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [06:10:09] INFO: Starting VNC server (local/yes)...
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 312#312: signal 15 (SIGTERM) received from 305, exiting
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 1549#1549: exiting
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 1549#1549: exit
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 312#312: signal 17 (SIGCHLD) received from 1549
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 312#312: worker process 1549 exited with code 0
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: 2022/04/22 06:10:09 [notice] 312#312: exit
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: In exit
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: Closing socket listening at 127.0.0.1:5901
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [cont-finish.d] executing container finish scripts...
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [cont-finish.d] done.
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [s6-finish] waiting for services.
abr 22 06:10:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [s6-finish] sending all processes the TERM signal.
abr 22 06:10:12 homeassistant homeassistant/amd64-hassio-supervisor:latest/hassio_supervisor[376]:
abr 22 06:10:12 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [s6-finish] sending all processes the KILL signal and exiting.

As mentioned by @Bert-R I can see a lot of wmiir problems too. I guess they aren't impacting now in my platform because the watchdog I enabled last week. But dumped core exists indeed

abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Websockify waiting for VNC to start
abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Running the IKEA OTA updater...
abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Running the OSRAM LEdvance OTA updater...
abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Running the deCONZ OTA updater...
abr 28 18:09:20 homeassistant systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
abr 28 18:09:20 homeassistant ghcr.io/hassio-addons/zwavejs2mqtt/amd64:0.38.0/addon_a0d7b954_zwavejs2mqtt[371]: 2022-04-28 18:09:20.459 INFO ZWAVE-SERVER: ZwaveJS server listening on 0.0.0.0:3000
abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Starting VNC server (local/yes)...
abr 28 18:09:20 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [18:09:20] INFO: Starting websockify...
abr 28 18:09:21 homeassistant audit[5486]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=5486 comm="wmiir" exe="/usr/bin/wmiir" sig=11 res=1
abr 28 18:09:21 homeassistant systemd[1]: Created slice Slice /system/systemd-coredump.
abr 28 18:09:21 homeassistant audit: BPF prog-id=15 op=LOAD
abr 28 18:09:21 homeassistant audit: BPF prog-id=16 op=LOAD
abr 28 18:09:21 homeassistant systemd[1]: Started Process Core Dump (PID 5502/UID 0).
abr 28 18:09:21 homeassistant systemd-coredump[5509]: Process 5486 (wmiir) of user 0 dumped core.
abr 28 18:09:21 homeassistant systemd[1]: systemd-coredump@0-5502-0.service: Deactivated successfully.
abr 25 20:11:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [20:11:09] INFO: Running the IKEA OTA updater...
abr 25 20:11:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [20:11:09] INFO: Running the deCONZ OTA updater...
abr 25 20:11:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [20:11:09] INFO: Starting VNC server (local/yes)...
abr 25 20:11:09 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: [20:11:09] INFO: Starting websockify...
abr 25 20:11:10 homeassistant audit[5009]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=5009 comm="wmiir" exe="/usr/bin/wmiir" sig=11 res=1
abr 25 20:11:10 homeassistant systemd[1]: Created slice Slice /system/systemd-coredump.
abr 25 20:11:10 homeassistant audit: BPF prog-id=15 op=LOAD
abr 25 20:11:10 homeassistant audit: BPF prog-id=16 op=LOAD
abr 25 20:11:10 homeassistant systemd[1]: Started Process Core Dump (PID 5052/UID 0).
abr 25 20:11:10 homeassistant systemd-coredump[5059]: Process 5009 (wmiir) of user 0 dumped core.
abr 25 20:11:10 homeassistant systemd[1]: systemd-coredump@0-5052-0.service: Deactivated successfully.
abr 25 20:11:10 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 25 20:11:10 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 25 20:11:10 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[376]: WebSocket server settings:
abr 25 03:46:49 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [03:46:49] INFO: Starting VNC server (local/yes)...
abr 25 03:46:50 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: [03:46:50] INFO: Starting websockify...
abr 25 03:46:50 homeassistant audit[5393]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=5393 comm="wmiir" exe="/usr/bin/wmiir" sig=11 res=1
abr 25 03:46:50 homeassistant systemd[1]: Created slice Slice /system/systemd-coredump.
abr 25 03:46:50 homeassistant audit: BPF prog-id=15 op=LOAD
abr 25 03:46:50 homeassistant audit: BPF prog-id=16 op=LOAD
abr 25 03:46:50 homeassistant systemd[1]: Started Process Core Dump (PID 5426/UID 0).
abr 25 03:46:51 homeassistant systemd-coredump[5431]: Process 5393 (wmiir) of user 0 dumped core.
abr 25 03:46:51 homeassistant systemd[1]: systemd-coredump@0-5426-0.service: Deactivated successfully.
abr 25 03:46:51 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 25 03:46:51 homeassistant audit: BPF prog-id=0 op=UNLOAD
abr 25 03:46:51 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]: WebSocket server settings:
abr 25 03:46:51 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]:   - Listen on 127.0.0.1:5901
abr 25 03:46:51 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]:   - Flash security policy server
abr 25 03:46:51 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]:   - Web server. Web root: /usr/share/novnc
abr 25 03:46:51 homeassistant homeassistant/amd64-addon-deconz:6.12.0/addon_core_deconz[371]:   - No SSL/TLS support (no cert file)

As mentioned by @mdegat01 , I start to think problem would happen too with official docker image (not in position to give it a try right now): searching at dresden-elektronik github I can see a few closed cases mentioning "wmiir" segfaults (I'm assuming those "segfaults" are translated into our coredumps): https://github.com/dresden-elektronik/deconz-rest-plugin/issues/3430 https://github.com/dresden-elektronik/deconz-rest-plugin/issues/3341 https://github.com/dresden-elektronik/deconz-rest-plugin/issues/1598

I can't see any solution for those cases: use extension cord, upgrade firmware, change usb port... but no clear statement regarding the issue (or I missed it).

In case it helps (to find a pattern or whatever): I have ConBee II adapter with extension cord over an USB 3.0 (no USB 2.0 in my machine) + Proxmox USB passthrough + Bluetooth & Wifi disabled from BIOS

Bert-R commented 2 years ago

@mdegat01 I am running Prometheus Node Exporter, so I have metrics of the periods of repeated crashes. I don't see any thing remarkable in these intervals (beyond being more busy, but that's quite logical given the many restarts). If there's anything you're interested in, let me know.

mdegat01 commented 2 years ago

I thought maybe that ANOM_ABEND was something and this was being caused by apparmor blocking access to something. Apparently though that means this:

Triggered when a processes ends abnormally (with a signal that could cause a core dump, if enabled).

Basically just telling us a core dump is coming. Not very useful for figuring out why a segfault is occurring.

Sorry I'm really not sure how to proceed with this one. It appears to me like you found a bug in the underlying software used by the addon but its hard to be sure. I guess all I can really suggest at this time is make sure to enable the debug options in the addon config. Perhaps then if/when it happens again we can get more insight.

Bert-R commented 2 years ago

Promising update from the issue I reported on the deCONZ project:

I think this should be fixed with the upcoming v2.15.3 version, there were two fixes after v2.14.1 related to crashes under certain conditions

mdegat01 commented 2 years ago

Nice! Actually a PR was just opened for that, #2458 . I need to test it first to make sure the customizations for ingress still work but should be available this week.

mdegat01 commented 2 years ago

@Bert-R @katiuskt 6.13.0 of the addon just went out which updates deconz to v2.15.3. Can you give it a shot and let me know if that resolves this issue for you?

Bert-R commented 2 years ago

Thanks @mdegat01! I'm running it now. I've set an alert to get notified if it crashes again, so I'll keep a close watch.

katiuskt commented 2 years ago

Thank you @mdegat01 . Updated and let's see how it goes 🤞

@Bert-R : please, could you elaborate a little bit how did you do that? I searched for a event when supervisor restart an addon but I didn't find any so no clue how to achieve that and I think it might be useful.

Bert-R commented 2 years ago

@katiuskt That depends on your setup. I've created a Home Assistant add-on for Filebeat. Through that, I send all log messages to Elasticsearch and on that, I've created an alert in Grafana.

If you have that setup available, it's trivial. If not, then it's quite an effort to set it up.

katiuskt commented 2 years ago

@katiuskt That depends on your setup. I've created a Home Assistant add-on for Filebeat. Through that, I send all log messages to Elasticsearch and on that, I've created an alert in Grafana.

If you have that setup available, it's trivial. If not, then it's quite an effort to set it up.

Thank you @Bert-R but I thought it was done with usual automations/scripts. I'm afraid your setup is quite beyond my knowledge! I'll keep watching my instance any way just in case I'm able to catch up another core dump at my side. Thank you for the offering!

Bert-R commented 2 years ago

Unfortunately, the issue is not resolved. Yesterday between 14:10 and 14:33, the deCONZ add on had 40 core dumps. The problem is very intermittent: 33 days passed since the previous set of crashes.

I've reported this on the deCONZ project too.

Bert-R commented 2 years ago

Today, it started crashing at 7:47. So far, it created 100 core dumps in 90 minutes, and counting.

I've reported this on the deCONZ project too.

cagnulein commented 2 years ago

probably a similar issue here in loop

10:20:40:681 ZCL attribute report 0x00158D00028C4DC5 for cluster: 0x0000, ep: 0x01, frame control: 0x1C, mfcode: 0x115F 
10:20:40:682 0x00158D00028C4DC5 extract Xiaomi special attribute 0xFF01
10:20:40:682    01 battery 3055 (0x0BEF)
10:20:40:682    03 Device temperature 28 °C
10:20:40:682    04 unknown 17320 (0x43A8)
10:20:40:682    05 RSSI dB (?) 23 (0x0017)
10:20:40:682    06 LQI (?) 4294967296 (0x0100000000)
10:20:40:682    0a Parent NWK 12091 (0x2F3B)
10:20:40:682    64 on/off 0
10:20:51:816 Bind response success for 0x60a423fffee2923a ep: 0x01 cluster: 0x0006
10:20:51:861 ZCL configure reporting rsp seq: 86 0x60A423FFFEE2923A for ep: 0x01 cluster: 0x0006 attr: 0x0000 status: 0x00
10:20:51:953 Bind response success for 0x84ba20fffe6e76c5 ep: 0x01 cluster: 0x0006
10:20:51:953 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x84BA20FFFE6E76C5 (seems to be active)
10:20:52:280 ZCL attribute report 0x60A423FFFEE2923A for cluster: 0x0006, ep: 0x01, frame control: 0x18, mfcode: 0x0000 
10:20:56:816 Bind response success for 0x60a423fffee2923a ep: 0x01 cluster: 0x0008
10:20:56:816 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x60A423FFFEE2923A (wait reading or unsupported)
10:20:56:893 Bind response success for 0x842e14fffe35a110 ep: 0x01 cluster: 0x0006
10:20:56:893 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x842E14FFFE35A110 (seems to be active)
10:20:58:839 Bind response success for 0x60a423fffee2923a ep: 0x01 cluster: 0x0300
10:20:58:839 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x60A423FFFEE2923A (wait reading or unsupported)
10:20:58:900 ZCL configure reporting rsp seq: 96 0x60A423FFFEE2923A for ep: 0x01 cluster: 0x0300 attr: 0x0003 status: 0x00
10:20:58:900 ZCL configure reporting rsp seq: 96 0x60A423FFFEE2923A for ep: 0x01 cluster: 0x0300 attr: 0x0004 status: 0x00
10:20:58:900 ZCL configure reporting rsp seq: 96 0x60A423FFFEE2923A for ep: 0x01 cluster: 0x0300 attr: 0x0008 status: 0x00
10:20:59:705 ZCL attribute report 0xF0D1B80000147765 for cluster: 0x0006, ep: 0x01, frame control: 0x08, mfcode: 0x0000 
10:20:59:722 ZCL attribute report 0xF0D1B80000147765 for cluster: 0x0008, ep: 0x01, frame control: 0x08, mfcode: 0x0000 
10:20:59:880 Bind response success for 0xf0d1b80000147765 ep: 0x01 cluster: 0x0006
10:20:59:880 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0xF0D1B80000147765 (seems to be active)
10:20:59:988 Bind response success for 0x588e81fffed39fac ep: 0x01 cluster: 0x0006
10:20:59:988 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x588E81FFFED39FAC (seems to be active)
172.30.32.2 - - [27/May/2022:10:21:00 +0200] "GET /pwa/index.html HTTP/1.1" 200 113229 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/ingress.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:00:996 ZCL attribute report 0x00124B002265E668 for cluster: 0x0006, ep: 0x01, frame control: 0x08, mfcode: 0x0000 
172.30.32.2 - - [27/May/2022:10:21:01 +0200] "GET /pwa/language/it/plugs-it.json HTTP/1.1" 404 149 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:01 +0200] "GET /pwa/language/it/plugs-it.json HTTP/1.1" 404 149 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:01:021 ZCL attribute report 0x00124B002265E668 for cluster: 0x0006, ep: 0x02, frame control: 0x08, mfcode: 0x0000 
10:21:01:043 ZCL attribute report 0x00124B002265E668 for cluster: 0x0006, ep: 0x03, frame control: 0x08, mfcode: 0x0000 
10:21:01:063 ZCL attribute report 0x00124B002265E668 for cluster: 0x0006, ep: 0x04, frame control: 0x08, mfcode: 0x0000 
172.30.32.2 - - [27/May/2022:10:21:01 +0200] "GET /api/A196B62B11/config?_=1653639661104 HTTP/1.1" 200 7878 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:01:920 Bind response success for 0xf0d1b80000147765 ep: 0x01 cluster: 0x0008
10:21:01:920 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0xF0D1B80000147765 (seems to be active)
10:21:02:356 New websocket 127.0.0.1:38298 (state: 3) 
172.30.32.2 - - [27/May/2022:10:21:03 +0200] "GET /api/A196B62B11/sensors/34 HTTP/1.1" 200 383 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:04 +0200] "GET /api/A196B62B11/sensors/35 HTTP/1.1" 200 381 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
2022/05/27 10:21:09 [info] 1646#1646: *1 recv() failed (104: Connection reset by peer) while proxying upgraded connection, client: 172.30.32.2, server: _, request: "GET /websocket HTTP/1.1", upstream: "http://127.0.0.1:8081/websocket", host: "5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa"
172.30.32.2 - - [27/May/2022:10:21:09 +0200] "GET /websocket HTTP/1.1" 101 366 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:09:595 Websocket disconnected 127.0.0.1:38298, state: 0, close-code: 1000, reason: 
10:21:11:814 Bind response success for 0x60a423fffee2923a ep: 0x01 cluster: 0x0006
10:21:11:814 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x60A423FFFEE2923A (seems to be active)
172.30.32.2 - - [27/May/2022:10:21:12 +0200] "GET /pwa/language/it/plugs-it.json HTTP/1.1" 404 149 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:13 +0200] "GET /pwa/language/it/plugs-it.json HTTP/1.1" 404 149 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:13 +0200] "GET /api/A196B62B11/config?_=1653639672952 HTTP/1.1" 200 7878 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:14:140 New websocket 127.0.0.1:38330 (state: 3) 
10:21:15:780 ZCL attribute report 0xF0D1B80000147A58 for cluster: 0x0006, ep: 0x01, frame control: 0x08, mfcode: 0x0000 
10:21:15:782 ZCL attribute report 0xF0D1B80000147A58 for cluster: 0x0008, ep: 0x01, frame control: 0x08, mfcode: 0x0000 
10:21:16:278 Device TTL 3290 s flags: 0x7
172.30.32.2 - - [27/May/2022:10:21:18 +0200] "GET /api/A196B62B11/lights?_=1653639672953 HTTP/1.1" 200 4866 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:19:817 Bind response success for 0x60a423fffee2923a ep: 0x01 cluster: 0x0300
10:21:19:817 skip configure report for cluster: 0x0300 attr: 0x0007 of node 0x60A423FFFEE2923A (wait reading or unsupported)
10:21:19:817 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x60A423FFFEE2923A (seems to be active)
10:21:19:818 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x60A423FFFEE2923A (seems to be active)
10:21:19:818 skip configure report for cluster: 0x0300 attr: 0x0008 of node 0x60A423FFFEE2923A (seems to be active)
172.30.32.2 - - [27/May/2022:10:21:19 +0200] "GET /api/A196B62B11/lights?_=1653639672954 HTTP/1.1" 200 4866 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:21 +0200] "GET /api/A196B62B11/sensors/21 HTTP/1.1" 200 367 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/pwa/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
172.30.32.2 - - [27/May/2022:10:21:22 +0200] "GET /websocket HTTP/1.1" 101 5613 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
10:21:22:350 Websocket disconnected 127.0.0.1:38330, state: 0, close-code: 1000, reason: 
127.0.0.1: new handler Process
localhost - - [27/May/2022 10:21:23] "GET //vnc_lite.html?scale=yes HTTP/1.1" 200 -
172.30.32.2 - - [27/May/2022:10:21:23 +0200] "GET /novnc/vnc_lite.html?scale=yes HTTP/1.1" 200 3399 "https://5v0ro80ydsqvonixh09t4ats35pjkn0b.ui.nabu.casa/api/hassio_ingress/6d7MxgYM2yngRTG7DGx6D2jg_5takmV8LxIs_kQQ0yQ/ingress.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
Ignoring interrupted syscall
127.0.0.1: new handler Process
localhost - - [27/May/2022 10:21:23] "GET //websockify HTTP/1.1" 101 -
localhost - - [27/May/2022 10:21:23] 127.0.0.1: Plain non-SSL (ws://) WebSocket connection
localhost - - [27/May/2022 10:21:23] 127.0.0.1: Version hybi-13, base64: 'False'
localhost - - [27/May/2022 10:21:23] 127.0.0.1: Path: '//websockify'
localhost - - [27/May/2022 10:21:23] connecting to: 127.0.0.1:5900
10:21:27:074 0x00124b002265e668 found group 0xFFF0
10:21:27:826 0x00124b002265e668 found group 0xFFF0
10:21:28:615 0x00124b002265e668 found group 0xFFF0
10:21:29:339 0x00124b002265e668 found group 0xFFF0
10:21:30:104 0x84ba20fffe6e76c5 found group 0xFFF0
localhost - - [27/May/2022 10:21:30] 127.0.0.1:5900: Client closed connection
172.30.32.2 - - [27/May/2022:10:21:30 +0200] "GET /novnc/websockify HTTP/1.1" 101 226333 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.67 Safari/537.36"
localhost - - [27/May/2022 10:21:30] 127.0.0.1:5900: Closed target
Ignoring interrupted syscall
10:21:30:825 0xf0d1b80000147a58 found group 0xFFF0
10:21:30:826 0xf0d1b80000147a58 found group 0x0001
10:21:31:579 0x842e14fffe35a110 found group 0xFFF0
[10:21:32] INFO: Starting VNC server (local/yes)...
2022/05/27 10:21:32 [notice] 316#316: signal 15 (SIGTERM) received from 308, exiting
2022/05/27 10:21:32 [notice] 1646#1646: exiting
2022/05/27 10:21:32 [notice] 1646#1646: exit
In exit
Closing socket listening at 127.0.0.1:5901
2022/05/27 10:21:32 [notice] 316#316: signal 17 (SIGCHLD) received from 1646
2022/05/27 10:21:32 [notice] 316#316: worker process 1646 exited with code 0
2022/05/27 10:21:32 [notice] 316#316: exit
[cont-finish.d] executing container finish scripts...
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.
[s6-finish] sending all processes the KILL signal and exiting.
Bert-R commented 2 years ago

@mdegat01 So far, the issue has not been resolved yet. Do you happen to know where the core dump files are put? I'm running Home Assistant OS 8.2 on a Raspberry PI 4.

github-actions[bot] commented 2 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

Bert-R commented 2 years ago

@mdegat01 Do you know where I can find such core dumps? I'm running Home Assistant Operating System on a Raspberry PI 4. The issue still occurs and the deCONZ developer asks for a dump file on dresden-elektronik/deconz-rest-plugin#5993.

github-actions[bot] commented 2 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.