Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: Turning on scene using Google Nest Mini Gen 2 crashes HAMH #284

Open
2 tasks done
Moonbase59 opened this issue Dec 11, 2024 · 5 comments
Open
2 tasks done
Labels
bug Something isn't working waiting for feedback

Comments

@Moonbase59
Copy link

Version

3.0.0-alpha.54

Matter Controller

Google Nest Mini 2nd Gen

Steps to reproduce

Using a Google Nest Mini Gen 2, trying to switch on a scene ("Kaminfeuer") crashes HAMH. I used the sentence "Hey Google, Kaminfeuer an". The same sentence works fine with an Alexa Echo Dot Gen 5 ("Computer, Kaminfeuer an").

State and attributes

entity_id:

  • light.magwled
  • select.magwled_playlist
  • select.magwled_preset
  • light.wled_sofa
  • select.wled_sofa_playlist
  • select.wled_sofa_preset
  • light.fado_sofa
  • select.fado_sofa_playlist
  • select.fado_sofa_preset
  • light.fado_tisch
  • select.fado_tisch_playlist
  • select.fado_tisch_preset
  • light.wohnzimmer_stehlampe
  • select.wohnzimmer_stehlampe_playlist
  • select.wohnzimmer_stehlampe_preset
    id: "1727458551694"
    icon: mdi:fireplace
    friendly_name: Kaminfeuer

Relevant log output

[ 2024-12-11T19:45:20.117Z ] [ INFO  ] [ Matter / Behavior                                  ]: Invoke 6acd35c7e35a4877a629c28ca8063061.aggregator.scene_kaminfeuer.onOff.on online#9e31e8d@b81b89e6 (no payload)
[ 2024-12-11T19:45:20.117Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction online#9e31e8d@b81b89e6 locked 6acd35c7e35a4877a629c28ca8063061.aggregator.scene_kaminfeuer.onOff.state
[ 2024-12-11T19:45:20.117Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction online#9e31e8d@b81b89e6 committed and unlocked 1 resource
[ 2024-12-11T19:45:20.118Z ] [ DEBUG ] [ Matter / ExchangeManager                           ]: Message » id: 14251/8663/241411665 type: 1/9 acked: 165879437 reqAck: true duplicate: false payload: 152800360115350137002400732401062402011835012400001818181824ff0c18
[ 2024-12-11T19:45:20.118Z ] [ DEBUG ] [ HomeAssistantActions                               ]: Calling action 'homeassistant.turn_on' for target {"entity_id":"scene.kaminfeuer"} with data {}
[ 2024-12-11T19:45:20.120Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « id: 14251/8663/165879438 type: 0/16 acked: 241411665 reqAck: false duplicate: false payload: 
[ 2024-12-11T19:45:20.224Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<6acd35c7e35a4877a629c28ca8063061.aggregator.scene_kaminfeuer>#106b locked 6acd35c7e35a4877a629c28ca8063061.aggregator.scene_kaminfeuer.homeAssistantEntity.state
[ 2024-12-11T19:45:20.225Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<6acd35c7e35a4877a629c28ca8063061.aggregator.scene_kaminfeuer>#106b committed and unlocked 1 resource
[ 2024-12-11T19:45:20.227Z ] [ ERROR ] [ Matter / Logger                                    ]: Unhandled error detected: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#<Object>".
node:internal/process/promises:288
            triggerUncaughtException(err, true /* fromPromise */);
            ^

[UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#<Object>".] {
  code: 'ERR_UNHANDLED_REJECTION'
}

Node.js v18.20.4
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service base-addon-log-level: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service base-addon-log-level successfully stopped
s6-rc: info: service base-addon-banner: stopping
s6-rc: info: service base-addon-banner successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service base-addon-banner: starting

�[34m-----------------------------------------------------------�[0m
�[34m Add-on: Home-Assistant-Matter-Hub�[0m
�[34m Publish your entities from Home Assistant to any Matter-compatible controller like Alexa, Apple Home or Google Home.�[0m
�[34m-----------------------------------------------------------�[0m
�[34m Add-on version: 3.0.0-alpha.54�[0m
�[32m You are running the latest version of this add-on.�[0m
�[34m System: Home Assistant OS 14.0  (amd64 / qemux86-64)�[0m
�[34m Home Assistant Core: 2024.12.2�[0m
�[34m Home Assistant Supervisor: 2024.11.4�[0m
�[34m-----------------------------------------------------------�[0m
�[34m Please, share the above information when looking for help�[0m
�[34m or support in, e.g., GitHub, forums or the Discord chat.�[0m
�[34m-----------------------------------------------------------�[0m
s6-rc: info: service base-addon-banner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service base-addon-log-level: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service base-addon-log-level successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
[ 2024-12-11T19:45:27.302Z ] [ DEBUG ] [ Matter / UdpChannelNode                            ]: Socket created and bound remoteAddress: undefined:5353 localAddress: 0.0.0.0:5353
[ 2024-12-11T19:45:27.306Z ] [ DEBUG ] [ Matter / UdpChannelNode                            ]: Socket created and bound remoteAddress: undefined:5353 localAddress: :::5353
[ 2024-12-11T19:45:27.320Z ] [ DEBUG ] [ Matter / UdpChannelNode                            ]: Socket created and bound remoteAddress: undefined:5353 localAddress: 0.0.0.0:5353
[ 2024-12-11T19:45:27.321Z ] [ DEBUG ] [ Matter / UdpChannelNode                            ]: Socket created and bound remoteAddress: undefined:5353 localAddress: :::5353
[ 2024-12-11T19:45:27.403Z ] [ INFO  ] [ Matter / ServerNodeStore                           ]: Opened 6acd35c7e35a4877a629c28ca8063061 storage at /config/data/6acd35c7e35a4877a629c28ca8063061
[ 2024-12-11T19:45:27.408Z ] [ INFO  ] [ Matter / SessionManager                            ]: restoring resumption record for node 296671831803078161 and peer node 296671831803078161 for fabric index 1
[ 2024-12-11T19:45:27.409Z ] [ INFO  ] [ Matter / SessionManager                            ]: restoring resumption record for node 3138970146 and peer node 3138970146 for fabric index 3
[ 2024-12-11T19:45:27.410Z ] [ INFO  ] [ Matter / SessionManager                            ]: restoring resumption record for node 3088812518 and peer node 3088812518 for fabric index 3
[ 2024-12-11T19:45:27.425Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.basicInformation.state
[ 2024-12-11T19:45:27.438Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.accessControl.state
[ 2024-12-11T19:45:27.443Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.groupKeyManagement.state
[ 2024-12-11T19:45:27.449Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.generalCommissioning.state
[ 2024-12-11T19:45:27.454Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.administratorCommissioning.state
[ 2024-12-11T19:45:27.459Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.operationalCredentials.state
[ 2024-12-11T19:45:27.471Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction initialize<6acd35c7e35a4877a629c28ca8063061>#1 locked 6acd35c7e35a4877a629c28ca8063061.generalDiagnostics.state
[ 2024-12-11T19:45:27.483Z ] [ DEBUG ] [ Matter / EventHandler                              ]: Set/Restore last event number: 201

Documentation & Issues

  • I have reviewed the documentation and the linked troubleshooting guide.
  • I have searched the issues for a similar problem.
@Moonbase59 Moonbase59 added the bug Something isn't working label Dec 11, 2024
@Moonbase59
Copy link
Author

Hm. After the watchdog (apparently) restarted HAMH, I now get the same crash using Alexa "Computer, Kaminfeuer an":

491eb00d_hamh_2024-12-11T20-01-29.347Z.log

@t0bst4r
Copy link
Owner

t0bst4r commented Dec 12, 2024

But does it execute the command anyway?
So the question is:

is it failing sending the command to HA, or is it failing updating the matter devices after they changed in HA.

@Moonbase59
Copy link
Author

Moonbase59 commented Dec 12, 2024

Yeah, that's why I didn't realize at first: It actually does execute the command.

The "Kaminfeuer" scene actually sets 5 WLED devices (2xESP32, 1xESP8266 and 2xAthom 15W bulbs using ESP8285), all using WLED 0.15.0. Very seldom, usually under high WiFi load (like yesterday), the Athom lights don't always catch the command from HA (they then simply continue running the previous preset). Simply triggering the scene again usually fixes that.

Makes me think this could be some timing/WiFi load issue when updating the device status after the command. Status updates in both the Alexa and Google Home apps on my smartphone were also rather slow.

Re-check today: Activating "Kaminfeuer" scene worked smoothly from both Alexa Echo Dot and Google Nest Mini, but switching back to scene "Nur Stehlampe" (switches off 4 of 5 WLED devices, sets WLED "Stehlampe" to solid white) produced "device unreachable" messages on both Alexa and Google. The command was eventually executed by Alexa after a while. WiFi load today as measured by Fritz!Box 7490 router (incl. all neighbour's use): around 10–15% (yesterday was at 80–90%).

Total number of LEDs controlled: 462. Since adding scenes to the HAMH, I also notice some rather long messages, don't know if that has anything to do with it:

[ 2024-12-12T14:00:48.848Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « id: 44153/28152/195411553 type: 1/1 acked: 74620743 reqAck: true duplicate: false payload: 1524000024ff0b18
[ 2024-12-12T14:00:48.853Z ] [ DEBUG ] [ Matter / InteractionMessenger                      ]: Sending DataReport chunk with 35 attributes and 0 events: 1151 bytes (moreChunkedMessages: true, suppressResponse: false)
[ 2024-12-12T14:00:48.853Z ] [ DEBUG ] [ Matter / ExchangeManager                           ]: Message » id: 44153/28152/74620744 type: 1/5 acked: 195411553 reqAck: true duplicate: false payload: 152600d9d7311c360115350126008979080b370125021d012403032504fdff18240204181815350126008979080b370125021d012403032504fcff18240200181815350126008979080b370125021d012403032504fbff1836020400040105fdff05fcff05fbff05f9ff05f8ff18181815350126008979080b370125021d012403032504f9ff183602040018181815350126008979080b370125021d012403032504f8ff18360218181815350126003db5ecbe370125021d0124030424040018240200181815350126003db5ecbe370125021d012403042504fdff18240204181815350126003db5ecbe370125021d012403042504fcff18240201181815350126003db5ecbe370125021d012403042504fbff183602040005fdff05fcff05fbff05f9ff05f8ff18181815350126003db5ecbe370125021d012403042504f9ff18360218181815350126003db5ecbe370125021d012403042504f8ff1836021818181535012600deba0dc6370125021d0124030624040018280218181535012600deba0dc6370125021d012403062504fdff1824020618181535012600deba0dc6370125021d012403062504fcff1824020118181535012600deba0dc6370125021d012403062504fbff183602040005fdff05fcff05fbff05f9ff05f8ff0500400501400502400503401818181535012600deba0dc6370125021d012403062504f9ff1836020400044004410442040104021818181535012600deba0dc6370125021d012403062504f8ff1836021818181535012600deba0dc6370125021d012403062504004018290218181535012600deba0dc6370125021d01240306250401401824020018181535012600deba0dc6370125021d01240306250402401824020018181535012600deba0dc6370125021d0124030625040340183402181815350126005e510291370125021d0124031d240400183602152500000124010318152400132401021818181815350126005e510291370125021d0124031d2404011836020403040404060439041d18181815350126005e510291370125021d0124031d24040218360218181815350126005e510291370125021d0124031d24040318360218181815350126005e510291370125021d0124031d2504fdff18240202181815350126005e510291370125021d0124031d2504fcff18240200181815350126005e510291370125021d0124031d2504fbff183602040004010402040305fdff05fcff05fbff05f9ff05f8ff18181815350126005e510291370125021d0124031d2504f9ff18360218181815350126005e510291370125021d0124031d2504f8ff1836021818181535012600a3d47e4f370125021d01240339240401182c02077430627374347218181535012600a3d47e4f370125021d01240339240402182502f1ff18181535012600a3d47e4f370125021d01240339240403182c02094d617474657248756218181535012600a3d47e4f370125021d01240339240405182c0214576f686e7a696d6d65722044656b6f6c6963687418181535012600a3d47e4f370125021d01240339240407182502e8071818182903280424ff0c18
[ 2024-12-12T14:00:48.937Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « id: 44153/28152/195411554 type: 1/1 acked: 74620744 reqAck: true duplicate: false payload: 1524000024ff0b18

Using HAMH 3.0.0-alpha.54, HA Core 2024.12.2, HA Supervisor 2024.11.4, HA OS 14.0, HA Frontend 20241127.7.

@Apollon77
Copy link

Please provide more log ... this logpart just shows that the bridge reported some change values to the subscriber ... so basically: you left out all potentially interesting logparts ;-)

@t0bst4r
Copy link
Owner

t0bst4r commented Dec 17, 2024

There was a log file attached some comments above:


Unhandled error detected: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#<Object>".
node:internal/process/promises:288
            triggerUncaughtException(err, true /* fromPromise */);
            ^

[UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#<Object>".] {
  code: 'ERR_UNHANDLED_REJECTION'
}

This is most likely the home assistant call failing. The error in there wasn't catched, but detached (with setTimeout(..., 0) - this prevents the matter transaction to be blocked by the home assistant call) which lead to missing trace and unknown location in code.

I have added a catch command there in alpha.55. So please upgrade and try again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working waiting for feedback
Projects
None yet
Development

No branches or pull requests

3 participants