Hi Triode
Previously I have been using the windows LMS/spotify plugin and all was
working well. I've recently moved our music server to linux Mint 17,
wunning latest LMS 7.8.1 .deb from nightlines.
I can't seem to get spotify stable....it works for hours on end, then I
will start getting droputs with server logs that look like this (I
restart LMS to try and solve it, which sometimes works for a while):
Code:
--------------------
[14-08-27 12:59:01.7022] main::init (368) Starting Logitech Media Server
(v7.8.1, 1408690219, Sun Aug 24 02:59:27 UTC 2014) perl 5.018002
[14-08-27 12:59:01.8942] Slim::Utils::Misc::msg (1311) Warning:
[12:59:01.8940] DBIx::Class::ResultSet::update_or_create(): Query returned more
than one row. SQL that returns multiple rows is DEPRECATED for ->find and
->single at /usr/share/perl5/Slim/Schema.pm line 1886
[14-08-27 12:59:02.4665] Slim::Web::JSONRPC::requestMethod (443) request not
dispatchable!
[14-08-27 12:59:02.7497] Slim::Web::Cometd::handler (422) errorNeedsClient:
00:25:22:bf:8c:e8, status, -, 10, menu:menu, useContextMenu:1, subscribe:600
[14-08-27 12:59:24.3375] Plugins::Spotify::Spotifyd::relogin (219) requesting
relogin
[14-08-27 12:59:57.4045] Plugins::Spotify::Spotifyd::relogin (219) requesting
relogin
[14-08-27 13:00:55.0603] Plugins::Spotify::Spotifyd::relogin (219) requesting
relogin
[14-08-27 13:01:33.6084] Plugins::Spotify::Spotifyd::relogin (219) requesting
relogin
--------------------
Spotify logs:
Code:
--------------------
[13:02:41.760031] main:619 req: toplist.json res: (null) par: q=tracks&r=user
prot: HTTP/1.1 auth: (null)
[13:02:41.760062] main:1220 toplist type: 2 region: 16725
[13:02:42.818393] toplist_callback:916 toplist: ok
[13:02:42.818419] toplist_callback:920 toplist tracks: 100
[13:02:42.821658] metadata_updated:86 new meta
[13:02:42.885167] main:567 new connection
[13:02:42.885261] main:619 req: status.json res: (null) par: (null) prot:
HTTP/1.1 auth: (null)
[13:02:42.885285] process_status:1451 process status
[13:02:42.890341] main:567 new connection
[13:02:42.890434] main:619 req: streamtest.json res: (null) par: (null) prot:
HTTP/1.1 auth: (null)
[13:02:42.890456] main:916 existing streaming connection exists - killing
[13:02:42.890699] main:960 streambuf_newstream: streamtest (1)
[13:02:42.890720] main:961 created toplist tracks to find track
[13:02:43.258836] metadata_updated:86 new meta
[13:02:43.491416] teststream_toplist_callback:1093 found track
[13:02:43.491508] metadata_updated:86 new meta
[13:02:43.491539] main:1835 streambuf_newstream: test
[13:02:43.492718] main:1620 Now playing: Timber
[13:02:43.493085] log_message:81 log: 03:02:43.493 I
[social_presence.cpp:135] Presence: A track was played
[13:02:43.919086] metadata_updated:86 new meta
[13:02:43.996117] music_delivery:485 channels: 2 sample rate: 44100 streaming
as: PCM
[13:02:44.680975] metadata_updated:86 new meta
[13:02:48.088357] log_message:81 log: 03:02:48.088 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:02:50.129570] log_message:81 log: 03:02:50.129 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:03:00.025862] log_message:81 log: 03:03:00.025 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:03:12.822299] log_message:81 log: 03:03:12.822 I [offline-mgr:2058] 0
files unlocked. 0 images unlocked
[13:03:16.736480] log_message:81 log: 03:03:16.736 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:03:36.275747] log_message:81 log: 03:03:36.275 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:03:51.185059] log_message:81 log: 03:03:51.185 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:04:03.002389] main:567 new connection
[13:04:03.003341] main:619 req: prefetch.json res:
spotify:track:31N0GMHJxsEKEjhphLxij1 par: (null) prot: HTTP/1.0 auth: (null)
[13:04:03.003498] main:985 prefetching track: No error
[13:04:03.198351] metadata_updated:86 new meta
[13:04:09.750779] log_message:81 log: 03:04:09.750 I
[file_streamer_simple.cpp:769] Request for file
ccc97823d53682c2f06ea4082c37553cc52424ea complete (code: 0)
[13:04:33.199539] log_message:81 log: 03:04:33.199 I [offline-mgr:2058] 0
files unlocked. 0 images unlocked
[13:04:57.841790] streambuf_end_of_track:639 end of track
[13:04:57.841971] log_message:81 log: 03:04:57.841 I
[social_presence.cpp:135] Presence: A track was played
[13:04:58.008825] main:567 new connection
[13:04:58.008920] main:619 req: streamtest.json res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par: (null) prot: HTTP/1.1 auth: (null)
[13:04:58.008981] main:930 streambuf_newstream: streamtest (2)
[13:04:58.009071] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.009128] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.021709] main:567 new connection
[13:04:58.029161] main:619 req: browse.json res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par: (null) prot: HTTP/1.0 auth: (null)
[13:04:58.029199] main:1078 queuing track browse
[13:04:58.029207] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.029222] main:567 new connection
[13:04:58.029349] main:619 req: browse.json res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par: (null) prot: HTTP/1.0 auth: (null)
[13:04:58.029373] main:1078 queuing track browse
[13:04:58.029379] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.046135] main:567 new connection
[13:04:58.047408] main:619 req: stream.flc res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par:
player=00%3A04%3A20%3A12%3A8a%3A5b&start=0&sync=2&id=10 prot: SPOTSTREAM/1.0
auth: (null)
[13:04:58.047488] main:813 newstream connection from 192.168.16.33
[13:04:58.047504] main:849 streamid: 0 newid: 10 type: FLAC
[13:04:58.047514] main:886 streambuf_newstream
[13:04:58.047531] set_sndbuf:227 setsockopt: asked for 524288 got 425984
[13:04:58.047542] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.300568] main:1656 new stream pending state: Resource not loaded yet
[13:04:58.301130] main:1620 Now playing: Timber
[13:04:58.301362] process_track:1401 process track
[13:04:58.301536] process_track:1425 browse track: ok
[13:04:58.302101] process_track:1401 process track
[13:04:58.302244] process_track:1425 browse track: ok
[13:04:58.302793] metadata_updated:86 new meta
[13:04:58.500700] metadata_updated:86 new meta
[13:04:59.457229] main:567 new connection
[13:04:59.458179] main:619 req: stream.flc res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par:
player=00%3A04%3A20%3A1e%3A4c%3Aa2&start=0&sync=2&id=10 prot: SPOTSTREAM/1.0
auth: (null)
[13:04:59.458293] main:813 newstream connection from 192.168.16.22
[13:04:59.458316] main:849 streamid: 10 newid: 10 type: FLAC
[13:04:59.458332] main:896 streambuf_addplayer
[13:04:59.458357] set_sndbuf:227 setsockopt: asked for 524288 got 425984
[13:04:59.569498] music_delivery:485 channels: 2 sample rate: 44100 streaming
as: FLAC
[13:05:01.339259] main:567 new connection
[13:05:01.348050] main:619 req: cover.jpg res:
spotify:image:fad28af03d6381d90324a95c7bf702503c00c311 par: (null) prot:
HTTP/1.0 auth: (null)
[13:05:01.726741] write_cover:123 cover fetch: No error
[13:05:02.328857] main:567 new connection
[13:05:02.329427] main:619 req: cover.jpg res:
spotify:image:fad28af03d6381d90324a95c7bf702503c00c311 par: (null) prot:
HTTP/1.0 auth: (null)
[13:05:02.330206] write_cover:123 cover fetch: No error
[13:05:11.325028] main:567 new connection
[13:05:11.326212] main:619 req: stream.flc res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par:
player=00%3A04%3A20%3A12%3A8a%3A5b&start=0&sync=2&id=11 prot: SPOTSTREAM/1.0
auth: (null)
[13:05:11.326299] main:813 newstream connection from 192.168.16.33
[13:05:11.326319] main:849 streamid: 10 newid: 11 type: FLAC
[13:05:11.326335] main:853 existing streaming connection exists - killing
[13:05:11.326453] main:886 streambuf_newstream
[13:05:11.326487] set_sndbuf:227 setsockopt: asked for 524288 got 425984
[13:05:11.326503] main:1620 Now playing: Timber
[13:05:11.329707] main:567 new connection
[13:05:11.334026] main:619 req: stream.flc res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par:
player=00%3A04%3A20%3A1e%3A4c%3Aa2&start=0&sync=2&id=11 prot: SPOTSTREAM/1.0
auth: (null)
[13:05:11.334063] main:813 newstream connection from 192.168.16.22
[13:05:11.334071] main:849 streamid: 11 newid: 11 type: FLAC
[13:05:11.334077] main:896 streambuf_addplayer
[13:05:11.334086] set_sndbuf:227 setsockopt: asked for 524288 got 425984
[13:05:11.748747] music_delivery:485 channels: 2 sample rate: 44100 streaming
as: FLAC
[13:05:28.304263] log_message:81 log: 03:05:28.304 I [offline-mgr:2058] 0
files unlocked. 0 images unlocked
[13:05:34.169494] music_delivery:571 error writing
[13:05:34.169607] main:1603 resetting streambuf
[13:08:05.001863] main:567 new connection
[13:08:05.002654] main:619 req: prefetch.json res:
spotify:track:3cHyrEgdyYRjgJKSOiOtcS par: (null) prot: HTTP/1.0 auth: (null)
[13:08:05.002731] main:985 prefetching track: No error
--------------------
The spotify self test passes ok.
I am not sure why it's repetitively trying to login - or why it says
it's killing various streams etc. in that log.
Can you help me interperet and or point at things I can do to diagnose
further?
Many thanks - it's a great plugin!
------------------------------------------------------------------------
bossanova808's Profile: http://forums.slimdevices.com/member.php?userid=619
View this thread: http://forums.slimdevices.com/showthread.php?t=79706
_______________________________________________
plugins mailing list
[email protected]
http://lists.slimdevices.com/mailman/listinfo/plugins