weixin_39574065
weixin_39574065
2020-12-09 12:45

[volspotconnect2] Playback stops on track change

Hi,

I'm running Volumio 2.368 with volspotconnect2 0.6.4 on rpi3 with hifiberry digi+. Whenever I change the the track in Spotify, be at automatically at the end of another one, or with the playback controls, volspotconnect stops playing. If I push play it starts working again.

Below is the output of

<code>sudo journalctl -f | grep 'librespot\|SpCon'</code></pre>

Initial state, nothing plays. I start playback from Spotify client:

`
Mar 08 20:41:07 volumio-pi volumio[998]: info: [SpConDebug] Token: BQBW7ci5epvf6rl_2uRXNReI_LHS1obYy8E37Sd1FjAMzXSGHbAPJRBPyBZrGWWx3G_O-newmpyO5f20XLxl71BRCInjUe0kjg33G1dtQVOu136KTFY26qTFRfkOnrhLeXTi-276C_ceqxBMTDdGrcyqR9GkMbLrD4aI80Q
Mar 08 20:41:07 volumio-pi volumio[998]: info: [SpConDebug] Session is active!
Mar 08 20:41:08 volumio-pi volumio[1057]: INFO:librespot::player: Loaded Track "Society" by Eddie Vedder from Music For The Motion Picture Into The Wild
Mar 08 20:41:08 volumio-pi volumio[1057]: INFO:librespot_core::util: Running ./onstart1.sh
Mar 08 20:41:08 volumio-pi volumio[1057]: INFO:librespot_core::util: Exit status: exit code: 0
Mar 08 20:41:08 volumio-pi volumio[998]: info: [SpConDebug] SpotConn is playing

`

I push next on Spotify player. Music stops. Spotify app shows status as stopped.

`
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] Token: BQDJIhzYjHJ8kocAEjy-lQMQPlH-8tXoS26uSEFXJMJAx3C4LNboZbjMg5Y7FScJ68StkTKZQ-BVwQs1EG5Hk55gejeaLCkxWDAAlXw0WcnUAgUeAizG4fBZk1SY_3vPyUBbm7dsUxgzoLJvncItnlVnyZPHpmzDdSo2-OE
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] Session is active!
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] Killing Volumio state, Spotify session: true
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] SpotConn is done!
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] Received stop
Mar 08 20:42:06 volumio-pi volumio[998]: info: [SpConDebug] Killing Volumio state, Spotify session: true
Mar 08 20:42:07 volumio-pi volumio[1057]: INFO:librespot::player: Loaded Track "Sunny Road" by Emilíana Torrini from Fisherman's Woman
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] SpotConn is playing
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] Token: BQCbykc748r1GjO4LZcnVyyfRs_gGOexuikELrnz1eBi8QNW7pCNB9gLc2hKA1IWcLQ20K3eZ3ZBT8SzI2K7euUfwFvr8kwW1caQKc_hFjFAlvhwJ4PnZkqOl30gamJhrnBytth5FcX5SeD9aNXKAJlly0wfOUFy43NgLZs
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] Killing Volumio state, Spotify session: true
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] SpotConn is done!
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] Received stop
Mar 08 20:42:07 volumio-pi volumio[998]: info: [SpConDebug] Killing Volumio state, Spotify session: true

`

I push play again. Music resumes:

`
Mar 08 20:42:41 volumio-pi volumio[998]: info: [SpConDebug] Token: BQD2Dwa-JjXNlyvSzs_cN93dnQvf3jSnNAnLpCavvfOlehId_DlsHcavy5K40ZLueb5_zBxdQnfWL-hED52-p9gh5rDoclwjwZapd08IkvVlP9vg-t5bKiz686luEjln4Ga73M_-CIB1nrjbn2sTIAeCQHXwZLvr1-1BaV0
Mar 08 20:42:41 volumio-pi volumio[1057]: INFO:librespot_core::util: Running ./onstart1.sh
Mar 08 20:42:41 volumio-pi volumio[1057]: INFO:librespot_core::util: Exit status: exit code: 0
Mar 08 20:42:41 volumio-pi volumio[998]: info: [SpConDebug] SpotConn is playing

`

Below are the corresponding contents from

<code>/var/log/volumio.log</code></pre>
`
2018-03-08T20:41:07.972Z - info: [SpConDebug] Token: BQBW7ci5epvf6rl_2uRXNReI_LHS1obYy8E37Sd1FjAMzXSGHbAPJRBPyBZrGWWx3G_O-newmpyO5f20XLxl71BRCInjUe0kjg33G1dtQVOu136KTFY26qTFRfkOnrhLeXTi-276C_ceqxBMTDdGrcyqR9GkMbLrD4aI80Q
2018-03-08T20:41:07.978Z - info: [SpConDebug] Session is active!
2018-03-08T20:41:07.978Z - info: CoreCommandRouter::volumioGetState
2018-03-08T20:41:07.978Z - info: CoreStateMachine::getState
2018-03-08T20:41:07.979Z - info: CorePlayQueue::getTrack 0
2018-03-08T20:41:07.979Z - info: CoreCommandRouter::volumioStop
2018-03-08T20:41:07.979Z - info: CoreStateMachine::stop
2018-03-08T20:41:07.980Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:41:08.224Z - info: [SpConDebug] SpotConn is playing
2018-03-08T20:41:08.225Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:41:08.225Z - info: CoreCommandRouter::servicePushState
2018-03-08T20:41:08.226Z - info: CoreStateMachine::syncState
2018-03-08T20:41:08.226Z - info: CoreStateMachine::pushState
2018-03-08T20:41:08.227Z - info: CoreStateMachine::getState
2018-03-08T20:41:08.227Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:41:08.228Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:41:08.232Z - info: interfaceApi::pushState
2018-03-08T20:41:08.257Z - info: Pushing Favourites {"service":"volspotconnect2","uri":"spotify:track:ef57977abf084916bc20ed17aa45258f","favourite":false}
2018-03-08T20:41:08.730Z - info: CoreCommandRouter::servicePushState
2018-03-08T20:41:08.731Z - info: CoreStateMachine::syncState
2018-03-08T20:41:08.731Z - info: CoreStateMachine::pushState
2018-03-08T20:41:08.731Z - info: CoreStateMachine::getState
2018-03-08T20:41:08.732Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:41:08.732Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:41:08.737Z - info: interfaceApi::pushState
2018-03-08T20:41:08.758Z - info: Pushing Favourites {"service":"volspotconnect2","uri":"spotify:track:f997ab61cb2c4b429f205ab1163302cc","favourite":false}

`

`
2018-03-08T20:42:06.976Z - info: [SpConDebug] Token: BQDJIhzYjHJ8kocAEjy-lQMQPlH-8tXoS26uSEFXJMJAx3C4LNboZbjMg5Y7FScJ68StkTKZQ-BVwQs1EG5Hk55gejeaLCkxWDAAlXw0WcnUAgUeAizG4fBZk1SY_3vPyUBbm7dsUxgzoLJvncItnlVnyZPHpmzDdSo2-OE
2018-03-08T20:42:06.982Z - info: [SpConDebug] Session is active!
2018-03-08T20:42:06.982Z - info: CoreCommandRouter::volumioGetState
2018-03-08T20:42:06.983Z - info: CoreStateMachine::getState
2018-03-08T20:42:06.983Z - info: [SpConDebug] Killing Volumio state, Spotify session: true
2018-03-08T20:42:06.984Z - info: [SpConDebug] SpotConn is done!
2018-03-08T20:42:06.984Z - info: [SpConDebug] Received stop
2018-03-08T20:42:06.989Z - info: [SpConDebug] Killing Volumio state, Spotify session: true
2018-03-08T20:42:06.991Z - info: CoreStateMachine::resetVolumioState
2018-03-08T20:42:06.993Z - info: CoreStateMachine::getcurrentVolume
2018-03-08T20:42:06.993Z - info: CoreCommandRouter::volumioRetrievevolume
2018-03-08T20:42:07.007Z - info: CoreStateMachine::updateTrackBlock
2018-03-08T20:42:07.007Z - info: CorePlayQueue::getTrackBlock
2018-03-08T20:42:07.009Z - info: CoreCommandRouter::volumioStop
2018-03-08T20:42:07.009Z - info: CoreStateMachine::stop
2018-03-08T20:42:07.010Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:42:07.035Z - info: VolumeController:: Volume=undefined Mute =undefined
2018-03-08T20:42:07.036Z - info: CoreStateMachine::pushState
2018-03-08T20:42:07.036Z - info: CoreStateMachine::getState
2018-03-08T20:42:07.037Z - info: CorePlayQueue::getTrack 0
2018-03-08T20:42:07.037Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:42:07.037Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:42:07.039Z - info: interfaceApi::pushState
2018-03-08T20:42:07.060Z - info: Pushing Favourites {"service":"webradio","uri":"http://rfm-live-mp3-128.scdn.arkena.com/rfm.mp3","favourite":false}
2018-03-08T20:42:07.251Z - info: [SpConDebug] SpotConn is playing
2018-03-08T20:42:07.252Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:42:07.252Z - info: CoreCommandRouter::servicePushState
2018-03-08T20:42:07.253Z - info: CoreStateMachine::syncState
2018-03-08T20:42:07.253Z - info: CoreStateMachine::pushState
2018-03-08T20:42:07.253Z - info: CoreStateMachine::getState
2018-03-08T20:42:07.254Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:42:07.254Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:42:07.256Z - info: interfaceApi::pushState
2018-03-08T20:42:07.281Z - info: Pushing Favourites {"service":"volspotconnect2","uri":"spotify:track:f997ab61cb2c4b429f205ab1163302cc","favourite":false}
2018-03-08T20:42:07.362Z - info: CoreCommandRouter::servicePushState
2018-03-08T20:42:07.362Z - info: CoreStateMachine::syncState
2018-03-08T20:42:07.363Z - info: CoreStateMachine::pushState
2018-03-08T20:42:07.363Z - info: CoreStateMachine::getState
2018-03-08T20:42:07.363Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:42:07.364Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:42:07.365Z - info: interfaceApi::pushState
2018-03-08T20:42:07.396Z - info: Pushing Favourites {"service":"volspotconnect2","uri":"spotify:track:ab4743553d9f46d8a744c37028825d5c","favourite":false}
2018-03-08T20:42:07.688Z - info: [SpConDebug] Token: BQCbykc748r1GjO4LZcnVyyfRs_gGOexuikELrnz1eBi8QNW7pCNB9gLc2hKA1IWcLQ20K3eZ3ZBT8SzI2K7euUfwFvr8kwW1caQKc_hFjFAlvhwJ4PnZkqOl30gamJhrnBytth5FcX5SeD9aNXKAJlly0wfOUFy43NgLZs
2018-03-08T20:42:07.698Z - info: [SpConDebug] Killing Volumio state, Spotify session: true
2018-03-08T20:42:07.698Z - info: [SpConDebug] SpotConn is done!
2018-03-08T20:42:07.699Z - info: [SpConDebug] Received stop
2018-03-08T20:42:07.707Z - info: [SpConDebug] Killing Volumio state, Spotify session: true
2018-03-08T20:42:07.714Z - info: CoreStateMachine::resetVolumioState
2018-03-08T20:42:07.715Z - info: CoreStateMachine::getcurrentVolume
2018-03-08T20:42:07.715Z - info: CoreCommandRouter::volumioRetrievevolume
2018-03-08T20:42:07.733Z - info: CoreStateMachine::updateTrackBlock
2018-03-08T20:42:07.736Z - info: CorePlayQueue::getTrackBlock
2018-03-08T20:42:07.738Z - info: CoreCommandRouter::volumioStop
2018-03-08T20:42:07.738Z - info: CoreStateMachine::stop
2018-03-08T20:42:07.739Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:42:07.763Z - info: VolumeController:: Volume=undefined Mute =undefined
2018-03-08T20:42:07.763Z - info: CoreStateMachine::pushState
2018-03-08T20:42:07.764Z - info: CoreStateMachine::getState
2018-03-08T20:42:07.765Z - info: CorePlayQueue::getTrack 0
2018-03-08T20:42:07.766Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:42:07.766Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:42:07.774Z - info: interfaceApi::pushState
2018-03-08T20:42:07.803Z - info: Pushing Favourites {"service":"webradio","uri":"http://rfm-live-mp3-128.scdn.arkena.com/rfm.mp3","favourite":false}

`

`
2018-03-08T20:42:41.008Z - info: [SpConDebug] Token: BQD2Dwa-JjXNlyvSzs_cN93dnQvf3jSnNAnLpCavvfOlehId_DlsHcavy5K40ZLueb5_zBxdQnfWL-hED52-p9gh5rDoclwjwZapd08IkvVlP9vg-t5bKiz686luEjln4Ga73M_-CIB1nrjbn2sTIAeCQHXwZLvr1-1BaV0
2018-03-08T20:42:41.019Z - info: [SpConDebug] SpotConn is playing
2018-03-08T20:42:41.020Z - info: CoreStateMachine::setConsumeUpdateService undefined
2018-03-08T20:42:41.020Z - info: CoreCommandRouter::servicePushState
2018-03-08T20:42:41.020Z - info: CoreStateMachine::syncState
2018-03-08T20:42:41.020Z - info: CoreStateMachine::pushState
2018-03-08T20:42:41.021Z - info: CoreStateMachine::getState
2018-03-08T20:42:41.021Z - info: CoreCommandRouter::volumioPushState
2018-03-08T20:42:41.021Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-03-08T20:42:41.022Z - info: interfaceApi::pushState
2018-03-08T20:42:41.043Z - info: Pushing Favourites {"service":"volspotconnect2","uri":"spotify:track:ab4743553d9f46d8a744c37028825d5c","favourite":false}

`

该提问来源于开源项目:volumio/volumio-plugins

  • 点赞
  • 写回答
  • 关注问题
  • 收藏
  • 复制链接分享
  • 邀请回答

10条回答

  • weixin_39643338 weixin_39643338 5月前

    Aah! This was what I meant!

    点赞 评论 复制链接分享
  • weixin_39638801 weixin_39638801 5月前

    Same issue with 0.6.5

    点赞 评论 复制链接分享
  • weixin_39643338 weixin_39643338 5月前

    With my old implementation, https://github.com/volumio/volumio-plugins/commit/881e1eb07e80610a3e29c75b237823775e48bda6#diff-6020fb51ebbc23a3db2dbda47e9b9665L59 would release the sink, and hence reset the state. While not perfect ( there is a small switch back to the old state, before the next song's metadata is received) it should have been sufficient right?

    Same issue with 0.6.5

    They are both the same I'd reckon. Either way, I need to go through 881e1eb07e80610a3e29c75b237823775e48bda6 to see what the Volumio State machine wants and feed it properly! ;-)

    点赞 评论 复制链接分享
  • weixin_39574065 weixin_39574065 5月前

    I guess releasing the sink is why my DAC would "click" when changing songs with the old version. But the DAC still goes "click" when changing songs, only it does it twice in a row now.

    (it normally only does this when changing stream parameters, such as sampling rate).

    点赞 评论 复制链接分享
  • weixin_39643338 weixin_39643338 5月前

    Since continuous playback hasn't yet been implemented in the back end, there is a cycle of Play -> Pause -> Play on every track change. I could disable this behaviour of releasing, and acquiring the sink the in back end, but it's not considered 'best practices'. This is also why you'd have seen a brief flash in the WebUI of the old state information when a track changes.

    点赞 评论 复制链接分享
  • weixin_39574065 weixin_39574065 5月前

    Is this somehow related to the behaviour described in https://github.com/volumio/Volumio2/issues/1492 ?

    点赞 评论 复制链接分享
  • weixin_39574065 weixin_39574065 5月前

    I think the answer to my previous question is yes. I have been messing around a bit, installed volspotconnect2 0.6.6, and I have the same behaviour.

    However, that is while using the hifiberry digi+

    If I connect my DAC directly to a usb port, track change works OK. There's no clicking either.

    点赞 评论 复制链接分享
  • weixin_39643338 weixin_39643338 5月前

    I'd imagine the clicks are coming because the mpd releases the Alsa sink, and volspotconnect2 claims it, and then back again. You would witness this behaviour probably with any plugin that wants to claim the device from the mpd

    Ofcourse, the clicks are also noticed on every track changes cause volspotconnect2 gives up the sink on every track change, and claims it back from the mpd.

    点赞 评论 复制链接分享
  • weixin_39574065 weixin_39574065 5月前

    I think this might actually be related to the hifiberry and / or the driver rather than the player. I don't have this behaviour with the optical output of an Intel ICH sound card.

    There's definitely something fishy going on with the digi+, as if I'm using another sound card volspotconnect2 playback works as expected (plus no clicks).

    点赞 评论 复制链接分享
  • weixin_39643338 weixin_39643338 5月前

    You might be right about the driver issue --> forum/click-pop-crack-when-changing-tracks

    点赞 评论 复制链接分享

相关推荐