Just update to the latest version of the plugin, and I’m receiving new errors I hadn’t seen before:
2016-11-10T11:02:25.537Z - info: Spotify credentials grant failed with WebapiError: connect ETIMEDOUT 194.132.196.228:443
Right after the socket end message.
The strange thing is, my Pi2B seems to have trouble communicating to Spotify if I send too many commands in a short period of time, like switching playlists. If I continue down this path my playlists will not show anymore, with emphasis on my playlists, because ‘featured playlists’, ‘what’s new’ and ‘genres & moods’ do seem be working. Adding either one of those playlist to the queue works and volumio will start playback, still after playback has started browsing my playlists fails.
The PiB+ just jams and will not recover until I reboot the device.
Please also note that switching to my own music (SMB share) works flawlessly, on both the PiB+ and Pi2B (and Pi3B). All devices have been tested with DIGI DAC’s. (PiAudio and HifiBerry)
2016-11-10T11:00:52.928Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":177000,"samplerate":"320Kbps","bitdepth":null,"channels":null,"artist":"Zain Bhikha","title":"Nkosi Sikelel 'iAfrika","album":"Night Of Remembrance: Live At Royal Albert Hall"}
2016-11-10T11:00:52.952Z - info: CURRENT POSITION 0
2016-11-10T11:00:52.967Z - info: [1478775652954] CoreStateMachine::syncState stateService play
2016-11-10T11:00:52.982Z - info: [1478775652969] CoreStateMachine::syncState currentStatus stop
2016-11-10T11:00:53.017Z - info: [1478775652987] CoreStateMachine::pushState
2016-11-10T11:00:53.023Z - info: [1478775653018] CoreStateMachine::getState
2016-11-10T11:00:53.040Z - info: [1478775653024] CorePlayQueue::getTrack 0
2016-11-10T11:00:53.059Z - info: CoreCommandRouter::volumioPushState
2016-11-10T11:00:53.062Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2016-11-10T11:00:53.486Z - info: [1478775653462] InterfaceWebUI::pushState
2016-11-10T11:00:53.578Z - info: [1478775653571] ------------------------------ 1325ms
2016-11-10T11:00:53.640Z - info: Pushing Favourites {"service":"spop","uri":"spotify:track:2Gyt8gO9YoEIxyPnpHau7D","favourite":false}
2016-11-10T11:01:11.542Z - info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
2016-11-10T11:01:11.552Z - info: [1478775671547] ControllerSpop::sendSpopCommand
2016-11-10T11:01:11.564Z - info: ADDING DEFER FOR COMMAND ls
2016-11-10T11:01:11.573Z - info: SPOP command error:
2016-11-10T11:01:11.587Z - info: Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:285:12)
at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
at Promise._successFn (/data/plugins/music_service/spop/index.js:1201:16)
at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
at _combinedTickCallback (internal/process/next_tick.js:67:7)
at process._tickCallback (internal/process/next_tick.js:98:9)
2016-11-10T11:02:25.537Z - info: Spotify credentials grant failed with WebapiError: connect ETIMEDOUT 194.132.196.228:443
2016-11-10T11:02:45.903Z - info: Spotify credentials grant failed with WebapiError: connect ETIMEDOUT 194.132.196.228:443
2016-11-10T11:03:43.478Z - info: [1478775823472] CorePlayQueue::getTrack 0
2016-11-10T11:03:43.485Z - info: [1478775823479] CorePlayQueue::getTrack 1
2016-11-10T11:03:43.491Z - info: Prefetching next song
2016-11-10T11:04:18.867Z - info:
[1478775858860] ---------------------------- Client requests Volumio play at index 4
2016-11-10T11:04:18.871Z - info: CoreCommandRouter::volumioPlay
2016-11-10T11:04:18.876Z - info: [1478775858874] CoreStateMachine::play
2016-11-10T11:04:18.889Z - info: [1478775858887] CoreStateMachine::setConsumeUpdateService undefined
2016-11-10T11:04:18.894Z - info: [1478775858892] CoreStateMachine::stop
2016-11-10T11:04:18.907Z - info: [1478775858895] CoreStateMachine::setConsumeUpdateService undefined
2016-11-10T11:04:18.922Z - info: [1478775858916] CoreStateMachine::stPlaybackTimer
2016-11-10T11:04:18.932Z - info: [1478775858927] CoreStateMachine::updateTrackBlock
2016-11-10T11:04:18.939Z - info: [1478775858933] CorePlayQueue::getTrackBlock
2016-11-10T11:04:18.951Z - info: [1478775858946] CoreStateMachine::pushState
2016-11-10T11:04:18.958Z - info: [1478775858952] CoreStateMachine::getState
2016-11-10T11:04:18.964Z - info: [1478775858959] CorePlayQueue::getTrack 4
2016-11-10T11:04:18.967Z - info: CoreCommandRouter::volumioPushState
2016-11-10T11:04:18.969Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2016-11-10T11:04:18.975Z - info: [1478775858974] InterfaceWebUI::pushState
2016-11-10T11:04:19.094Z - info: [1478775859088] CoreStateMachine::serviceStop
2016-11-10T11:04:19.101Z - info: [1478775859095] CorePlayQueue::getTrack 4
2016-11-10T11:04:19.108Z - info: CoreCommandRouter::serviceStop
2016-11-10T11:04:19.120Z - info: [1478775859109] ControllerSpop::stop
2016-11-10T11:04:19.123Z - info: [1478775859121] ControllerSpop::sendSpopCommand
2016-11-10T11:04:19.126Z - info: ADDING DEFER FOR COMMAND stop
2016-11-10T11:04:19.160Z - info: SPOP command error:
2016-11-10T11:04:19.177Z - info: Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:285:12)
at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
at Promise._successFn (/data/plugins/music_service/spop/index.js:1201:16)
at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
at _combinedTickCallback (internal/process/next_tick.js:67:7)
at process._tickCallback (internal/process/next_tick.js:98:9)
2016-11-10T11:04:19.238Z - info: Pushing Favourites {"service":"spop","uri":"spotify:track:7i86nU8E2Fpn0UgGbXU6l9","favourite":false}
2016-11-10T11:04:24.132Z - info:
[1478775864123] ---------------------------- Client requests Volumio play
2016-11-10T11:04:24.136Z - info: CoreCommandRouter::volumioPlay
2016-11-10T11:04:24.143Z - info: [1478775864141] CoreStateMachine::play
2016-11-10T11:04:24.145Z - info: [1478775864144] CoreStateMachine::setConsumeUpdateService undefined
2016-11-10T11:04:24.159Z - info: [1478775864158] CorePlayQueue::getTrack 4
2016-11-10T11:04:24.163Z - info: [1478775864161] CoreStateMachine::startPlaybackTimer
2016-11-10T11:04:24.166Z - info: [1478775864164] CorePlayQueue::getTrack 4
2016-11-10T11:04:24.181Z - info: [1478775864179] ControllerSpop::clearAddPlayTrack
2016-11-10T11:04:24.184Z - info: {"uri":"spotify:track:7i86nU8E2Fpn0UgGbXU6l9","service":"spop","type":"song","name":"Beatles' Medley","title":"Beatles' Medley","artist":"Tommy Emmanuel","album":"Center Stage","duration":371,"albumart":"/albumart?web=Tommy%20Emmanuel/Center%20Stage/large&path=","samplerate":"320Kbps","bitdepth":"16 bit","trackType":"spotify"}
2016-11-10T11:04:24.197Z - info: [1478775864185] ControllerSpop::sendSpopCommand
2016-11-10T11:04:24.206Z - info: ADDING DEFER FOR COMMAND uplay
2016-11-10T11:04:24.230Z - info: SPOP command error:
2016-11-10T11:04:24.247Z - info: Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:285:12)
at applyWithContext (/data/plugins/music_service/spop/node_modules/fast.js/function/applyWithContext.js:15:22)
at /data/plugins/music_service/spop/node_modules/fast.js/function/bind.js:63:14
at onBoundPromise (/data/plugins/music_service/spop/node_modules/kew/kew.js:834:10)
at ncall (/data/plugins/music_service/spop/node_modules/kew/kew.js:816:44)
at Object.nfcall (/data/plugins/music_service/spop/node_modules/kew/kew.js:803:16)
at Promise._successFn (/data/plugins/music_service/spop/index.js:1201:16)
at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28)
at _combinedTickCallback (internal/process/next_tick.js:67:7)
at process._tickCallback (internal/process/next_tick.js:98:9)
2016-11-10T11:04:24.252Z - info: [1478775864250] ------------------------------ 128ms