philippe44 / LMS-YouTube

Play YouTube videos on LMS
38 stars 15 forks source link

Better error message when trying to play vorbis/opus stream #24

Closed alexanderadam closed 4 years ago

alexanderadam commented 4 years ago

I'm not quite sure whether this is possible, but I ran into the vorbis/opus issue and the Squeezebox just showed problem: unable to play file type for $youtube_title. It didn't even show anything about "vorbis" or "opus". I had to look in the LMS log to find Slim::Player::Song::open (409) Error: Couldn't create command line for ops playback for [youtube://www.youtube.com/v/… and thus finding the reason.

So I guess it would be great if the error message could be improved.

Apart from that the plugin is working flawlessly for me, so thank you so much for maintaining it and your work on LSM things in general! :pray: Your work is really outstanding!

PS: Do you know what could be missing when this error occurs? I'm using @apnar's Docker image and I thought that all required dependencies should be available?

philippe44 commented 4 years ago

Thank you :-)

That error should not occur - can you send me an URL when it happens?

alexanderadam commented 4 years ago

I have to thank you, Philippe! :wink: It happens on every YouTube URL for me as long vorbis/opus is activated. I'm not the only one as I saw others having the same problem in the Forum and some mailing lists. Can I give you some data or log helping you to debug this?

philippe44 commented 4 years ago

Have you tried version 0.110.2? I've just uploaded 0.120 and integrated a PR which seems to have broken things, but AFAIK, vorbis/opus works for me on every single track on 0.110.2

philippe44 commented 4 years ago

I missed the initial comment. I think one of of the transcoder is missing in your setup, seems to be sox. What player are you using? You should try to set "player.source" logging to debug and see what's being spit out.

alexanderadam commented 4 years ago

I missed the initial comment. I think one of of the transcoder is missing in your setup, seems to be sox. What player are you using? You should try to set "player.source" logging to debug and see what's being spit out.

sox is installed in the image and these are the specs of the player that I use:

Player Model: Squeezebox Radio Player Type: baby Firmware: 7.7.3-r16676 The plugin has version v0.110.2

I increased logging and this is the output (click to expand). ``` Slim::Player::StreamingController::stop (2097) 00:12:34:56:78:90 Slim::Player::StreamingController::_eventAction (273) 00:12:34:56:78:90: Stop in STOPPED-IDLE -> Slim::Player::StreamingController::_NoOp Slim::Player::Song::DESTROY (160) DESTROY(Slim::Player::Song=ARRAY(0x9c2aec0)) live=2: index=0, url=youtube://www.youtube.com/v/GKSRyLdjsPA Slim::Player::StreamingController::resetSongqueue (1776) Song queue is now Slim::Player::StreamingController::playerActive (1993) 00:12:34:56:78:90 player already active: 00:12:34:56:78:90 Slim::Player::StreamingController::play (2100) 00:12:34:56:78:90 Slim::Player::StreamingController::_eventAction (273) 00:12:34:56:78:90: Play in STOPPED-IDLE -> Slim::Player::StreamingController::_StopGetNext Slim::Player::StreamingController::_eventAction (284) params: index => 0 seekdata => undef Slim::Player::StreamingController::_setPlayingState (2357) new playing state STOPPED Slim::Player::StreamingController::_setStreamingState (2366) new streaming state IDLE Slim::Player::Song::new (108) index 0 -> youtube://www.youtube.com/v/nYh-n7EOtMA Slim::Player::Song::new (150) live=3 Slim::Player::StreamingController::_setStreamingState (2366) new streaming state TRACKWAIT Slim::Player::StreamingController::_playersMessage (789) Getting stream info...: youtube://www.youtube.com/v/nYh-n7EOtMA Slim::Player::Song::getNextSong (229) youtube://www.youtube.com/v/nYh-n7EOtMA Slim::Player::StreamingController::_eventAction (303) 00:12:34:56:78:90: Play - new state STOPPED-TRACKWAIT Slim::Player::StreamingController::_nextTrackReady (737) 00:12:34:56:78:90: nextTrack will be index 0 Slim::Player::StreamingController::_eventAction (273) 00:12:34:56:78:90: NextTrackReady in STOPPED-TRACKWAIT -> Slim::Player::StreamingController::_Stream Slim::Player::StreamingController::_Stream (1203) Song queue is now 0 Slim::Player::StreamingController::_Stream (1206) 00:12:34:56:78:90: preparing to stream song index 0 Slim::Player::Song::open (363) youtube://www.youtube.com/v/nYh-n7EOtMA Slim::Player::Song::open (387) seek=false time=0 canSeek=1 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-alc-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-alc-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-alc-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-alc-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wma-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wma-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wma-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wma-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmap-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmap-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmap-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmap-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmal-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmal-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmal-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-wmal-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aac-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aac-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aac-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aac-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spt-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spt-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spt-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spt-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-ogg-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-ogg-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-ogg-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-ogg-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-flc-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-flc-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-flc-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-flc-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aif-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aif-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aif-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-aif-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-pcm-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-pcm-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-pcm-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-pcm-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-mp3-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-mp3-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-mp3-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-mp3-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spdr-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spdr-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spdr-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-spdr-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-test-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-test-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-test-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: ops-test-*-* Slim::Player::TranscodingHelper::getConvertCommand2 (443) Error: Didn't find any command matches for type: ops Slim::Player::Song::open (409) Error: Couldn't create command line for ops playback for [youtube://www.youtube.com/v/nYh-n7EOtMA] Slim::Player::StreamingController::_playersMessage (789) Problem: Unable to play file type for:: youtube://www.youtube.com/v/nYh-n7EOtMA Slim::Player::StreamingController::_willRetry (1391) no retry data Slim::Player::StreamingController::_setStreamingState (2366) new streaming state IDLE Slim::Player::StreamingController::nextsong (882) The next song is number 0, was 0 Slim::Player::StreamingController::_eventAction (303) 00:12:34:56:78:90: NextTrackReady - new state STOPPED-IDLE ```

PS: Did you see my PR to extend the README?

**PPS:** Later on it also complains about not being able to play `aac` but it doesn't seem to be related to YouTube (click to expand) ``` Slim::Player::TranscodingHelper::checkBin (252) Found command: [faad] -q -w -f 1 $FILE$ | [lame] --silent -q $QUALITY$ $BITRATE$ - - Slim::Player::TranscodingHelper::getConvertCommand2 (373) Rejecting [faad] -q -w -f 1 $FILE$ | [lame] --silent -q $QUALITY$ $BITRATE$ - - because no available stream mode supported: R Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-spdr-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-spdr-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-spdr-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-spdr-*-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-test-baby-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-test-*-00:12:34:56:78:90 Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-test-baby-* Slim::Player::TranscodingHelper::checkBin (242) Checking formats for: aac-test-*-* Slim::Player::TranscodingHelper::getConvertCommand2 (443) Error: Didn't find any command matches for type: aac ```

PPPS: I also saw another error when I was switching tracks. Everything seemed to work fine, though and I'm not sure whether this one is related to the youtube plugin at all. I just saw youtube in the backtrace (Plugins/YouTube/M4a.pm line 134 — click to expand).

``` Slim::Schema::objectForUrl (814) Error: Null track request! Returning undef. Slim::Schema::objectForUrl (814) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema.pm line 814) frame 1: Slim::Schema::objectForUrl (/usr/share/perl5/Slim/Player/ReplayGain.pm line 116) frame 2: Slim::Player::ReplayGain::findTracksByIndex (/usr/share/perl5/Slim/Player/ReplayGain.pm line 200) frame 3: Slim::Player::ReplayGain::trackSampleRateMatch (/usr/share/perl5/Slim/Player/Squeezebox.pm line 965) frame 4: Slim::Player::Squeezebox::stream_s (/usr/share/perl5/Slim/Player/Squeezebox.pm line 167) frame 5: Slim::Player::Squeezebox::play (/usr/share/perl5/Slim/Player/Squeezebox2.pm line 391) frame 6: Slim::Player::Squeezebox2::play (/usr/share/perl5/Slim/Player/StreamingController.pm line 1283) frame 7: Slim::Player::StreamingController::_Stream (/usr/share/perl5/Slim/Player/StreamingController.pm line 288) frame 8: Slim::Player::StreamingController::_eventAction (/usr/share/perl5/Slim/Player/StreamingController.pm line 739) frame 9: Slim::Player::StreamingController::_nextTrackReady (/usr/share/perl5/Slim/Player/StreamingController.pm line 693) frame 10: Slim::Player::StreamingController::__ANON__ (/srv/squeezebox/cache/InstalledPlugins/Plugins/YouTube/M4a.pm line 134) frame 11: Plugins::YouTube::M4a::__ANON__ (/usr/share/perl5/Slim/Networking/Async/HTTP.pm line 483) frame 12: Slim::Networking::Async::HTTP::_http_read_body (/usr/share/perl5/Slim/Networking/IO/Select.pm line 123) frame 13: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 119) frame 14: Slim::Networking::IO::Select::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 168) frame 15: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 168) frame 16: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 727) frame 17: main::idle (/usr/sbin/squeezeboxserver line 677) frame 18: main::main (/usr/sbin/squeezeboxserver line 1213) ```
philippe44 commented 4 years ago

Very strange - what are your convert.conf and custom-convert.conf? I'm hesitating with the README because that talks about opus/vorbis as I think this is specific to a problem with your configuration

alexanderadam commented 4 years ago

I never touched those files and I don't think they're modified in the rest of the simple Docker setup.

However, I just saw that I was using an older LMS release (7.x). I just updated to 8 and now everything is working again. I'm so sorry Philippe! :see_no_evil:

I'm hesitating with the README because that talks about opus/vorbis as I think this is specific to a problem with your configuration

The setup doesn't change anything regarding codecs.

Also this seem to happen in other cases as well (this is how I found out that disabling vorbis works in the first place :wink:). See this forum entry of the user Squid or this GitHub comment.

They might have had different causes but you can't have problems with vorbis logic if you disable it, right? :wink: Furthermore it solved to problem.

However, I just removed the part with the solution from the README now as that's your wish.

philippe44 commented 4 years ago

There was indeed a problem with vorbis/opus but that was a while ago and I corrected it, hence I was confused. You absolutely can remove opus/vorbis support but these are good, modern, codecs and I donc know how much YT will support aac in the future. They already have abandoned codecs in the past and the trend for them really seems to be opus