Spotify Plugin not working > [WARN] Login failed: Cannot connect to Spotify/ [ERR ] Could not get the playlist container.

WalterBorgstein commented 8 years ago

Added the Spotify Plugin. Tested on RPi3, fresh install.

I use Facebook to logon to Spotify. So I had to create a password for devices. I entered the information in the Spotify plugin after installing (installing went perfect)

I can see general playlists, but can't seem to play anything.

Aug 20 13:16:57 volumio volumio[10501]: 2016-08-20 13:16:57 [SPTF] 13:16:57.472 E [ap:3953] Connection error: 117 Aug 20 13:16:57 volumio volumio[10501]: 2016-08-20 13:16:57 [SPTF] 13:16:57.472 I [ap:1752] Connecting to AP ap.spotify.com:443 Aug 20 13:16:57 volumio volumio[595]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 20 13:16:57 volumio volumio[595]: info: [1471699017479] CoreMusicLibrary::Adding element Spotify Aug 20 13:16:57 volumio volumio[595]: info: FIRST BRANCH Aug 20 13:17:02 volumio volumio[10501]: 2016-08-20 13:17:02 [SPTF] 13:17:02.476 E [ap:1694] AP Socket Error: Timeout reached (20000) Aug 20 13:17:02 volumio volumio[10501]: 2016-08-20 13:17:02 [SPTF] 13:17:02.477 E [ap:3953] Connection error: 117 Aug 20 13:17:02 volumio volumio[10501]: 2016-08-20 13:17:02 [SPTF] 13:17:02.477 I [ap:1752] Connecting to AP ap.spotify.com:80 Aug 20 13:17:03 volumio volumio[595]: info: Spotify access token expires at 1471702617468 Aug 20 13:17:03 volumio volumio[595]: info: Spotify access token is token removed Aug 20 13:17:03 volumio volumio[595]: info: Spotify credentials grant success Aug 20 13:17:07 volumio volumio[10501]: 2016-08-20 13:17:07 [SPTF] 13:17:07.480 E [ap:1694] AP Socket Error: Timeout reached (20000) Aug 20 13:17:07 volumio volumio[10501]: 2016-08-20 13:17:07 [SPTF] 13:17:07.481 E [ap:3953] Connection error: 117 Aug 20 13:17:07 volumio volumio[10501]: 2016-08-20 13:17:07 [SPTF] 13:17:07.481 I [ap:1752] Connecting to AP ap.spotify.com:4070 Aug 20 13:17:12 volumio volumio[10501]: 2016-08-20 13:17:12 [SPTF] 13:17:12.485 E [ap:1694] AP Socket Error: Timeout reached (20000) Aug 20 13:17:12 volumio volumio[10501]: 2016-08-20 13:17:12 [SPTF] 13:17:12.485 E [ap:3953] Connection error: 117 Aug 20 13:17:12 volumio volumio[10501]: 2016-08-20 13:17:12 [SPTF] 13:17:12.485 I [ap:1752] Connecting to AP ap.spotify.com:443 Aug 20 13:17:17 volumio volumio[10501]: 2016-08-20 13:17:17 [SPTF] 13:17:17.488 E [ap:1694] AP Socket Error: Timeout reached (20000) Aug 20 13:17:17 volumio volumio[10501]: 2016-08-20 13:17:17 [SPTF] 13:17:17.488 E [ap:3953] Connection error: 117 Aug 20 13:17:17 volumio volumio[10501]: 2016-08-20 13:17:17 [SPTF] 13:17:17.488 I [ap:1752] Connecting to AP ap.spotify.com:80 Aug 20 13:17:22 volumio volumio[10501]: 2016-08-20 13:17:22 [SPTF] 13:17:22.491 E [ap:1694] AP Socket Error: Timeout reached (20000) Aug 20 13:17:22 volumio volumio[10501]: 2016-08-20 13:17:22 [SPTF] 13:17:22.491 E [ap:3953] Connection error: 117 Aug 20 13:17:22 volumio volumio[10501]: 2016-08-20 13:17:22 [WARN] Login failed: Cannot connect to Spotify Aug 20 13:17:22 volumio volumio[10501]: 2016-08-20 13:17:22 [ERR ] Could not get the playlist container. Aug 20 13:17:22 volumio systemd[1]: spop.service: main process exited, code=killed, status=5/TRAP Aug 20 13:17:22 volumio systemd[1]: Unit spop.service entered failed state.

WalterBorgstein commented 8 years ago

On playing from a "general" playlist, the following appeared in the journal log.

Aug 20 13:25:21 volumio volumio[595]: info: {"uri":"spotify:track:23L5CiUhw2jV1OIMwthR3S","service":"spop","name":"In the Name of Love","artist":"Martin Garrix","album":"In the Name of Love","type":"track","duration":195,"tracknumber":1,"albumart":"https://i.scdn.co/image/a1a2e08be66df92c75e46ad8330c9d4937bff209","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}
Aug 20 13:25:21 volumio volumio[595]: info: [1471699521624] ControllerSpop::sendSpopCommand
Aug 20 13:25:21 volumio volumio[595]: info: ADDING DEFER FOR COMMAND play
Aug 20 13:25:21 volumio volumio[595]: COMMON.PLAY_TITLE
Aug 20 13:25:21 volumio volumio[595]: [ 'COMMON', 'PLAY_TITLE' ]
Aug 20 13:25:21 volumio volumio[595]: COMMON.PLAY_TEXT
Aug 20 13:25:21 volumio volumio[595]: [ 'COMMON', 'PLAY_TEXT' ]
Aug 20 13:25:21 volumio volumio[595]: info: SPOP command error:
Aug 20 13:25:21 volumio volumio[595]: info:  Error: This socket has been ended by the other party
Aug 20 13:25:21 volumio volumio[595]: at Socket.writeAfterFIN [as write] (net.js:285:12)
Aug 20 13:25:21 volumio volumio[595]: at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
Aug 20 13:25:21 volumio volumio[595]: at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
Aug 20 13:25:21 volumio volumio[595]: at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
Aug 20 13:25:21 volumio volumio[595]: at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
Aug 20 13:25:21 volumio volumio[595]: at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
Aug 20 13:25:21 volumio volumio[595]: at Promise._successFn (/data/plugins/music_service/spop/index.js:1031:16)
Aug 20 13:25:21 volumio volumio[595]: at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
Aug 20 13:25:21 volumio volumio[595]: at _combinedTickCallback (internal/process/next_tick.js:67:7)
Aug 20 13:25:21 volumio volumio[595]: at process._tickCallback (internal/process/next_tick.js:98:9)

WalterBorgstein commented 8 years ago

Fresh install, install of Spotify plugin:

I can see the public playlist, not private.

Error appears in the log:

info: Error: This socket has been ended by the other party

Following is the log of clicking a random song:

Aug 20 19:06:48 volumio volumio[545]: info: CoreCommandRouter::volumioAddQueueItems
Aug 20 19:06:48 volumio volumio[545]: info: [1471720008072] CoreStateMachine::addQueueItems
Aug 20 19:06:48 volumio volumio[545]: info: [1471720008073] CorePlayQueue::addQueueItems
Aug 20 19:06:48 volumio volumio[545]: info:  uri=spotify:track:3hfN1wQSiLPa6b1RX5Kfbj, title=WHISTLE, service=spop
Aug 20 19:06:48 volumio volumio[545]: info: First index is 0
Aug 20 19:06:48 volumio volumio[545]: info: ADDING THIS ITEM TO QUEUE: {"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","title":"WHISTLE","service":"stop"}
Aug 20 19:06:48 volumio volumio[545]: info: Exploding uri spotify:track:3hfN1wQSiLPa6b1RX5Kfbj in service spop
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013841] CorePlayQueue::saveQueue
Aug 20 19:06:53 volumio volumio[545]: info: Adding item to queue: [{"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}]
Aug 20 19:06:53 volumio volumio[545]: info: CoreCommandRouter::volumioPushQueue
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013844] InterfaceWebUI::pushQueue
Aug 20 19:06:53 volumio volumio[545]: info: [{"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}]
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013846] CoreStateMachine::updateTrackBlock
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013847] CorePlayQueue::getTrackBlock
Aug 20 19:06:53 volumio volumio[545]: info: CoreCommandRouter::volumioPlay
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013848] CoreStateMachine::play
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013848] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013849] CoreStateMachine::stop
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013849] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013850] CoreStateMachine::play
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013851] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013851] CorePlayQueue::getTrack 0
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013852] CoreStateMachine::startPlaybackTimer
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013853] ControllerSpop::clearAddPlayTrack
Aug 20 19:06:53 volumio volumio[545]: info: {"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013855] ControllerSpop::sendSpopCommand
Aug 20 19:06:53 volumio volumio[545]: info: ADDING DEFER FOR COMMAND play
Aug 20 19:06:53 volumio volumio[545]: COMMON.PLAY_TITLE
Aug 20 19:06:53 volumio volumio[545]: [ 'COMMON', 'PLAY_TITLE' ]
Aug 20 19:06:53 volumio volumio[545]: COMMON.PLAY_TEXT
Aug 20 19:06:53 volumio volumio[545]: [ 'COMMON', 'PLAY_TEXT' ]
Aug 20 19:06:53 volumio volumio[545]: info: SPOP command error:
Aug 20 19:06:53 volumio volumio[545]: info:  Error: This socket has been ended by the other party
Aug 20 19:06:53 volumio volumio[545]: at Socket.writeAfterFIN [as write] (net.js:285:12)
Aug 20 19:06:53 volumio volumio[545]: at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
Aug 20 19:06:53 volumio volumio[545]: at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
Aug 20 19:06:53 volumio volumio[545]: at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
Aug 20 19:06:53 volumio volumio[545]: at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
Aug 20 19:06:53 volumio volumio[545]: at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
Aug 20 19:06:53 volumio volumio[545]: at Promise._successFn (/data/plugins/music_service/spop/index.js:1031:16)
Aug 20 19:06:53 volumio volumio[545]: at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
Aug 20 19:06:53 volumio volumio[545]: at _combinedTickCallback (internal/process/next_tick.js:67:7)
Aug 20 19:06:53 volumio volumio[545]: at process._tickCallback (internal/process/next_tick.js:98:9)

Aug 20 19:06:48 volumio volumio[545]: info: CoreCommandRouter::volumioAddQueueItems
Aug 20 19:06:48 volumio volumio[545]: info: [1471720008072] CoreStateMachine::addQueueItems
Aug 20 19:06:48 volumio volumio[545]: info: [1471720008073] CorePlayQueue::addQueueItems
Aug 20 19:06:48 volumio volumio[545]: info:  uri=spotify:track:3hfN1wQSiLPa6b1RX5Kfbj, title=WHISTLE, service=spop
Aug 20 19:06:48 volumio volumio[545]: info: First index is 0
Aug 20 19:06:48 volumio volumio[545]: info: ADDING THIS ITEM TO QUEUE: {"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","title":"WHISTLE","service":"stop"}
Aug 20 19:06:48 volumio volumio[545]: info: Exploding uri spotify:track:3hfN1wQSiLPa6b1RX5Kfbj in service spop
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013841] CorePlayQueue::saveQueue
Aug 20 19:06:53 volumio volumio[545]: info: Adding item to queue: [{"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}]
Aug 20 19:06:53 volumio volumio[545]: info: CoreCommandRouter::volumioPushQueue
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013844] InterfaceWebUI::pushQueue
Aug 20 19:06:53 volumio volumio[545]: info: [{"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}]
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013846] CoreStateMachine::updateTrackBlock
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013847] CorePlayQueue::getTrackBlock
Aug 20 19:06:53 volumio volumio[545]: info: CoreCommandRouter::volumioPlay
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013848] CoreStateMachine::play
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013848] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013849] CoreStateMachine::stop
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013849] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013850] CoreStateMachine::play
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013851] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013851] CorePlayQueue::getTrack 0
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013852] CoreStateMachine::startPlaybackTimer
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013853] ControllerSpop::clearAddPlayTrack
Aug 20 19:06:53 volumio volumio[545]: info: {"uri":"spotify:track:3hfN1wQSiLPa6b1RX5Kfbj","service":"spop","name":"WHISTLE","artist":"Blackpink","album":"SQUARE ONE","type":"track","duration":211,"tracknumber":1,"albumart":"https://i.scdn.co/image/119a66360da4b3f446d709b19b4a91b319daaebc","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}
Aug 20 19:06:53 volumio volumio[545]: info: [1471720013855] ControllerSpop::sendSpopCommand
Aug 20 19:06:53 volumio volumio[545]: info: ADDING DEFER FOR COMMAND play
Aug 20 19:06:53 volumio volumio[545]: COMMON.PLAY_TITLE
Aug 20 19:06:53 volumio volumio[545]: [ 'COMMON', 'PLAY_TITLE' ]
Aug 20 19:06:53 volumio volumio[545]: COMMON.PLAY_TEXT
Aug 20 19:06:53 volumio volumio[545]: [ 'COMMON', 'PLAY_TEXT' ]
Aug 20 19:06:53 volumio volumio[545]: info: SPOP command error:
Aug 20 19:06:53 volumio volumio[545]: info:  Error: This socket has been ended by the other party
Aug 20 19:06:53 volumio volumio[545]: at Socket.writeAfterFIN [as write] (net.js:285:12)
Aug 20 19:06:53 volumio volumio[545]: at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
Aug 20 19:06:53 volumio volumio[545]: at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
Aug 20 19:06:53 volumio volumio[545]: at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
Aug 20 19:06:53 volumio volumio[545]: at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
Aug 20 19:06:53 volumio volumio[545]: at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
Aug 20 19:06:53 volumio volumio[545]: at Promise._successFn (/data/plugins/music_service/spop/index.js:1031:16)
Aug 20 19:06:53 volumio volumio[545]: at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
Aug 20 19:06:53 volumio volumio[545]: at _combinedTickCallback (internal/process/next_tick.js:67:7)
Aug 20 19:06:53 volumio volumio[545]: at process._tickCallback (internal/process/next_tick.js:98:9)

balbuze commented 8 years ago

are you using Spotify with the same account from an other device ? (I mean in the same time)

WalterBorgstein commented 8 years ago

No. I do have a family account, that has 5 users for the account. Maybe one of them is using it. I can't be sure.

balbuze commented 8 years ago

ok but I mean log with the same credential. I 've got a family account too, but each member have its own credential. In the case a account is used, I don't think you're able to use it in the same time from a other device. But is just a question as I never encounter such problem. But I don't log with a facebook account...

WalterBorgstein commented 8 years ago

No for sure I'm not using my credentials somewhere else (like iPhone or KODI). So it not a general issue then. That makes me worry about my install :(.

WalterBorgstein commented 8 years ago

volumio@volumio:~$ nslookup ap.spotify.com
Server: 8.8.4.4 Address: 8.8.4.4#53

Non-authoritative answer: ap.spotify.com canonical name = ap.gslb.spotify.com. Name: ap.gslb.spotify.com Address: 193.182.7.82 Name: ap.gslb.spotify.com Address: 194.132.162.151 Name: ap.gslb.spotify.com Address: 194.14.177.22 Name: ap.gslb.spotify.com Address: 194.132.162.149 Name: ap.gslb.spotify.com Address: 194.14.177.37 Name: ap.gslb.spotify.com Address: 194.132.204.162 Name: ap.gslb.spotify.com Address: 194.132.162.136 Name: ap.gslb.spotify.com Address: 194.14.177.18

I can nslookup the Spotify adres. (I performed a sudo apt-get install dnsutils to get NSLOOKUP for that.

skikirkwood commented 8 years ago

From the log files it looks to me like there's some problem connecting to the Spotify spop daemon on your machine.

Look at your process list (ps -ef) and you should have the spopd process running:

/usr/bin/spopd -f -c /etc/spopd.conf

If not, try starting it and restarting Volumio's node.js process (killall node). If spopd is running try killing it, restarting Volumio and see if that helps.

The Spotify plugin tries to connect to the spop process on port 6602, and for some reason that is not happening on your machine.

WalterBorgstein commented 8 years ago

Thanks.

I could not find the /usr/bin/spopd -f -c /etc/spopd.conf so I executed killall node After that, Volumio restarts (i hear the startup sound) I can see the /usr/bin/spopd -f -c /etc/spopd.conf couple seconds later using the ps -ef, it is gone.

Following appears in the journal log.

Aug 20 21:28:36 volumio systemd[1]: spop.service: main process exited, code=killed, status=5/TRAP
Aug 20 21:28:36 volumio systemd[1]: Unit spop.service entered failed state.

after starting the spopd I receive the following:

volumio@volumio:~$ /usr/bin/spopd -f -c /etc/spopd.conf
/usr/bin/spopd: error while loading shared libraries: libspotify.so.12: cannot open shared object file: No such file or directory
volumio@volumio:~$

skikirkwood commented 8 years ago

Ok, it's good we definitely narrowed down the issue to spopd. I worked on the recent enhancements to the Spotify Plugin that uses the new Spotify Web API, but not that familiar with spopd. I did find the error message you got listed as an open issue with spop however:

https://github.com/Schnouki/spop/issues/22

Can you delete your queue to make sure nothing is starting up before you try using Spotify. I'm afraid I don't think I can help diagnose the problem beyond this.

WalterBorgstein commented 8 years ago

To make sure I didn't miss any log entries. I did the killall node again. From that point (including me clearing the queue as requested) is pasted below.

Aug 20 21:43:02 volumio volumio[546]: [1471729382407] ---------------------------- Client requests Volumio Clear Queue
Aug 20 21:43:02 volumio volumio[546]: info: CoreCommandRouter::volumioClearQueue
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382409] CoreStateMachine::ClearQueue
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382410] CoreStateMachine::stop
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382411] CoreStateMachine::setConsumeUpdateService undefined
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382413] CorePlayQueue::clearPlayQueue
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382414] CorePlayQueue::saveQueue
Aug 20 21:43:02 volumio volumio[546]: info: CoreCommandRouter::volumioPushQueue
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382418] InterfaceWebUI::pushQueue
Aug 20 21:43:02 volumio volumio[546]: info: []
Aug 20 21:43:02 volumio volumio[546]: info: [1471729382422] ------------------------------ 15ms
Aug 20 21:43:42 volumio sudo[2134]: volumio : TTY=pts/1 ; PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/killall node
Aug 20 21:43:42 volumio sudo[2134]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Aug 20 21:43:42 volumio sudo[2134]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:42 volumio mpd[578]: client: [0] closed
Aug 20 21:43:42 volumio systemd[1]: volumio.service holdoff time over, scheduling restart.
Aug 20 21:43:42 volumio systemd[1]: Stopping volumio.service...
Aug 20 21:43:42 volumio systemd[1]: Starting volumio.service...
Aug 20 21:43:42 volumio systemd[1]: Started volumio.service.
Aug 20 21:43:45 volumio volumio[2144]: info: -------------------------------------------
Aug 20 21:43:45 volumio volumio[2144]: info: -----            Volumio2              ----
Aug 20 21:43:45 volumio volumio[2144]: info: -------------------------------------------
Aug 20 21:43:45 volumio volumio[2144]: info: -----          System startup          ----
Aug 20 21:43:45 volumio volumio[2144]: info: -------------------------------------------
Aug 20 21:43:45 volumio volumio[2144]: info: Plugin folders cleanup
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning into folder /volumio/app/plugins/
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category audio_interface
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category miscellanea
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category music_service
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category plugins.json
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category system_controller
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category user_interface
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning into folder /data/plugins/
Aug 20 21:43:45 volumio volumio[2144]: info: Scanning category music_service
Aug 20 21:43:45 volumio volumio[2144]: info: Plugin folders cleanup completed
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugins from folder /volumio/app/plugins/
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugins from folder /data/plugins/
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "system"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "appearance"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "network"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "services"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "alsa_controller"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "volumio_command_line_client"...
Aug 20 21:43:45 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:45 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:45 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "volumiodiscovery"...
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 20 21:43:45 volumio node[2144]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 20 21:43:45 volumio volumio[2144]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Aug 20 21:43:45 volumio volumio[2144]: info: Applying required configuration parameters for plugin volumiodiscovery
Aug 20 21:43:45 volumio volumio[2144]: Discovery: StartAdv! undefined
Aug 20 21:43:45 volumio volumio[2144]: Discovery: Started advertising... Volumio - undefined
Aug 20 21:43:45 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "upnp"...
Aug 20 21:43:45 volumio volumio[2144]: info: [1471729425786] Starting Upmpd Daemon
Aug 20 21:43:45 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "airplay_emulation"...
Aug 20 21:43:45 volumio volumio[2144]: info: [1471729425811] Starting Shairport Sync
Aug 20 21:43:45 volumio volumio[2144]: plight:5,0
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "mpd"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "networkfs"...
Aug 20 21:43:45 volumio volumio[2144]: info: Loading plugin "alarm-clock"...
Aug 20 21:43:45 volumio sudo[2171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.3:volume1/Music /mnt/NAS/Synology
Aug 20 21:43:45 volumio sudo[2171]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "webradio"...
Aug 20 21:43:46 volumio sudo[2171]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "i2s_dacs"...
Aug 20 21:43:46 volumio volumio[2144]: info: I2S DAC not set, start Auto-detection on USB Bus
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "albumart"...
Aug 20 21:43:46 volumio volumio[2144]: info: Plugin example_plugin is not enabled
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "updater_comm"...
Aug 20 21:43:46 volumio volumio[2144]: info: Plugin mpdemulation is not enabled
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "websocket"...
Aug 20 21:43:46 volumio volumio[2144]: info: Loading plugin "spop"...
Aug 20 21:43:47 volumio volumio[2144]: info: Applying required configuration parameters for plugin stop
Aug 20 21:43:47 volumio volumio[2144]: info: ___________ START PLUGINS ___________
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 20 21:43:47 volumio volumio[2144]: info: [1471729427524] CoreMusicLibrary::Adding element Webradio
Aug 20 21:43:47 volumio volumio[2144]: info: Loading i18n strings for locale en
Aug 20 21:43:47 volumio volumio[2144]: Updating browse sources language
Aug 20 21:43:47 volumio volumio[2144]: COMMON.FAVOURITES
Aug 20 21:43:47 volumio sudo[2195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start spop.service
Aug 20 21:43:47 volumio sudo[2195]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 20 21:43:47 volumio volumio[2144]: [ 'COMMON', 'FAVOURITES' ]
Aug 20 21:43:47 volumio volumio[2144]: COMMON.PLAYLISTS
Aug 20 21:43:47 volumio volumio[2144]: [ 'COMMON', 'PLAYLISTS' ]
Aug 20 21:43:47 volumio volumio[2144]: COMMON.MUSIC_LIBRARY
Aug 20 21:43:47 volumio volumio[2144]: [ 'COMMON', 'MUSIC_LIBRARY' ]
Aug 20 21:43:47 volumio volumio[2144]: WEBRADIO.WEBRADIO
Aug 20 21:43:47 volumio volumio[2144]: [ 'WEBRADIO', 'WEBRADIO' ]
Aug 20 21:43:47 volumio systemd[1]: Starting Spotify Daemon...
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:47 volumio sudo[2195]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:47 volumio systemd[1]: Started Spotify Daemon.
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 20 21:43:47 volumio volumio[2144]: info: BOOT COMPLETED
Aug 20 21:43:47 volumio volumio[2144]: Express server listening on port 3000
Aug 20 21:43:47 volumio volumio[2144]: Volumio Calling Home
Aug 20 21:43:47 volumio volumio[2200]: 2016-08-20 21:43:47 [SPTF] 21:43:47.680 I [offline_authorizer.cpp:297] Unable to login offline: no such user
Aug 20 21:43:47 volumio volumio[2200]: 2016-08-20 21:43:47 [SPTF] 21:43:47.681 I [ap:1752] Connecting to AP ap.spotify.com:4070
Aug 20 21:43:47 volumio volumio[2144]: info: [1471729427688] CoreStateMachine::resetVolumioState
Aug 20 21:43:47 volumio volumio[2144]: info: [1471729427691] CoreStateMachine::getcurrentVolume
Aug 20 21:43:47 volumio volumio[2144]: info: CoreCommandRouter::volumioRetrievevolume
Aug 20 21:43:47 volumio volumio[2144]: info: [1471729427713] CoreStateMachine::updateTrackBlock
Aug 20 21:43:47 volumio volumio[2144]: info: [1471729427715] CorePlayQueue::getTrackBlock
Aug 20 21:43:47 volumio volumio[2144]: info: SpopD Daemon Started
Aug 20 21:43:47 volumio volumio[2144]: info: MPD running with PID578 ,establishing connection
Aug 20 21:43:47 volumio sudo[2215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cdetect -y 1
Aug 20 21:43:47 volumio sudo[2215]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 20 21:43:47 volumio volumio[2144]: info: Setting Device type: Raspberry PI
Aug 20 21:43:47 volumio mpd[578]: client: [2] opened from ::ffff:127.0.0.1:56994
Aug 20 21:43:47 volumio sudo[2215]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428045] VolumeController:: Volume=undefined Mute =undefined
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428050] CoreStateMachine::pushState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428053] CoreStateMachine::getState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428056] CorePlayQueue::getTrack 0
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::volumioPushState
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428065] InterfaceWebUI::pushState
Aug 20 21:43:48 volumio volumio[2144]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Aug 20 21:43:48 volumio volumio[2144]: info: Reloading queue from file
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Aug 20 21:43:48 volumio volumio[2144]: info: Setting volume on startup at disabled
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::volumioGetState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428325] CoreStateMachine::getState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428326] CorePlayQueue::getTrack 0
Aug 20 21:43:48 volumio volumio[2144]: info:
Aug 20 21:43:48 volumio volumio[2144]: [1471729428327] ---------------------------- Client requests Volumio state
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428332] Listing playlists
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 20 21:43:48 volumio volumio[2144]: Plugin multiroom or method getMultiroom not found
Aug 20 21:43:48 volumio volumio[2144]: info:
Aug 20 21:43:48 volumio volumio[2144]: [1471729428340] ---------------------------- Client requests Menu Items
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::volumioGetBrowseSources
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::volumioGetQueue
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428349] CoreStateMachine::getQueue
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428350] CorePlayQueue::getQueue
Aug 20 21:43:48 volumio volumio[2144]: info:
Aug 20 21:43:48 volumio volumio[2144]: [1471729428352] ---------------------------- Client requests Volumio queue
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428358] InterfaceWebUI::pushState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428364] InterfaceWebUI::pushQueue
Aug 20 21:43:48 volumio volumio[2144]: info: []
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428368] ------------------------------ 44ms
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428370] ------------------------------ 23ms
Aug 20 21:43:48 volumio volumio[2144]: info:
Aug 20 21:43:48 volumio volumio[2144]: info:
Aug 20 21:43:48 volumio volumio[2144]: [1471729428395] ---------------------------- Client requests Volume disabled
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428399] VolumeController::SetAlsaVolumedisabled
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428415] ------------------------------ 20ms
Aug 20 21:43:48 volumio sudo[2226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428487] VolumeController::Volume 100
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428489] CoreStateMachine::pushState
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428491] CoreStateMachine::getState
Aug 20 21:43:48 volumio sudo[2226]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428492] CorePlayQueue::getTrack 0
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::volumioPushState
Aug 20 21:43:48 volumio volumio[2144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428498] InterfaceWebUI::pushState
Aug 20 21:43:48 volumio systemd[1]: [/lib/systemd/system/upmpdcli.service:8] Failed to parse service restart specifier, ignoring: never
Aug 20 21:43:48 volumio systemd[1]: Starting UPnP Renderer front-end to MPD...
Aug 20 21:43:48 volumio sudo[2228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Aug 20 21:43:48 volumio sudo[2228]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 20 21:43:48 volumio systemd[1]: Started UPnP Renderer front-end to MPD.
Aug 20 21:43:48 volumio volumio[2144]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Aug 20 21:43:48 volumio systemd[1]: Stopping ShairportSync AirTunes receiver...
Aug 20 21:43:48 volumio shairport-sync[859]: exit...
Aug 20 21:43:48 volumio systemd[1]: Starting ShairportSync AirTunes receiver...
Aug 20 21:43:48 volumio sudo[2226]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:48 volumio systemd[1]: Started ShairportSync AirTunes receiver.
Aug 20 21:43:48 volumio mpd[578]: client: [3] opened from ::ffff:127.0.0.1:56996
Aug 20 21:43:48 volumio sudo[2228]: pam_unix(sudo:session): session closed for user root
Aug 20 21:43:48 volumio shairport-sync[2240]: startup
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428599] ------------------------------ 260ms
Aug 20 21:43:48 volumio volumio[2144]: Discovery: adding 1e5a3670-093d-478f-a205-cab31193bd5e
Aug 20 21:43:48 volumio volumio[2144]: info: mDNS: Found device Volumio
Aug 20 21:43:48 volumio volumio[2144]: info: [1471729428629] Shairport-Sync Started
Aug 20 21:43:48 volumio volumio[2144]: info: Upmpdcli Daemon Started
Aug 20 21:43:48 volumio volumio[2144]: success!
Aug 20 21:43:52 volumio volumio[2200]: 2016-08-20 21:43:52 [SPTF] 21:43:52.686 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:43:52 volumio volumio[2200]: 2016-08-20 21:43:52 [SPTF] 21:43:52.686 E [ap:3953] Connection error:  117
Aug 20 21:43:52 volumio volumio[2200]: 2016-08-20 21:43:52 [SPTF] 21:43:52.687 I [ap:1752] Connecting to AP ap.spotify.com:443
Aug 20 21:43:52 volumio volumio[2144]: info: Connecting to daemon
Aug 20 21:43:52 volumio volumio[2144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 20 21:43:52 volumio volumio[2144]: info: [1471729432980] CoreMusicLibrary::Adding element Spotify
Aug 20 21:43:52 volumio volumio[2144]: info: FIRST BRANCH
Aug 20 21:43:54 volumio volumio[2144]: info: Volumio called home
Aug 20 21:43:57 volumio volumio[2200]: 2016-08-20 21:43:57 [SPTF] 21:43:57.691 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:43:57 volumio volumio[2200]: 2016-08-20 21:43:57 [SPTF] 21:43:57.692 E [ap:3953] Connection error:  117
Aug 20 21:43:57 volumio volumio[2200]: 2016-08-20 21:43:57 [SPTF] 21:43:57.692 I [ap:1752] Connecting to AP ap.spotify.com:80
Aug 20 21:43:58 volumio volumio[2144]: info: Spotify access token expires at 1471733032882
Aug 20 21:43:58 volumio volumio[2144]: info: Spotify access token is *token removed*
Aug 20 21:43:58 volumio volumio[2144]: info: Spotify credentials grant success
Aug 20 21:44:02 volumio volumio[2200]: 2016-08-20 21:44:02 [SPTF] 21:44:02.696 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:44:02 volumio volumio[2200]: 2016-08-20 21:44:02 [SPTF] 21:44:02.696 E [ap:3953] Connection error:  117
Aug 20 21:44:02 volumio volumio[2200]: 2016-08-20 21:44:02 [SPTF] 21:44:02.696 I [ap:1752] Connecting to AP ap.spotify.com:4070
Aug 20 21:44:07 volumio volumio[2200]: 2016-08-20 21:44:07 [SPTF] 21:44:07.701 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:44:07 volumio volumio[2200]: 2016-08-20 21:44:07 [SPTF] 21:44:07.701 E [ap:3953] Connection error:  117
Aug 20 21:44:07 volumio volumio[2200]: 2016-08-20 21:44:07 [SPTF] 21:44:07.701 I [ap:1752] Connecting to AP ap.spotify.com:443
Aug 20 21:44:12 volumio volumio[2200]: 2016-08-20 21:44:12 [SPTF] 21:44:12.706 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:44:12 volumio volumio[2200]: 2016-08-20 21:44:12 [SPTF] 21:44:12.706 E [ap:3953] Connection error:  117
Aug 20 21:44:12 volumio volumio[2200]: 2016-08-20 21:44:12 [SPTF] 21:44:12.706 I [ap:1752] Connecting to AP ap.spotify.com:80
Aug 20 21:44:17 volumio volumio[2200]: 2016-08-20 21:44:17 [SPTF] 21:44:17.710 E [ap:1694] AP Socket Error: Timeout reached (20000)
Aug 20 21:44:17 volumio volumio[2200]: 2016-08-20 21:44:17 [SPTF] 21:44:17.710 E [ap:3953] Connection error:  117
Aug 20 21:44:17 volumio volumio[2200]: 2016-08-20 21:44:17 [WARN] Login failed: Cannot connect to Spotify
Aug 20 21:44:17 volumio volumio[2200]: 2016-08-20 21:44:17 [ERR ] Could not get the playlist container.
Aug 20 21:44:17 volumio systemd[1]: spop.service: main process exited, code=killed, status=5/TRAP
Aug 20 21:44:17 volumio systemd[1]: Unit spop.service entered failed state.

skikirkwood commented 8 years ago

Walter, you are getting a bunch of 117 connection errors, which I believe is coming from spopd trying to connect to Spotify. People have had this before:

https://ubuntuforums.org/showthread.php?t=1035338

Have you ever successfully run Spotify on Volumio on this Rpi?

skikirkwood commented 8 years ago

Here's a posting from Spotify support regarding what to check when a 117 error occurs:

https://community.spotify.com/t5/Desktop-Linux-Windows-Web-Player/Troubleshooting-connection-issues/td-p/104003

WalterBorgstein commented 8 years ago

No I never got Spotify to work. Just started with RPB3 and Volumio. ;)

WalterBorgstein commented 8 years ago

Spotify does work on my iPhone, and Windows 10 PC. They are all going thru the same router. So it should work connection wise. (btw, the other accounts are not running as I am testing)

skikirkwood commented 8 years ago

A final thing I would try checking, if you haven't, is running the Spotify Web player (play.spotify.com) on your PC and ensure that works, in case you are using the Spotify Windows app. I'm pretty sure it's some kind of networking issue blocking the connection, but I'm out of ideas as to how to diagnose it further, beyond perhaps logging out of your Spotify account on the Web, and logging back in, which might reset something on Spotify's servers. Final thing is I would change your Spotify password.

Here's one more odd posting on the Spotify forums:

joaquimabc joaquimabc Concert Regular ‎2015-10-11 02:46 PM I have a family account. Since i cancel and adn sing to add a new user i get a error 117 message in linux... In android the downlowd to play off-line stay in waiting...

My firewall is off, and, other users play normaly....

I think this is a change in the server...

Is this?

WalterBorgstein commented 8 years ago

Thanks for all your help! I will try this.

I reset my router
created a new account for Spotify
Tried the web player on Windows 10 with the new account. Worked. (had to activate Flash yuk)
Gave that new account a family invite and am now using that one Still nothing.

IT WORKS! Possible causes:

changed the DNS sorting in my router (made 8.8.4.4 DNS1)
rebooted router
I logged in via Web Player with this new account
changed password again

shawaj commented 8 years ago

I had the same issue when trying to log in to Spotify with email address instead of username.

I never created the username so didn't know it existed but accidentally happened upon it in Spotify settings and tried it and it worked. Could this have been your issue?

WalterBorgstein commented 8 years ago

No, I tried all combinations. User number, user account, email etc. I'm currently logged in as my Spotify number.

renatocribeiro commented 5 years ago

For the Facebook users coming here for an answer, you need a device password and a username. Not your facebook login/password! Go to https://www.spotify.com/au/account/set-device-password/ for your username (sequence of numbers) and to set a device password.

volumio / Volumio2

Spotify Plugin not working > [WARN] Login failed: Cannot connect to Spotify/ [ERR ] Could not get the playlist container. #657