-- Logs begin at Thu 2019-02-14 20:41:59 ACDT, end at Wed 2024-10-30 09:58:37 ACDT. --
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Oct 30 09:57:07 volumio volumio[968]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Oct 30 09:57:07 volumio volumio[968]: info: Received Get System Version
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 30 09:57:07 volumio volumio[968]: info: Received Get System Info
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 30 09:57:07 volumio volumio[968]: info: Discovery: Getting this device information
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::volumioGetState
Oct 30 09:57:07 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:07 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 30 09:57:09 volumio volumio[968]: info: CoreCommandRouter::volumioGetQueue
Oct 30 09:57:09 volumio volumio[968]: info: CoreStateMachine::getQueue
Oct 30 09:57:09 volumio volumio[968]: info: CorePlayQueue::getQueue
Oct 30 09:57:09 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 30 09:57:09 volumio volumio[968]: info: In handleBrowseUri, curUri=spotify
Oct 30 09:57:10 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:10 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:10 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:10 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume50
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 50
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:17 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 50
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume7558
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 7558
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume7487
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 7487
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 50
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:17 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume30
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 30
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:17 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 30
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume3254
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 3254
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume3237
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 3237
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 30
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:17 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:17 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume25612
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25612
Oct 30 09:57:17 volumio volumio[968]: info: VolumeController::SetAlsaVolume25700
Oct 30 09:57:17 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25700
Oct 30 09:57:17 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:17 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:17 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:17 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume25
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume15
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 15
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:18 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 15
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume1107
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 1107
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume1011
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 1011
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 15
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:18 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume25603
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25603
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume25700
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25700
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume20
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 20
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:18 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 20
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume1712
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 1712
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: info: VolumeController::SetAlsaVolume1618
Oct 30 09:57:18 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 1618
Oct 30 09:57:18 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:18 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:18 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:18 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 20
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:18 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:18 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:20 volumio volumio[968]: SPOTIFY: SETTING SPOTIFY VOLUME 100
Oct 30 09:57:20 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/volume
Oct 30 09:57:20 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:20 volumio volumio[968]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 30 09:57:20 volumio volumio[968]: info: CoreStateMachine::ClearQueue
Oct 30 09:57:20 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:20 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:20 volumio volumio[968]: info: CorePlayQueue::clearPlayQueue
Oct 30 09:57:20 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:20 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:21 volumio volumio[968]: info: CoreStateMachine::addQueueItems
Oct 30 09:57:21 volumio volumio[968]: info: CorePlayQueue::addQueueItems
Oct 30 09:57:21 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:21 volumio volumio[968]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWXXs9GFYnvLB
Oct 30 09:57:21 volumio volumio[968]: info: Exploding uri spotify:playlist:37i9dQZF1DWXXs9GFYnvLB in service spop
Oct 30 09:57:21 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWXXs9GFYnvLB
Oct 30 09:57:22 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:22 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::updateTrackBlock
Oct 30 09:57:22 volumio volumio[968]: info: CorePlayQueue::getTrackBlock
Oct 30 09:57:22 volumio volumio[968]: info: CoreCommandRouter::volumioPlay
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::play index 0
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::play index undefined
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:22 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:22 volumio volumio[968]: info: CoreStateMachine::startPlaybackTimer
Oct 30 09:57:22 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:22 volumio volumio[968]: info: [1730244442387] ControllerSpotify::clearAddPlayTrack
Oct 30 09:57:22 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/play
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=debug msg="resolved context of track" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=trace msg="emitting websocket event: will_play"
Oct 30 09:57:22 volumio volumio[968]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=debug msg="selected format OGG_VORBIS_320 (69bfa72c0b275f7f8c05248dc3a6953c27f88a35)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:22 volumio go-librespot[1191]: time="2024-10-30T09:57:22+10:30" level=debug msg="requested aes key for file 69bfa72c0b275f7f8c05248dc3a6953c27f88a35, gid: 3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:23 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:23 volumio volumio[968]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::ClearQueue
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::clearPlayQueue
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:23 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::addQueueItems
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::addQueueItems
Oct 30 09:57:23 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:23 volumio volumio[968]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWXXs9GFYnvLB
Oct 30 09:57:23 volumio volumio[968]: info: Using cached record of: spotify:playlist:37i9dQZF1DWXXs9GFYnvLB
Oct 30 09:57:23 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::updateTrackBlock
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::getTrackBlock
Oct 30 09:57:23 volumio volumio[968]: info: CoreCommandRouter::volumioPlay
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::play index 0
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::play index undefined
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:23 volumio volumio[968]: info: CoreStateMachine::startPlaybackTimer
Oct 30 09:57:23 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:23 volumio volumio[968]: info: [1730244443549] ControllerSpotify::clearAddPlayTrack
Oct 30 09:57:23 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/play
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=debug msg="fetched first chunk of 17, total size is 8445487 bytes" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=debug msg="created new output device"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=info msg="loaded track \"Somedays\" (paused: false, position: 0ms, duration: 207168ms, prefetched: false)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=trace msg="scheduling prefetch in 177s"
Oct 30 09:57:23 volumio go-librespot[1191]: time="2024-10-30T09:57:23+10:30" level=trace msg="emitting websocket event: metadata"
Oct 30 09:57:23 volumio volumio[968]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","name":"Somedays","artist_names":["Sonny Fodera","Jazzy","D.O.D"],"album_name":"Somedays","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","position":0,"duration":207168,"release_date":"year:2024 month:7 day:26","track_number":1,"disc_number":1}}
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=trace msg="emitting websocket event: playing"
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:24 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus stop
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="resolved context of track" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:24 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus play
Oct 30 09:57:24 volumio volumio[968]: info: Received an update from plugin. extracting info from payload
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 30 09:57:24 volumio volumio[968]: info: In handleBrowseUri, curUri=spotify:playlist:37i9dQZF1DWXXs9GFYnvLB
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=trace msg="emitting websocket event: will_play"
Oct 30 09:57:24 volumio volumio[968]: info: VolumeController::SetAlsaVolume25606
Oct 30 09:57:24 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25606
Oct 30 09:57:24 volumio volumio[968]: info: VolumeController::SetAlsaVolume25700
Oct 30 09:57:24 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25700
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:24 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:24 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:24 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:24 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:24 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="selected format OGG_VORBIS_320 (69bfa72c0b275f7f8c05248dc3a6953c27f88a35)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:24 volumio go-librespot[1191]: time="2024-10-30T09:57:24+10:30" level=debug msg="requested aes key for file 69bfa72c0b275f7f8c05248dc3a6953c27f88a35, gid: 3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="fetched first chunk of 17, total size is 8445487 bytes" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=info msg="loaded track \"Somedays\" (paused: false, position: 0ms, duration: 207168ms, prefetched: false)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=trace msg="scheduling prefetch in 177s"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=trace msg="emitting websocket event: metadata"
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","name":"Somedays","artist_names":["Sonny Fodera","Jazzy","D.O.D"],"album_name":"Somedays","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","position":0,"duration":207168,"release_date":"year:2024 month:7 day:26","track_number":1,"disc_number":1}}
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=trace msg="emitting websocket event: playing"
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:25 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus play
Oct 30 09:57:25 volumio volumio[968]: info: Received an update from plugin. extracting info from payload
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:25 volumio go-librespot[1191]: time="2024-10-30T09:57:25+10:30" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:25 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:25 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus play
Oct 30 09:57:25 volumio volumio[968]: info: Received an update from plugin. extracting info from payload
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:25 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:25 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:25 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:25 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:26 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:26 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:26 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3wo3d0I5H8KjkwGvnz8WbB
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:19KlZwqlT3fguP2BeHF1Q1
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3nHuKdFJZm78CoeBnDcFKe
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1Es7AUAhQvapIcoh3qMKDL
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2plbrEY59IikOBgBGLjaoe
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:7z3PblAN3dH1JMewiRydkZ
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1d7Ptw3qYcfpdLNL5REhtJ
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6WO7IDGLakjO38lsvI2gHB
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2dono2Koz7DEvGwxUsmMLq
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2FQrifJ1N335Ljm3TjTVVf
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:4IadxL6BUymXlh8RCJJu7T
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6dOtVTDdiauQNBQEDOtlAB
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5vNRhkKd0yEAg8suGBpjeY
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0WbMK4wrZ1wFSty9F7FCgu
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3GiORO0zRwRT3g9CCklzkQ
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0oV6f0YDeVTGwdOeba8h89
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:7221xIgOnuakPdLqT0F3nP
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6u6vaQoR0IXCWRSOP7h7D6
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6MzofobZt2dm0Kf1hTThFz
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5kDgJffgJ0lYHTSiaXFWNw
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3Vr3zh0r7ALn8VLqCiRR10
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:24XihnoVPWXlKJ4BgXqjVM
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1ubTFuP9rXCYzYQM7jUoWM
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:7gxQXemQ5MBeK9PUrKRtfV
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2kZ0cv0J6lRQxep2nA3Ilm
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2uqYupMHANxnwgeiXTZXzd
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6yuBDYdORL4p8gQZYpGz3a
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5N3hjp1WNayUPZrA8kJmJP
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2262bWmqomIaJXwCRHr13j
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6iYxkBHyMpsgVxUgfy5fSx
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3dj4wgM3cPeuLwMNHDuBon
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6rGksJP4hwS7Qw4dURZUyd
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1xmvq1fYLs9TEgikaFilGW
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2LUD3874dlzeRa34Hi7ohW
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0h3Xy4V4apMraB5NuM8U7Z
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0OA00aPt3BV10qeMIs3meW
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:7z7kvUQGwlC6iOl7vMuAr9
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3QaPy1KgI7nu9FJEQUgn6h
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5AJ9hqTS2wcFQCELCFRO7A
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:4xdBrk0nFZaP54vvZj0yx7
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1bJRd2ey6ER7neSxZwYdAG
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:24MvIfLvlRyemQX4ena9W6
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2qSkIjg1o9h3YT9RAgYN75
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3tqyv30P7pO53IAIUo8IeN
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0qKKAOF4kezKlvtyYyv12C
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3WOhcATHxK2SLNeP5W3v1v
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3dTcqX8YTH1Hpk2pGHbBbq
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5uQ7de4EWjb3rkcFxyEOpu
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:787Y2idwCU2Rk60Prv4wpr
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:4arNFfHtD5FPYcpUUiUOM1
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0io16MKpbeDIdYzmGpQaES
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2GxrNKugF82CnoRFbQfzPf
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3HrHhTWonBqF4mDasi8xvC
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1juBRo49adrKPIJDdOf6zt
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:51rfRCiUSvxXlCSCfIztBy
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3qhlB30KknSejmIvZZLjOD
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6AI3ezQ4o3HUoP6Dhudph3
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2OzhQlSqBEmt7hmkYxfT6m
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6khKJVbTxzfhbGfHMtyOM8
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:3Pbp7cUCx4d3OAkZSCoNvn
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:46kspZSY3aKmwQe7O77fCC
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6GG4yyk3UATdBfTHVgI8PB
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2hrycoFU1mZw6YPvMcn8yC
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:0agQ9vIV7NP4dntGKLcCXO
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6jlG8gBPNAgBgoivw2Ig09
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:5wbg8kepMFoMzHOEuxiI0q
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1aHy1ipWQRNauI0ee9uYfi
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:4q5YezDOIPcoLr8R81x9qy
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:7jEpRsSusmGqKFISucMnV7
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2HYFX63wP3otVIvopRS99Z
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:2bmwbLM7isIZoaZwsOC1ce
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:6tNQ70jh4OwmPGpYy6R2o9
Oct 30 09:57:26 volumio volumio[968]: info: Preloading song: spotify:track:1bjeWoagtHmUKputLVyDxQ
Oct 30 09:57:26 volumio volumio[968]: info: Exploding uri spotify:track:3wo3d0I5H8KjkwGvnz8WbB in service spop
Oct 30 09:57:26 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3wo3d0I5H8KjkwGvnz8WbB
Oct 30 09:57:26 volumio volumio[968]: info: Exploding uri spotify:track:19KlZwqlT3fguP2BeHF1Q1 in service spop
Oct 30 09:57:26 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:19KlZwqlT3fguP2BeHF1Q1
Oct 30 09:57:26 volumio volumio[968]: info: Exploding uri spotify:track:3nHuKdFJZm78CoeBnDcFKe in service spop
Oct 30 09:57:26 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3nHuKdFJZm78CoeBnDcFKe
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:1Es7AUAhQvapIcoh3qMKDL in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1Es7AUAhQvapIcoh3qMKDL
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:2plbrEY59IikOBgBGLjaoe in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2plbrEY59IikOBgBGLjaoe
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:7z3PblAN3dH1JMewiRydkZ in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:7z3PblAN3dH1JMewiRydkZ
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:1d7Ptw3qYcfpdLNL5REhtJ in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1d7Ptw3qYcfpdLNL5REhtJ
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","service":"spop","name":"Somedays","artist":"Sonny Fodera","album":"Somedays","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273d572297e63fcc5a8ca10440f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:6WO7IDGLakjO38lsvI2gHB in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6WO7IDGLakjO38lsvI2gHB
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:19KlZwqlT3fguP2BeHF1Q1","service":"spop","name":"Disease","artist":"Lady Gaga","album":"Disease","type":"song","duration":229,"albumart":"https://i.scdn.co/image/ab67616d0000b273465e58cfc2ee480a7d0ae59d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:2dono2Koz7DEvGwxUsmMLq in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2dono2Koz7DEvGwxUsmMLq
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:2FQrifJ1N335Ljm3TjTVVf in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2FQrifJ1N335Ljm3TjTVVf
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:4IadxL6BUymXlh8RCJJu7T in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:4IadxL6BUymXlh8RCJJu7T
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:6dOtVTDdiauQNBQEDOtlAB in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6dOtVTDdiauQNBQEDOtlAB
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3nHuKdFJZm78CoeBnDcFKe","service":"spop","name":"Bad Dreams","artist":"Teddy Swims","album":"Bad Dreams","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b273de4b0388cb6e5267132a07bc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:5vNRhkKd0yEAg8suGBpjeY in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5vNRhkKd0yEAg8suGBpjeY
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Es7AUAhQvapIcoh3qMKDL","service":"spop","name":"Timeless (with Playboi Carti)","artist":"The Weeknd","album":"Timeless","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee2fe4a7b285d3817b470859","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7z3PblAN3dH1JMewiRydkZ","service":"spop","name":"GIRLS","artist":"The Kid LAROI","album":"GIRLS","type":"song","duration":152,"albumart":"https://i.scdn.co/image/ab67616d0000b273c8af7237bb25ad59488944c1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2plbrEY59IikOBgBGLjaoe","service":"spop","name":"Die With A Smile","artist":"Lady Gaga","album":"Die With A Smile","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b27382ea2e9e1858aa012c57cd45","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:0WbMK4wrZ1wFSty9F7FCgu in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0WbMK4wrZ1wFSty9F7FCgu
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1d7Ptw3qYcfpdLNL5REhtJ","service":"spop","name":"Taste","artist":"Sabrina Carpenter","album":"Short n' Sweet","type":"song","duration":157,"albumart":"https://i.scdn.co/image/ab67616d0000b2735e1ec3f6b114e4e4924f006f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6WO7IDGLakjO38lsvI2gHB","service":"spop","name":"Slow It Down","artist":"Benson Boone","album":"Slow It Down","type":"song","duration":161,"albumart":"https://i.scdn.co/image/ab67616d0000b273f824b0f45489f0f3388d5398","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:3GiORO0zRwRT3g9CCklzkQ in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3GiORO0zRwRT3g9CCklzkQ
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:0oV6f0YDeVTGwdOeba8h89 in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0oV6f0YDeVTGwdOeba8h89
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2FQrifJ1N335Ljm3TjTVVf","service":"spop","name":"A Bar Song (Tipsy)","artist":"Shaboozey","album":"A Bar Song (Tipsy)","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b27380d86d636244b72a3a1eede2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:7221xIgOnuakPdLqT0F3nP in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:7221xIgOnuakPdLqT0F3nP
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2dono2Koz7DEvGwxUsmMLq","service":"spop","name":"Linger - SiriusXM Session","artist":"Royel Otis","album":"Linger / Heading For The Door (Sirius XM Session)","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b273ccaa2ab01efad107f3952454","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:6u6vaQoR0IXCWRSOP7h7D6 in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6u6vaQoR0IXCWRSOP7h7D6
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4IadxL6BUymXlh8RCJJu7T","service":"spop","name":"Too Sweet","artist":"Hozier","album":"Unheard","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b273a5aab55aa65e5f6bd19564a2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6dOtVTDdiauQNBQEDOtlAB","service":"spop","name":"BIRDS OF A FEATHER","artist":"Billie Eilish","album":"HIT ME HARD AND SOFT","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b27371d62ea7ea8a5be92d3c1f62","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:6MzofobZt2dm0Kf1hTThFz in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6MzofobZt2dm0Kf1hTThFz
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:5kDgJffgJ0lYHTSiaXFWNw in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5kDgJffgJ0lYHTSiaXFWNw
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5vNRhkKd0yEAg8suGBpjeY","service":"spop","name":"APT.","artist":"ROSÉ","album":"APT.","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b273f8c8297efc6022534f1357e1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:3Vr3zh0r7ALn8VLqCiRR10 in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3Vr3zh0r7ALn8VLqCiRR10
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:24XihnoVPWXlKJ4BgXqjVM in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:24XihnoVPWXlKJ4BgXqjVM
Oct 30 09:57:27 volumio volumio[968]: info: Exploding uri spotify:track:1ubTFuP9rXCYzYQM7jUoWM in service spop
Oct 30 09:57:27 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1ubTFuP9rXCYzYQM7jUoWM
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0WbMK4wrZ1wFSty9F7FCgu","service":"spop","name":"Good Luck, Babe!","artist":"Chappell Roan","album":"Good Luck, Babe!","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b27391b4bc7c88d91a42e0f3a8b7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3GiORO0zRwRT3g9CCklzkQ","service":"spop","name":"It's That Time - FISHER Remix","artist":"Marlon Hoffstadt","album":"It's That Time (FISHER Remix)","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b27331f60a0ce2b1c6588d80877d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0oV6f0YDeVTGwdOeba8h89","service":"spop","name":"Dance With Me","artist":"Tones And I","album":"Dance With Me","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b2732d7b1961733cf85a6f8c5cb2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:7gxQXemQ5MBeK9PUrKRtfV in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:7gxQXemQ5MBeK9PUrKRtfV
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7221xIgOnuakPdLqT0F3nP","service":"spop","name":"I Had Some Help (Feat. Morgan Wallen)","artist":"Post Malone","album":"I Had Some Help","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b27397306976e3eb8aad53b754eb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:2kZ0cv0J6lRQxep2nA3Ilm in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2kZ0cv0J6lRQxep2nA3Ilm
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:2uqYupMHANxnwgeiXTZXzd in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2uqYupMHANxnwgeiXTZXzd
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6MzofobZt2dm0Kf1hTThFz","service":"spop","name":"Diet Pepsi","artist":"Addison Rae","album":"Diet Pepsi","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b2734e5a5862355a5e953549292b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6u6vaQoR0IXCWRSOP7h7D6","service":"spop","name":"Get Busy - Odd Mob Club Mix","artist":"Sean Paul","album":"Get Busy (Odd Mob Club Mix)","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b2739c3811a3d6395ad2588a9c34","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:6yuBDYdORL4p8gQZYpGz3a in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6yuBDYdORL4p8gQZYpGz3a
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5kDgJffgJ0lYHTSiaXFWNw","service":"spop","name":"BABY I'M BACK","artist":"The Kid LAROI","album":"THE FIRST TIME (DELUXE VERSION)","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b273127bb9583e9861edbcde38f6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:5N3hjp1WNayUPZrA8kJmJP in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5N3hjp1WNayUPZrA8kJmJP
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:2262bWmqomIaJXwCRHr13j in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2262bWmqomIaJXwCRHr13j
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3Vr3zh0r7ALn8VLqCiRR10","service":"spop","name":"Stargazing","artist":"Myles Smith","album":"Stargazing","type":"song","duration":172,"albumart":"https://i.scdn.co/image/ab67616d0000b27381b12e1a0584e8ea7ba2ae4a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:6iYxkBHyMpsgVxUgfy5fSx in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6iYxkBHyMpsgVxUgfy5fSx
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:3dj4wgM3cPeuLwMNHDuBon in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3dj4wgM3cPeuLwMNHDuBon
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:24XihnoVPWXlKJ4BgXqjVM","service":"spop","name":"It's ok I'm ok","artist":"Tate McRae","album":"It's ok I'm ok","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b273cd9a93745f6a7cd54deaab22","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:6rGksJP4hwS7Qw4dURZUyd in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6rGksJP4hwS7Qw4dURZUyd
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2kZ0cv0J6lRQxep2nA3Ilm","service":"spop","name":"CAVE (with Tove Lo)","artist":"Dom Dolla","album":"CAVE (with Tove Lo)","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b273619f2ae57f9c87be06cd69ed","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ubTFuP9rXCYzYQM7jUoWM","service":"spop","name":"Pressure","artist":"RÜFÜS DU SOL","album":"Pressure","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b2736a8a6ad5453f5d19ec4295f9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:1xmvq1fYLs9TEgikaFilGW in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1xmvq1fYLs9TEgikaFilGW
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6yuBDYdORL4p8gQZYpGz3a","service":"spop","name":"Tangerine","artist":"Ocean Alley","album":"Tangerine","type":"song","duration":290,"albumart":"https://i.scdn.co/image/ab67616d0000b2730e1f61a6fef8685563935b8e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:2LUD3874dlzeRa34Hi7ohW in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2LUD3874dlzeRa34Hi7ohW
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2uqYupMHANxnwgeiXTZXzd","service":"spop","name":"Austin (Boots Stop Workin')","artist":"Dasha","album":"What Happens Now?","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ccf88b66e04cfd247f287eb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:0h3Xy4V4apMraB5NuM8U7Z in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0h3Xy4V4apMraB5NuM8U7Z
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7gxQXemQ5MBeK9PUrKRtfV","service":"spop","name":"Burning Down","artist":"Alex Warren","album":"Burning Down","type":"song","duration":179,"albumart":"https://i.scdn.co/image/ab67616d0000b27380fd7741b86bdcc9940f90a8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5N3hjp1WNayUPZrA8kJmJP","service":"spop","name":"Please Please Please","artist":"Sabrina Carpenter","album":"Please Please Please","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b273de84adf0e48248ea2d769c3e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:0OA00aPt3BV10qeMIs3meW in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0OA00aPt3BV10qeMIs3meW
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:7z7kvUQGwlC6iOl7vMuAr9 in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:7z7kvUQGwlC6iOl7vMuAr9
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2262bWmqomIaJXwCRHr13j","service":"spop","name":"Sailor Song","artist":"Gigi Perez","album":"Sailor Song","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b273e6065f209e0a01986206bd53","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:3QaPy1KgI7nu9FJEQUgn6h in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3QaPy1KgI7nu9FJEQUgn6h
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6iYxkBHyMpsgVxUgfy5fSx","service":"spop","name":"ALL MY LOVE","artist":"Coldplay","album":"Moon Music","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b27309ba52a5116e0c3e8461f58b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:5AJ9hqTS2wcFQCELCFRO7A in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5AJ9hqTS2wcFQCELCFRO7A
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3dj4wgM3cPeuLwMNHDuBon","service":"spop","name":"The Door","artist":"Teddy Swims","album":"I've Tried Everything But Therapy (Part 1)","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b2731a0323cc23419360a34a3ace","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6rGksJP4hwS7Qw4dURZUyd","service":"spop","name":"Lights Camera Action","artist":"Kylie Minogue","album":"Lights Camera Action","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b27331abeb666576d808de340b3d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:4xdBrk0nFZaP54vvZj0yx7 in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:4xdBrk0nFZaP54vvZj0yx7
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:1bJRd2ey6ER7neSxZwYdAG in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1bJRd2ey6ER7neSxZwYdAG
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","service":"spop","name":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b2739a903819d8a5d3c80c47734c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:24MvIfLvlRyemQX4ena9W6 in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:24MvIfLvlRyemQX4ena9W6
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0OA00aPt3BV10qeMIs3meW","service":"spop","name":"Big Dawgs","artist":"Hanumankind","album":"Big Dawgs","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b273d9afe5c70c43cb2bd34605ea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:28 volumio volumio[968]: info: Exploding uri spotify:track:2qSkIjg1o9h3YT9RAgYN75 in service spop
Oct 30 09:57:28 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2qSkIjg1o9h3YT9RAgYN75
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2LUD3874dlzeRa34Hi7ohW","service":"spop","name":"Talk talk featuring troye sivan","artist":"Charli xcx","album":"Talk talk featuring troye sivan","type":"song","duration":173,"albumart":"https://i.scdn.co/image/ab67616d0000b273470ad9a1d33be4f63316e0c7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7z7kvUQGwlC6iOl7vMuAr9","service":"spop","name":"Dancing In The Flames","artist":"The Weeknd","album":"Dancing In The Flames","type":"song","duration":220,"albumart":"https://i.scdn.co/image/ab67616d0000b273f0e9b93cadbeb4d0227a59eb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3tqyv30P7pO53IAIUo8IeN in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3tqyv30P7pO53IAIUo8IeN
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:0qKKAOF4kezKlvtyYyv12C in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0qKKAOF4kezKlvtyYyv12C
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3QaPy1KgI7nu9FJEQUgn6h","service":"spop","name":"WILDFLOWER","artist":"Billie Eilish","album":"HIT ME HARD AND SOFT","type":"song","duration":261,"albumart":"https://i.scdn.co/image/ab67616d0000b27371d62ea7ea8a5be92d3c1f62","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5AJ9hqTS2wcFQCELCFRO7A","service":"spop","name":"MILLION DOLLAR BABY","artist":"Tommy Richman","album":"MILLION DOLLAR BABY","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b27301c0cd5da820e6128655854f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3WOhcATHxK2SLNeP5W3v1v in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3WOhcATHxK2SLNeP5W3v1v
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3dTcqX8YTH1Hpk2pGHbBbq in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3dTcqX8YTH1Hpk2pGHbBbq
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4xdBrk0nFZaP54vvZj0yx7","service":"spop","name":"HOT TO GO!","artist":"Chappell Roan","album":"The Rise and Fall of a Midwest Princess","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b27396fa88fb1789be437d5cb4b6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1bJRd2ey6ER7neSxZwYdAG","service":"spop","name":"Kisses (feat. bbyclose)","artist":"BL3SS","album":"Kisses (feat. bbyclose)","type":"song","duration":138,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ba70f49a78d818fc0758667","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1xmvq1fYLs9TEgikaFilGW","service":"spop","name":"Thick Of It (feat. Trippie Redd)","artist":"KSI","album":"Thick Of It (feat. Trippie Redd) / Low","type":"song","duration":160,"albumart":"https://i.scdn.co/image/ab67616d0000b2734b8b52a487c842534619501a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:5uQ7de4EWjb3rkcFxyEOpu in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5uQ7de4EWjb3rkcFxyEOpu
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:24MvIfLvlRyemQX4ena9W6","service":"spop","name":"Gang Ties (feat. Headie One)","artist":"ONEFOUR","album":"Gang Ties (feat. Headie One)","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ab7055657c643f34adc23c7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2qSkIjg1o9h3YT9RAgYN75","service":"spop","name":"Espresso","artist":"Sabrina Carpenter","album":"Espresso","type":"song","duration":175,"albumart":"https://i.scdn.co/image/ab67616d0000b273659cd4673230913b3918e0d5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:787Y2idwCU2Rk60Prv4wpr in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:787Y2idwCU2Rk60Prv4wpr
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8 in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3tqyv30P7pO53IAIUo8IeN","service":"spop","name":"Break My Love","artist":"RÜFÜS DU SOL","album":"Break My Love","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b27387a323e8609672a65a6badfd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:4arNFfHtD5FPYcpUUiUOM1 in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:4arNFfHtD5FPYcpUUiUOM1
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0qKKAOF4kezKlvtyYyv12C","service":"spop","name":"DIE FOR ME","artist":"Chase Atlantic","album":"DIE FOR ME","type":"song","duration":206,"albumart":"https://i.scdn.co/image/ab67616d0000b2739d9ada31f6f09bd19b7c6886","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:0io16MKpbeDIdYzmGpQaES in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0io16MKpbeDIdYzmGpQaES
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3WOhcATHxK2SLNeP5W3v1v","service":"spop","name":"Guess featuring billie eilish","artist":"Charli xcx","album":"Guess featuring Billie Eilish","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b273dca19fcb7a25410224da080b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:2GxrNKugF82CnoRFbQfzPf in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2GxrNKugF82CnoRFbQfzPf
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3dTcqX8YTH1Hpk2pGHbBbq","service":"spop","name":"APEROL SPRITZ","artist":"The Kid LAROI","album":"APEROL SPRITZ","type":"song","duration":130,"albumart":"https://i.scdn.co/image/ab67616d0000b273867eaff1b88702a798ebba93","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3HrHhTWonBqF4mDasi8xvC in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3HrHhTWonBqF4mDasi8xvC
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5uQ7de4EWjb3rkcFxyEOpu","service":"spop","name":"Belong Together","artist":"Mark Ambor","album":"Belong Together","type":"song","duration":148,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed71b8008aaa879622f8c3b5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:1juBRo49adrKPIJDdOf6zt in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1juBRo49adrKPIJDdOf6zt
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:787Y2idwCU2Rk60Prv4wpr","service":"spop","name":"Saving Up","artist":"Dom Dolla","album":"Saving Up","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273585c329dfd9cdeb22b6cd247","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:51rfRCiUSvxXlCSCfIztBy in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:51rfRCiUSvxXlCSCfIztBy
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8","service":"spop","name":"obsessed","artist":"Olivia Rodrigo","album":"GUTS (spilled)","type":"song","duration":170,"albumart":"https://i.scdn.co/image/ab67616d0000b2734063d624ebf8ff67bc3701ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3qhlB30KknSejmIvZZLjOD in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3qhlB30KknSejmIvZZLjOD
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4arNFfHtD5FPYcpUUiUOM1","service":"spop","name":"World Gone Wild (feat. Sam Martin)","artist":"Robin Schulz","album":"World Gone Wild (feat. Sam Martin)","type":"song","duration":146,"albumart":"https://i.scdn.co/image/ab67616d0000b2733121f6eefc3b15ace827415c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:6AI3ezQ4o3HUoP6Dhudph3 in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6AI3ezQ4o3HUoP6Dhudph3
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0io16MKpbeDIdYzmGpQaES","service":"spop","name":"Embrace It","artist":"Ndotz","album":"Embrace It","type":"song","duration":104,"albumart":"https://i.scdn.co/image/ab67616d0000b273536637d541ec8a43842ef126","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2GxrNKugF82CnoRFbQfzPf","service":"spop","name":"i like the way you kiss me","artist":"Artemas","album":"i like the way you kiss me","type":"song","duration":142,"albumart":"https://i.scdn.co/image/ab67616d0000b273e67611dbbf69a90d0b6cb738","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:2OzhQlSqBEmt7hmkYxfT6m in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2OzhQlSqBEmt7hmkYxfT6m
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:6khKJVbTxzfhbGfHMtyOM8 in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6khKJVbTxzfhbGfHMtyOM8
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3HrHhTWonBqF4mDasi8xvC","service":"spop","name":"BACKBONE","artist":"Chase & Status","album":"BACKBONE","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c7e93001b846b12ae2c7e3b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1juBRo49adrKPIJDdOf6zt","service":"spop","name":"Apple","artist":"Charli xcx","album":"Brat and it’s the same but there’s three more songs so it’s not","type":"song","duration":151,"albumart":"https://i.scdn.co/image/ab67616d0000b273df174e0dcb15de7b625a7194","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:3Pbp7cUCx4d3OAkZSCoNvn in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:3Pbp7cUCx4d3OAkZSCoNvn
Oct 30 09:57:29 volumio volumio[968]: info: Exploding uri spotify:track:46kspZSY3aKmwQe7O77fCC in service spop
Oct 30 09:57:29 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:46kspZSY3aKmwQe7O77fCC
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:51rfRCiUSvxXlCSCfIztBy","service":"spop","name":"I Love You, I'm Sorry","artist":"Gracie Abrams","album":"The Secret of Us","type":"song","duration":157,"albumart":"https://i.scdn.co/image/ab67616d0000b2736e2101520787791370f4a96b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:6GG4yyk3UATdBfTHVgI8PB in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6GG4yyk3UATdBfTHVgI8PB
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea","service":"spop","name":"feelslikeimfallinginlove - Single Version","artist":"Coldplay","album":"feelslikeimfallinginlove","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b27390ac383add08fbff7286958c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:2hrycoFU1mZw6YPvMcn8yC in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2hrycoFU1mZw6YPvMcn8yC
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6AI3ezQ4o3HUoP6Dhudph3","service":"spop","name":"Not Like Us","artist":"Kendrick Lamar","album":"Not Like Us","type":"song","duration":274,"albumart":"https://i.scdn.co/image/ab67616d0000b2731ea0c62b2339cbf493a999ad","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3qhlB30KknSejmIvZZLjOD","service":"spop","name":"End of Beginning","artist":"Djo","album":"DECIDE","type":"song","duration":159,"albumart":"https://i.scdn.co/image/ab67616d0000b273fddfffec51b4580acae727c1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:0agQ9vIV7NP4dntGKLcCXO in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:0agQ9vIV7NP4dntGKLcCXO
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:6jlG8gBPNAgBgoivw2Ig09 in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6jlG8gBPNAgBgoivw2Ig09
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6khKJVbTxzfhbGfHMtyOM8","service":"spop","name":"S P E Y S I D E","artist":"Bon Iver","album":"S P E Y S I D E","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b273b00ba18c78cab0d9331a4d7c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2OzhQlSqBEmt7hmkYxfT6m","service":"spop","name":"Fortnight (feat. Post Malone)","artist":"Taylor Swift","album":"THE TORTURED POETS DEPARTMENT","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2735076e4160d018e378f488c33","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:5wbg8kepMFoMzHOEuxiI0q in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:5wbg8kepMFoMzHOEuxiI0q
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3Pbp7cUCx4d3OAkZSCoNvn","service":"spop","name":"Scared To Start","artist":"Michael Marcagi","album":"Scared To Start","type":"song","duration":159,"albumart":"https://i.scdn.co/image/ab67616d0000b27351ef67c49732e45cd2b26fbe","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:1aHy1ipWQRNauI0ee9uYfi in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1aHy1ipWQRNauI0ee9uYfi
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:46kspZSY3aKmwQe7O77fCC","service":"spop","name":"we can't be friends (wait for your love)","artist":"Ariana Grande","album":"eternal sunshine","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b273c75a14e746ffe2030e8cd5da","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:4q5YezDOIPcoLr8R81x9qy in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:4q5YezDOIPcoLr8R81x9qy
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6GG4yyk3UATdBfTHVgI8PB","service":"spop","name":"Ain't No Love In Oklahoma (From Twisters: The Album)","artist":"Luke Combs","album":"Ain't No Love In Oklahoma (From Twisters: The Album)","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b27339808230102049beb62fdd7b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:7jEpRsSusmGqKFISucMnV7 in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:7jEpRsSusmGqKFISucMnV7
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2hrycoFU1mZw6YPvMcn8yC","service":"spop","name":"KEHLANI","artist":"Jordan Adetunji","album":"KEHLANI","type":"song","duration":122,"albumart":"https://i.scdn.co/image/ab67616d0000b273f2cd132495d61b0da6a900d2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:2HYFX63wP3otVIvopRS99Z in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2HYFX63wP3otVIvopRS99Z
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0agQ9vIV7NP4dntGKLcCXO","service":"spop","name":"Somebody (2024)","artist":"Gotye","album":"Somebody (2024)","type":"song","duration":153,"albumart":"https://i.scdn.co/image/ab67616d0000b273decbf9beecb3cb749ce3a2e2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:2bmwbLM7isIZoaZwsOC1ce in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:2bmwbLM7isIZoaZwsOC1ce
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6jlG8gBPNAgBgoivw2Ig09","service":"spop","name":"DEVIL IS A LIE","artist":"Tommy Richman","album":"DEVIL IS A LIE","type":"song","duration":130,"albumart":"https://i.scdn.co/image/ab67616d0000b273f1708ceacc5e678619364239","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:6tNQ70jh4OwmPGpYy6R2o9 in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:6tNQ70jh4OwmPGpYy6R2o9
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5wbg8kepMFoMzHOEuxiI0q","service":"spop","name":"Close To You","artist":"Gracie Abrams","album":"The Secret of Us","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ba1c73e08db2c003a78e148","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: info: Exploding uri spotify:track:1bjeWoagtHmUKputLVyDxQ in service spop
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: EXPLODING URI:spotify:track:1bjeWoagtHmUKputLVyDxQ
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1aHy1ipWQRNauI0ee9uYfi","service":"spop","name":"Fall Back","artist":"Lithe","album":"Fall Back / Selfish Game","type":"song","duration":129,"albumart":"https://i.scdn.co/image/ab67616d0000b273e00f97607068f797b703559e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4q5YezDOIPcoLr8R81x9qy","service":"spop","name":"I Can Do It With a Broken Heart","artist":"Taylor Swift","album":"THE TORTURED POETS DEPARTMENT","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b2735076e4160d018e378f488c33","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7jEpRsSusmGqKFISucMnV7","service":"spop","name":"Please Don't Fall In Love With Me","artist":"Khalid","album":"Please Don't Fall In Love With Me","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b273855c84d9d5d2302d1e0fca9c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2HYFX63wP3otVIvopRS99Z","service":"spop","name":"Houdini","artist":"Eminem","album":"Houdini","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b273810603c94c9246379604cf1a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2bmwbLM7isIZoaZwsOC1ce","service":"spop","name":"Lifetime","artist":"Tobiahs","album":"Lifetime","type":"song","duration":158,"albumart":"https://i.scdn.co/image/ab67616d0000b273a894ac819bc12e1d87635ed9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tNQ70jh4OwmPGpYy6R2o9","service":"spop","name":"Beautiful Things","artist":"Benson Boone","album":"Beautiful Things","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b273bef221ea02a821e7feeda9cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:30 volumio volumio[968]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1bjeWoagtHmUKputLVyDxQ","service":"spop","name":"Saturn","artist":"SZA","album":"Saturn","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b273d70916ee9e40c90380ba5f07","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 30 09:57:31 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::ClearQueue
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::stPlaybackTimer
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::updateTrackBlock
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrackBlock
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:31 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:31 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::serviceStop
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::serviceStop
Oct 30 09:57:31 volumio volumio[968]: info: Spotify Stop
Oct 30 09:57:31 volumio volumio[968]: SPOTIFY: SPOTIFY STOP
Oct 30 09:57:31 volumio volumio[968]: SPOTIFY: {"status":"play","position":0,"title":"Somedays","artist":"Sonny Fodera","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d0000b273d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","codec":"ogg","seek":0,"duration":207,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Oct 30 09:57:31 volumio volumio[968]: info: Sending Spotify command to local API: /player/pause
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::clearPlayQueue
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::addQueueItems
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::addQueueItems
Oct 30 09:57:31 volumio volumio[968]: info: Preload queue cleared
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3wo3d0I5H8KjkwGvnz8WbB
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3wo3d0I5H8KjkwGvnz8WbB
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:19KlZwqlT3fguP2BeHF1Q1
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:19KlZwqlT3fguP2BeHF1Q1
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3nHuKdFJZm78CoeBnDcFKe
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3nHuKdFJZm78CoeBnDcFKe
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1Es7AUAhQvapIcoh3qMKDL
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1Es7AUAhQvapIcoh3qMKDL
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2plbrEY59IikOBgBGLjaoe
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2plbrEY59IikOBgBGLjaoe
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:7z3PblAN3dH1JMewiRydkZ
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:7z3PblAN3dH1JMewiRydkZ
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1d7Ptw3qYcfpdLNL5REhtJ
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1d7Ptw3qYcfpdLNL5REhtJ
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6WO7IDGLakjO38lsvI2gHB
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6WO7IDGLakjO38lsvI2gHB
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2dono2Koz7DEvGwxUsmMLq
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2dono2Koz7DEvGwxUsmMLq
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2FQrifJ1N335Ljm3TjTVVf
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2FQrifJ1N335Ljm3TjTVVf
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:4IadxL6BUymXlh8RCJJu7T
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:4IadxL6BUymXlh8RCJJu7T
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6dOtVTDdiauQNBQEDOtlAB
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6dOtVTDdiauQNBQEDOtlAB
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5vNRhkKd0yEAg8suGBpjeY
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5vNRhkKd0yEAg8suGBpjeY
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0WbMK4wrZ1wFSty9F7FCgu
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0WbMK4wrZ1wFSty9F7FCgu
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3GiORO0zRwRT3g9CCklzkQ
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3GiORO0zRwRT3g9CCklzkQ
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0oV6f0YDeVTGwdOeba8h89
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0oV6f0YDeVTGwdOeba8h89
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:7221xIgOnuakPdLqT0F3nP
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:7221xIgOnuakPdLqT0F3nP
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6u6vaQoR0IXCWRSOP7h7D6
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6u6vaQoR0IXCWRSOP7h7D6
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6MzofobZt2dm0Kf1hTThFz
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6MzofobZt2dm0Kf1hTThFz
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5kDgJffgJ0lYHTSiaXFWNw
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5kDgJffgJ0lYHTSiaXFWNw
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3Vr3zh0r7ALn8VLqCiRR10
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3Vr3zh0r7ALn8VLqCiRR10
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:24XihnoVPWXlKJ4BgXqjVM
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:24XihnoVPWXlKJ4BgXqjVM
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1ubTFuP9rXCYzYQM7jUoWM
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1ubTFuP9rXCYzYQM7jUoWM
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:7gxQXemQ5MBeK9PUrKRtfV
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:7gxQXemQ5MBeK9PUrKRtfV
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2kZ0cv0J6lRQxep2nA3Ilm
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2kZ0cv0J6lRQxep2nA3Ilm
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2uqYupMHANxnwgeiXTZXzd
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2uqYupMHANxnwgeiXTZXzd
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6yuBDYdORL4p8gQZYpGz3a
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6yuBDYdORL4p8gQZYpGz3a
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5N3hjp1WNayUPZrA8kJmJP
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5N3hjp1WNayUPZrA8kJmJP
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2262bWmqomIaJXwCRHr13j
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2262bWmqomIaJXwCRHr13j
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6iYxkBHyMpsgVxUgfy5fSx
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6iYxkBHyMpsgVxUgfy5fSx
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3dj4wgM3cPeuLwMNHDuBon
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3dj4wgM3cPeuLwMNHDuBon
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6rGksJP4hwS7Qw4dURZUyd
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6rGksJP4hwS7Qw4dURZUyd
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1xmvq1fYLs9TEgikaFilGW
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1xmvq1fYLs9TEgikaFilGW
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2LUD3874dlzeRa34Hi7ohW
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2LUD3874dlzeRa34Hi7ohW
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0h3Xy4V4apMraB5NuM8U7Z
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0h3Xy4V4apMraB5NuM8U7Z
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0OA00aPt3BV10qeMIs3meW
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0OA00aPt3BV10qeMIs3meW
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:7z7kvUQGwlC6iOl7vMuAr9
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:7z7kvUQGwlC6iOl7vMuAr9
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3QaPy1KgI7nu9FJEQUgn6h
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3QaPy1KgI7nu9FJEQUgn6h
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5AJ9hqTS2wcFQCELCFRO7A
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5AJ9hqTS2wcFQCELCFRO7A
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:4xdBrk0nFZaP54vvZj0yx7
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:4xdBrk0nFZaP54vvZj0yx7
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1bJRd2ey6ER7neSxZwYdAG
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1bJRd2ey6ER7neSxZwYdAG
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:24MvIfLvlRyemQX4ena9W6
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:24MvIfLvlRyemQX4ena9W6
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2qSkIjg1o9h3YT9RAgYN75
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2qSkIjg1o9h3YT9RAgYN75
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3tqyv30P7pO53IAIUo8IeN
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3tqyv30P7pO53IAIUo8IeN
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0qKKAOF4kezKlvtyYyv12C
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0qKKAOF4kezKlvtyYyv12C
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3WOhcATHxK2SLNeP5W3v1v
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3WOhcATHxK2SLNeP5W3v1v
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3dTcqX8YTH1Hpk2pGHbBbq
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3dTcqX8YTH1Hpk2pGHbBbq
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5uQ7de4EWjb3rkcFxyEOpu
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5uQ7de4EWjb3rkcFxyEOpu
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:787Y2idwCU2Rk60Prv4wpr
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:787Y2idwCU2Rk60Prv4wpr
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6tNgRQ0K2NYZ0Rb9l9DzL8
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:4arNFfHtD5FPYcpUUiUOM1
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:4arNFfHtD5FPYcpUUiUOM1
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0io16MKpbeDIdYzmGpQaES
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0io16MKpbeDIdYzmGpQaES
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2GxrNKugF82CnoRFbQfzPf
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2GxrNKugF82CnoRFbQfzPf
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3HrHhTWonBqF4mDasi8xvC
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3HrHhTWonBqF4mDasi8xvC
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1juBRo49adrKPIJDdOf6zt
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1juBRo49adrKPIJDdOf6zt
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:51rfRCiUSvxXlCSCfIztBy
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:51rfRCiUSvxXlCSCfIztBy
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3qhlB30KknSejmIvZZLjOD
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1YsU8rW2u8z4F0pwOBQ4Ea
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6AI3ezQ4o3HUoP6Dhudph3
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6AI3ezQ4o3HUoP6Dhudph3
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2OzhQlSqBEmt7hmkYxfT6m
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2OzhQlSqBEmt7hmkYxfT6m
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6khKJVbTxzfhbGfHMtyOM8
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6khKJVbTxzfhbGfHMtyOM8
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:3Pbp7cUCx4d3OAkZSCoNvn
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:3Pbp7cUCx4d3OAkZSCoNvn
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:46kspZSY3aKmwQe7O77fCC
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:46kspZSY3aKmwQe7O77fCC
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6GG4yyk3UATdBfTHVgI8PB
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6GG4yyk3UATdBfTHVgI8PB
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2hrycoFU1mZw6YPvMcn8yC
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2hrycoFU1mZw6YPvMcn8yC
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:0agQ9vIV7NP4dntGKLcCXO
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:0agQ9vIV7NP4dntGKLcCXO
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6jlG8gBPNAgBgoivw2Ig09
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6jlG8gBPNAgBgoivw2Ig09
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:5wbg8kepMFoMzHOEuxiI0q
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:5wbg8kepMFoMzHOEuxiI0q
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1aHy1ipWQRNauI0ee9uYfi
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1aHy1ipWQRNauI0ee9uYfi
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:4q5YezDOIPcoLr8R81x9qy
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:4q5YezDOIPcoLr8R81x9qy
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:7jEpRsSusmGqKFISucMnV7
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:7jEpRsSusmGqKFISucMnV7
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2HYFX63wP3otVIvopRS99Z
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2HYFX63wP3otVIvopRS99Z
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:2bmwbLM7isIZoaZwsOC1ce
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:2bmwbLM7isIZoaZwsOC1ce
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:6tNQ70jh4OwmPGpYy6R2o9
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:6tNQ70jh4OwmPGpYy6R2o9
Oct 30 09:57:31 volumio volumio[968]: info: Adding Item to queue: spotify:track:1bjeWoagtHmUKputLVyDxQ
Oct 30 09:57:31 volumio volumio[968]: info: Using cached record of: spotify:track:1bjeWoagtHmUKputLVyDxQ
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::volumioPushQueue
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::saveQueue
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::updateTrackBlock
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrackBlock
Oct 30 09:57:31 volumio volumio[968]: info: CoreCommandRouter::volumioPlay
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::play index 0
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::stop
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::play index undefined
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:31 volumio volumio[968]: info: CoreStateMachine::startPlaybackTimer
Oct 30 09:57:31 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:31 volumio volumio[968]: info: [1730244451380] ControllerSpotify::clearAddPlayTrack
Oct 30 09:57:31 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/play
Oct 30 09:57:31 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:31 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=debug msg="pause track at 6318ms"
Oct 30 09:57:31 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:31 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=debug msg="resolved context of track" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:31 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:31 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:31+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=trace msg="emitting websocket event: will_play"
Oct 30 09:57:32 volumio volumio[968]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=debug msg="selected format OGG_VORBIS_320 (69bfa72c0b275f7f8c05248dc3a6953c27f88a35)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=debug msg="requested aes key for file 69bfa72c0b275f7f8c05248dc3a6953c27f88a35, gid: 3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=debug msg="fetched first chunk of 17, total size is 8445487 bytes" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=info msg="loaded track \"Somedays\" (paused: false, position: 0ms, duration: 207168ms, prefetched: false)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=trace msg="scheduling prefetch in 177s"
Oct 30 09:57:32 volumio go-librespot[1191]: time="2024-10-30T09:57:32+10:30" level=trace msg="emitting websocket event: metadata"
Oct 30 09:57:32 volumio volumio[968]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","name":"Somedays","artist_names":["Sonny Fodera","Jazzy","D.O.D"],"album_name":"Somedays","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","position":0,"duration":207168,"release_date":"year:2024 month:7 day:26","track_number":1,"disc_number":1}}
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=trace msg="emitting websocket event: paused"
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: {"status":"pause","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState stateService pause
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus stop
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:57:33 volumio go-librespot[1191]: time="2024-10-30T09:57:33+10:30" level=trace msg="emitting websocket event: playing"
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","play_origin":"go-librespot"}}
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus stop
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:57:33 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus play
Oct 30 09:57:33 volumio volumio[968]: info: Received an update from plugin. extracting info from payload
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:33 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:33 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:33 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:33 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:33 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:36 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:57:36 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:57:36 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:57:36 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:57:36 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:57:36 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:57:37 volumio volumio[968]: info: VolumeController::SetAlsaVolume75
Oct 30 09:57:37 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:37 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 75
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:37 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 75
Oct 30 09:57:37 volumio volumio[968]: info: VolumeController::SetAlsaVolume15621
Oct 30 09:57:37 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 15621
Oct 30 09:57:37 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:37 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:37 volumio volumio[968]: info: VolumeController::SetAlsaVolume15581
Oct 30 09:57:37 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 15581
Oct 30 09:57:37 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:37 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:37 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:37 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 75
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:37 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:37 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: info: VolumeController::SetAlsaVolume50
Oct 30 09:57:38 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:38 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 50
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:38 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 50
Oct 30 09:57:38 volumio volumio[968]: info: VolumeController::SetAlsaVolume7518
Oct 30 09:57:38 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 7518
Oct 30 09:57:38 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:38 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:38 volumio volumio[968]: info: VolumeController::SetAlsaVolume7487
Oct 30 09:57:38 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 7487
Oct 30 09:57:38 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:38 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 50
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:38 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: info: VolumeController::SetAlsaVolume25629
Oct 30 09:57:38 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25629
Oct 30 09:57:38 volumio volumio[968]: info: VolumeController::SetAlsaVolume25700
Oct 30 09:57:38 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25700
Oct 30 09:57:38 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:38 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:38 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:38 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:38 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:38 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:38 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: info: VolumeController::SetAlsaVolume60
Oct 30 09:57:39 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:39 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 60
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:39 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 60
Oct 30 09:57:39 volumio volumio[968]: info: VolumeController::SetAlsaVolume10581
Oct 30 09:57:39 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 10581
Oct 30 09:57:39 volumio volumio[968]: info: VolumeController::SetAlsaVolume10522
Oct 30 09:57:39 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 10522
Oct 30 09:57:39 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:39 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:39 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:39 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: SPOTIFY VOLUME 60
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: VOLUMIO VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 30 09:57:39 volumio volumio[968]: info: Setting Spotify Volume from Volumio: 100
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: info: VolumeController::SetAlsaVolume25640
Oct 30 09:57:39 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25640
Oct 30 09:57:39 volumio volumio[968]: info: VolumeController::SetAlsaVolume25700
Oct 30 09:57:39 volumio volumio[968]: BT PLUGIN MESSAGE: Volume set to 25700
Oct 30 09:57:39 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:39 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:39 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:57:39 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:57:39 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:57:39 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:39 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:57:40 volumio volumio[968]: SPOTIFY: SETTING SPOTIFY VOLUME 100
Oct 30 09:57:40 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/volume
Oct 30 09:57:46 volumio go-librespot[1191]: time="2024-10-30T09:57:46+10:30" level=debug msg="fetched chunk 4/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:58:00 volumio go-librespot[1191]: time="2024-10-30T09:58:00+10:30" level=debug msg="fetched chunk 5/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:58:06 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:06 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:06 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:06 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:06 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:06 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:08 volumio volumio[968]: error: Failed request for metavolumio API
Oct 30 09:58:13 volumio go-librespot[1191]: time="2024-10-30T09:58:13+10:30" level=debug msg="fetched chunk 6/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:58:13 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 30 09:58:13 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 30 09:58:17 volumio volumio[968]: info: CoreCommandRouter::getUIConfigOnPlugin
Oct 30 09:58:17 volumio volumio[968]: info: Discoverable: true
Oct 30 09:58:17 volumio volumio[968]: info: CALLMETHOD: audio_interface bluetooth_controller getBluetoothDevices [object Object]
Oct 30 09:58:17 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: bluetooth_controller , getBluetoothDevices
Oct 30 09:58:17 volumio volumio[968]: info: Starting bluetooth device scan
Oct 30 09:58:17 volumio volumio[968]: info: Found bluetooth devices: {
Oct 30 09:58:17 volumio volumio[968]: "message": "pushBluetoothDevices",
Oct 30 09:58:17 volumio volumio[968]: "payload": {
Oct 30 09:58:17 volumio volumio[968]: "hasBluetooth": true,
Oct 30 09:58:17 volumio volumio[968]: "devices": [
Oct 30 09:58:17 volumio volumio[968]: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "77:2F:43:FF:3B:D6",
Oct 30 09:58:17 volumio volumio[968]: "name": "Yealink BH70",
Oct 30 09:58:17 volumio volumio[968]: "signal": 38,
Oct 30 09:58:17 volumio volumio[968]: "paired": "",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "20:64:DE:4C:09:8D",
Oct 30 09:58:17 volumio volumio[968]: "name": "WONDERBOOM 3",
Oct 30 09:58:17 volumio volumio[968]: "signal": 0,
Oct 30 09:58:17 volumio volumio[968]: "paired": "yes",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "yes",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "yes",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "44:73:D6:F7:18:D1",
Oct 30 09:58:17 volumio volumio[968]: "name": "MeetUp Soft Remote",
Oct 30 09:58:17 volumio volumio[968]: "signal": 62,
Oct 30 09:58:17 volumio volumio[968]: "paired": "",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: ]
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: info: Device list changed:
Oct 30 09:58:17 volumio volumio[968]: info: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "77:2F:43:FF:3B:D6",
Oct 30 09:58:17 volumio volumio[968]: "name": "Yealink BH70",
Oct 30 09:58:17 volumio volumio[968]: "signal": 38,
Oct 30 09:58:17 volumio volumio[968]: "paired": "",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: info: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "20:64:DE:4C:09:8D",
Oct 30 09:58:17 volumio volumio[968]: "name": "WONDERBOOM 3",
Oct 30 09:58:17 volumio volumio[968]: "signal": 0,
Oct 30 09:58:17 volumio volumio[968]: "paired": "yes",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "yes",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "yes",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: info: AVRCP: adding device: 20:64:DE:4C:09:8D
Oct 30 09:58:17 volumio volumio[968]: info: known: {
Oct 30 09:58:17 volumio volumio[968]: "20:64:DE:4C:09:8D": {
Oct 30 09:58:17 volumio volumio[968]: "virtualPath": "/devices/virtual/input/input0",
Oct 30 09:58:17 volumio volumio[968]: "devicePath": "/dev/input/event0",
Oct 30 09:58:17 volumio volumio[968]: "inputEvent": {
Oct 30 09:58:17 volumio volumio[968]: "_events": {},
Oct 30 09:58:17 volumio volumio[968]: "_eventsCount": 1,
Oct 30 09:58:17 volumio volumio[968]: "device": "/dev/input/event0",
Oct 30 09:58:17 volumio volumio[968]: "options": {
Oct 30 09:58:17 volumio volumio[968]: "flags": "r",
Oct 30 09:58:17 volumio volumio[968]: "encoding": null,
Oct 30 09:58:17 volumio volumio[968]: "fd": 62
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "fd": {
Oct 30 09:58:17 volumio volumio[968]: "_readableState": {
Oct 30 09:58:17 volumio volumio[968]: "objectMode": false,
Oct 30 09:58:17 volumio volumio[968]: "highWaterMark": 65536,
Oct 30 09:58:17 volumio volumio[968]: "buffer": {
Oct 30 09:58:17 volumio volumio[968]: "head": null,
Oct 30 09:58:17 volumio volumio[968]: "tail": null,
Oct 30 09:58:17 volumio volumio[968]: "length": 0
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "length": 0,
Oct 30 09:58:17 volumio volumio[968]: "pipes": [],
Oct 30 09:58:17 volumio volumio[968]: "flowing": true,
Oct 30 09:58:17 volumio volumio[968]: "ended": false,
Oct 30 09:58:17 volumio volumio[968]: "endEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "reading": true,
Oct 30 09:58:17 volumio volumio[968]: "sync": false,
Oct 30 09:58:17 volumio volumio[968]: "needReadable": true,
Oct 30 09:58:17 volumio volumio[968]: "emittedReadable": false,
Oct 30 09:58:17 volumio volumio[968]: "readableListening": false,
Oct 30 09:58:17 volumio volumio[968]: "resumeScheduled": false,
Oct 30 09:58:17 volumio volumio[968]: "errorEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "emitClose": true,
Oct 30 09:58:17 volumio volumio[968]: "autoDestroy": false,
Oct 30 09:58:17 volumio volumio[968]: "destroyed": false,
Oct 30 09:58:17 volumio volumio[968]: "errored": null,
Oct 30 09:58:17 volumio volumio[968]: "closed": false,
Oct 30 09:58:17 volumio volumio[968]: "closeEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "defaultEncoding": "utf8",
Oct 30 09:58:17 volumio volumio[968]: "awaitDrainWriters": null,
Oct 30 09:58:17 volumio volumio[968]: "multiAwaitDrain": false,
Oct 30 09:58:17 volumio volumio[968]: "readingMore": false,
Oct 30 09:58:17 volumio volumio[968]: "decoder": null,
Oct 30 09:58:17 volumio volumio[968]: "encoding": null
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "_events": {},
Oct 30 09:58:17 volumio volumio[968]: "_eventsCount": 3,
Oct 30 09:58:17 volumio volumio[968]: "path": null,
Oct 30 09:58:17 volumio volumio[968]: "fd": 62,
Oct 30 09:58:17 volumio volumio[968]: "flags": "r",
Oct 30 09:58:17 volumio volumio[968]: "mode": 438,
Oct 30 09:58:17 volumio volumio[968]: "end": null,
Oct 30 09:58:17 volumio volumio[968]: "autoClose": true,
Oct 30 09:58:17 volumio volumio[968]: "bytesRead": 0,
Oct 30 09:58:17 volumio volumio[968]: "closed": false
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "keyboard": {
Oct 30 09:58:17 volumio volumio[968]: "_events": {},
Oct 30 09:58:17 volumio volumio[968]: "_eventsCount": 2,
Oct 30 09:58:17 volumio volumio[968]: "device": "/dev/input/event0",
Oct 30 09:58:17 volumio volumio[968]: "options": {
Oct 30 09:58:17 volumio volumio[968]: "flags": "r",
Oct 30 09:58:17 volumio volumio[968]: "encoding": null,
Oct 30 09:58:17 volumio volumio[968]: "fd": 64
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "fd": {
Oct 30 09:58:17 volumio volumio[968]: "_readableState": {
Oct 30 09:58:17 volumio volumio[968]: "objectMode": false,
Oct 30 09:58:17 volumio volumio[968]: "highWaterMark": 65536,
Oct 30 09:58:17 volumio volumio[968]: "buffer": {
Oct 30 09:58:17 volumio volumio[968]: "head": null,
Oct 30 09:58:17 volumio volumio[968]: "tail": null,
Oct 30 09:58:17 volumio volumio[968]: "length": 0
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "length": 0,
Oct 30 09:58:17 volumio volumio[968]: "pipes": [],
Oct 30 09:58:17 volumio volumio[968]: "flowing": true,
Oct 30 09:58:17 volumio volumio[968]: "ended": false,
Oct 30 09:58:17 volumio volumio[968]: "endEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "reading": true,
Oct 30 09:58:17 volumio volumio[968]: "sync": false,
Oct 30 09:58:17 volumio volumio[968]: "needReadable": true,
Oct 30 09:58:17 volumio volumio[968]: "emittedReadable": false,
Oct 30 09:58:17 volumio volumio[968]: "readableListening": false,
Oct 30 09:58:17 volumio volumio[968]: "resumeScheduled": false,
Oct 30 09:58:17 volumio volumio[968]: "errorEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "emitClose": true,
Oct 30 09:58:17 volumio volumio[968]: "autoDestroy": false,
Oct 30 09:58:17 volumio volumio[968]: "destroyed": false,
Oct 30 09:58:17 volumio volumio[968]: "errored": null,
Oct 30 09:58:17 volumio volumio[968]: "closed": false,
Oct 30 09:58:17 volumio volumio[968]: "closeEmitted": false,
Oct 30 09:58:17 volumio volumio[968]: "defaultEncoding": "utf8",
Oct 30 09:58:17 volumio volumio[968]: "awaitDrainWriters": null,
Oct 30 09:58:17 volumio volumio[968]: "multiAwaitDrain": false,
Oct 30 09:58:17 volumio volumio[968]: "readingMore": false,
Oct 30 09:58:17 volumio volumio[968]: "decoder": null,
Oct 30 09:58:17 volumio volumio[968]: "encoding": null
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "_events": {
Oct 30 09:58:17 volumio volumio[968]: "error": [
Oct 30 09:58:17 volumio volumio[968]: null,
Oct 30 09:58:17 volumio volumio[968]: null
Oct 30 09:58:17 volumio volumio[968]: ]
Oct 30 09:58:17 volumio volumio[968]: },
Oct 30 09:58:17 volumio volumio[968]: "_eventsCount": 3,
Oct 30 09:58:17 volumio volumio[968]: "path": null,
Oct 30 09:58:17 volumio volumio[968]: "fd": 64,
Oct 30 09:58:17 volumio volumio[968]: "flags": "r",
Oct 30 09:58:17 volumio volumio[968]: "mode": 438,
Oct 30 09:58:17 volumio volumio[968]: "end": null,
Oct 30 09:58:17 volumio volumio[968]: "autoClose": true,
Oct 30 09:58:17 volumio volumio[968]: "bytesRead": 0,
Oct 30 09:58:17 volumio volumio[968]: "closed": false
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:17 volumio volumio[968]: info: {
Oct 30 09:58:17 volumio volumio[968]: "mac": "44:73:D6:F7:18:D1",
Oct 30 09:58:17 volumio volumio[968]: "name": "MeetUp Soft Remote",
Oct 30 09:58:17 volumio volumio[968]: "signal": 60,
Oct 30 09:58:17 volumio volumio[968]: "paired": "",
Oct 30 09:58:17 volumio volumio[968]: "trusted": "",
Oct 30 09:58:17 volumio volumio[968]: "icon": "",
Oct 30 09:58:17 volumio volumio[968]: "class": "",
Oct 30 09:58:17 volumio volumio[968]: "blocked": "",
Oct 30 09:58:17 volumio volumio[968]: "connected": "",
Oct 30 09:58:17 volumio volumio[968]: "trycount": 4
Oct 30 09:58:17 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: info: Device list changed:
Oct 30 09:58:18 volumio volumio[968]: info: {
Oct 30 09:58:18 volumio volumio[968]: "mac": "77:2F:43:FF:3B:D6",
Oct 30 09:58:18 volumio volumio[968]: "name": "Yealink BH70",
Oct 30 09:58:18 volumio volumio[968]: "signal": 41,
Oct 30 09:58:18 volumio volumio[968]: "paired": "",
Oct 30 09:58:18 volumio volumio[968]: "trusted": "",
Oct 30 09:58:18 volumio volumio[968]: "icon": "",
Oct 30 09:58:18 volumio volumio[968]: "class": "",
Oct 30 09:58:18 volumio volumio[968]: "blocked": "",
Oct 30 09:58:18 volumio volumio[968]: "connected": "",
Oct 30 09:58:18 volumio volumio[968]: "trycount": 4
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: info: {
Oct 30 09:58:18 volumio volumio[968]: "mac": "20:64:DE:4C:09:8D",
Oct 30 09:58:18 volumio volumio[968]: "name": "WONDERBOOM 3",
Oct 30 09:58:18 volumio volumio[968]: "signal": 0,
Oct 30 09:58:18 volumio volumio[968]: "paired": "yes",
Oct 30 09:58:18 volumio volumio[968]: "trusted": "yes",
Oct 30 09:58:18 volumio volumio[968]: "icon": "",
Oct 30 09:58:18 volumio volumio[968]: "class": "",
Oct 30 09:58:18 volumio volumio[968]: "blocked": "",
Oct 30 09:58:18 volumio volumio[968]: "connected": "yes",
Oct 30 09:58:18 volumio volumio[968]: "trycount": 4
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: info: AVRCP: adding device: 20:64:DE:4C:09:8D
Oct 30 09:58:18 volumio volumio[968]: info: known: {
Oct 30 09:58:18 volumio volumio[968]: "20:64:DE:4C:09:8D": {
Oct 30 09:58:18 volumio volumio[968]: "virtualPath": "/devices/virtual/input/input0",
Oct 30 09:58:18 volumio volumio[968]: "devicePath": "/dev/input/event0",
Oct 30 09:58:18 volumio volumio[968]: "inputEvent": {
Oct 30 09:58:18 volumio volumio[968]: "_events": {},
Oct 30 09:58:18 volumio volumio[968]: "_eventsCount": 1,
Oct 30 09:58:18 volumio volumio[968]: "device": "/dev/input/event0",
Oct 30 09:58:18 volumio volumio[968]: "options": {
Oct 30 09:58:18 volumio volumio[968]: "flags": "r",
Oct 30 09:58:18 volumio volumio[968]: "encoding": null,
Oct 30 09:58:18 volumio volumio[968]: "fd": 62
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "fd": {
Oct 30 09:58:18 volumio volumio[968]: "_readableState": {
Oct 30 09:58:18 volumio volumio[968]: "objectMode": false,
Oct 30 09:58:18 volumio volumio[968]: "highWaterMark": 65536,
Oct 30 09:58:18 volumio volumio[968]: "buffer": {
Oct 30 09:58:18 volumio volumio[968]: "head": null,
Oct 30 09:58:18 volumio volumio[968]: "tail": null,
Oct 30 09:58:18 volumio volumio[968]: "length": 0
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "length": 0,
Oct 30 09:58:18 volumio volumio[968]: "pipes": [],
Oct 30 09:58:18 volumio volumio[968]: "flowing": true,
Oct 30 09:58:18 volumio volumio[968]: "ended": false,
Oct 30 09:58:18 volumio volumio[968]: "endEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "reading": true,
Oct 30 09:58:18 volumio volumio[968]: "sync": false,
Oct 30 09:58:18 volumio volumio[968]: "needReadable": true,
Oct 30 09:58:18 volumio volumio[968]: "emittedReadable": false,
Oct 30 09:58:18 volumio volumio[968]: "readableListening": false,
Oct 30 09:58:18 volumio volumio[968]: "resumeScheduled": false,
Oct 30 09:58:18 volumio volumio[968]: "errorEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "emitClose": true,
Oct 30 09:58:18 volumio volumio[968]: "autoDestroy": false,
Oct 30 09:58:18 volumio volumio[968]: "destroyed": false,
Oct 30 09:58:18 volumio volumio[968]: "errored": null,
Oct 30 09:58:18 volumio volumio[968]: "closed": false,
Oct 30 09:58:18 volumio volumio[968]: "closeEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "defaultEncoding": "utf8",
Oct 30 09:58:18 volumio volumio[968]: "awaitDrainWriters": null,
Oct 30 09:58:18 volumio volumio[968]: "multiAwaitDrain": false,
Oct 30 09:58:18 volumio volumio[968]: "readingMore": false,
Oct 30 09:58:18 volumio volumio[968]: "decoder": null,
Oct 30 09:58:18 volumio volumio[968]: "encoding": null
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "_events": {},
Oct 30 09:58:18 volumio volumio[968]: "_eventsCount": 3,
Oct 30 09:58:18 volumio volumio[968]: "path": null,
Oct 30 09:58:18 volumio volumio[968]: "fd": 62,
Oct 30 09:58:18 volumio volumio[968]: "flags": "r",
Oct 30 09:58:18 volumio volumio[968]: "mode": 438,
Oct 30 09:58:18 volumio volumio[968]: "end": null,
Oct 30 09:58:18 volumio volumio[968]: "autoClose": true,
Oct 30 09:58:18 volumio volumio[968]: "bytesRead": 0,
Oct 30 09:58:18 volumio volumio[968]: "closed": false
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "keyboard": {
Oct 30 09:58:18 volumio volumio[968]: "_events": {},
Oct 30 09:58:18 volumio volumio[968]: "_eventsCount": 2,
Oct 30 09:58:18 volumio volumio[968]: "device": "/dev/input/event0",
Oct 30 09:58:18 volumio volumio[968]: "options": {
Oct 30 09:58:18 volumio volumio[968]: "flags": "r",
Oct 30 09:58:18 volumio volumio[968]: "encoding": null,
Oct 30 09:58:18 volumio volumio[968]: "fd": 64
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "fd": {
Oct 30 09:58:18 volumio volumio[968]: "_readableState": {
Oct 30 09:58:18 volumio volumio[968]: "objectMode": false,
Oct 30 09:58:18 volumio volumio[968]: "highWaterMark": 65536,
Oct 30 09:58:18 volumio volumio[968]: "buffer": {
Oct 30 09:58:18 volumio volumio[968]: "head": null,
Oct 30 09:58:18 volumio volumio[968]: "tail": null,
Oct 30 09:58:18 volumio volumio[968]: "length": 0
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "length": 0,
Oct 30 09:58:18 volumio volumio[968]: "pipes": [],
Oct 30 09:58:18 volumio volumio[968]: "flowing": true,
Oct 30 09:58:18 volumio volumio[968]: "ended": false,
Oct 30 09:58:18 volumio volumio[968]: "endEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "reading": true,
Oct 30 09:58:18 volumio volumio[968]: "sync": false,
Oct 30 09:58:18 volumio volumio[968]: "needReadable": true,
Oct 30 09:58:18 volumio volumio[968]: "emittedReadable": false,
Oct 30 09:58:18 volumio volumio[968]: "readableListening": false,
Oct 30 09:58:18 volumio volumio[968]: "resumeScheduled": false,
Oct 30 09:58:18 volumio volumio[968]: "errorEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "emitClose": true,
Oct 30 09:58:18 volumio volumio[968]: "autoDestroy": false,
Oct 30 09:58:18 volumio volumio[968]: "destroyed": false,
Oct 30 09:58:18 volumio volumio[968]: "errored": null,
Oct 30 09:58:18 volumio volumio[968]: "closed": false,
Oct 30 09:58:18 volumio volumio[968]: "closeEmitted": false,
Oct 30 09:58:18 volumio volumio[968]: "defaultEncoding": "utf8",
Oct 30 09:58:18 volumio volumio[968]: "awaitDrainWriters": null,
Oct 30 09:58:18 volumio volumio[968]: "multiAwaitDrain": false,
Oct 30 09:58:18 volumio volumio[968]: "readingMore": false,
Oct 30 09:58:18 volumio volumio[968]: "decoder": null,
Oct 30 09:58:18 volumio volumio[968]: "encoding": null
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "_events": {
Oct 30 09:58:18 volumio volumio[968]: "error": [
Oct 30 09:58:18 volumio volumio[968]: null,
Oct 30 09:58:18 volumio volumio[968]: null
Oct 30 09:58:18 volumio volumio[968]: ]
Oct 30 09:58:18 volumio volumio[968]: },
Oct 30 09:58:18 volumio volumio[968]: "_eventsCount": 3,
Oct 30 09:58:18 volumio volumio[968]: "path": null,
Oct 30 09:58:18 volumio volumio[968]: "fd": 64,
Oct 30 09:58:18 volumio volumio[968]: "flags": "r",
Oct 30 09:58:18 volumio volumio[968]: "mode": 438,
Oct 30 09:58:18 volumio volumio[968]: "end": null,
Oct 30 09:58:18 volumio volumio[968]: "autoClose": true,
Oct 30 09:58:18 volumio volumio[968]: "bytesRead": 0,
Oct 30 09:58:18 volumio volumio[968]: "closed": false
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:18 volumio volumio[968]: info: {
Oct 30 09:58:18 volumio volumio[968]: "mac": "44:73:D6:F7:18:D1",
Oct 30 09:58:18 volumio volumio[968]: "name": "MeetUp Soft Remote",
Oct 30 09:58:18 volumio volumio[968]: "signal": 60,
Oct 30 09:58:18 volumio volumio[968]: "paired": "",
Oct 30 09:58:18 volumio volumio[968]: "trusted": "",
Oct 30 09:58:18 volumio volumio[968]: "icon": "",
Oct 30 09:58:18 volumio volumio[968]: "class": "",
Oct 30 09:58:18 volumio volumio[968]: "blocked": "",
Oct 30 09:58:18 volumio volumio[968]: "connected": "",
Oct 30 09:58:18 volumio volumio[968]: "trycount": 4
Oct 30 09:58:18 volumio volumio[968]: }
Oct 30 09:58:26 volumio go-librespot[1191]: time="2024-10-30T09:58:26+10:30" level=debug msg="fetched chunk 7/16, size: 524288" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:58:28 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:28 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:28 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:28 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:28 volumio volumio[968]: info: Executing endpoint metavolumio
Oct 30 09:58:28 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::volumioSeek
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::seek
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: info: TRACKBLOCK {"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","service":"spop","name":"Somedays","artist":"Sonny Fodera","album":"Somedays","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273d572297e63fcc5a8ca10440f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2}
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::startPlaybackTimer
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: info: Spotify seek to: 37000
Oct 30 09:58:34 volumio volumio[968]: info: Sending Spotify command with payload to local API: /player/seek
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:58:34 volumio go-librespot[1191]: time="2024-10-30T09:58:34+10:30" level=debug msg="seek track to 37000ms"
Oct 30 09:58:34 volumio go-librespot[1191]: time="2024-10-30T09:58:34+10:30" level=trace msg="seek to 37000ms (diff: 188ms, samples: 1631700, bytes: 1381373)" uri="spotify:track:3wo3d0I5H8KjkwGvnz8WbB"
Oct 30 09:58:34 volumio go-librespot[1191]: time="2024-10-30T09:58:34+10:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 30 09:58:34 volumio go-librespot[1191]: time="2024-10-30T09:58:34+10:30" level=trace msg="scheduling prefetch in 140s"
Oct 30 09:58:34 volumio go-librespot[1191]: time="2024-10-30T09:58:34+10:30" level=trace msg="emitting websocket event: seek"
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","position":37000,"duration":207168,"play_origin":"go-librespot"}}
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: PUSH STATE SPOTIFY
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":37000,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::servicePushState
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Somedays","artist":"Sonny Fodera, Jazzy, D.O.D","album":"Somedays","albumart":"https://i.scdn.co/image/ab67616d00001e02d572297e63fcc5a8ca10440f","uri":"spotify:track:3wo3d0I5H8KjkwGvnz8WbB","trackType":"spotify","seek":37000,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 30 09:58:34 volumio volumio[968]: verbose: CURRENT POSITION 0
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::syncState stateService play
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::syncState currentStatus play
Oct 30 09:58:34 volumio volumio[968]: info: Received an update from plugin. extracting info from payload
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:58:34 volumio volumio[968]: info: CoreStateMachine::pushState
Oct 30 09:58:34 volumio volumio[968]: info: CorePlayQueue::getTrack 0
Oct 30 09:58:34 volumio volumio[968]: info: CoreCommandRouter::volumioPushState
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output update for this device
Oct 30 09:58:34 volumio volumio[968]: info: MRS: Pushing multiroomSync output
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:58:34 volumio volumio[968]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Oct 30 09:58:36 volumio volumio[968]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay
Oct 30 09:58:36 volumio volumio[968]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom
Oct 30 09:58:36 volumio volumio[968]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 30 09:58:36 volumio volumio[968]: TypeError: Cannot read property 'then' of undefined
Oct 30 09:58:36 volumio volumio[968]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9)
Oct 30 09:58:36 volumio volumio[968]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30)
Oct 30 09:58:36 volumio volumio[968]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1442:26)
Oct 30 09:58:36 volumio volumio[968]: at Socket.emit (events.js:315:20)
Oct 30 09:58:36 volumio volumio[968]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Oct 30 09:58:36 volumio volumio[968]: at processTicksAndRejections (internal/process/task_queues.js:75:11)
Oct 30 09:58:36 volumio volumio[968]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 30 09:58:37 volumio sudo[1791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-30 09:57
Oct 30 09:58:37 volumio sudo[1791]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST"
VOLUMIO_VERSION="3.757"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"