Just set up Volumio and I have to say I am very impressed after using Musicbox for a couple of years. Everything up and running…almost.
I can scrobble content from my NAS source OK, but it isn’t scrobbling any tracks I play from Spotify. Is this by design?
Anyone able to confirm or comment on this? Thanks
How are you scrobbling?
I have installed the LastFM plugin and configured.
Did you install from source (github)? Because there are still some changes pending for Volumio.
Also, how do you play Spotify? Spop or volspotconnect?
All installed via the plugins in the Volumio interface.
And my second question?
I go to the Browse option and I click the Spotify icon and play tracks from there. That’s as much as I know
Sounds like SPOP (the integrated Spotify implementation), this should be scrobbled as of version 1.1.12 of the LastFM plugin.
I’m going to need logging to determine what is going wrong, can you provide me the journalctl of a scrobble attempt with debug logging enabled in the plugin?
Are there any details on how to do this? Sorry noob here. I have the details logs turned on for LastFM plugin. Where are they saved?
Run
sudo journalctl -fin an SSH session
Then play a song on Spotify and capture the details, it’s easier if you set the threshold to 5%, it will scrobble faster that way.
Thanks for the reply. Here’s the details
Apr 17 09:36:48 volumio sudo[1530]: pam_unix(sudo:session): session opened for u ser root by volumio(uid=0)
Apr 17 09:36:56 volumio volumio[771]: info: CoreCommandRouter::volumioPlay
Apr 17 09:36:56 volumio volumio[771]: UNSET VOLATILE
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::play index undefin ed
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::setConsumeUpdateSe rvice undefined
Apr 17 09:36:56 volumio volumio[771]: info: CorePlayQueue::getTrack 0
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::startPlaybackTimer
Apr 17 09:36:56 volumio volumio[771]: info: CorePlayQueue::getTrack 0
Apr 17 09:36:56 volumio volumio[771]: info: [1523957816028] ControllerSpop::clea rAddPlayTrack
Apr 17 09:36:56 volumio volumio[771]: info: {“uri”:“spotify:track:3FeyKZZcU7ywuJ 0LtFSuBO”,“service”:“spop”,“name”:“Cool”,“artist”:“Soccer Mommy”,“album”:“Clean” ,“type”:“song”,“duration”:196,“tracknumber”:2,“albumart”:“https://i.scdn.co/imag e/d6dcd9fea656f19b6253865d641b39451043245f”,“samplerate”:“320Kbps”,“bitdepth”:“1 6 bit”,“trackType”:“spotify”}
Apr 17 09:36:56 volumio volumio[771]: info: [1523957816034] ControllerSpop::send SpopCommand
Apr 17 09:36:56 volumio volumio[771]: info: ADDING DEFER FOR COMMAND uplay
Apr 17 09:36:56 volumio volumio[771]: info: STATUS
Apr 17 09:36:56 volumio volumio[771]: info: {
Apr 17 09:36:56 volumio volumio[771]: “status” : “playing”,
Apr 17 09:36:56 volumio volumio[771]: “repeat” : false,
Apr 17 09:36:56 volumio volumio[771]: “shuffle” : false,
Apr 17 09:36:56 volumio volumio[771]: “total_tracks” : 1,
Apr 17 09:36:56 volumio volumio[771]: “current_track” : 1,
Apr 17 09:36:56 volumio volumio[771]: “artist” : “Soccer Mommy”,
Apr 17 09:36:56 volumio volumio[771]: “title” : “Cool”,
Apr 17 09:36:56 volumio volumio[771]: “album” : “Clean”,
Apr 17 09:36:56 volumio volumio[771]: “duration” : 196000,
Apr 17 09:36:56 volumio volumio[771]: “position” : 0,
Apr 17 09:36:56 volumio volumio[771]: “uri” : “spotify:track:3FeyKZZcU7ywuJ0LtFS uBO”,
Apr 17 09:36:56 volumio volumio[771]: “popularity” : 54
Apr 17 09:36:56 volumio volumio[771]: }
Apr 17 09:36:56 volumio volumio[771]: info:
Apr 17 09:36:56 volumio volumio[771]: [1523957816066] -------------------------- – Spop announces state update
Apr 17 09:36:56 volumio volumio[771]: info: [1523957816076] ControllerSpop::pars eState
Apr 17 09:36:56 volumio volumio[771]: { status: ‘playing’,
Apr 17 09:36:56 volumio volumio[771]: repeat: false,
Apr 17 09:36:56 volumio volumio[771]: shuffle: false,
Apr 17 09:36:56 volumio volumio[771]: total_tracks: 1,
Apr 17 09:36:56 volumio volumio[771]: current_track: 1,
Apr 17 09:36:56 volumio volumio[771]: artist: ‘Soccer Mommy’,
Apr 17 09:36:56 volumio volumio[771]: title: ‘Cool’,
Apr 17 09:36:56 volumio volumio[771]: album: ‘Clean’,
Apr 17 09:36:56 volumio volumio[771]: duration: 196000,
Apr 17 09:36:56 volumio volumio[771]: position: 0,
Apr 17 09:36:56 volumio volumio[771]: uri: 'spotify:track:3FeyKZZcU7ywuJ0LtFSuBO ',
Apr 17 09:36:56 volumio volumio[771]: popularity: 54 }
Apr 17 09:36:56 volumio volumio[771]: info: [1523957816110] ControllerSpop::push State
Apr 17 09:36:56 volumio volumio[771]: info: CoreCommandRouter::servicePushState
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::syncState
Apr 17 09:36:56 volumio volumio[771]: info: CorePlayQueue::getTrack 0
Apr 17 09:36:56 volumio volumio[771]: info: STATE SERVICE {“status”:“play”,“posi tion”:0,“seek”:0,“duration”:196,“samplerate”:“320Kbps”,“bitdepth”:null,"channels ":null,“artist”:“Soccer Mommy”,“title”:“Cool”,“album”:“Clean”}
Apr 17 09:36:56 volumio volumio[771]: info: CURRENT POSITION 0
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::syncState stateS ervice play
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::syncState curren tStatus stop
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 09:36:56 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 09:36:56 volumio volumio[771]: info: CorePlayQueue::getTrack 0
Apr 17 09:36:56 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 09:36:56 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 09:36:56 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 09:36:56 volumio volumio[771]: info: [1523957816240] -------------------- ---------- 179ms
Apr 17 09:36:56 volumio volumio[771]: info: FIRST BRANCH
Apr 17 09:36:56 volumio volumio[771]: info: BEFORE: SPOP HAS 1 PROMISE IN STACK
Apr 17 09:36:56 volumio volumio[771]: info: AFTER: SPOP HAS 0 PROMISE IN STACK
Apr 17 09:36:56 volumio volumio[771]: info: [LastFM] timer should be there… us ing the existing instance
Apr 17 09:36:56 volumio volumio[771]: info: ------------------------------------ --------------------------------// [LastFM] new state has been pushed; status: p lay | service: spop | duration: 196 | title: Cool | previous title: Cool
Apr 17 09:36:56 volumio volumio[771]: info: Pushing Favourites {“service”:“spop” ,“uri”:“spotify:track:3FeyKZZcU7ywuJ0LtFSuBO”,“favourite”:true}
Apr 17 09:36:56 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2
Apr 17 09:36:56 volumio volumio[934]: 2018-04-17 09:36:56 [SPTF] 09:36:56.668 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:36:56 volumio volumio[934]: 2018-04-17 09:36:56 [SPTF] 09:36:56.820 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:37:09 volumio volumio[934]: 2018-04-17 09:37:09 [SPTF] 09:37:09.447 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:37:25 volumio volumio[934]: 2018-04-17 09:37:25 [SPTF] 09:37:25.477 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:37:41 volumio volumio[934]: 2018-04-17 09:37:41 [SPTF] 09:37:41.050 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:37:56 volumio volumio[934]: 2018-04-17 09:37:56 [SPTF] 09:37:56.194 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:38:10 volumio volumio[934]: 2018-04-17 09:38:10 [SPTF] 09:38:10.685 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:38:25 volumio volumio[934]: 2018-04-17 09:38:25 [SPTF] 09:38:25.437 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:38:41 volumio volumio[934]: 2018-04-17 09:38:41 [SPTF] 09:38:41.201 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:38:56 volumio volumio[934]: 2018-04-17 09:38:56 [SPTF] 09:38:56.243 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:39:10 volumio volumio[934]: 2018-04-17 09:39:10 [SPTF] 09:39:10.843 I [file_streamer_simple.cpp:769] Request for file 1a4fdb398e1e1f4d70504462e998570e 8eff9b73 complete (code: 0)
Apr 17 09:39:25 volumio volumio[934]: 2018-04-17 09:39:25 [SPTF] 09:39:25.245 I [db398e1e1f4d70504462e998570e8eff9b73 complete (code: 0)
Apr 17 09:39:40 volumio volumio[934]: 2018-04-17 09:39:40 [SPTF] 09:39:40.531 I [db398e1e1f4d70504462e998570e8eff9b73 complete (code: 0)
Here’s a scrobble when I play from my NAS box
– Logs begin at Mon 2018-03-26 18:36:24 UTC. –
Apr 17 10:05:40 volumio systemd[15151]: Reached target Basic System.
Apr 17 10:05:40 volumio systemd[15151]: Starting Default.
Apr 17 10:05:40 volumio systemd[15151]: Reached target Default.
Apr 17 10:05:40 volumio systemd[15151]: Startup finished in 37ms.
Apr 17 10:05:40 volumio systemd[1]: Started User Manager for UID 1000.
Apr 17 10:05:40 volumio sshd[15104]: lastlog_openseek: Couldn’t stat /var/log/lastlog: No such file or directory
Apr 17 10:05:40 volumio sshd[15104]: lastlog_openseek: Couldn’t stat /var/log/lastlog: No such file or directory
Apr 17 10:05:41 volumio volumio[934]: 2018-04-17 10:05:41 [SPTF] 10:05:41.228 I [file_streamer_simple.cpp:769] Request for file 6707299da42d9a1121a26b5c5bcdbb656f23b0b0 complete (code: 0)
Apr 17 10:05:49 volumio sudo[15242]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Apr 17 10:05:49 volumio sudo[15242]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Apr 17 10:05:54 volumio volumio[934]: 2018-04-17 10:05:54 [SPTF] 10:05:54.238 I [file_streamer_simple.cpp:769] Request for file 6707299da42d9a1121a26b5c5bcdbb656f23b0b0 complete (code: 0)
Apr 17 10:05:56 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:05:56 volumio volumio[771]: info: CURURI: music-library
Apr 17 10:05:57 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:05:57 volumio volumio[771]: info: CURURI: music-library/NAS
Apr 17 10:05:58 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:05:58 volumio volumio[771]: info: CURURI: music-library/NAS/winnie
Apr 17 10:06:03 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:06:03 volumio volumio[771]: info: CURURI: music-library/NAS/winnie/Dance
Apr 17 10:06:07 volumio volumio[934]: 2018-04-17 10:06:07 [SPTF] 10:06:07.240 I [file_streamer_simple.cpp:769] Request for file 6707299da42d9a1121a26b5c5bcdbb656f23b0b0 complete (code: 0)
Apr 17 10:06:07 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:06:07 volumio volumio[771]: info: CURURI: music-library/NAS/winnie/Dance/Bomb the Bass
Apr 17 10:06:08 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 10:06:08 volumio volumio[771]: info: CURURI: music-library/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust
Apr 17 10:06:10 volumio volumio[771]: info: CoreCommandRouter::volumioAddQueueItems
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::addQueueItems
Apr 17 10:06:10 volumio volumio[771]: info: CorePlayQueue::addQueueItems
Apr 17 10:06:10 volumio volumio[771]: info: Adding Item to queue: music-library/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3
Apr 17 10:06:10 volumio volumio[771]: info: Exploding uri music-library/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3 in service mpd
Apr 17 10:06:10 volumio volumio[771]: info: ALBUMART /albumart?cacheid=501&web=Bomb%20The%20Bass/Bug%20Powder%20Dust%20(CDS%201)/extralarge&path=%2Fmnt%2FNAS%2Fwinnie%2FDance%2FBomb%20the%20Bass%2FBug%20Powder%20Dust%2F01%20-%20Radio%20Mix.mp3&metadata=true
Apr 17 10:06:10 volumio volumio[771]: info: URI /mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3
Apr 17 10:06:10 volumio volumio[771]: info: CorePlayQueue::saveQueue
Apr 17 10:06:10 volumio volumio[771]: info: CoreCommandRouter::volumioPushQueue
Apr 17 10:06:10 volumio volumio[771]: info: interfaceApi::pushQueue
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::updateTrackBlock
Apr 17 10:06:10 volumio volumio[771]: info: CorePlayQueue::getTrackBlock
Apr 17 10:06:10 volumio volumio[771]: info: CoreCommandRouter::volumioPlay
Apr 17 10:06:10 volumio volumio[771]: UNSET VOLATILE
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::play index 185
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::stop
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 10:06:10 volumio volumio[771]: UNSET VOLATILE
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::stPlaybackTimer
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::updateTrackBlock
Apr 17 10:06:10 volumio volumio[771]: info: CorePlayQueue::getTrackBlock
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:10 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:10 volumio volumio[771]: info: CorePlayQueue::getTrack 177
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:11 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::serviceStop
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 177
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::serviceStop
Apr 17 10:06:11 volumio volumio[771]: info: [1523959571005] ControllerSpop::stop
Apr 17 10:06:11 volumio volumio[771]: info: [1523959571006] ControllerSpop::sendSpopCommand
Apr 17 10:06:11 volumio volumio[771]: info: ADDING DEFER FOR COMMAND stop
Apr 17 10:06:11 volumio volumio[771]: info: Pushing Favourites {“service”:“spop”,“uri”:“spotify:track:43Al6qQ8XjbTUKdn7uZMbp”,“favourite”:false}
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:11 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: spop | duration: 299 | title: Cave-In - Live | previous title: Cave-In - Live
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] stopping timer, song has ended.
Apr 17 10:06:11 volumio volumio[771]: info: STATUS
Apr 17 10:06:11 volumio volumio[771]: info: {
Apr 17 10:06:11 volumio volumio[771]: “status” : “stopped”,
Apr 17 10:06:11 volumio volumio[771]: “repeat” : false,
Apr 17 10:06:11 volumio volumio[771]: “shuffle” : false,
Apr 17 10:06:11 volumio volumio[771]: “total_tracks” : 1
Apr 17 10:06:11 volumio volumio[771]: }
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: [1523959571435] ---------------------------- Spop announces state update
Apr 17 10:06:11 volumio volumio[771]: info: [1523959571437] ControllerSpop::parseState
Apr 17 10:06:11 volumio volumio[771]: { status: ‘stopped’,
Apr 17 10:06:11 volumio volumio[771]: repeat: false,
Apr 17 10:06:11 volumio volumio[771]: shuffle: false,
Apr 17 10:06:11 volumio volumio[771]: total_tracks: 1 }
Apr 17 10:06:11 volumio volumio[771]: info: [1523959571441] ControllerSpop::pushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::servicePushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::syncState
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 177
Apr 17 10:06:11 volumio volumio[771]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:“320Kbps”,“bitdepth”:null,“channels”:null}
Apr 17 10:06:11 volumio volumio[771]: info: CURRENT POSITION 177
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::syncState stateService stop
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::syncState currentStatus stop
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 177
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:11 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:11 volumio volumio[771]: info: No code
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 177
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:11 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:11 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:11 volumio volumio[771]: info: [1523959571553] ------------------------------ 120ms
Apr 17 10:06:11 volumio volumio[771]: info: FIRST BRANCH
Apr 17 10:06:11 volumio volumio[771]: info: BEFORE: SPOP HAS 1 PROMISE IN STACK
Apr 17 10:06:11 volumio volumio[771]: info: AFTER: SPOP HAS 0 PROMISE IN STACK
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::play index undefined
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:11 volumio volumio[771]: info: CoreStateMachine::startPlaybackTimer
Apr 17 10:06:11 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::clearAddPlayTracks NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand stop
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:11 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: spop | duration: 299 | title: Cave-In - Live | previous title: Cave-In - Live
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] stopping timer, song has ended.
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:11 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: spop | duration: 299 | title: Cave-In - Live | previous title: Cave-In - Live
Apr 17 10:06:11 volumio volumio[771]: info: [LastFM] stopping timer, song has ended.
Apr 17 10:06:11 volumio volumio[771]: info: parsing response…
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand clear
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: ---------------------------- MPD announces system playlist update
Apr 17 10:06:11 volumio volumio[771]: info: Ignoring MPD Status Update
Apr 17 10:06:11 volumio volumio[771]: info: parsing response…
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand add “NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: ---------------------------- MPD announces system playlist update
Apr 17 10:06:11 volumio volumio[771]: info: Ignoring MPD Status Update
Apr 17 10:06:11 volumio volumio[771]: info: ------------------------------ 30ms
Apr 17 10:06:11 volumio volumio[771]: info: parsing response…
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand play
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info: Pushing Favourites {“service”:“spop”,“uri”:“spotify:track:43Al6qQ8XjbTUKdn7uZMbp”,“favourite”:false}
Apr 17 10:06:11 volumio volumio[771]: info: Pushing Favourites {“service”:“spop”,“uri”:“spotify:track:43Al6qQ8XjbTUKdn7uZMbp”,“favourite”:false}
Apr 17 10:06:11 volumio volumio[771]: info: ------------------------------ 40ms
Apr 17 10:06:11 volumio volumio[771]: info: parsing response…
Apr 17 10:06:11 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: ---------------------------- MPD announces state update: player
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::getState
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand status
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info:
Apr 17 10:06:11 volumio volumio[771]: ---------------------------- MPD announces state update: player
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::getState
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand status
Apr 17 10:06:11 volumio volumio[771]: info: parsing response…
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::parseState
Apr 17 10:06:11 volumio volumio[771]: info: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 10:06:11 volumio volumio[771]: info: sending command…
Apr 17 10:06:12 volumio volumio[771]: info: parsing response…
Apr 17 10:06:12 volumio volumio[771]: info: parsing response…
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::parseState
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::parseTrackInfo
Apr 17 10:06:12 volumio volumio[771]: info: sending command…
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::servicePushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState
Apr 17 10:06:12 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:12 volumio volumio[771]: info: STATE SERVICE {“status”:“play”,“position”:0,“seek”:487,“duration”:260,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“Radio Mix”,“artist”:“Bomb The Bass”,“album”:“Bug Powder Dust (CDS 1)”,“uri”:“NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“trackType”:“mp3”}
Apr 17 10:06:12 volumio volumio[771]: info: CURRENT POSITION 185
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState stateService play
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState currentStatus stop
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:12 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:12 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:12 volumio volumio[771]: info: ------------------------------ 157ms
Apr 17 10:06:12 volumio volumio[771]: info: parsing response…
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::parseTrackInfo
Apr 17 10:06:12 volumio volumio[771]: info: ControllerMpd::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::servicePushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState
Apr 17 10:06:12 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:12 volumio volumio[771]: info: STATE SERVICE {“status”:“play”,“position”:0,“seek”:487,“duration”:260,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“Radio Mix”,“artist”:“Bomb The Bass”,“album”:“Bug Powder Dust (CDS 1)”,“uri”:“NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“trackType”:“mp3”}
Apr 17 10:06:12 volumio volumio[771]: info: CURRENT POSITION 185
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState stateService play
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::syncState currentStatus play
Apr 17 10:06:12 volumio volumio[771]: info: Received an update from plaugin. extracting info from payload
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:12 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:12 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:12 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:12 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:12 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:12 volumio volumio[771]: info: ------------------------------ 274ms
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:12 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 260 | title: 1 - Radio Mix | previous title: Cave-In - Live
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] artist and song are (still) the same; but not necessarily no update.
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] trying to authenticate…
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] playtime for current track: 0
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] starting new timer for 13000 milliseconds [Bomb The Bass - 1 - Radio Mix].
Apr 17 10:06:12 volumio volumio[771]: -------------------------------------------------// S T A R T I N G
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:12 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 260 | title: 1 - Radio Mix | previous title: 1 - Radio Mix
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] could not process current state: {“status”:“play”,“position”:185,“title”:“1 - Radio Mix”,“artist”:“Bomb The Bass”,“album”:“Bug Powder Dust (CDS 1)”,“albumart”:"/albumart?cacheid=501&web=Bomb%20The%20Bass/Bug%20Powder%20Dust%20(CDS%201)/extralarge&path=%2FNAS%2Fwinnie%2FDance%2FBomb%20the%20Bass%2FBug%20Powder%20Dust&metadata=true",“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“trackType”:“mp3”,“seek”:487,“duration”:260,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:null,“repeat”:null,“repeatSingle”:false,“consume”:false,“volume”:100,“mute”:false,“stream”:“mp3”,“updatedb”:false,“volatile”:false,“service”:“mpd”}
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:12 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 260 | title: 1 - Radio Mix | previous title: 1 - Radio Mix
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] could not process current state: {“status”:“play”,“position”:185,“title”:“1 - Radio Mix”,“artist”:“Bomb The Bass”,“album”:“Bug Powder Dust (CDS 1)”,“albumart”:"/albumart?cacheid=501&web=Bomb%20The%20Bass/Bug%20Powder%20Dust%20(CDS%201)/extralarge&path=%2FNAS%2Fwinnie%2FDance%2FBomb%20the%20Bass%2FBug%20Powder%20Dust&metadata=true",“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“trackType”:“mp3”,“seek”:487,“duration”:260,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:null,“repeat”:null,“repeatSingle”:false,“consume”:false,“volume”:100,“mute”:false,“stream”:“mp3”,“updatedb”:false,“volatile”:false,“service”:“mpd”}
Apr 17 10:06:12 volumio volumio[771]: info: Pushing Favourites {“service”:“mpd”,“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“favourite”:false}
Apr 17 10:06:12 volumio volumio[771]: info: Pushing Favourites {“service”:“mpd”,“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“favourite”:false}
Apr 17 10:06:12 volumio volumio[771]: info: Pushing Favourites {“service”:“mpd”,“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“favourite”:false}
Apr 17 10:06:12 volumio volumio[771]: info: [LastFM] authenticated successfully!
Apr 17 10:06:13 volumio volumio[771]: info: [LastFM] corrected artist from: Bomb The Bass to: Bomb the Bass
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] checking previously scrobbled song…
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] previous scrobble: {“artist”:"",“title”:"",“scrobbleTime”:0}
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] trying to authenticate for scrobbling…
Apr 17 10:06:25 volumio volumio[771]: -------------------------------------------------// S T O P P I N G
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] authenticated successfully for scrobbling!
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] preparing to scrobble…
Apr 17 10:06:25 volumio volumio[771]: info: [LastFM] corrected artist from: Bomb The Bass to: Bomb the Bass
Apr 17 10:06:26 volumio volumio[771]: info: [LastFM] Scrobble successful for: Bomb the Bass - 1 - Radio Mix (Bug Powder Dust (CDS 1)).
Apr 17 10:06:32 volumio volumio[771]: info: CoreCommandRouter::volumioPause
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::pause
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::stPlaybackTimer
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::servicePause
Apr 17 10:06:32 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:32 volumio volumio[771]: info: CoreCommandRouter::servicePause
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::pause
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::sendMpdCommand pause
Apr 17 10:06:32 volumio volumio[771]: info: sending command…
Apr 17 10:06:32 volumio volumio[771]: info:
Apr 17 10:06:32 volumio volumio[771]: ---------------------------- MPD announces state update: player
Apr 17 10:06:32 volumio volumio[771]: info: parsing response…
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::getState
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::sendMpdCommand status
Apr 17 10:06:32 volumio volumio[771]: info: sending command…
Apr 17 10:06:32 volumio volumio[771]: info: parsing response…
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::parseState
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 10:06:32 volumio volumio[771]: info: sending command…
Apr 17 10:06:32 volumio volumio[771]: info: parsing response…
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::parseTrackInfo
Apr 17 10:06:32 volumio volumio[771]: info: ControllerMpd::pushState
Apr 17 10:06:32 volumio volumio[771]: info: CoreCommandRouter::servicePushState
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::syncState
Apr 17 10:06:32 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:32 volumio volumio[771]: info: STATE SERVICE {“status”:“pause”,“position”:0,“seek”:20584,“duration”:260,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“Radio Mix”,“artist”:“Bomb The Bass”,“album”:“Bug Powder Dust (CDS 1)”,“uri”:“NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“trackType”:“mp3”}
Apr 17 10:06:32 volumio volumio[771]: info: CURRENT POSITION 185
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::syncState stateService pause
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::syncState currentStatus pause
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::pushState
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::getState
Apr 17 10:06:32 volumio volumio[771]: info: CorePlayQueue::getTrack 185
Apr 17 10:06:32 volumio volumio[771]: info: CoreCommandRouter::volumioPushState
Apr 17 10:06:32 volumio volumio[771]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 10:06:32 volumio volumio[771]: info: interfaceApi::pushState
Apr 17 10:06:32 volumio volumio[771]: info: CoreStateMachine::stPlaybackTimer
Apr 17 10:06:32 volumio volumio[771]: info: ------------------------------ 138ms
Apr 17 10:06:32 volumio volumio[771]: info: [LastFM] timer should be there… using the existing instance
Apr 17 10:06:32 volumio volumio[771]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 260 | title: 1 - Radio Mix | previous title: 1 - Radio Mix
Apr 17 10:06:32 volumio volumio[771]: info: Pushing Favourites {“service”:“mpd”,“uri”:“mnt/NAS/winnie/Dance/Bomb the Bass/Bug Powder Dust/01 - Radio Mix.mp3”,“favourite”:false}
Thanks for that, I will enable spop and see what happens… I’m missing the following for spop playback:
[LastFM] new state has been pushed; status: play....Thanks
Oh and web radio is scrobbling OK so just seems to be Spotify spop
Did Scrobbling of Spotify ever get resolved at all? Would love this feature to work in Volumio.
As far as I know everything is working, but should you come across something, please log an issue on github. 