Unable to cast to a Nest Hub

[frankusb]

When trying to select a Nest Hub from the Remotes & Outputs page, it is checked, then the log message appears: [2020-04-19 14:07:54] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting Then it un-checks the output. No audio is played.

I am able to cast music to the Nest Hub from Plex.

[ejurgensen]

Ok, don't have one of those, but maybe I can borrow one. Otherwise I will get back to you and ask for some help.

[frankusb]

Happy to help, just let me know.

[frankusb]

Interestingly, I have a speaker group that includes the Nest Hub, "All the speakers" and I can play to that fine.

[ejurgensen]

Can you set the log level to debug and try again? Just paste the part of the log that has "cast:", so I can see what is being communicated with the device.

From first glance I think the error comes because the device doesn't launch the app that forked-daapd tries to start. So I would like to check if that is indeed the case.

[frankusb]

I will try the debug.

Simple work around, create a group with only the Nest Hub in it.

[frankusb]

After restarting forked-daapd I am unable to reproduce in debug and log level logging.

[ejurgensen]

Ok, we'll have to close the issue then. I have added some clearer logging in case it happens again.

[frankusb]

FWIW, this came back. I realize you have added logging but I have not updated to the latest version but I will probably tonight and hopefully capture some more useful information.

[2020-04-21 11:54:29] [ LOG] cast: Request 6 timed out, will run empty callback [2020-04-21 11:54:29] [ LOG] cast: No MEDIA_STATUS reply to our STOP - will continue anyway [2020-04-21 11:54:30] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:30] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:35] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:35] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:42] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:42] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:46] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:46] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:47] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:47] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:47] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:47] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:48] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:48] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:49] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:49] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:49] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:49] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:49] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:50] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:52] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:52] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:54:58] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:54:58] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:55:18] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:55:18] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:55:54] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:55:54] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:56:06] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:56:18] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:56:19] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:56:24] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 11:56:24] [ LOG] cast: No RECEIVER_STATUS reply to our LAUNCH (got type: 9) - aborting [2020-04-21 11:56:24] [ LOG] dacp: Speakers de/activation failed! [2020-04-21 11:56:29] [ LOG] cast: Request 11 timed out, will run empty callback [2020-04-21 11:56:29] [ LOG] cast: No MEDIA_STATUS reply to our STOP - will continue anyway

[frankusb]

@ejurgensen got the log for you.

[2020-04-21 13:15:31] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 13:15:45] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 13:15:45] [ LOG] cast: Offset is set to 2:100000000 [2020-04-21 13:15:45] [ LOG] cast: Device 'Kitchen' could not launch app id '85CDB22F' nor '0F5096E8' - aborting

[ejurgensen]

Ok, seems to confirm that the device doesn't launch the app. Could you install the Chromium browser and test if you are able to stream a youtube video from that to the device?

[frankusb]

Oh yes, I just casted Youtube from Chrome. I cast music from Plex to it as well. I've never had any issues interacting with the Nest Hub otherwise to my knowledge.

[ejurgensen]

Chromium, not Chrome. There are different ways of casting, I don't know what Chrome and Plex uses, they are both closed source. forked-daapd should use the same as Chromium.

[frankusb]

Chromium Version 81.0.4044.113 (Developer Build) (64-bit) on Mac OS finds no devices to cast to unless you enable chrome://flags/#load-media-router-component-extension

Once I do that, then I am able to cast YouTube to the Nest Hub.

[ejurgensen]

Ok, I'll reopen the issue.

I can't think of a way to proceed without the device, so let's see if I can get hold of one. It would be interesting to get an unencrypted dump of the traffic between Chromium and the device. Not easy to do, but maybe you or someone else out there is able to do that.

[frankusb]

Will Wireshark do it?

On Wed, Apr 22, 2020 at 4:07 AM ejurgensen notifications@github.com wrote:

Ok, I'll reopen the issue.

I can't think of a way to proceed without the device, so let's see if I can get hold of one. It would be interesting to get an unencrypted dump of the traffic between Chromium and the device. Not easy to do, but maybe you or someone else out there is able to do that.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/ejurgensen/forked-daapd/issues/957#issuecomment-617653373, or unsubscribe https://github.com/notifications/unsubscribe-auth/APETTJU3F6G2GTBWYTYGMJDRN2XWPANCNFSM4ML5OPAQ .

[ejurgensen]

No it would encrypted. I think it would need to be via Chromium. Maybe if it has a debug mode where it dumps the traffic?

[frankusb]

Is forked-daapd communication also encrypted? I could capture the working vs non working case (in a speaker group of 1 or direct).

On Wed, Apr 22, 2020 at 7:42 AM ejurgensen notifications@github.com wrote:

No it would encrypted. I think it would need to be via Chromium. Maybe if it has a debug mode where it dumps the traffic?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/ejurgensen/forked-daapd/issues/957#issuecomment-617755338, or unsubscribe https://github.com/notifications/unsubscribe-auth/APETTJUZUB4HZO4AXGC7A5TRN3Q2BANCNFSM4ML5OPAQ .

[ejurgensen]

I have now tested with a Nest Hub, but it didn't give any clues since it worked ok. Maybe it was another version or something.

[Jbautista13]

@ejurgensen Below is the debug level log when attempting to connect to a single nest hub.

nest_hub_filtered.log

[Jbautista13]

These logs,

[2023-02-17 04:12:53] [DEBUG] cast: TX 700 sender-0 0e1fbbda-c737-418d-be7e-795690360738 urn:x-cast:com.google.cast.webrtc {"type":"OFFER","seqNum":5,"offer":{"castMode":"mirroring","supportedStreams":[{"index":0,"type":"audio_source","codecName":"opus","rtpProfile":"cast","rtpPayloadType":127,"ssrc":164664,"storeTime":400,"targetDelay":400,"bitRate":128000,"sampleRate":48000,"timeBase":"1/48000","channels":2,"receiverRtcpEventLog":false},{"codecName":"vp8","index":1,"maxBitRate":5000000,"maxFrameRate":"30000/1000","receiverRtcpEventLog":false,"renderMode":"video","resolutions":[{"height":900,"width":1600}],"rtpPayloadType":96,"rtpProfile":"cast","ssrc":999999,"targetDelay":400,"timeBase":"1/90000","type":"video_source"}]}}

[2023-02-17 04:12:53] [DEBUG] cast: RX 205 0e1fbbda-c737-418d-be7e-795690360738 sender-0 urn:x-cast:com.google.cast.webrtc {"error":{"code":10092,"description":"Failed to parse malformed OFFER"},"result":"error","seqNum":5,"type":"ANSWER"}

[2023-02-17 04:12:53] [ LOG] cast: Missing UDP port (or unexpected result 'error') in ANSWER - aborting

seem to be the culprit, if I'm understanding it correctly the first message is being sent by owntone to the nest hub, the second message,

{"error":{"code":10092,"description":"Failed to parse malformed OFFER"},"result":"error","seqNum":5,"type":"ANSWER"}

is being sent back by the nest hub? If so, it would seem that it could be fixed by sending an offer that the Nest Hub can accept?

[ejurgensen]

Yes, that's interesting. It is an error coming from the Nest, and yes, maybe just changing the OFFER would fix this. Would you be able to install Chromium and do the following (with some mp3)?

1) chromium --user-data-dir=~/chromium --enable-logging --v=1 ~/test.mp3 2) right-click, select Cast, select Nest 3) look for the OFFER in ~/chromium/chrome_debug.log

[Jbautista13]

[24432:4140:0217/140643.590:VERBOSE1:cast_message_handler.cc(455)] SendCastMessageToSocket: channel_id: 1, message: {source_id: sender-[sender], destination_id: [dest], namespace: urn:x-cast:com.google.cast.webrtc, payload_utf8: {"offer":{"castMode":"mirroring","supportedStreams":[{"aesIvMask":"[mask]","aesKey":"[key]","bitRate":32000,"channels":2,"codecName":"opus","codecParameter":"","index":0,"receiverRtcpDscp":"","receiverRtcpEventLog":false,"rtpPayloadType":127,"rtpProfile":"cast","ssrc":34343,"targetDelay":400,"timeBase":"1/48000","type":"audio_source"},{"aesIvMask":"[mask]","aesKey":"[key]","channels":1,"codecName":"vp8","codecParameter":"","errorRecoveryMode":"","index":1,"level":"","maxBitRate":5000000,"maxFrameRate":"30","profile":"","protection":"","receiverRtcpDscp":"","receiverRtcpEventLog":false,"resolutions":[{"height":1080,"width":1920}],"rtpPayloadType":96,"rtpProfile":"cast","ssrc":54666,"targetDelay":400,"timeBase":"1/90000","type":"video_source"}]},"seqNum":1,"type":"OFFER"}}

chromium_offer_to_nest_hub.txt

[Jbautista13]

The previous offer and log entry was from Chromium on Windows, below is one off the rpi4 which owntone is installed on.

[1808:1844:0217/143154.096626:VERBOSE1:cast_message_handler.cc(454)] SendCastMessageToSocket: channel_id: 6, message: {source_id: sender-[sender], destination_id: [dest], namespace: urn:x-cast:com.google.cast.webrtc, payload_utf8: {"offer":{"castMode":"mirroring","receiverGetStatus":true,"supportedStreams":[{"aesIvMask":"[mask]","aesKey":"[key]","bitRate":102000,"channels":2,"codecName":"opus","index":0,"receiverRtcpEventLog":true,"rtpExtensions":"adaptive_playout_delay","rtpPayloadType":127,"rtpProfile":"cast","sampleRate":48000,"ssrc":105618,"targetDelay":400,"timeBase":"1/48000","type":"audio_source"},{"aesIvMask":"[mask]","aesKey":"[key]","codecName":"vp8","index":1,"maxBitRate":5000000,"maxFrameRate":"30000/1000","receiverRtcpEventLog":true,"renderMode":"video","resolutions":[{"height":1080,"width":1920}],"rtpExtensions":"adaptive_playout_delay","rtpPayloadType":96,"rtpProfile":"cast","ssrc":584923,"targetDelay":400,"timeBase":"1/90000","type":"video_source"}]},"seqNum":827941470,"type":"OFFER"}}

rpi_chromium_offer_to_nest_hub.txt

[ejurgensen]

Quick testing, very nice :-) So the next step would be some trial and error to see which of the differences is causing the issue. To do this, you need to be able to build from source - is that possible for you? You would need to modify the template for the OFFER request which you can find here. I don't see anything obvious, though. Maybe try removing storeTime and setting the bitrate to 102000. If that doesn't do it, then I guess it's general experimenting. I think it's unlikely to be the aes encryption, it doesn't sound plausible that the Nest requires this when the others don't.

The error says the OFFER is malformed, which at face value sounds like an issue with the request format, not so much the content. So maybe experiment with the json itself (order of fields?) and it could reveal the culprit.

[Jbautista13]

I was able to build the app with a new offer template, I'll continue doing so later today and report back any new info

[BuffaloBun]

When casting to Google Nest/Home Hub (Gen 1 & 2) you are presented with:

[2023-08-12 17:45:51] [DEBUG]     cast: TX 115 sender-0 receiver-0 urn:x-cast:com.google.cast.receiver {"type":"LAUNCH","requestId":2,"appId":"85CDB22F"}
[2023-08-12 17:45:51] [DEBUG]     cast: RX 123 receiver-0 sender-0 urn:x-cast:com.google.cast.receiver {"reason":"NOT_FOUND","requestId":2,"type":"LAUNCH_ERROR"}
[2023-08-12 17:45:51] [ WARN]     cast: Device 'Kitchen display' could not launch app id '85CDB22F', trying '0F5096E8' instead
[2023-08-12 17:45:51] [DEBUG]     cast: TX 115 sender-0 receiver-0 urn:x-cast:com.google.cast.receiver {"type":"LAUNCH","requestId":3,"appId":"0F5096E8"}

and then the below error:

[2023-08-12 17:45:53] [DEBUG]     cast: RX 205 e97a135e-4979-4964-bb4d-3360b2a3628f sender-0 urn:x-cast:com.google.cast.webrtc {"error":{"code":10092,"description":"Failed to parse malformed OFFER"},"result":"error","seqNum":5,"type":"ANSWER"}

On the hub itself you can observe that the app attempts to launch and then promptly returns to screensaver/idle. Note: Casting to Google Nest Mini works fine.

Adding

"aesIvMask":"0DEAA9847B5B36DC9C23EC3EA41F5D99","aesKey":"890BDEABEAA351279B66051C37A7560C"

to OFFER appears to solve the problem of the malformed offer error and the app no longer closes to screensaver/idle, however, no audio can be heard, screen is black until casting is stopped (this applies to Google Nest Mini as well).

Casting a test mp3 from Chromium works fine and looks like:

2832700:2832799:0812/163824.436368:VERBOSE1:cast_message_handler.cc(456)] SendCastMessageToSocket: channel_id: 5, message: {source_id: sender-589345, destination_id: receiver-0, namespace: urn:x-cast:com.google.cast.receiver, payload_utf
8: {"appId":"0F5096E8","language":"en-US","requestId":31,"supportedAppTypes":["WEB"],"type":"LAUNCH"}}
[2832700:2832799:0812/163824.443087:VERBOSE1:cast_message_handler.cc(373)] OnMessage: channel_id: 5, message: {source_id: receiver-0, destination_id: sender-589345, namespace: urn:x-cast:com.google.cast.receiver, payload_utf8: {"launchReq
uestId":31,"status":"USER_ALLOWED","type":"LAUNCH_STATUS"}}
[2832700:2832799:0812/163824.447357:VERBOSE1:cast_message_handler.cc(373)] OnMessage: channel_id: 5, message: {source_id: receiver-0, destination_id: *, namespace: urn:x-cast:com.google.cast.receiver, payload_utf8: {"requestId":0,"status"
:{"userEq":{"high_shelf":{"frequency":4500.0,"gain_db":0.0,"quality":0.707},"low_shelf":{"frequency":150.0,"gain_db":0.0,"quality":0.707},"max_peaking_eqs":0,"peaking_eqs":[]},"volume":{"controlType":"master","level":0.20000000298023224,"
muted":false,"stepInterval":0.019999999552965164}},"type":"RECEIVER_STATUS"}}
[2832700:2832700:0812/163824.465426:VERBOSE1:service_discovery_device_lister.cc(54)] OnServiceUpdated: service_type: _googlecast._tcp.local, service_name: google-nest-hub-68701974a0a47477d74ef378b092dce5._googlecast._tcp.local, update: 1
[2832700:2832700:0812/163824.465474:VERBOSE1:service_discovery_device_lister.cc(75)] Adding resolver for service_name: google-nest-hub-68701974a0a47477d74ef378b092dce5._googlecast._tcp.local
[2832700:2832700:0812/163824.465735:VERBOSE1:service_discovery_device_lister.cc(91)] OnResolveComplete: service_type: _googlecast._tcp.local, service_name: google-nest-hub-68701974a0a47477d74ef378b092dce5._googlecast._tcp.local, status: 0
[2832700:2832799:0812/163824.753784:WARNING:net_errors_posix.cc(127)] Unknown error Required key not available (126) mapped to net::ERR_FAILED
[2832700:2832799:0812/163824.753873:VERBOSE1:mdns_client_impl.cc(182)] Socket error. id=2, error=-2
[2832700:2832799:0812/163824.754845:VERBOSE1:mdns_client_impl.cc(339)] MDNS OnConnectionError (code: -2)
[2832700:2832799:0812/163825.982090:VERBOSE1:cast_message_handler.cc(373)] OnMessage: channel_id: 5, message: {source_id: receiver-0, destination_id: *, namespace: urn:x-cast:com.google.cast.receiver, payload_utf8: {"requestId":31,"status":{"applications":[{"appId":"0F5096E8","appType":"WEB","displayName":"Chrome Mirroring","iconUrl":"http://lh4.ggpht.com/x-plP9YZXhCaiDkTKQ5S29PwLmdi4feEKrMOtQle4NuoOaUgKUMH9pPWIg91da3anhSmw-G8erEIuU0d","isIdleScreen":false,"launchedFromCloud":false,"namespaces":[{"name":"urn:x-cast:com.google.cast.webrtc"},{"name":"urn:x-cast:com.google.cast.remoting"},{"name":"urn:x-cast:com.google.cast.media"}],"sessionId":"c4b9fe4d-861b-4f10-9ea4-ec21534a78f8","statusText":"Chrome Mirroring","transportId":"c4b9fe4d-861b-4f10-9ea4-ec21534a78f8","universalAppId":"0F5096E8"}],"userEq":{"high_shelf":{"frequency":4500.0,"gain_db":0.0,"quality":0.707},"low_shelf":{"frequency":150.0,"gain_db":0.0,"quality":0.707},"max_peaking_eqs":0,"peaking_eqs":[]},"volume":{"controlType":"master","level":0.20000000298023224,"muted":false,"stepInterval":0.019999999552965164}},"type":"RECEIVER_STATUS"}}
[2832700:2832799:0812/163825.983496:VERBOSE1:cast_message_handler.cc(474)] Creating VC for channel: 5, source: sender-589345, dest: c4b9fe4d-861b-4f10-9ea4-ec21534a78f8
[2832972:1:0812/163826.016507:VERBOSE1:sandbox_linux.cc(78)] Activated seccomp-bpf sandbox for process type: utility.
[2832700:2832799:0812/163826.023755:VERBOSE1:cast_message_handler.cc(456)] SendCastMessageToSocket: channel_id: 5, message: {source_id: sender-589345, destination_id: c4b9fe4d-861b-4f10-9ea4-ec21534a78f8, namespace: urn:x-cast:com.google.cast.webrtc, payload_utf8: {"offer":{"castMode":"mirroring","receiverGetStatus":true,"supportedStreams":[{"aesIvMask":"<REDACTED>","aesKey":"<REDACTED>","bitRate":102000,"channels":2,"codecName":"opus","index":0,"receiverRtcpEventLog":true,"rtpExtensions":"adaptive_playout_delay","rtpPayloadType":127,"rtpProfile":"cast","sampleRate":48000,"ssrc":233618,"targetDelay":400,"timeBase":"1/48000","type":"audio_source"},{"aesIvMask":"<REDACTED>","aesKey":"<REDACTED>","codecName":"vp8","index":1,"maxBitRate":5000000,"maxFrameRate":"30000/1000","receiverRtcpEventLog":true,"renderMode":"video","resolutions":[{"height":1080,"width":1920}],"rtpExtensions":"adaptive_playout_delay","rtpPayloadType":96,"rtpProfile":"cast","ssrc":515589,"targetDelay":400,"timeBase":"1/90000","type":"video_source"}]},"seqNum":726381291,"type":"OFFER"}}

[ejurgensen]

Great info, good job looking into this. Perhaps this means that the reason it isn't working with these devices is that they require encrypted audio. Still puzzling that the same app works differently depending on device.

I guess adding AES encryption would be possible, maybe some of the stuff in raop.c can even be reused. You seem to have dived a bit into this, so if you're comfortable with C and want to give it a go, let me know.

[BuffaloBun]

Time is unfortunately not my friend at the moment, I was hoping that my investigation would be quick :smile: However I did manage to find some material that can be used as reference for encrypting/decrypting these packets. https://chromium.googlesource.com/openscreen/+/refs/heads/main/cast/streaming/frame_crypto.h https://chromium.googlesource.com/openscreen/+/refs/heads/main/cast/streaming/offer_messages.cc https://chromium.googlesource.com/openscreen/+/refs/heads/main/cast/streaming/encoded_frame.cc

[Matchlighter]

I seem to be hitting this on a Nest Hub as well. Any new developments or findings in the last month?

[anirudhra]

I can confirm this issue. Owntone would cast just fine until Google upgrade Nest Hub (2) to fuchsia. The app on the hub never seems to be launched (or it's launched and killed immediately?). It used to work when the hubs were based off chromecast OS.

[anirudhra]

I can also confirm that the casting fails only for nest hub. Nest minis work just fine with chromecast protocol. To work around Nest hub issue, I use airconnect to expose them as airplay endpoints.

My Nest hubs (2nd gen) use firmware 14.20230831.4.72 and chromecast firmware 3.72387262.