ebaauw / homebridge-zp

Homebridge plugin for Sonos ZonePlayer
Apache License 2.0
241 stars 20 forks source link

TypeError: Cannot read properties of undefined (reading 'info') #220

Open Peter314159265 opened 4 months ago

Peter314159265 commented 4 months ago

Issue

Whenever my Sonos Roam is turned on, the same error occurs and homebridge-zp is restarted.

Log Messages

[6-6-2024, 09:05:22] [Sonos ZP] Sonos Roam: warning: rebooted (40 -> 41)

/var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:181
    const id = message.txt.info.split('/')[4]
                           ^
TypeError: Cannot read properties of undefined (reading 'info')
    at ZpPlatform.handleMdnsMessage (/var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:181:28)
    at Browser.<anonymous> (/var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:43:47)
    at Browser.emit (node:events:519:28)
    at Browser._addService (/var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:112:8)
    at /var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:88:16
    at Array.forEach (<anonymous>)
    at /var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:84:15
    at Array.forEach (<anonymous>)
    at EventEmitter._onresponse (/var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:76:26)
    at EventEmitter.emit (node:events:519:28)
[6-6-2024, 09:05:23] [Sonos ZP] Child bridge process ended
[6-6-2024, 09:05:23] [Sonos ZP] Process Ended. Code: 1, Signal: null
[6-6-2024, 09:05:30] [Sonos ZP] Restarting Process...

Debug Files

ebaauw commented 4 months ago

I did see the same TypeError last night, apparently when/after my zone players were updating their firmware. On restart, Homebridge ZP lost two of my zones, presumably because they were still upgrading.

Looks like I fail to try/catch the processing of mDNS (Bonjour) messages, which, apparently, look different from what Homebridge ZP expects. This was already fixed in https://github.com/ebaauw/homebridge-zp/commit/2d47af3d3b30ee07adbe446eedadf5b9b5ef166f, but not yet published.

As workaround (for now), could you try power cycle your zone players and restart Homebridge ZP?

Peter314159265 commented 4 months ago

Tried power cycling already, but it keeps throwing the error.

ebaauw commented 4 months ago

Now seeing other errors, indicating that the mDNS message arrived before Homebridge ZP initialised the household:

[6/6/2024, 10:05:07 AM] [Sonos] error: SyntaxError: RINCON_38420B43E37601400 not in Sonos_VeWcTkRtlSB9e3xJdEIDu4FmZ5

and

[6/6/2024, 10:07:31 AM] [Sonos] error: SyntaxError: RINCON_38420B30E94E01400 not in undefined

Disabled listening for mDNS messages for now in beta v1.4.46-0.

ebaauw commented 3 months ago

Should be fixed in v1.4.46. If not, please list the mDNS message that fails to parse, which should now be logged.

Peter314159265 commented 3 months ago

getting mDNS warning message, but plugin does not crash anymore. So I guess it is fixed (?)

[16/06/2024, 18:41:41] [Sonos ZP] Sonos Roam: warning: rebooted (48 -> 49)
[16/06/2024, 18:41:44] [Sonos ZP] warning: mdns: message {"addresses":["192.168.178.31","2001:1c04:1337:7d00:f2f6:c1ff:fe37:8d8e","fe80::f2f6:c1ff:fe37:8d8e"],"name":"Sonos-F0F6C1378D8E@Sonos Roam","fqdn":"Sonos-F0F6C1378D8E@Sonos Roam._sonos._tcp.local","host":"Sonos-F0F6C1378D8E.local","referer":{"address":"192.168.178.31","family":"IPv4","port":5353,"size":1375},"port":1443,"type":"sonos","protocol":"tcp","subtypes":[]}: TypeError: Cannot read properties of undefined (reading 'uuid')
    at ZpPlatform.handleMdnsMessage (file:///var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:184:30)
    at Browser.<anonymous> (file:///var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:45:47)
    at Browser.emit (node:events:519:28)
    at Browser._addService (/var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:112:8)
    at /var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:88:16
    at Array.forEach (<anonymous>)
    at /var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:84:15
    at Array.forEach (<anonymous>)
    at EventEmitter._onresponse (/var/lib/homebridge/node_modules/homebridge-zp/node_modules/bonjour-hap/lib/Browser.js:76:26)
    at EventEmitter.emit (node:events:519:28)

It seems to throw a new error now on startup:

[16/06/2024, 18:48:04] [Sonos ZP] error: SyntaxError: RINCON_F0F6C1378D8E01400 not in undefined
    at ZpHousehold.setAssociated (file:///var/lib/homebridge/node_modules/homebridge-zp/lib/ZpHousehold.js:27:13)
    at ZpPlatform.logTopology (file:///var/lib/homebridge/node_modules/homebridge-zp/lib/ZpPlatform.js:406:27)
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
[16/06/2024, 18:48:04] [Sonos ZP] undefined: found 6 S2 zone players in 3 zones
[16/06/2024, 18:48:04] [Sonos ZP] ├─ Sonos Roam
[16/06/2024, 18:48:04] [Sonos ZP] │  └─ RINCON_F0F6C1378D8E01400 [Sonos Roam]: Sonos Roam SL (S35) (master, airPlay)
[16/06/2024, 18:48:04] [Sonos ZP] ├─ Sonos Slaapkamer
[16/06/2024, 18:48:04] [Sonos ZP] │  └─ RINCON_542A1B53A51601400 [Sonos Slaapkamer]: SYMFONISK Table lamp (S30) (master, airPlay)
[16/06/2024, 18:48:04] [Sonos ZP] └─ Sonos Woonkamer (LS+RS+Sub)
[16/06/2024, 18:48:04] [Sonos ZP]    ├─ RINCON_48A6B83677EE01400 [Sonos Woonkamer]: Sonos Beam (S14) (master, airPlay, tvIn)
[16/06/2024, 18:48:04] [Sonos ZP]    ├─ RINCON_347E5CFC772201400 [Sonos Woonkamer (LS)]: SYMFONISK Bookshelf (S21) (satellite)
[16/06/2024, 18:48:04] [Sonos ZP]    ├─ RINCON_347E5CFC4EEA01400 [Sonos Woonkamer (RS)]: SYMFONISK Bookshelf (S21) (satellite)
[16/06/2024, 18:48:04] [Sonos ZP]    └─ RINCON_F0F6C101C95C01400 [Sonos Woonkamer (Sub)]: Sonos Sub Mini (S37) (satellite)
ebaauw commented 3 months ago

getting mDNS warning message, but plugin does not crash anymore. So I guess it is fixed (?)

The crash is fixed, but handling the advertisement still fails. With this log, I can now have a look at fixing that.

It seems to throw a new error now on startup:

I’ve seen that one myself, occasionally. Seems to be a concurrency error, that the mDNS announcement is received before Homebridge ZP has fully initialised the household. Seems the household ID is also missing from the mDNS advertisement.

[16/06/2024, 18:48:04] [Sonos ZP] undefined: found 6 S2 zone players in 3 zones

Are these indeed all your zones and zoneplayers, or are some of them missing?

Peter314159265 commented 3 months ago

Yes, all zones and zoneplayers are listed

ebaauw commented 3 months ago

Did some more testing: mDNS advertisements are received only on Homebridge ZP startup and when a zone player reboots. There's no periodic "alive" messages as with UPnP.

I still cannot get my installation to send an mDNS advertisement without a txt field (which caused the TypeError). On what system are you running Homebridge ZP? Maybe it's related to the mDNS implementation of that system?

I did find another bug in Homebridge ZP: the household ID sits in the txt field as well. That would explain the SyntaxError.

Beta 1.4.47-0 now checks explicitly that the advertisement includes the id, household id, boot sequence, and address of the zone player, ignoring the advertisement when not. I'm hoping the errors will be gone with that version.

Peter314159265 commented 3 months ago

I still cannot get my installation to send an mDNS advertisement without a txt field (which caused the TypeError). On what system are you running Homebridge ZP? Maybe it's related to the mDNS implementation of that system?

I’m running Homebridge ZP on a Rasberry Pi with Raspbian OS