PDA

View Full Version : Trying to solve Spotty and buffering issues on SBT



MKV
2017-11-18, 10:26
Hi all,

As per Michael's request, starting a new thread in the hope that this issue might be tackled and not be snowed under by connect issues.

Have been using Spotty since it launched. Overall brilliant and many thanks to Michael. I have my SB Touch connected to LMS Repack 7.9.1 using latest Spotty plugin on a Synology DS 415+, and sometimes get buffering issues. I want to see what causes it. Tried to increase logging level on some things I thought relevant. Actually see the buffering issues mentioned in the log now. But how do I know where they are originating? Is it in the Synology (LMS) or is it in the SB Touch player? As I connected it through WiFi, it might be possible. But would the log in LMS show lines of buffering if the player suffers from loss of data due to WiFi issues? Somehow that seems not so logical.

Snippet from log:


[17-11-18 18:26:38.9749] Slim::Player::Song::open (558) Tokenized command: "/volume1/@appstore/LmsRepack/Cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64" -n Squeezebox -c "/volume1/@appstore/LmsRepack/Cache/spotty/18372a97" --single-track "spotify://track:6I9HXaU8zbTgASGe7evWnu" --disable-discovery --disable-audio-cache | "/volume1/@appstore/LmsRepack/Bin/flac" -cs --channels=2 --sample-rate=44100 --bps=16 --endian=little --sign=signed --fast --totally-silent --ignore-chunk-sizes - & |
[17-11-18 18:26:38.9851] Slim::Player::StreamingController::_Stream (1265) 00:04:20:23:47:a4: stream
[17-11-18 18:26:38.9890] Slim::Player::StreamingController::_Stream (1302) Song queue is now 70,69
[17-11-18 18:26:38.9895] Slim::Player::StreamingController::_setStreamingSt ate (2366) new streaming state STREAMING
[17-11-18 18:26:39.0608] Slim::Player::Squeezebox2::directHeaders (471) Processing headers for direct streaming:
HTTP/1.1 200 OK
Server: Logitech Media Server (7.9.1 - 1503129892)
Connection: close
Content-Type: audio/x-flac

[17-11-18 18:26:46.5959] Slim::Player::StreamingController::playerTrackStar ted (2180) 00:04:20:23:47:a4
[17-11-18 18:26:46.5963] Slim::Player::StreamingController::_setPlayingStat e (2357) new playing state PLAYING
[17-11-18 18:26:46.5966] Slim::Player::StreamingController::_Playing (355) Song 69 is not longer in the queue
[17-11-18 18:26:46.5969] Slim::Player::StreamingController::_Playing (361) Song 70 has now started playing
[17-11-18 18:26:46.5981] Slim::Player::StreamingController::_Playing (390) Song queue is now 70
[17-11-18 18:27:25.0006] Plugins::Spotty::Connect::initHelpers (270) Initializing Spotty Connect helper daemons...
[17-11-18 18:28:24.0004] Plugins::Spotty::Connect::initHelpers (270) Initializing Spotty Connect helper daemons...
[17-11-18 18:28:48.7025] Slim::Player::StreamingController::playerOutputUnd errun (2219) 00:04:20:23:47:a4: decoder: 19872 / output: 0
[17-11-18 18:28:48.7029] Slim::Player::StreamingController::_setPlayingStat e (2357) new playing state BUFFERING
[17-11-18 18:28:48.8293] Slim::Player::Player::_buffering (1140) Buffering... 18496 / 441000
[17-11-18 18:28:48.8297] Slim::Player::Player::_buffering (1141) +output... 221184 / 1764000
[17-11-18 18:28:49.1315] Slim::Player::Player::_buffering (1140) Buffering... 18496 / 441000
[17-11-18 18:28:49.1319] Slim::Player::Player::_buffering (1141) +output... 221184 / 1764000
[17-11-18 18:28:49.4333] Slim::Player::Player::_buffering (1140) Buffering... 34860 / 441000
[17-11-18 18:28:49.4337] Slim::Player::Player::_buffering (1141) +output... 377856 / 1764000
[17-11-18 18:28:49.7349] Slim::Player::Player::_buffering (1140) Buffering... 34860 / 441000
[17-11-18 18:28:49.7353] Slim::Player::Player::_buffering (1141) +output... 377856 / 1764000
[17-11-18 18:28:50.0365] Slim::Player::Player::_buffering (1140) Buffering... 48440 / 441000
[17-11-18 18:28:50.0369] Slim::Player::Player::_buffering (1141) +output... 451584 / 1764000
[17-11-18 18:28:50.3381] Slim::Player::Player::_buffering (1140) Buffering... 48440 / 441000
[17-11-18 18:28:50.3384] Slim::Player::Player::_buffering (1141) +output... 451584 / 1764000
[17-11-18 18:28:50.6398] Slim::Player::Player::_buffering (1140) Buffering... 20008 / 441000
[17-11-18 18:28:50.6401] Slim::Player::Player::_buffering (1141) +output... 635904 / 1764000
[17-11-18 18:28:50.9414] Slim::Player::Player::_buffering (1140) Buffering... 20008 / 441000
[17-11-18 18:28:50.9418] Slim::Player::Player::_buffering (1141) +output... 635904 / 1764000
[17-11-18 18:28:51.2431] Slim::Player::Player::_buffering (1140) Buffering... 20504 / 441000
[17-11-18 18:28:51.2688] Slim::Player::Player::_buffering (1141) +output... 903168 / 1764000
[17-11-18 18:28:51.5701] Slim::Player::Player::_buffering (1140) Buffering... 20504 / 441000
[17-11-18 18:28:51.5705] Slim::Player::Player::_buffering (1141) +output... 903168 / 1764000
[17-11-18 18:28:51.8718] Slim::Player::Player::_buffering (1140) Buffering... 27340 / 441000
[17-11-18 18:28:51.8721] Slim::Player::Player::_buffering (1141) +output... 1004544 / 1764000
[17-11-18 18:28:52.1735] Slim::Player::Player::_buffering (1140) Buffering... 23512 / 441000
[17-11-18 18:28:52.1738] Slim::Player::Player::_buffering (1141) +output... 1179648 / 1764000
[17-11-18 18:28:52.4752] Slim::Player::Player::_buffering (1140) Buffering... 23512 / 441000
[17-11-18 18:28:52.4755] Slim::Player::Player::_buffering (1141) +output... 1179648 / 1764000
[17-11-18 18:28:52.7768] Slim::Player::Player::_buffering (1140) Buffering... 23044 / 441000
[17-11-18 18:28:52.7772] Slim::Player::Player::_buffering (1141) +output... 1317888 / 1764000
[17-11-18 18:28:53.0784] Slim::Player::Player::_buffering (1140) Buffering... 23044 / 441000
[17-11-18 18:28:53.0788] Slim::Player::Player::_buffering (1141) +output... 1317888 / 1764000
[17-11-18 18:28:53.3802] Slim::Player::Player::_buffering (1140) Buffering... 17204 / 441000
[17-11-18 18:28:53.3806] Slim::Player::Player::_buffering (1141) +output... 1511424 / 1764000
[17-11-18 18:28:53.6818] Slim::Player::Player::_buffering (1140) Buffering... 32736 / 441000
[17-11-18 18:28:53.6821] Slim::Player::Player::_buffering (1141) +output... 1612800 / 1764000
[17-11-18 18:28:53.9834] Slim::Player::Player::_buffering (1140) Buffering... 32736 / 441000
[17-11-18 18:28:53.9837] Slim::Player::Player::_buffering (1141) +output... 1612800 / 1764000
[17-11-18 18:28:54.2850] Slim::Player::Player::_buffering (1140) Buffering... 28348 / 441000
[17-11-18 18:28:54.2854] Slim::Player::Player::_buffering (1141) +output... 1824768 / 1764000
[17-11-18 18:28:54.2857] Slim::Player::StreamingController::playerBufferRea dy (2258) 00:04:20:23:47:a4
[17-11-18 18:28:54.2860] Slim::Player::StreamingController::_setPlayingStat e (2357) new playing state WAITING_TO_SYNC
[17-11-18 18:28:54.2864] Slim::Player::StreamingController::_setPlayingStat e (2357) new playing state PLAYING
[17-11-18 18:29:23.0006] Plugins::Spotty::Connect::initHelpers (270) Initializing Spotty Connect helper daemons...
[17-11-18 18:30:22.0004] Plugins::Spotty::Connect::initHelpers (270) Initializing Spotty Connect helper daemons...
[17-11-18 18:30:45.2513] Slim::Player::Source::_readNextChunk (373) end of file or error on socket, song pos: 14542257924
[17-11-18 18:30:45.2518] Slim::Player::Source::_readNextChunk (378) 00:04:20:23:47:a4 mark end of stream
[17-11-18 18:30:45.2524] Slim::Player::StreamingController::_setStreamingSt ate (2366) new streaming state STREAMOUT
[17-11-18 18:30:45.7891] Slim::Player::StreamingController::playerEndOfStre am (2266) 00:04:20:23:47:a4
[17-11-18 18:30:45.7895] Slim::Player::StreamingController::_setStreamingSt ate (2366) new streaming state STREAMOUT
[17-11-18 18:30:45.9786] Slim::Player::StreamingController::playerReadyToSt ream (2198) 00:04:20:23:47:a4
[17-11-18 18:30:45.9791] Slim::Player::StreamingController::_setStreamingSt ate (2366) new streaming state IDLE
[17-11-18 18:30:45.9796] Slim::Player::StreamingController::nextsong (882) The next song is number 71, was 70
[17-11-18 18:30:45.9804] Slim::Player::Song::new (108) index 71 -> spotify://track:7KY40pRBPKQSaSe0j5nKUK
[17-11-18 18:30:45.9813] Slim::Player::StreamingController::_setStreamingSt ate (2366) new streaming state TRACKWAIT
[17-11-18 18:30:45.9817] Slim::Player::Song::getNextSong (229) spotify://track:7KY40pRBPKQSaSe0j5nKUK
[17-11-18 18:30:45.9821] Slim::Player::StreamingController::_nextTrackReady (737) 0

Anyone who can shine a little light on this?

Many thanks, Martijn

mherger
2017-11-19, 23:22
> player? As I connected it through WiFi, it might be possible. But would
> the log in LMS show lines of buffering if the player suffers from loss
> of data due to WiFi issues? Somehow that seems not so logical.

What is connected through WiFi? The NAS? Or the player? Make sure the
NAS (or whatever is running LMS) is wired. You could enable transcoding
to MP3 to see whether wireless to the player was a problem. This would
highly reduce the bandwidth needs.

--

Michael

paulgizmo
2017-12-05, 19:52
This is happening to me on LMS installs on 2 Raspberry Pis now with LMS 7.9.1~1511211491 & Spotty 1.99.0
Just started happening on my stable setup (installed around the end of Spotify official plugin) and my networking hasn't changed, cable connected RPis and Wi-Fi SBTs
Any ideas?
Thanks
Paul
--
Players: 2 x Squeezebox Touch and Max2Play on Raspberry Pi A1
Server: Raspberry Pi B1 (512MB) with LMS 7.9.1~1511211491 & Spotty 1.99.0
Control: OrangeSqueeze for Android

paulgizmo
2017-12-20, 16:44
This is happening to me on LMS installs on 2 Raspberry Pis now with LMS 7.9.1~1511211491 & Spotty 1.99.0
Just started happening on my stable setup (installed around the end of Spotify official plugin) and my networking hasn't changed, cable connected RPis and Wi-Fi SBTs
Any ideas?
Thanks
Paul
--
Players: 2 x Squeezebox Touch and Max2Play on Raspberry Pi A1
Server: Raspberry Pi B1 (512MB) with LMS 7.9.1~1511211491 & Spotty 1.99.0
Control: OrangeSqueeze for Android

Title says it all, back to Spotty streaming just fine :)