[SOLVED] Chromecast goes offline when playsound is used

jimmyalias · February 7, 2019, 5:06pm

Hello,

I have the problem my chromecast goes to offline status when i try playing a mp3 via console command:“smarthome:audio play doorbell.mp3”. This happenes with my CC audio and my CC AV. I know there is allready a toppic on this. There the solution was removing the callback url from the binding.cfg. I have done this but it doesnt work for me. Tried removing the mention of callback url, tried leaving it empty but no result. Can anybody help on this? This is the trace output of the chromecast binding:

2019-02-07 17:47:33.683 [DEBUG] [ast.internal.ChromecastStatusUpdater] - MEDIA_STATUS null

==> /var/log/openhab2/events.log <==



2019-02-07 17:47:37.008 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: null

2019-02-07 17:47:37.013 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

2019-02-07 17:47:37.016 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Found: 192.168.1.6 8009

2019-02-07 17:47:37.019 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:43.832 [DEBUG] [ast.internal.ChromecastStatusUpdater] - MEDIA_STATUS null

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:47.800 [DEBUG] [ast.internal.ChromecastStatusUpdater] - MEDIA_STATUS MediaStatus{activeTrackIds: <null>, mediaSessionId: 2, playbackRate: 1, playerState: IDLE, currentItemId: 2, currentTime: 0.000000, customData: <null>, loadingItemId: null, items: <null>, preloadedItemId: null, supportedMediaCommands: 274447, volume: Volume{level: 1.0, muted: false, increment: 0.05, stepInterval: 0.05000000074505806, controlType: null}, media: Media{url: /audio/0e862f6b-9860-4dbc-ab2d-812874c38541, contentType: audio/mpeg, duration: null}, repeatMode: REPEAT_OFF, idleReason: null}

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:47.814 [vent.ItemStateChangedEvent] - currentTime changed from UNDEF to 0.0

2019-02-07 17:47:47.917 [vent.ItemStateChangedEvent] - title changed from UNDEF to Notification

2019-02-07 17:47:47.922 [vent.ItemStateChangedEvent] - statustext changed from Default Media Receiver to Casting: Notification

==> /var/log/openhab2/openhab.log <==

2019-02-07 17:47:47.976 [DEBUG] [omecast.internal.ChromecastCommander] - Failed playing media: Unable to load media

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:47.982 [hingStatusInfoChangedEvent] - 'chromecast:chromecast:myCC' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unable to load media

2019-02-07 17:47:48.006 [hingStatusInfoChangedEvent] - 'chromecast:chromecast:myCC' changed from OFFLINE (COMMUNICATION_ERROR): Unable to load media to ONLINE

2019-02-07 17:47:48.024 [vent.ItemStateChangedEvent] - statustext changed from Casting: Notification to Default Media Receiver

2019-02-07 17:47:54.179 [DEBUG] [ast.internal.ChromecastStatusUpdater] - MEDIA_STATUS MediaStatus{activeTrackIds: <null>, mediaSessionId: 2, playbackRate: 1, playerState: IDLE, currentItemId: 2, currentTime: 0.000000, customData: <null>, loadingItemId: null, items: <null>, preloadedItemId: null, supportedMediaCommands: 274447, volume: Volume{level: 1.0, muted: false, increment: 0.05, stepInterval: 0.05000000074505806, controlType: null}, media: Media{url: /audio/0e862f6b-9860-4dbc-ab2d-812874c38541, contentType: audio/mpeg, duration: null}, repeatMode: null, idleReason: ERROR}

2019-02-07 17:47:54.395 [DEBUG] [omecast.internal.ChromecastCommander] - Media player app stopped

2019-02-07 17:47:54.402 [DEBUG] [ast.internal.ChromecastEventReceiver] - Unhandled event type: java.lang.Object@4c8080

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:54.402 [vent.ItemStateChangedEvent] - appName changed from Default Media Receiver to UNDEF

2019-02-07 17:47:54.417 [vent.ItemStateChangedEvent] - appId changed from CC1AD845 to UNDEF

2019-02-07 17:47:54.421 [vent.ItemStateChangedEvent] - statustext changed from Default Media Receiver to UNDEF

2019-02-07 17:47:54.424 [vent.ItemStateChangedEvent] - idling changed from OFF to ON

==> /var/log/openhab2/openhab.log <==

2019-02-07 17:47:55.421 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

2019-02-07 17:47:55.423 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Found: 192.168.1.6 8009

2019-02-07 17:47:55.426 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

==> /var/log/openhab2/events.log <==

2019-02-07 17:47:57.328 [vent.ItemStateChangedEvent] - appName changed from UNDEF to Backdrop

2019-02-07 17:47:57.358 [vent.ItemStateChangedEvent] - appId changed from UNDEF to E8C28D3C

2019-02-07 17:47:57.370 [vent.ItemStateChangedEvent] - statustext changed from UNDEF to 

2019-02-07 17:47:58.931 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: null

==> /var/log/openhab2/events.log <==


2019-02-07 17:48:17.052 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: null

2019-02-07 17:48:17.058 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

2019-02-07 17:48:17.062 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Found: 192.168.1.6 8009

2019-02-07 17:48:17.066 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

==> /var/log/openhab2/events.log <==

2019-02-07 17:48:34.467 [DEBUG] [omecast.internal.ChromecastCommander] - Failed to request media status with a running app: Waiting for response timed out

==> /var/log/openhab2/events.log <==

2019-02-07 17:48:38.934 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: null

==> /var/log/openhab2/events.log <==

2019-02-07 17:48:56.974 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: null

2019-02-07 17:48:56.977 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

2019-02-07 17:48:56.981 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Found: 192.168.1.6 8009

2019-02-07 17:48:56.983 [DEBUG] [overy.ChromecastDiscoveryParticipant] - Chromecast Type: Chromecast

Casting from phone works just fine.
Thanks

jimmyalias · February 7, 2019, 5:22pm

Ok seems like the problem lays with the default audiosink in openhab. Before i set CC audio as default in paperUI (and hit save ) but when using command :“smarthome:audio play doorbell.mp3” in the console it didn’t play. Now i specified the audiosink in the command like: “smarthome:audio play chromecast:audio:myCC doorbell.mp3” and now it did play. Strange

wlanrouter1 · January 23, 2024, 4:34pm

I have the same issue but with Chomecast.

If I use the console command:

openhab:audio play doorbell.mp3

or:

openhab:audio play chromecast:chromecast:52116d144816c25a3d722fa625f11b8e doorbell.mp3

Or within the rule:

say("Hello World")

Or more detailed in rule:

say("Hello World","marytts:bits3hsmm","chromecast:chromecast:52116d144816c25a3d722fa625f11b8e")

I always get this error in console logging:

Thing 'chromecast:chromecast:68e84c132317d2e8edf03d0ec9e1d91b' changed from OFFLINE (COMMUNICATION_ERROR): IOException while trying to play media: Waiting for response timed out to ONLINE

But if I use it as an Item (which has the same channel) related rule command it works:

MyChromecast_Volume .sendCommand(40)
MyChromecast_PlayURI .sendCommand("http://192.168.91.11:8080/static/text/helloWorld.mp3")
MyChromecast_Control .sendCommand(ON)

I assume it happend after updating from Openhab3 to Openhab4, but as I had more issues, I can not confirm it. It worked fine in OH3 for sure for at least a year.
I have tested different text-to-speech Addons and tried changes in the settings, I am pretty sure the problem is not in the Addons as the doorbell is also not playing.

Raspberry Pi5

openhab> system:version
4.4.4

openhab> info
Karaf
  Karaf version               4.4.4
  Karaf home                  /usr/share/openhab/runtime
  Karaf base                  /var/lib/openhab
  OSGi Framework              org.eclipse.osgi-3.18.0.v20220516-2155

JVM
  Java Virtual Machine        OpenJDK Client VM version 17.0.9+9-Raspbian-1deb12u1rpt1
  Version                     17.0.9
  Vendor                      Raspbian
  Pid                         806
  Uptime                      5 days 22 hours
  Process CPU time            1 hour 58 minutes
  Process CPU load            0.01
  System CPU load             0.02
  Open file descriptors       262
  Max file descriptors        102,642
  Total compile time          37.187 seconds
Threads
  Live threads                376
  Daemon threads              146
  Peak                        385
  Total started               203233
Memory
  Current heap size           631,833 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         654,444 kbytes
  Pending objects             0
  Garbage collector           Name = 'Copy', Collections = 2870, Time = 52.695 seconds
  Garbage collector           Name = 'MarkSweepCompact', Collections = 8, Time = 5.389 seconds
Classes
  Current classes loaded      29,497
  Total classes loaded        51,904
  Total classes unloaded      22,407
Operating system
  Name                        Linux version 6.1.0-rpi6-rpi-v8
  Architecture                arm
  Processors                  4
  Total physical memory       4,088,948 kbytes
  Free physical memory        186,128 kbytes

openhab> openhab:audio sinks
* MyChromecast (chromecast:chromecast:68e84c132317d2e8edf03d0ec9e1d91b)
  System Speaker (enhancedjavasound)
  Web Audio (webaudio)

openhab> voice voices
* MaryTTS - Deutsch - bits1-hsmm (marytts:bits1hsmm)
  MaryTTS - Deutsch - bits3-hsmm (marytts:bits3hsmm)
  MaryTTS - Englisch (Vereinigte Staaten) - cmu-slt-hsmm (marytts:cmuslthsmm)

wlanrouter1 · January 24, 2024, 7:44am

Additional “debug” logging after console command

openhab:audio play chromecast:chromecast:52116d144816c25a3d722fa625f11b8e doorbell.mp3

08:37:44.958 [DEBUG] [handler.ChromecastHandler$Coordinator] - Connect failed, trying to reconnect: No route to host
08:37:44.959 [DEBUG] [romecast.internal.ChromecastScheduler] - Canceling connection
08:37:44.959 [DEBUG] [romecast.internal.ChromecastScheduler] - Scheduling connection
08:37:49.728 [DEBUG] [cast.internal.ChromecastStatusUpdater] - MEDIA_STATUS null
08:37:49.743 [DEBUG] [cast.internal.ChromecastStatusUpdater] - MEDIA_STATUS MediaStatus{activeTrackIds: <null>, mediaSessionId: 3, playbackRate: 1, playerState: IDLE, currentItemId: 1, currentTime: 0.000000, customData: <null>, loadingItemId: null, items: <null>, preloadedItemId: null, supportedMediaCommands: 12303, volume: Volume{level: 1.0, muted: false, increment: 0.05, stepInterval: 0.05000000074505806, controlType: null}, media: null, repeatMode: null, idleReason: ERROR}
08:37:49.814 [DEBUG] [cast.internal.ChromecastStatusUpdater] - MEDIA_STATUS MediaStatus{activeTrackIds: <null>, mediaSessionId: 4, playbackRate: 1, playerState: IDLE, currentItemId: 1, currentTime: 0.000000, customData: <null>, loadingItemId: null, items: <null>, preloadedItemId: null, supportedMediaCommands: 12303, volume: Volume{level: 1.0, muted: false, increment: 0.05, stepInterval: 0.05000000074505806, controlType: null}, media: Media{url: http://172.20.0.1:8080/audio/c2e2e362-23af-4774-8453-aa81de12dea3, contentType: audio/mpeg, duration: null}, repeatMode: REPEAT_OFF, idleReason: null}
08:37:50.849 [DEBUG] [cast.internal.ChromecastStatusUpdater] - MEDIA_STATUS MediaStatus{activeTrackIds: <null>, mediaSessionId: 4, playbackRate: 1, playerState: BUFFERING, currentItemId: 1, currentTime: 0.000000, customData: <null>, loadingItemId: null, items: <null>, preloadedItemId: null, supportedMediaCommands: 12303, volume: Volume{level: 1.0, muted: false, increment: 0.05, stepInterval: 0.05000000074505806, controlType: null}, media: null, repeatMode: REPEAT_OFF, idleReason: null}
08:37:50.851 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'MyChromecast_Control' changed from PAUSE to PLAY
08:37:50.863 [DEBUG] [covery.ChromecastDiscoveryParticipant] - Chromecast Type: null
08:37:50.863 [DEBUG] [covery.ChromecastDiscoveryParticipant] - Chromecast Type: Google Home Mini
08:37:50.864 [DEBUG] [covery.ChromecastDiscoveryParticipant] - Chromecast Found: 192.168.91.45 8009
08:37:50.864 [DEBUG] [covery.ChromecastDiscoveryParticipant] - Chromecast Type: Google Home Mini
08:37:58.014 [DEBUG] [handler.ChromecastHandler$Coordinator] - Connect failed, trying to reconnect: No route to host
08:37:58.015 [DEBUG] [romecast.internal.ChromecastScheduler] - Canceling connection
08:37:58.015 [DEBUG] [romecast.internal.ChromecastScheduler] - Scheduling connection
08:38:11.070 [DEBUG] [handler.ChromecastHandler$Coordinator] - Connect failed, trying to reconnect: No route to host
08:38:11.071 [DEBUG] [romecast.internal.ChromecastScheduler] - Canceling connection
08:38:11.071 [DEBUG] [romecast.internal.ChromecastScheduler] - Scheduling connection
08:38:19.750 [DEBUG] [romecast.internal.ChromecastCommander] - Failed playing media: Waiting for response timed out
08:38:19.754 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'chromecast:chromecast:52116d144816c25a3d722fa625f11b8e' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): IOException while trying to play media: Waiting for response timed out
08:38:24.126 [DEBUG] [handler.ChromecastHandler$Coordinator] - Connect failed, trying to reconnect: No route to host
08:38:24.128 [DEBUG] [romecast.internal.ChromecastScheduler] - Canceling connection
08:38:24.129 [DEBUG] [romecast.internal.ChromecastScheduler] - Scheduling connection

Any clue how to dig deeper?