“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.

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.

---

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:

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.