-- Logs begin at Sat 2025-09-06 21:01:13 BST, end at Sat 2025-09-06 22:14:02 BST. --
Sep 06 22:13:01 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:01+01:00" level=debug msg="fetched chunk 24/24, size: 157784" uri="spotify:track:5nSAoHM9qM1RAKiyqx7AAu"
Sep 06 22:13:14 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:14+01:00" level=trace msg="sent dealer ping"
Sep 06 22:13:14 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:14+01:00" level=trace msg="received dealer pong"
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: Discovery: Getting this device information
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: Discovery: Getting this device information
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:35 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 4
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: Prefetching next song
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: [1757193216096] ControllerSpotify::prefetch
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: Sending Spotify command with payload to local API: /player/add_to_queue
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=debug msg="prefetching next track" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=debug msg="selected format OGG_VORBIS_320 (5f03aef63920b92f08893307ce3b2c5289154d64)" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=debug msg="requested aes key for file 5f03aef63920b92f08893307ce3b2c5289154d64, gid: 2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=debug msg="fetched first chunk of 21, total size is 10573556 bytes" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:36+01:00" level=info msg="prefetched track \"I'm So Sorry - Live in Vegas\" (duration: 282208ms)" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: verbose: New Socket.io Connection to 192.168.1.28 from 192.168.1.41 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: Received Get System Info
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: Discovery: Getting this device information
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: Listing playlists
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetQueue
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::getQueue
Sep 06 22:13:36 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getQueue
Sep 06 22:13:37 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:37+01:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:37 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:37+01:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:37 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:37+01:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:37 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Sep 06 22:13:37 musical-fidelity-volumio volumio[2636]: verbose: New Socket.io Connection to 192.168.1.28:3000 from 192.168.1.41 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7
Sep 06 22:13:38 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:38+01:00" level=trace msg="emitting websocket event: not_playing"
Sep 06 22:13:38 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:38+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: error: Failed to decode event: not_playing
Sep 06 22:13:38 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:38+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:38 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:38+01:00" level=trace msg="emitting websocket event: will_play"
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:38+01:00" level=info msg="loaded track \"I'm So Sorry - Live in Vegas\" (paused: false, position: 0ms, duration: 282208ms, prefetched: true)" uri="spotify:track:2tOetqEr23IS6t8qizBVt2"
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:38 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:39 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:39+01:00" level=trace msg="scheduling prefetch in 252s"
Sep 06 22:13:39 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:39+01:00" level=trace msg="emitting websocket event: metadata"
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","name":"I'm So Sorry - Live in Vegas","artist_names":["Imagine Dragons"],"album_name":"Imagine Dragons Live in Vegas","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","position":0,"duration":282208,"release_date":"year:2023 month:7 day:28","track_number":5,"disc_number":1}}
Sep 06 22:13:39 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:39 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:39+01:00" level=trace msg="emitting websocket event: playing"
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","resume":false,"play_origin":"go-librespot"}}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus play
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: Received an update from plugin. extracting info from payload
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:39 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::servicePause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: Spotify Received pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: SPOTIFY PAUSE
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"play","position":3,"title":"It's Time - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d0000b273de6d776a57b267164a9f358b","uri":"spotify:track:5nSAoHM9qM1RAKiyqx7AAu","trackType":"spotify","codec":"ogg","seek":299326,"duration":301,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: Sending Spotify command to local API: /player/pause
Sep 06 22:13:40 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:40+01:00" level=debug msg="pause track at 827ms"
Sep 06 22:13:40 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:40 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Sep 06 22:13:40 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:40+01:00" level=trace msg="emitting websocket event: paused"
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","play_origin":"go-librespot"}}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: PUSH STATE SPOTIFY
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: SPOTIFY: {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::servicePushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"I'm So Sorry - Live in Vegas","artist":"Imagine Dragons","album":"Imagine Dragons Live in Vegas","albumart":"https://i.scdn.co/image/ab67616d00001e02de6d776a57b267164a9f358b","uri":"spotify:track:2tOetqEr23IS6t8qizBVt2","trackType":"spotify","seek":1000,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: verbose: CURRENT POSITION 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState stateService pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::syncState currentStatus pause
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::pushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioPushState
Sep 06 22:13:40 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::stPlaybackTimer
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: verbose: New Socket.io Connection to 192.168.1.28 from 192.168.1.41 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: Received Get System Info
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: Discovery: Getting this device information
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: Listing playlists
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetQueue
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreStateMachine::getQueue
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getQueue
Sep 06 22:13:43 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Sep 06 22:13:44 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:44+01:00" level=trace msg="sent dealer ping"
Sep 06 22:13:44 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:44+01:00" level=trace msg="received dealer pong"
Sep 06 22:13:44 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:44+01:00" level=trace msg="received accesspoint ping"
Sep 06 22:13:44 musical-fidelity-volumio go-librespot[8188]: time="2025-09-06T22:13:44+01:00" level=trace msg="received accesspoint pong ack"
Sep 06 22:13:52 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Sep 06 22:13:52 musical-fidelity-volumio volumio[2636]: info: CURURI: music-library
Sep 06 22:13:52 musical-fidelity-volumio volumio[2636]: error: Failed LSINFO: null
Sep 06 22:13:52 musical-fidelity-volumio volumio[2636]: info: Preload queue cleared
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: Discovery: Getting this device information
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::volumioGetState
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: CorePlayQueue::getTrack 3
Sep 06 22:13:54 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 06 22:13:57 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 06 22:13:57 musical-fidelity-volumio volumio[2636]: info: Preload queue cleared
Sep 06 22:13:58 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 06 22:13:58 musical-fidelity-volumio volumio[2636]: info: Preload queue cleared
Sep 06 22:14:00 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 06 22:14:00 musical-fidelity-volumio volumio[2636]: info: Preload queue cleared
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: TypeError: Cannot read property 'length' of undefined
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at Parser.emit (events.js:400:28)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at IncomingMessage.emit (events.js:412:35)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at endReadableNT (internal/streams/readable.js:1333:12)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: at processTicksAndRejections (internal/process/task_queues.js:82:21)
Sep 06 22:14:01 musical-fidelity-volumio volumio[2636]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 06 22:14:02 musical-fidelity-volumio sudo[18656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-06 22:13
Sep 06 22:14:02 musical-fidelity-volumio sudo[18656]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST"
VOLUMIO_VERSION="3.832"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"