Home of the Squeezebox™ & Transporter® network music players.
Page 1 of 5 123 ... LastLast
Results 1 to 10 of 46
  1. #1

    (Some) music not playing on (some) players

    Hey all,

    I've been reading posts on this forum for some time since I started using LMS, and I'm impressed by all the help & knowledge provided on this forum!
    Unfortunately, I have a need for a help thread myself since yesterday.

    I've installed the latest LMS 8.0 build on my Synology DS212+, which installed just fine. I can see my music files in the library, and I've setup the Youtube plugin as well.
    I can play music from YouTube fine on my Google Mini Nest (using the chromecast bridge plugin), but when I try to play the same music on my RPi-squeezelite the songs just keep skipping immediately. I've checked the logs, I can't find anything going wrong in the YouTube plugin logging. I see the same symptom when playing music files from the NAS itself. When playing a radio stream, it plays fine on the squeezelite player.
    The NAS resources are not 100%, but when trying to play a YouTube-stream I can see that the NAS is (at least trying to) processing the stream (+- 150 kb/s download, cpu goes up to 80%, memory usage increases).

    I suspect the NAS is having an issue with certain filetypes or the like, but I don't have enough knowledge on LMS to figure out what is going on. Is there anybody that can give me some clues as to what could be wrong?
    I'm happy to provide any information that could help with figuring this out.

    Thanks in advance!!!

  2. #2
    Senior Member
    Join Date
    Apr 2005
    Location
    UK/London
    Posts
    3,109
    Have a look in the LMS logs - it may well show some conversion failures.
    From LMS web interface - click Settings (bottom right) and then the Information tab.
    Paul Webster
    http://dabdig.blogspot.com
    Author of "Now Playing" plugins covering Radio France (FIP etc), KCRW, Supla Finland, ABC Australia, CBC/Radio-Canada and RTE Ireland

  3. #3
    Quote Originally Posted by Paul Webster View Post
    Have a look in the LMS logs - it may well show some conversion failures.
    From LMS web interface - click Settings (bottom right) and then the Information tab.
    I checked those earlier and couldn't find anything indicating an error. Any particular group that needs to be increased in log level to give a clue? I'll reproduce the issue and post the logs here.

  4. #4
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    19,546
    Quote Originally Posted by Hawkeyenl View Post
    I checked those earlier and couldn't find anything indicating an error. Any particular group that needs to be increased in log level to give a clue? I'll reproduce the issue and post the logs here.
    Player.source to INFO

    It "feels" like one of the transcoding/resampling support executables is not working. The log will show which ones are trying to be used.

  5. #5
    Ok so I set the player.source logging to INFO, which now gives me the following information when playing a song fails:

    20-10-25 17:45:40.7550] Slim::Player::Song:pen (489) URL is a song (audio): youtube://www.youtube.com/v/RUTyS7v0ZF0, type=ops
    [20-10-25 17:45:40.7584] Slim::Player::TranscodingHelper::tokenizeConvertCo mmand2 (641) Using command for conversion: "/volume2/@appstore/SqueezeCenter/Bin/sox" -t opus - -t flac -C 0 -
    [20-10-25 17:45:40.7602] Slim::Player::Song:pen (565) Tokenized command: "/volume2/@appstore/SqueezeCenter/Bin/sox" -t opus - -t flac -C 0 -
    [20-10-25 17:45:40.8110] Slim::Player::StreamingController::_Stream (1282) 01:c6:83:66:f3:f2: stream
    [20-10-25 17:45:40.8343] Slim::Player::StreamingController::_Stream (1319) Song queue is now 24
    [20-10-25 17:45:40.8367] Slim::Player::StreamingController::_setPlayingStat e (2377) new playing state BUFFERING
    [20-10-25 17:45:40.8446] Slim::Player::StreamingController::_setStreamingSt ate (2386) new streaming state STREAMING
    [20-10-25 17:45:40.9462] Slim::Player::Player::_buffering (1144) Buffering... 0 / 261120
    [20-10-25 17:45:41.0933] Slim::Player::Source::_readNextChunk (372) end of file or error on socket, song pos: 0
    [20-10-25 17:45:41.0950] Slim::Player::Source::_readNextChunk (377) 01:c6:83:66:f3:f2 mark end of stream
    [20-10-25 17:45:41.0966] Slim::Player::Source::_readNextChunk (385) Didn't stream any bytes for this song; mark it as failed
    [20-10-25 17:45:41.0984] Slim::Player::StreamingController:layerStreamingFailed (2248) 01:c6:83:66:f3:f2
    [20-10-25 17:45:41.1004] Slim::Player::StreamingController::_playersMessage (796) Problem: Can't open file for:: youtube://www.youtube.com/v/RUTyS7v0ZF0
    [20-10-25 17:45:41.1131] Slim::Player::StreamingController::_Stop (610) Song queue is now 24
    [20-10-25 17:45:41.1152] Slim::Player::StreamingController::_setPlayingStat e (2377) new playing state STOPPED
    [20-10-25 17:45:41.1169] Slim::Player::StreamingController::_setStreamingSt ate (2386) new streaming state IDLE
    [20-10-25 17:45:41.1193] Slim::Player::StreamingController::_willRetry (1408) no retry data
    [20-10-25 17:45:41.1215] Slim::Player::StreamingController::nextsong (889) The next song is number 0, was 24
    [20-10-25 17:45:41.3340] Slim::Player::StreamingController:layerReadyToStream (2218) 01:c6:83:66:f3:f2
    [20-10-25 17:45:41.3358] Slim::Player::StreamingController::_Invalid (326) 01:c6:83:66:f3:f2: event ReadyToStream received while in invalid state STOPPED-IDLE
    [20-10-25 17:45:41.3375] Slim::Player::StreamingController::_Invalid (327) Error:
    [20-10-25 17:45:41.3401] Slim::Player::StreamingController::_Invalid (327) Backtrace:

    frame 0: Slim::Utils::Log::logBacktrace (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 327)
    frame 1: Slim::Player::StreamingController::_Invalid (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 287)
    frame 2: Slim::Player::StreamingController::_eventAction (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 2230)
    frame 3: Slim::Player::StreamingController:layerReadyToStream (/volume2/@appstore/SqueezeCenter/Slim/Player/Squeezebox2.pm line 146)
    frame 4: Slim::Player::Squeezebox2::statHandler (/volume2/@appstore/SqueezeCenter/Slim/Networking/Slimproto.pm line 852)
    frame 5: Slim::Networking::Slimproto::_stat_handler (/volume2/@appstore/SqueezeCenter/Slim/Networking/Slimproto.pm line 401)
    frame 6: Slim::Networking::Slimproto::client_readable (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 122)
    frame 7: (eval) (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 118)
    frame 8: Slim::Networking::IO::Select::__ANON__ (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 167)
    frame 9: (eval) (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 167)
    frame 10: Slim::Networking::IO::Select::loop (/volume2/@appstore/SqueezeCenter/slimserver.pl line 728)
    frame 11: main::idle (/volume2/@appstore/SqueezeCenter/slimserver.pl line 678)
    frame 12: main::main (/volume2/@appstore/SqueezeCenter/slimserver.pl line 1211)

    [20-10-25 17:45:41.3725] Slim::Player::StreamingController:layerEndOfStream (2286) 01:c6:83:66:f3:f2

  6. #6
    Ok so the log have new this information, hope somebody has a clue...

    20-10-25 17:45:40.7550] Slim::Player::Song:pen (489) URL is a song (audio): youtube://www.youtube.com/v/RUTyS7v0ZF0, type=ops
    [20-10-25 17:45:40.7584] Slim::Player::TranscodingHelper::tokenizeConvertCo mmand2 (641) Using command for conversion: "/volume2/@appstore/SqueezeCenter/Bin/sox" -t opus - -t flac -C 0 -
    [20-10-25 17:45:40.7602] Slim::Player::Song:pen (565) Tokenized command: "/volume2/@appstore/SqueezeCenter/Bin/sox" -t opus - -t flac -C 0 -
    [20-10-25 17:45:40.8110] Slim::Player::StreamingController::_Stream (1282) 01:c6:83:66:f3:f2: stream
    [20-10-25 17:45:40.8343] Slim::Player::StreamingController::_Stream (1319) Song queue is now 24
    [20-10-25 17:45:40.8367] Slim::Player::StreamingController::_setPlayingStat e (2377) new playing state BUFFERING
    [20-10-25 17:45:40.8446] Slim::Player::StreamingController::_setStreamingSt ate (2386) new streaming state STREAMING
    [20-10-25 17:45:40.9462] Slim::Player::Player::_buffering (1144) Buffering... 0 / 261120
    [20-10-25 17:45:41.0933] Slim::Player::Source::_readNextChunk (372) end of file or error on socket, song pos: 0
    [20-10-25 17:45:41.0950] Slim::Player::Source::_readNextChunk (377) 01:c6:83:66:f3:f2 mark end of stream
    [20-10-25 17:45:41.0966] Slim::Player::Source::_readNextChunk (385) Didn't stream any bytes for this song; mark it as failed
    [20-10-25 17:45:41.0984] Slim::Player::StreamingController:layerStreamingFailed (2248) 01:c6:83:66:f3:f2
    [20-10-25 17:45:41.1004] Slim::Player::StreamingController::_playersMessage (796) Problem: Can't open file for:: youtube://www.youtube.com/v/RUTyS7v0ZF0
    [20-10-25 17:45:41.1131] Slim::Player::StreamingController::_Stop (610) Song queue is now 24
    [20-10-25 17:45:41.1152] Slim::Player::StreamingController::_setPlayingStat e (2377) new playing state STOPPED
    [20-10-25 17:45:41.1169] Slim::Player::StreamingController::_setStreamingSt ate (2386) new streaming state IDLE
    [20-10-25 17:45:41.1193] Slim::Player::StreamingController::_willRetry (1408) no retry data
    [20-10-25 17:45:41.1215] Slim::Player::StreamingController::nextsong (889) The next song is number 0, was 24
    [20-10-25 17:45:41.3340] Slim::Player::StreamingController:layerReadyToStream (2218) 01:c6:83:66:f3:f2
    [20-10-25 17:45:41.3358] Slim::Player::StreamingController::_Invalid (326) 01:c6:83:66:f3:f2: event ReadyToStream received while in invalid state STOPPED-IDLE
    [20-10-25 17:45:41.3375] Slim::Player::StreamingController::_Invalid (327) Error:
    [20-10-25 17:45:41.3401] Slim::Player::StreamingController::_Invalid (327) Backtrace:

    frame 0: Slim::Utils::Log::logBacktrace (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 327)
    frame 1: Slim::Player::StreamingController::_Invalid (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 287)
    frame 2: Slim::Player::StreamingController::_eventAction (/volume2/@appstore/SqueezeCenter/Slim/Player/StreamingController.pm line 2230)
    frame 3: Slim::Player::StreamingController:layerReadyToStream (/volume2/@appstore/SqueezeCenter/Slim/Player/Squeezebox2.pm line 146)
    frame 4: Slim::Player::Squeezebox2::statHandler (/volume2/@appstore/SqueezeCenter/Slim/Networking/Slimproto.pm line 852)
    frame 5: Slim::Networking::Slimproto::_stat_handler (/volume2/@appstore/SqueezeCenter/Slim/Networking/Slimproto.pm line 401)
    frame 6: Slim::Networking::Slimproto::client_readable (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 122)
    frame 7: (eval) (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 118)
    frame 8: Slim::Networking::IO::Select::__ANON__ (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 167)
    frame 9: (eval) (/volume2/@appstore/SqueezeCenter/Slim/Networking/IO/Select.pm line 167)
    frame 10: Slim::Networking::IO::Select::loop (/volume2/@appstore/SqueezeCenter/slimserver.pl line 728)
    frame 11: main::idle (/volume2/@appstore/SqueezeCenter/slimserver.pl line 678)
    frame 12: main::main (/volume2/@appstore/SqueezeCenter/slimserver.pl line 1211)

    [20-10-25 17:45:41.3725] Slim::Player::StreamingController:layerEndOfStream (2286) 01:c6:83:66:f3:f2

  7. #7
    Quote Originally Posted by bpa View Post
    Player.source to INFO

    It "feels" like one of the transcoding/resampling support executables is not working. The log will show which ones are trying to be used.
    I hope this gives an idea on where to look for the fault...

    20-10-25 17:45:40.9462] Slim::Player::Player::_buffering (1144) Buffering... 0 / 261120
    [20-10-25 17:45:41.0933] Slim::Player::Source::_readNextChunk (372) end of file or error on socket, song pos: 0
    [20-10-25 17:45:41.0950] Slim::Player::Source::_readNextChunk (377) 01:c6:83:66:f3:f2 mark end of stream
    [20-10-25 17:45:41.0966] Slim::Player::Source::_readNextChunk (385) Didn't stream any bytes for this song; mark it as failed
    [20-10-25 17:45:41.0984] Slim::Player::StreamingController:layerStreamingFailed (2248) 01:c6:83:66:f3:f2
    [20-10-25 17:45:41.1004] Slim::Player::StreamingController::_playersMessage (796) Problem: Can't open file for:: youtube://www.youtube.com/v/RUTyS7v0ZF0
    [20-10-25 17:45:41.1131] Slim::Player::StreamingController::_Stop (610) Song queue is now 24
    Last edited by Hawkeyenl; 2020-10-25 at 10:05.

  8. #8
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    19,546
    Quote Originally Posted by Hawkeyenl View Post
    I hope this gives an idea on where to look for the fault...
    There will be too many lines to copy into a post.
    Copy ALL entries from server.log from just before you presses play to about 30 secs afterwards and copy them into a plain text file, zip the file and attach to a post.
    Do not edit or remove any lines from the log.

    Code:
    0-10-25 17:45:40.9462] Slim::Player::Player::_buffering (1144) Buffering... 0 / 261120
    [20-10-25 17:45:41.0933] Slim::Player::Source::_readNextChunk (372) end of file or error on socket, song pos: 0
    These lines are just after the important stuff but it says the transcode chain failed - the preceding lines will show what is being used to transcode.

  9. #9
    Senior Member
    Join Date
    Apr 2005
    Location
    UK/London
    Posts
    3,109
    Also note that others have recently reported playback issues with the YouTube plugin - so do make sure that what you are playing really is the same on different devices (working v not working)
    eg does YouTube offer different encoding for same material and plugin/LMS picks a different one based on expected capabilities of the player?
    Paul Webster
    http://dabdig.blogspot.com
    Author of "Now Playing" plugins covering Radio France (FIP etc), KCRW, Supla Finland, ABC Australia, CBC/Radio-Canada and RTE Ireland

  10. #10
    Quote Originally Posted by bpa View Post
    There will be too many lines to copy into a post.
    Copy ALL entries from server.log from just before you presses play to about 30 secs afterwards and copy them into a plain text file, zip the file and attach to a post.
    Do not edit or remove any lines from the log.

    Code:
    0-10-25 17:45:40.9462] Slim::Player::Player::_buffering (1144) Buffering... 0 / 261120
    [20-10-25 17:45:41.0933] Slim::Player::Source::_readNextChunk (372) end of file or error on socket, song pos: 0
    These lines are just after the important stuff but it says the transcode chain failed - the preceding lines will show what is being used to transcode.

    Sorry, it seems my initial post came through twice with more information. Does the extended logging I posted provide more detail, or is an attachment with logging still required?

    Apologies for the multiple postings :/

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •