search

geekuillaume / soundsync

Virtual cables between any audio source and any speaker in your home
https://soundsync.app
Other
840 stars 36 forks source link

Unable to add second Chromecast device to Soundsync #49

Open balaji-dutt opened 4 years ago

balaji-dutt commented 4 years ago

I have two Chromecast devices on my network - a Google Home Mini as well as a Chromecast Audio. I was able to successfully add the Mini to the list of Speakers in Soundsync. However, whenever I try to add the Chromecast Audio to the Speaker list I see the following messages in journalctl logs:

Oct 19 10:49:49 repeater soundsync[1137]: 2020-10-19T10:49:49.630Z soundsync:peer:f083ee79-c510-4b12-8f6c-5893dc52dea2:rpc Sending controller message {
Oct 19 10:49:49 repeater soundsync[1137]:   type: 'rpc',
Oct 19 10:49:49 repeater soundsync[1137]:   isResponse: true,
Oct 19 10:49:49 repeater soundsync[1137]:   body: [
Oct 19 10:49:49 repeater soundsync[1137]:     { host: '192.168.50.31', name: 'Living Room Speaker' },
Oct 19 10:49:49 repeater soundsync[1137]:     { host: '192.168.50.28', name: 'Living Room Mini' }
Oct 19 10:49:49 repeater soundsync[1137]:   ],
Oct 19 10:49:49 repeater soundsync[1137]:   uuid: '2c7eab96-d172-4ddd-86f3-d36c310c385a',
Oct 19 10:49:49 repeater soundsync[1137]:   rpcType: 'scanChromecast'
Oct 19 10:49:49 repeater soundsync[1137]: }
Oct 19 10:49:51 repeater soundsync[1137]: 2020-10-19T10:49:51.934Z soundsync:peer:f083ee79-c510-4b12-8f6c-5893dc52dea2:rpc Received controller message {
Oct 19 10:49:51 repeater soundsync[1137]:   type: 'rpc',
Oct 19 10:49:51 repeater soundsync[1137]:   rpcType: 'startChromecast',
Oct 19 10:49:51 repeater soundsync[1137]:   isResponse: false,
Oct 19 10:49:51 repeater soundsync[1137]:   body: '192.168.50.31',
Oct 19 10:49:51 repeater soundsync[1137]:   uuid: '687b0c43-7b0d-4dd5-9507-625bad8035b4'
Oct 19 10:49:51 repeater soundsync[1137]: }
Oct 19 10:49:52 repeater soundsync[1137]: 2020-10-19T10:49:52.144Z soundsync:peer:aeab6239-3ac1-4e4d-9329-4d55b845ba4a Destroying peer, reason: controller channel is closed
Oct 19 10:49:52 repeater soundsync[1137]: 2020-10-19T10:49:52.145Z soundsync:peer:aeab6239-3ac1-4e4d-9329-4d55b845ba4a Cleaning webrtc state
Oct 19 10:49:54 repeater soundsync[1137]: 2020-10-19T10:49:54.500Z soundsync:peer:f083ee79-c510-4b12-8f6c-5893dc52dea2:rpc Sending controller message {
Oct 19 10:49:54 repeater soundsync[1137]:   type: 'rpc',
Oct 19 10:49:54 repeater soundsync[1137]:   isResponse: true,
Oct 19 10:49:54 repeater soundsync[1137]:   body: undefined,
Oct 19 10:49:54 repeater soundsync[1137]:   uuid: '687b0c43-7b0d-4dd5-9507-625bad8035b4',
Oct 19 10:49:54 repeater soundsync[1137]:   rpcType: 'startChromecast'
Oct 19 10:49:54 repeater soundsync[1137]: }
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.280Z soundsync:eventloop last 5 seconds: event loop blocked for 20.922367ms, mean: 10.14611668292683ms
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.710Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73 Created new peer
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.713Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73 Setting remote description
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.714Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73 Creating answer
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.714Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73 Setting local description
Oct 19 10:49:55 repeater soundsync[1137]: 2020-10-19T10:49:55.716Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73 Sending answer
Oct 19 10:49:56 repeater soundsync[1137]: 2020-10-19T10:49:56.857Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73:peerInfo Sending controller message {
Oct 19 10:49:56 repeater soundsync[1137]:   type: 'peerInfo',
Oct 19 10:49:56 repeater soundsync[1137]:   peer: {
Oct 19 10:49:56 repeater soundsync[1137]:     uuid: 'e422b321-bfe8-4174-af33-47ae84ad1583',
Oct 19 10:49:56 repeater soundsync[1137]:     name: 'repeater',
Oct 19 10:49:56 repeater soundsync[1137]:     instanceUuid: '8286233e-1178-4dc9-bc59-62fdb2686323',
Oct 19 10:49:56 repeater soundsync[1137]:     capacities: [
Oct 19 10:49:56 repeater soundsync[1137]:       'librespot',
Oct 19 10:49:56 repeater soundsync[1137]:       'shairport',
Oct 19 10:49:56 repeater soundsync[1137]:       'http_server_accessible',
Oct 19 10:49:56 repeater soundsync[1137]:       'hue',
Oct 19 10:49:56 repeater soundsync[1137]:       'chromecast_interaction',
Oct 19 10:49:56 repeater soundsync[1137]:       'shared_state_keeper',
Oct 19 10:49:56 repeater soundsync[1137]:       'airplay_sink'
Oct 19 10:49:56 repeater soundsync[1137]:     ],
Oct 19 10:49:56 repeater soundsync[1137]:     version: '0.4.4'
Oct 19 10:49:56 repeater soundsync[1137]:   },
Oct 19 10:49:56 repeater soundsync[1137]:   sharedState: { hueBridges: [], lastUpdateTimestamp: -1 }
Oct 19 10:49:56 repeater soundsync[1137]: }
Oct 19 10:49:56 repeater soundsync[1137]: 2020-10-19T10:49:56.922Z soundsync:peer:placeholderForRendezvousInitiatorRequest_f7e09eea-2564-4b7e-ad4f-18d1e519cb73:peerInfo Received controller message {
Oct 19 10:49:56 repeater soundsync[1137]:   type: 'peerInfo',
Oct 19 10:49:56 repeater soundsync[1137]:   peer: {
Oct 19 10:49:56 repeater soundsync[1137]:     uuid: 'aeab6239-3ac1-4e4d-9329-4d55b845ba4a',
Oct 19 10:49:56 repeater soundsync[1137]:     name: 'Chromecast',
Oct 19 10:49:56 repeater soundsync[1137]:     instanceUuid: '267f435c-c0e2-4a1c-ab99-35087c064212',
Oct 19 10:49:56 repeater soundsync[1137]:     capacities: [],
Oct 19 10:49:56 repeater soundsync[1137]:     version: '0.4.4'
Oct 19 10:49:56 repeater soundsync[1137]:   }
Oct 19 10:49:56 repeater soundsync[1137]: }
Oct 19 10:49:56 repeater soundsync[1137]: 2020-10-19T10:49:56.923Z soundsync:peer:aeab6239-3ac1-4e4d-9329-4d55b845ba4a Connected
Oct 19 10:49:57 repeater soundsync[1137]: 2020-10-19T10:49:57.233Z soundsync:peer:aeab6239-3ac1-4e4d-9329-4d55b845ba4a Updating timedelta to -162974.38605149993, diff: -162974.39ms
Oct 19 10:50:00 repeater soundsync[1137]: 2020-10-19T10:50:00.279Z soundsync:eventloop last 5 seconds: event loop blocked for 29.556735ms, mean: 10.181828440816327ms
Oct 19 10:50:02 repeater soundsync[1137]: 2020-10-19T10:50:02.183Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Created new peer
Oct 19 10:50:02 repeater soundsync[1137]: 2020-10-19T10:50:02.186Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Setting remote description
Oct 19 10:50:02 repeater soundsync[1137]: 2020-10-19T10:50:02.187Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Creating answer
Oct 19 10:50:02 repeater soundsync[1137]: 2020-10-19T10:50:02.187Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Setting local description
Oct 19 10:50:02 repeater soundsync[1137]: 2020-10-19T10:50:02.189Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Sending answer
Oct 19 10:50:03 repeater soundsync[1137]: 2020-10-19T10:50:03.336Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3:peerInfo Sending controller message {
Oct 19 10:50:03 repeater soundsync[1137]:   type: 'peerInfo',
Oct 19 10:50:03 repeater soundsync[1137]:   peer: {
Oct 19 10:50:03 repeater soundsync[1137]:     uuid: 'e422b321-bfe8-4174-af33-47ae84ad1583',
Oct 19 10:50:03 repeater soundsync[1137]:     name: 'repeater',
Oct 19 10:50:03 repeater soundsync[1137]:     instanceUuid: '8286233e-1178-4dc9-bc59-62fdb2686323',
Oct 19 10:50:03 repeater soundsync[1137]:     capacities: [
Oct 19 10:50:03 repeater soundsync[1137]:       'librespot',
Oct 19 10:50:03 repeater soundsync[1137]:       'shairport',
Oct 19 10:50:03 repeater soundsync[1137]:       'http_server_accessible',
Oct 19 10:50:03 repeater soundsync[1137]:       'hue',
Oct 19 10:50:03 repeater soundsync[1137]:       'chromecast_interaction',
Oct 19 10:50:03 repeater soundsync[1137]:       'shared_state_keeper',
Oct 19 10:50:03 repeater soundsync[1137]:       'airplay_sink'
Oct 19 10:50:03 repeater soundsync[1137]:     ],
Oct 19 10:50:03 repeater soundsync[1137]:     version: '0.4.4'
Oct 19 10:50:03 repeater soundsync[1137]:   },
Oct 19 10:50:03 repeater soundsync[1137]:   sharedState: { hueBridges: [], lastUpdateTimestamp: -1 }
Oct 19 10:50:03 repeater soundsync[1137]: }
Oct 19 10:50:03 repeater soundsync[1137]: 2020-10-19T10:50:03.373Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3:peerInfo Received controller message {
Oct 19 10:50:03 repeater soundsync[1137]:   type: 'peerInfo',
Oct 19 10:50:03 repeater soundsync[1137]:   peer: {
Oct 19 10:50:03 repeater soundsync[1137]:     uuid: 'aeab6239-3ac1-4e4d-9329-4d55b845ba4a',
Oct 19 10:50:03 repeater soundsync[1137]:     name: 'Chromecast',
Oct 19 10:50:03 repeater soundsync[1137]:     instanceUuid: '267f435c-c0e2-4a1c-ab99-35087c064212',
Oct 19 10:50:03 repeater soundsync[1137]:     capacities: [],
Oct 19 10:50:03 repeater soundsync[1137]:     version: '0.4.4'
Oct 19 10:50:03 repeater soundsync[1137]:   }
Oct 19 10:50:03 repeater soundsync[1137]: }
Oct 19 10:50:03 repeater soundsync[1137]: 2020-10-19T10:50:03.374Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Destroying peer, reason: Peer is already connected, this is a duplicate
Oct 19 10:50:03 repeater soundsync[1137]: 2020-10-19T10:50:03.374Z soundsync:peer:placeholderForRendezvousInitiatorRequest_7e215426-cb6d-4811-b469-7025849aacd3 Cleaning webrtc state

Note the message Peer is already connected. I have actually only added the Mini so I don't know why the Soundsync app thinks the Chromecast has also been added before. I also checked /etc/soundsync/config.json and I do not see any entry for the Chromecast.

balaji-dutt commented 4 years ago

Hi @geekuillaume I'm not sure if you had a chance to look into this issue. I notice in the changelogs for 0.4.13 there is mention of faster detection for Chromecasts and some other Chromecast related fixes.

Unfortunately for me, it now seems like I simply cannot find my Chromecasts in Soundsync. The initial scan takes a bit of time but if it does not detect anything then, the next few scans seem to be instantaneous but there is nothing in the logs during this process. I can see the Chromecasts exist as they show up in my local Spotify client. Any suggestions?

geekuillaume commented 4 years ago

Hello @balaji-dutt I took a look at this issue in the last few days and implemented a lot of small fixes and improvements for Chromecast but I also discovered a Chrome bug (https://bugs.chromium.org/p/chromium/issues/detail?id=1090441&q=component%3ABlink%3EWebAudio&sort=pri) that makes the audio playback very bad with Chromecast (and linux in general). There is nothing I can do to fix this except wait for the Chrome team to fix it. In the meantime, I'm not gonna spend more time on the Chromecast integration. At least it has been classes priority 1 (maximum) but there is no way to say when it will be fixed.

balaji-dutt commented 4 years ago

@geekuillaume Ah! I've been bitten by that issue as well. When I could add a Chromecast, the playback was very choppy and laggy. I was going to file a separate issue for that but given that you are blocked on the upstream issue, I will just have to hope Google releases a fix for older Chromecast devices like the one I have 🙁