Open GBMCGBMC opened 6 months ago
Appears to occur because you have no apps setup in the config. Please add an app e.g. Netflix in the plugin config for this TV for now, and let me know if that works. Will fix this bug shortly.
Hi @BlaT2512; very keen to help support this plugin, it's something I've wanted for a while.
I'm getting the same error too. Tried running in a child bridge and without, clearing cache & resetting accessories etc, but it's the same result. I've also tried with 0-2+ apps, but I don't think those are the issues here.
It looks like it's trying to connect to my Chromecast twice, as two accessories initialise.
Here's a log including a couple crash loops:
[31/12/2023, 4:12:58 pm] [homebridge-cast] [Sun Room TV] Chromecast remote connected
192.168.0.44 Receive : {"remoteSetActive":{}}
Create Remote {"remoteSetActive":{"active":622}}
Sending {"remoteSetActive":{"active":622}}
192.168.0.44 Receive : {"remoteSetActive":{}}
Create Remote {"remoteSetActive":{"active":622}}
Sending {"remoteSetActive":{"active":622}}
192.168.0.44 Receive : {"remoteSetVolumeLevel":{"unknown1":942,"unknown2":9,"playerModel":"Chromecast","unknown4":0}}
192.168.0.44 Receive : {"remoteStart":{"started":false}}
192.168.0.44 Receive : {"remoteImeKeyInject":{"appInfo":{"appPackage":"com.android.tv.settings"}}}
192.168.0.44 Receive : {"remoteSetVolumeLevel":{"unknown1":942,"unknown2":9,"playerModel":"Chromecast","unknown4":0}}
192.168.0.44 Receive : {"remoteStart":{"started":false}}
192.168.0.44 Receive : {"remoteImeKeyInject":{"appInfo":{"appPackage":"com.android.tv.settings"}}}
[31/12/2023, 4:13:02 pm] Parent process did not respond to port allocation request within 5 seconds - assigning random port.
Error: Accessory Sun Room TV experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[31/12/2023, 4:13:02 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:02 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:09 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:10 pm] [homebridge-cast] Launched child bridge with PID 31493
*** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
*** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
[31/12/2023, 4:13:10 pm] Registering platform 'homebridge-cast.GoogleCastPlugin'
[31/12/2023, 4:13:10 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:11 pm] Loaded 0 cached accessories from cachedAccessories.0ED2A9E35B35.
[31/12/2023, 4:13:11 pm] Homebridge v1.7.0 (HAP v0.11.1) (homebridge-cast) is running on port 56077.
[31/12/2023, 4:13:11 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:11 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:11 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:11 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
Error: Accessory Sun Room TV experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[31/12/2023, 4:13:11 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:11 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:18 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:19 pm] [homebridge-cast] Launched child bridge with PID 31554
*** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
*** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
[31/12/2023, 4:13:19 pm] Registering platform 'homebridge-cast.GoogleCastPlugin'
[31/12/2023, 4:13:19 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:20 pm] Loaded 0 cached accessories from cachedAccessories.0ED2A9E35B35.
[31/12/2023, 4:13:20 pm] Homebridge v1.7.0 (HAP v0.11.1) (homebridge-cast) is running on port 56077.
[31/12/2023, 4:13:20 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:20 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:20 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:20 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
Error: Accessory Sun Room TV experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[31/12/2023, 4:13:20 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:20 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:27 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:28 pm] [homebridge-cast] Launched child bridge with PID 31634
*** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
*** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
[31/12/2023, 4:13:28 pm] Registering platform 'homebridge-cast.GoogleCastPlugin'
[31/12/2023, 4:13:28 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:29 pm] Loaded 0 cached accessories from cachedAccessories.0ED2A9E35B35.
[31/12/2023, 4:13:29 pm] Homebridge v1.7.0 (HAP v0.11.1) (homebridge-cast) is running on port 56077.
[31/12/2023, 4:13:29 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:29 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:29 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:29 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
Error: Accessory Sun Room TV experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[31/12/2023, 4:13:29 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:29 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:36 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:37 pm] [homebridge-cast] Launched child bridge with PID 31695
*** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
*** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
[31/12/2023, 4:13:37 pm] Registering platform 'homebridge-cast.GoogleCastPlugin'
[31/12/2023, 4:13:37 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:38 pm] Loaded 0 cached accessories from cachedAccessories.0ED2A9E35B35.
[31/12/2023, 4:13:38 pm] Homebridge v1.7.0 (HAP v0.11.1) (homebridge-cast) is running on port 56077.
[31/12/2023, 4:13:38 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:38 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:38 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:38 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
Error: Accessory Sun Room TV experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[31/12/2023, 4:13:38 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:38 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:45 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:46 pm] [homebridge-cast] Launched child bridge with PID 31756
[31/12/2023, 4:13:46 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:47 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:47 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:47 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:47 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:47 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:47 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
[31/12/2023, 4:13:54 pm] [homebridge-cast] Restarting Process...
[31/12/2023, 4:13:55 pm] [homebridge-cast] Launched child bridge with PID 31837
[31/12/2023, 4:13:55 pm] [homebridge-cast] Loaded homebridge-cast v1.0.0 child bridge successfully
[31/12/2023, 4:13:56 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:56 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:56 pm] [homebridge-cast] Found matching chromecast accessory: Sun Room TV
[31/12/2023, 4:13:56 pm] [homebridge-cast] [Sun Room TV] Connecting to Chromecast on 192.168.0.44:8009
[31/12/2023, 4:13:56 pm] [homebridge-cast] Child bridge process ended
[31/12/2023, 4:13:56 pm] [homebridge-cast] Process Ended. Code: 1, Signal: null
Config:
{
"devices": [
{
"name": "Sun Room TV",
"type": "streamstick",
"volumeService": true,
"motionService": true,
"tvApps": [
{
"id": "com.netflix.ninja",
"name": "Netflix"
},
{
"id": "com.netflix.ninja",
"name": "Netflix"
}
],
"tvCert": {
"key": "-----BEGIN RSA PRIVATE KEY-----\r my key -----END RSA PRIVATE KEY-----\r\n",
"cert": "-----BEGIN CERTIFICATE-----\r my cert -----END CERTIFICATE-----\r\n"
}
}
],
"_bridge": {
"username": "0E:D2:A9:E3:5B:35",
"port": 56077
},
"platform": "GoogleCastPlugin"
}
Minor update, I've forked & tried running this on my Windows dev laptop, and don't get this error.
The platform it does occur on is a Raspberry Pi.
My guess, is that there is a race condition somewhere that triggers on slower platforms. Looking at the logs above, its in the event this.browser.on('serviceUp', service => {
. It's either the event triggering multiple times, or it's somehow thinking there are multiple devices.
Will try and debug this on the Pi tomorrow if I have time.
Also worth adding, actually trying this through the Windows laptop - this is fantastic. Very keen to get this working on my main Pi. Props for pulling this together.
Hi @teh-hippo thanks for the info. I have not encountered this error, however I run Homebridge on a Mac mini so you may be right about it being something to do with slower platforms. I have a Rpi with Homebridge installed so will try this out today with similar config.
Interested in how it went for you @BlaT2512.
I've been adding some debug statements in, and it is because discoverDevices
executes multiple times.
It discovers the Chromecast a second time, but the plugin doesn't realise its an already published device.
Ran out of time before I could work out if the accessories
array is being handled right. It is always empty, so it doesn't realise its an existing accessory.
Not sure why the RaspberryPi is different still.
Had a spare 15mins.
On my system, the behaviour is:
serviceUp
2 times for the same device. According to their docs, this is possible and to be expected - but it should only happen when there are 2 network routes (first page, 'In fact...'). From what I can tell, they are equal in UUID and all service properties.publishExternalAccessories
, which is what causes the error. This shouldn't happen according to the current logic, as it should be flagged as an existingAccessory
.this.accessories
is only updated when Homebridge restores from cache. Seems right, checking 1 other plugin, but that plugin gets unique plugins from the cloud. I suspect that plugin would have the same issue.this.accessories
is pushed to when published, I don't get the error and it's identified as a unique device.new CastPlatformAccessory(this, accessory)
. This will still be called, resulting in doubled log entries and presumably doubled event handling.serviceDown
. My thought was that maybe the device goes down for some reason then up, but I get no such event when subscribing to it. Just seems to find the device 2 times.I haven't personally developed with cached accessories on HomeBridge yet so I'm not sure how to fix it.
But you can easy to replicate by attempting to handle a device 2 times. As mentioned, according to mDNS that's supposedly possible to happen - maybe there is some weird behaviour on the Pi causing it to be emitted twice. Either way though, having it serviceUp
2 times successfully, where it updates an existing accessory, would be a sufficient fix here.
I am having the same issue as well. The plugins finds and connects the TV successfully only for it to fail due to reboot loop. The error I am seeing is:
[24/02/2024, 02:39:31] Parent process did not respond to port allocation request within 5 seconds - assigning random port. Error: Accessory Android TV experienced an address collision. at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15) at processTicksAndRejections (node:internal/process/task_queues:95:5) [24/02/2024, 02:39:31] [homebridge-cast] Child bridge process ended [24/02/2024, 02:39:31] [homebridge-cast] Process Ended. Code: 1, Signal: null
I too am having the issue reported above, running on a PI 4
[03/03/2024, 23:54:10] Error: Accessory 192.168.1.180 experienced an address collision. at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15) at processTicksAndRejections (node:internal/process/task_queues:95:5)
I‘m having the same issue:
[19/04/2024, 21:10:23] [homebridge-cast] [Schlafzimmer] Chromecast connected Start Remote Connect Error: error:04800066:PEM routines::bad end line at node:internal/tls/secure-context:70:13 at Array.forEach (<anonymous>) at setCerts (node:internal/tls/secure-context:68:3) at configSecureContext (node:internal/tls/secure-context:157:5) at Object.createSecureContext (node:_tls_common:117:3) at Object.connect (node:_tls_wrap:1750:48) at /var/lib/homebridge/node_modules/homebridge-cast/node_modules/androidtv-remote/dist/remote/RemoteManager.js:49:37 at new Promise (<anonymous>) at /var/lib/homebridge/node_modules/homebridge-cast/node_modules/androidtv-remote/dist/remote/RemoteManager.js:40:14 at Generator.next (<anonymous>) { library: 'PEM routines', reason: 'bad end line', code: 'ERR_OSSL_PEM_BAD_END_LINE' } Error: connect ECONNREFUSED 192.168.2.106:6467 at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1555:16) { errno: -111, code: 'ECONNREFUSED', syscall: 'connect', address: '192.168.2.106', port: 6467 } 192.168.2.106 Pairing Connection closed true false
System: RPi 4
Config: { "devices": [ { "name": "192.168.2.106", "displayName": "Wohnzimmer", "type": "streamstick", "volumeService": true, "motionService": false }, { "name": "192.168.2.131", "displayName": "Schlafzimmer", "type": "tv", "volumeService": true, "motionService": false, "tvApps": [ { "id": "com.netflix.ninja", "name": "Netflix" } ], "tvCert": { //Not Empty! } } ], "_bridge": { "username": "0E:E7:18:5A:29:7B", "port": 56634 }, "platform": "GoogleCastPlugin" }
I’m having the same issue as those above, running on an Intel Mac mini
Describe The Bug: Installed homebridge-cast, generated certificate, set up certificate in json, rebooted homebridge. It connects to the TV and then bootloops homebridge.
To Reproduce: Install homebridge-cast, set up android TV.
Expected behavior: No bootloop.
Logs:
Plugin Config: { "devices": [ { "name": "192.168.1.128", "displayName": "Lounge Room TV", "type": "tv", "volumeService": true, "motionService": false, "tvCert": { "key": "-----BEGIN RSA PRIVATE KEY-----\r\n KEY \r\n-----END RSA PRIVATE KEY-----\r\n", "cert": "-----BEGIN CERTIFICATE-----\r\n CERT \r\n-----END CERTIFICATE-----\r\n" } } ], "platform": "GoogleCastPlugin" }
Screenshots:
Environment: