philippe44 / LMS-Cast

Chromecast to LMS bridge
65 stars 10 forks source link

No Volume Control #5

Closed nick295 closed 7 years ago

nick295 commented 7 years ago

I've got your pluggin up and running. If I set the volume control so that it ignores the commands from the server I can get audio out of my speakers. If I set it so that the server can control the volume I don't get any audio. Looking at the log it keeps resetting the volume to zero. Is there something I can change so that I can control the volume? Thanks

philippe44 commented 7 years ago

Can you post a log and have you tried the latest 2.4.1 version? I did some changes to fix a similar problem on sound management.

nick295 commented 7 years ago

I am running 2.4.1. Here is the log file. I have tried all 3 volume control settings and the only one that works is to have the CCA ignore volume commands. Let me know if you need anymore information.

Starting Squeeze2cast: /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/CastBridge/Bin/squeeze2cast-armv5el -Z -I -f /var/log/squeezeboxserver/castbridge.log -d output=debug -x /var/lib/squeezeboxserver/prefs/castbridge.xml [06:37:22.751019] main:1172 Starting squeeze2cast version: v0.2.4.1 (Dec 23 2016 @ 19:30:35)

[06:37:22.795569] Initialize:812 UPnP init success - 192.168.1.10:49152 [06:37:38.047756] AddCastDevice:902 [0xb41e4]: adding renderer (BlackWebGunner) [06:37:38.193510] CastConnect:388 [0xb41e4]: SSL connection opened [0xb1f00928] [06:37:38.195976] sq_run_device:1208 Buffer path /tmp [06:37:38.202929] output_mr_thread_init:826 [0x556d8] init output media renderer [06:37:38.206329] slimproto_thread_init:1004 [0x556d8] connecting to 192.168.1.10:3483 [06:37:38.215290] slimproto:913 [0x556d8] connected [06:37:38.215578] sendHELO:133 [0x556d8] cap: Model=squeezelite,ModelName=SqueezeLite,AccuratePlayPoints=0,HasDigitalOut=0,MaxSampleRate=96000,pcm,aif,flc,mp3 [06:37:38.224978] output_flush:904 [0x556d8]: flush output buffer [06:37:38.234941] sq_callback:359 Volume 30 [06:38:13.917071] sq_callback:359 Volume 100 [06:38:13.923527] sq_callback:359 Volume 100 [06:38:13.923814] CastSetDeviceVolume:309 [0xb41e4]: Queuing SET_VOLUME [06:38:14.449300] MRThread:566 [0xb41e4]: Volume local change 0 [06:38:14.450150] cli_open_socket:269 [0x556d8]: opened CLI socket 11 [06:38:14.481696] sq_callback:359 Volume 0 [06:38:14.482227] sq_callback:359 Volume 0 [06:38:23.933216] sq_callback:359 Volume 90 [06:38:23.944865] sq_callback:359 Volume 90 [06:38:23.945158] CastSetDeviceVolume:309 [0xb41e4]: Queuing SET_VOLUME [06:38:26.455556] MRThread:566 [0xb41e4]: Volume local change 0 [06:38:26.476700] sq_callback:359 Volume 0 [06:38:26.477201] sq_callback:359 Volume 0 [06:38:37.002845] slimproto_run:645 [0x556d8] Closing CLI socket 11 [06:38:43.228070] sq_callback:359 Volume 50 [06:38:43.233584] sq_callback:359 Volume 50 [06:38:43.233866] CastSetDeviceVolume:309 [0xb41e4]: Queuing SET_VOLUME [06:38:44.517424] MRThread:566 [0xb41e4]: Volume local change 0 [06:38:44.518374] cli_open_socket:269 [0x556d8]: opened CLI socket 11 [06:38:44.549931] sq_callback:359 Volume 0 [06:38:44.550462] sq_callback:359 Volume 0 [06:38:57.002610] slimproto_run:645 [0x556d8] Closing CLI socket 11

philippe44 commented 7 years ago

Is this a true Google CCA or a CC-compatible device? What happens is that my app detects when volume is changed on the CC using another "remote" and then it forward this info back to LMS which in return set the volume. In your case, the "local volume change" is always detected to be 0, so LMS reflects it an re-programs it to 0. Is your device part of a synchronized group? What have you set for MediaVolume? if you are not running on a PI original model, can you try to use the armv6hf version? In settings, can you set the additional debugging to "casting debugging"

nick295 commented 7 years ago

It is a true Chromecast Audio. Its not part of any group. I do have the Google Home app installed on my phone so that I can cast to it and the notification that something is casting to it comes up in my notification bar, but I don't have the ability to change the volume there either. The media volume is set to 50.

philippe44 commented 7 years ago

I was editing my comments live :-) here are the additions

if you are not running on a PI original model, can you try to use the armv6hf version? In settings, can you set the additional debugging to "casting debugging"

nick295 commented 7 years ago

I have my server running on an original pi so I can't use that version. Here is a log with the casting debugging.

Starting Squeeze2cast: /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/CastBridge/Bin/squeeze2cast-armv5el -Z -I -f /var/log/squeezeboxserver/castbridge.log -d cast=debug -x /var/lib/squeezeboxserver/prefs/castbridge.xml [12:55:37.776071] main:1172 Starting squeeze2cast version: v0.2.4.1 (Dec 23 2016 @ 19:30:35)

[12:55:37.806614] Initialize:812 UPnP init success - 192.168.1.10:49152 [12:57:23.272612] AddCastDevice:902 [0xb41e4]: adding renderer (BlackWebGunner) [12:57:23.610816] CastConnect:388 [0xb41e4]: SSL connection opened [0xb2200750] [12:57:23.612045] SendCastMessage:272 [0xb2200750]: Cast sending: {"type":"CONNECT"} [12:57:23.612937] sq_run_device:1208 Buffer path /tmp [12:57:23.622830] slimproto_thread_init:1004 [0x556d8] connecting to 192.168.1.10:3483 [12:57:23.630511] slimproto:913 [0x556d8] connected [12:57:23.630803] sendHELO:133 [0x556d8] cap: Model=squeezelite,ModelName=SqueezeLite,AccuratePlayPoints=0,HasDigitalOut=0,MaxSampleRate=96000,pcm,aif,flc,mp3 [12:57:23.804766] sq_callback:359 Volume 0 [12:57:23.806181] SendCastMessage:272 [0xb2200750]: Cast sending: {"type":"SET_VOLUME","requestId":2,"volume":{"muted":true}}

[12:57:26.680852] CastSocketThread:699 [0xb2208678]: recvID 1 (waitID 2)

[12:57:29.690454] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:32.697941] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:35.710503] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:38.720932] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:41.726272] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:44.740447] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:47.750416] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:50.775268] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:57:53.818829] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0) [12:57:56.086522] sq_callback:359 Volume 70 [12:57:56.087771] SendCastMessage:272 [0xb2200750]: Cast sending: {"type":"SET_VOLUME","requestId":4,"volume":{"level":0.700000,"muted":false}} [12:57:56.091963] sq_callback:359 Volume 70 [12:57:56.092244] CastSetDeviceVolume:309 [0xb41e4]: Queuing SET_VOLUME

[12:57:56.134940] CastSocketThread:699 [0xb2208678]: recvID 3 (waitID 0)

[12:57:56.139383] CastSocketThread:699 [0xb2208678]: recvID 3 (waitID 4)

[12:57:56.780854] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0) [12:57:56.781511] MRThread:566 [0xb41e4]: Volume local change 0 [12:57:56.782283] cli_open_socket:269 [0x556d8]: opened CLI socket 10 [12:57:58.421410] sq_callback:359 Volume 0 [12:57:58.436790] SendCastMessage:272 [0xb2200750]: Cast sending: {"type":"SET_VOLUME","requestId":6,"volume":{"muted":true}} [12:57:58.437306] sq_callback:359 Volume 0 [12:57:58.437945] CastSetDeviceVolume:309 [0xb41e4]: Queuing SET_VOLUME

[12:57:58.480772] CastSocketThread:699 [0xb2208678]: recvID 5 (waitID 0)

[12:57:59.790791] CastSocketThread:699 [0xb2208678]: recvID 5 (waitID 6)

[12:58:02.798851] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:58:05.840510] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0) [12:58:08.002495] slimproto_run:645 [0x556d8] Closing CLI socket 10

[12:58:08.855430] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

[12:58:11.860556] CastSocketThread:699 [0xb2208678]: recvID 0 (waitID 0)

philippe44 commented 7 years ago

I think it's likely a floating point management issue in a library with the armv5el version. I will investigate further but It's going to take me a week or so

nick295 commented 7 years ago

Thank you. Let me know if you need any other information.

philippe44 commented 7 years ago

if you ever have the chance to try on another computer, that would help me by confirming that this is linked to armv5 and not your CCA. The application does not need to run on the same machine with LMS. You can take any of the binaries found here and run it on a WIndows, Linux x86/64 or OSX computer. No config is needed, just launch it (Windows version requires the DLL as well)

philippe44 commented 7 years ago

One thing you could do for me is to take a log and set "additional debugging" to "none" but, in the extra command line option, set "-d cast=sdebug". It will create a pretty verbose file for the cast protocol but should allow me to see immediately if the sound reported by the player is really 0 or if this is a floating point conversion problem, as I suspect. You can zip the logfile an PM it so me

nick295 commented 7 years ago

I found a way to adjust the volume using the Google Home app on my phone, and if I do this I can control the volume but it doesn't get reported back to LMS, it still says displays the volume as 0. And if I try to adjust it with LMS it resets the volume to 0, which I can see in the Home app.

Was going to try installing the plugin on my laptop, but couldn't figure out what to do after downloading the files. I'm used to arduino type programming, but very new to computer programming. If you can provide me step by step instructions I can try that too.

Couldn't figure out how to PM you so we'll see if it will let me attach it. sdebug_log.zip

philippe44 commented 7 years ago

I've found the reason but the fix is complicated. It's due to the machine I'm using to build and an incompatibility between GNU libc versions when using emulated floating point calculation ... grrr. You can use the 'static' version meanwhile, it should work

philippe44 commented 7 years ago

Corrected in 0.2.5.1