I've seen various threads where people complain about Ubuntu and Spotify having skipping issues regardless of settings, but I haven't found a resolution yet.
I just upgraded my home server from FC17 to Ubuntu 13.10. I can confirm Pandora, etc. seem to work fine, but Spotify is now subject to constant skipping/track restarting whereas it was fine before (same hardware/network/player). I'm happy to help debug, but I cannot compare my old settings. I've got debug enabled and here's some logs: [18:23:54.019734] streambuf_newstream:143 newstream st_fd: 0 [18:23:54.019771] set_sndbuf:227 setsockopt: asked for 32768 got 65536 [18:23:54.019789] streambuf_newstream:150 state IDLE -> READY [18:23:54.019820] main:1667 new stream pending state: Resource not loaded yet [18:23:54.019899] main:1667 new stream pending state: Resource not loaded yet [18:23:54.118077] main:1667 new stream pending state: Resource not loaded yet [18:23:54.118366] metadata_updated:85 new meta [18:23:54.118405] main:1631 Now playing: Silent Night [18:23:54.172822] metadata_updated:85 new meta [18:23:54.265449] music_delivery:427 called with num_frames: 2048 [18:23:54.265520] music_delivery:459 state READY -> STREAMING [18:23:54.265601] _streambuf_write:274 player: 0 wrote 25 new bytes of 25 min 25 [18:23:54.265625] music_delivery:485 channels: 2 sample rate: 44100 streaming as: FLAC [18:23:54.265795] _streambuf_write:274 player: 0 wrote 4 new bytes of 4 min 4 [18:23:54.265832] _streambuf_write:274 player: 0 wrote 38 new bytes of 38 min 38 [18:23:54.265856] _streambuf_write:274 player: 0 wrote 44 new bytes of 44 min 44 [18:23:54.266223] _streambuf_write:274 player: 0 wrote 491 new bytes of 491 min 491 [18:23:54.266258] music_delivery:577 streamed frames: 2048 can't write: 0 rate: 2047999 / 44100 [18:23:54.267414] music_delivery:427 called with num_frames: 2048 So far so good -- my rate exceeds 44100 and the track is playing fine. [18:23:54.271835] music_delivery:525 streamed frames: 22528 can't write: 1 rate: 3218285 / 44100 [18:23:54.271840] music_delivery:427 called with num_frames: 2048 [18:23:54.271845] _streambuf_canwrite:320 player: 0 can't write error: Resource temporarily unavailable 11 [18:23:54.271849] music_delivery:517 returning without writing - can't write [18:23:54.271853] music_delivery:525 streamed frames: 22528 can't write: 2 rate: 3218285 / 44100 [18:23:54.345956] music_delivery:427 called with num_frames: 2048 [18:23:54.346060] _streambuf_canwrite:337 player: 0 wrote 162 stored bytes [18:23:54.346080] _streambuf_canwrite:353 state BUFFERING -> STREAMING [18:23:54.346396] _streambuf_write:274 player: 0 wrote 1427 new bytes of 1427 min 1427 [18:23:54.346621] _streambuf_write:274 player: 0 wrote 1430 new bytes of 1430 min 1430 [18:23:54.346645] music_delivery:577 streamed frames: 24576 can't write: 2 rate: 303407 / 44100 [18:23:54.347371] music_delivery:427 called with num_frames: 2048 Now I start to see 'Resource temporarily unavailable' and by buffer rate starts to drop. I'm unsure if this is normal or not, but it continues: [18:23:55.347596] _streambuf_canwrite:353 state BUFFERING -> STREAMING [18:23:55.347949] _streambuf_write:274 player: 0 wrote 1376 new bytes of 1376 min 1376 [18:23:55.348171] _streambuf_write:274 player: 0 wrote 1347 new bytes of 1347 min 1347 [18:23:55.348197] music_delivery:577 streamed frames: 43008 can't write: 16 rate: 39711 / 44100 [18:23:55.348925] music_delivery:427 called with num_frames: 2048 [18:23:55.349230] _streambuf_write:274 player: 0 wrote 1355 new bytes of 1355 min 1355 [18:23:55.349450] _streambuf_write:274 player: 0 wrote 1359 new bytes of 1359 min 1359 [18:23:55.349473] music_delivery:577 streamed frames: 45056 can't write: 16 rate: 41564 / 44100 [18:23:55.350207] music_delivery:427 called with num_frames: 2048 [18:23:55.350571] _streambuf_write:274 player: 0 wrote 1349 new bytes of 1349 min 1349 [18:23:55.350610] music_delivery:577 streamed frames: 47104 can't write: 16 rate: 43413 / 44100 [18:23:55.351273] music_delivery:427 called with num_frames: 2048 [18:23:55.351564] _streambuf_write:274 player: 0 wrote 1351 new bytes of 1351 min 1351 [18:23:55.351782] _streambuf_write:274 player: 0 wrote 1199 new bytes of 1331 min 1199 [18:23:55.351802] _streambuf_write:285 storing remaining 132 bytes [18:23:55.351816] _streambuf_write:286 state STREAMING -> BUFFERING [18:23:55.351842] music_delivery:577 streamed frames: 49152 can't write: 16 rate: 45218 / 44100 [18:23:55.352479] music_delivery:427 called with num_frames: 2048 [18:23:55.352508] _streambuf_canwrite:320 player: 0 can't write error: Resource temporarily unavailable 11 [18:23:55.352524] music_delivery:517 returning without writing - can't write [18:23:55.352539] music_delivery:525 streamed frames: 49152 can't write: 17 rate: 45218 / 44100 [18:23:55.352555] music_delivery:427 called with num_frames: 2048 [18:23:55.352572] _streambuf_canwrite:320 player: 0 can't write error: Resource temporarily unavailable 11 [18:23:55.352588] music_delivery:517 returning without writing - can't write [18:23:55.352601] music_delivery:525 streamed frames: 49152 can't write: 18 rate: 45218 / 44100 [18:23:55.550924] music_delivery:427 called with num_frames: 2048 [18:23:55.551074] _streambuf_canwrite:337 player: 0 wrote 132 stored bytes [18:23:55.551095] _streambuf_canwrite:353 state BUFFERING -> STREAMING Sometimes it will drop down and then go up again, but eventually we always seem to end up at (I think this might be a different attempt at playing a song): [18:24:10.749820] _streambuf_canwrite:337 player: 0 wrote 2469 stored bytes [18:24:10.749845] _streambuf_canwrite:353 state BUFFERING -> STREAMING [18:24:10.750190] _streambuf_write:274 player: 0 wrote 1726 new bytes of 1726 min 1726 [18:24:10.750234] music_delivery:577 streamed frames: 507904 can't write: 188 rate: 43325 / 44100 [18:24:10.750999] music_delivery:427 called with num_frames: 2048 [18:24:10.751308] _streambuf_write:274 player: 0 wrote 1698 new bytes of 1698 min 1698 [18:24:10.751544] _streambuf_write:274 player: 0 wrote 1679 new bytes of 1679 min 1679 [18:24:10.751579] music_delivery:577 streamed frames: 509952 can't write: 188 rate: 43496 / 44100 [18:24:10.752704] music_delivery:427 called with num_frames: 2048 [18:24:10.753078] _streambuf_write:274 player: 0 wrote 1188 new bytes of 1650 min 1188 [18:24:10.753110] _streambuf_write:285 storing remaining 462 bytes [18:24:10.753128] _streambuf_write:286 state STREAMING -> BUFFERING [18:24:10.753356] _streambuf_write:294 storing all 1670 bytes, newsize: 2132 [18:24:10.753421] _streambuf_write:295 state BUFFERING -> BUFFERING [18:24:10.753448] music_delivery:577 streamed frames: 512000 can't write: 188 rate: 43663 / 44100 [18:24:10.754097] music_delivery:427 called with num_frames: 2048 [18:24:10.754133] _streambuf_canwrite:337 player: 0 wrote 2132 stored bytes [18:24:10.754154] _streambuf_canwrite:353 state BUFFERING -> STREAMING [18:24:10.754461] _streambuf_write:274 player: 0 wrote 788 new bytes of 1680 min 788 [18:24:10.754494] _streambuf_write:285 storing remaining 892 bytes [18:24:10.754512] _streambuf_write:286 state STREAMING -> BUFFERING [18:24:10.754740] _streambuf_write:294 storing all 1671 bytes, newsize: 2563 [18:24:10.754765] _streambuf_write:295 state BUFFERING -> BUFFERING [18:24:10.754786] music_delivery:577 streamed frames: 514048 can't write: 188 rate: 43834 / 44100 Once I'm consistently below 44100, I get skips. After a while it will give up and relog into spotify (and restart the whole track): 18:24:34.949990] music_delivery:525 streamed frames: 1394688 can't write: 424 rate: 38824 / 44100 [18:24:34.950009] music_delivery:427 called with num_frames: 2048 [18:24:34.950030] _streambuf_canwrite:320 player: 0 can't write error: Resource temporarily unavailable 11 [18:24:34.950050] music_delivery:517 returning without writing - can't write [18:24:34.950067] music_delivery:525 streamed frames: 1394688 can't write: 425 rate: 38824 / 44100 [18:24:35.046243] main:539 new connection [18:24:35.047173] main:591 req: relogin res: (null) par: (null) prot: HTTP/1.0 auth: (null) [18:24:35.047308] main:1585 relogin requested [18:24:35.047567] main:1614 resetting streambuf [18:24:35.047627] _streambuf_reset:84 state BUFFERING -> IDLE [18:24:36.586000] main:539 new connection [18:24:36.587104] main:591 req: stream.flc res: spotify:track:5NfMQx9PC78r3ehFx137k6 par: player=00%3A04%3A20%3A1f%3A4b%3A1a&start=0&sync=1&id=3 pr ot: SPOTSTREAM/1.0 auth: (null) [18:24:36.587161] main:617 waiting for logout to complete [18:24:37.587309] main:617 waiting for logout to complete [18:24:37.590953] logged_out:60 logged out [18:24:38.592467] main:670 relogging in as user: jayjanssen [18:24:38.595353] log_message:80 log: 23:24:38.595 I [ap:1766] Connecting to AP ap.spotify.com:4070 [18:24:38.596315] logged_in:53 logged in [18:24:38.661709] log_message:80 log: 23:24:38.661 I [ap:1224] Connected to AP: 193.182.8.75:4070 [18:24:39.596613] main:781 newstream connection from 10.10.1.132 [18:24:39.596709] main:817 streamid: 0 newid: 3 type: FLAC [18:24:39.596732] main:854 streambuf_newstream [18:24:39.596755] streambuf_newstream:143 newstream st_fd: 0 [18:24:39.596784] set_sndbuf:227 setsockopt: asked for 32768 got 65536 [18:24:39.596802] streambuf_newstream:150 state IDLE -> READY I'd be happy to drop in some debugging version of the spotify library if it helps get more diagnostic data. ------------------------------------------------------------------------ jayjanssen's Profile: http://forums.slimdevices.com/member.php?userid=62034 View this thread: http://forums.slimdevices.com/showthread.php?t=100346 _______________________________________________ plugins mailing list [email protected] http://lists.slimdevices.com/mailman/listinfo/plugins
