“Unsupported sample-rate”: Logitech Media Server Won’t Play Some Files with SB Player

Muh musics!

tl;dr: If you’ve got a music file that you (say) downloaded from YouTube via youtube-dl (for example) and it won’t play in Logitech Media Server, check the sample rate- you may need to convert it to 44.1kHz. This only happens with some players! (eg SB Player)


Background

I use Logitech Media Server (aka logitechmediaserver aka LMS (not to be confused with LMS) aka squeezeserver) to play music synchronised around my house. I previously used icecast2 and started playback as simultaneously as possible; which, despite being a highly advanced technique, was prone to drift and desync over time.

On occasion I’ve had LMS refuse to play a file, skipping over it to the next item in the playlist instead. It can be easy to miss, particularly in an over 85 hour long playlist.

ABBA vibes all over this

In this case I was trying to play The Secret He Had Missed, and Orwellian. Both are from the Manics Street Preachers’ forthcoming album The Ultra Vivid Lament.

Another zeitgeist-capturing song

Tracking Down The Problem

These songs wouldn’t play, so I went hunting. First, I changed from webm to FLAC, then MP3; this is as simple as telling youtube-dl to change it’s output format, eg: youtube-dl -x --audio-format mp3 https://www.youtube.com/watch?v=4Q3sDyp3mbo. I have had issues with other media types in the past, but that didn’t solve it.

I went to LMS to look at the logs themselves. There wasn’t much of help, so I changed the player.source. log level to Info:

LMS logging info, on the ‘Advanced’ tab, found under ‘Settings’ (the gear icon)

this brought up something a bit more useful:

[21-07-20 10:51:48.4708] Slim::Player::StreamingController::playerTrackStarted (2200) d0:50:99:46:42:15
[21-07-20 10:51:48.9894] Slim::Player::StreamingController::skip (2127) d0:50:99:46:42:15
[21-07-20 10:51:48.9897] Slim::Player::StreamingController::_Stop (610) Song queue is now 898
[21-07-20 10:51:48.9899] Slim::Player::StreamingController::_setPlayingState (2377) new playing state STOPPED
[21-07-20 10:51:48.9900] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state IDLE
[21-07-20 10:51:48.9902] Slim::Player::StreamingController::nextsong (889) The next song is number 899, was 898
[21-07-20 10:51:48.9933] Slim::Player::Song::new (109) index 899 -> file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3
[21-07-20 10:51:48.9935] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state TRACKWAIT
[21-07-20 10:51:48.9961] Slim::Player::StreamingController::_playersMessage (796) Now Playing: file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3
[21-07-20 10:51:48.9977] Slim::Player::Song::getNextSong (223) file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3
[21-07-20 10:51:48.9978] Slim::Player::StreamingController::_nextTrackReady (744) d0:50:99:46:42:15: nextTrack will be index 899
[21-07-20 10:51:48.9980] Slim::Player::StreamingController::_Stream (1210) Song queue is now 899
[21-07-20 10:51:48.9982] Slim::Player::StreamingController::_Stream (1213) d0:50:99:46:42:15: preparing to stream song index 899
[21-07-20 10:51:48.9983] Slim::Player::Song::open (360) file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3
[21-07-20 10:51:48.9989] Slim::Player::TranscodingHelper::checkBin (297)    couldn't find binary for: lame
[21-07-20 10:51:48.9990] Slim::Player::TranscodingHelper::getConvertCommand2 (485) Error: Didn't find any command matches for type: mp3
[21-07-20 10:51:48.9992] Slim::Player::Song::open (384) seek=false time=0 canSeek=0SEEK_ERROR_TRANSCODED
[21-07-20 10:51:48.9995] Slim::Player::TranscodingHelper::checkBin (297)    couldn't find binary for: lame
[21-07-20 10:51:48.9997] Slim::Player::TranscodingHelper::getConvertCommand2 (485) Error: Didn't find any command matches for type: mp3
[21-07-20 10:51:48.9998] Slim::Player::Song::open (415) Error: Couldn't create command line for mp3 playback for [file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3]
[21-07-20 10:51:49.0000] Slim::Player::StreamingController::_playersMessage (796) Unsupported sample-rate: file:///home/robert/music/Manic%20Street%20Preachers%20feat.%20Julia%20Cumming/The%20Secret%20He%20Had%20Missed/01%20The%20Secret%20He%20Had%20Missed.mp3
[21-07-20 10:51:49.0007] Slim::Player::StreamingController::_willRetry (1408) no retry data
[21-07-20 10:51:49.0008] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state IDLE
[21-07-20 10:51:49.0010] Slim::Player::StreamingController::nextsong (889) The next song is number 900, was 899
[21-07-20 10:51:49.0012] Slim::Player::Song::new (109) index 900 -> tmp:///home/robert/music/Grateful%20Dead/Aoxomoxoa/08%20Cosmic%20Charlie.mp3

So, the player saw the file okay. But it decided that it needed to be transcoded, and then couldn’t invoke the transcoder (lame, in this case). Very odd. I thought libmp3’s lame was installed (it wasn’t), but I was more interested in figuring out why it was trying to re-encode an MP3 to MP3!

The part that is important is: “Unsupported sample-rate” . Sample rate (BBC, WP) — not to be confused with bitrate — was 44.1kHz for most of my MP3s. However, these were 48kHz:

Stream #0:0: Audio: mp3, 48000 Hz, stereo, fltp, 128 kb/s

The audio files can be resampled using, say, ffmpeg; or the original youtube-dl command can be amended:

$ youtube-dl --help | grep postprocess
    --postprocessor-args ARGS            Give these arguments to the postprocessor

$ ffmpeg --help | grep sampling
    -ar rate            set audio sampling rate (in Hz)

$ youtube-dl -x --audio-format mp3 --postprocessor-args "-ar 44100" https://www.youtube.com/watch?v=4Q3sDyp3mbo

Since youtube-dl uses ffmpeg as its backend, we specify its audio sampling rate argument (-ar) using --postprocessor-args.

After changing the audio sample rate the files played correctly.

Additional Note on Players

When I went to write this up — it’s a niche situation but might help someone and save them some time in tracking the issue down — I found I couldn’t replicate the problem! 48kHz sample rate media files were playing back just fine.

My theory was that it was related to the players connected. My main PC uses squeezelite, a command line player, and that played 48kHz just fine. When I connected another player, SB Player, which was running on an old Android tablet the songs refused to play.

Looking back at the log, I think that’s what it was originally trying to tell me: “Slim::Player::StreamingController::_playersMessage (796) Unsupported sample-rate“. More or less:

Logitech Media Server: New Song is: /path/to/foo.mp3

PC Squeezelite: No problem, I’ll get ready to play that

Android SB Player: Uh wait a minute, it’s too high a sample rate for me

Server: (sigh) Alright, let me serve it in a format you can handle.

Server: (checks tool drawer for MP3 transcoder)

Server: Dang, looks like I’m fresh out of MP3 encoders. Sorry Android, it’s 48kHz or nothing!

Android: Well now I am not doing it!

PC: Are we playing this or what?

Server: Alright, let’s just skip on to the next file, that one’s 44.1kHz.

Android: That’s good, I can play that

PC: Me too

(fin)

Interestingly, the issue has been discussed in the slimdevices forums thread for SB Player a number of times. Apparently, it can handle up to 192kHz sampling rate, but reports 44.1kHz to save power.

Tell us what's on your mind