-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2025-05-13 18:26:29 CEST. -- May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::volumioNext May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::next May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::stop May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrackBlock May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 0 May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::serviceStop May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 0 May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::serviceStop May 13 18:25:00 volumio volumio[923]: info: Spotify Stop May 13 18:25:00 volumio volumio[923]: SPOTIFY: SPOTIFY STOP May 13 18:25:00 volumio volumio[923]: SPOTIFY: {"status":"pause","position":0,"title":"Fenêtre Sur Rue","artist":"Hugo TSR","album":"Fenêtre Sur Rue","albumart":"https://i.scdn.co/image/ab67616d0000b273b71a55d7c06d524ff66991c1","uri":"spotify:track:0So2lJMLSOqbpz6VEXXU4h","trackType":"spotify","codec":"ogg","seek":7749,"duration":234,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":86,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} May 13 18:25:00 volumio volumio[923]: info: Sending Spotify command to local API: /player/pause May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::play index undefined May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::startPlaybackTimer May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: info: [1747153500205] ControllerSpotify::clearAddPlayTrack May 13 18:25:00 volumio volumio[923]: info: Sending Spotify command with payload to local API: /player/play May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrackBlock May 13 18:25:00 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="resolved context of track" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=trace msg="emitting websocket event: will_play" May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","play_origin":"go-librespot"}} May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","play_origin":"go-librespot"}} May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="selected format OGG_VORBIS_320 (5b250bcc066513964f06f6f162e8ca976ff60c22)" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="requested aes key for file 5b250bcc066513964f06f6f162e8ca976ff60c22, gid: 3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1412" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="fetched first chunk of 20, total size is 10020420 bytes" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="created new output device" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=info msg="loaded track \"Là-haut\" (paused: false, position: 0ms, duration: 238720ms, prefetched: false)" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1150" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=trace msg="scheduling prefetch in 209s" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=trace msg="emitting websocket event: metadata" May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","name":"Là-haut","artist_names":["Hugo TSR"],"album_name":"Tant qu'on est là","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","position":0,"duration":238720,"release_date":"year:2017 month:9 day:22","track_number":10,"disc_number":1}} May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","name":"Là-haut","artist_names":["Hugo TSR"],"album_name":"Tant qu'on est là","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","position":0,"duration":238720,"release_date":"year:2017 month:9 day:22","track_number":10,"disc_number":1}} May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 13 18:25:00 volumio go-librespot[4951]: time="2025-05-13T18:25:00+02:00" level=trace msg="emitting websocket event: playing" May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","play_origin":"go-librespot"}} May 13 18:25:00 volumio volumio[923]: SPOTIFY: PUSH STATE SPOTIFY May 13 18:25:00 volumio volumio[923]: SPOTIFY: {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::servicePushState May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:00 volumio volumio[923]: verbose: CURRENT POSITION 1 May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::syncState stateService play May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 13 18:25:00 volumio volumio[923]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","play_origin":"go-librespot"}} May 13 18:25:00 volumio volumio[923]: SPOTIFY: PUSH STATE SPOTIFY May 13 18:25:00 volumio volumio[923]: SPOTIFY: {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::servicePushState May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:00 volumio volumio[923]: verbose: CURRENT POSITION 1 May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::syncState stateService play May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play May 13 18:25:00 volumio volumio[923]: info: Received an update from plugin. extracting info from payload May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:00 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:00 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:00 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:00 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:00 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:01 volumio go-librespot[4951]: time="2025-05-13T18:25:01+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:01 volumio go-librespot[4951]: time="2025-05-13T18:25:01+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:01 volumio volumio[923]: SPOTIFY: PUSH STATE SPOTIFY May 13 18:25:01 volumio volumio[923]: SPOTIFY: {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::servicePushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:01 volumio volumio[923]: verbose: CURRENT POSITION 1 May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::syncState stateService play May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play May 13 18:25:01 volumio volumio[923]: info: Received an update from plugin. extracting info from payload May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:01 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:01 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:01 volumio volumio[923]: SPOTIFY: PUSH STATE SPOTIFY May 13 18:25:01 volumio volumio[923]: SPOTIFY: {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::servicePushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Là-haut","artist":"Hugo TSR","album":"Tant qu'on est là","albumart":"https://i.scdn.co/image/ab67616d00001e028597441fd03488bf52cd6fcb","uri":"spotify:track:3vjnuagiopTRGWIBNaZJF0","trackType":"spotify","seek":0,"duration":238,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 13 18:25:01 volumio volumio[923]: verbose: CURRENT POSITION 1 May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::syncState stateService play May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play May 13 18:25:01 volumio volumio[923]: info: Received an update from plugin. extracting info from payload May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:01 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:01 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:01 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:01 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:01 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 13 18:25:10 volumio volumio[923]: verbose: New Socket.io Connection to 192.168.2.173 from 192.168.2.26 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 13 18:25:10 volumio volumio[923]: info: Received Get System Info May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 18:25:10 volumio volumio[923]: info: Discovery: Getting this device information May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetState May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetState May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetVisibleSources May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetState May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetQueue May 13 18:25:10 volumio volumio[923]: info: CoreStateMachine::getQueue May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getQueue May 13 18:25:10 volumio volumio[923]: info: Listing playlists May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 13 18:25:10 volumio volumio[923]: info: Received Get System Info May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 18:25:10 volumio volumio[923]: info: Discovery: Getting this device information May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetState May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::volumioGetState May 13 18:25:10 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:10 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 13 18:25:13 volumio go-librespot[4951]: time="2025-05-13T18:25:13+02:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:15 volumio go-librespot[4951]: time="2025-05-13T18:25:15+02:00" level=trace msg="sent dealer ping" May 13 18:25:15 volumio go-librespot[4951]: time="2025-05-13T18:25:15+02:00" level=trace msg="received dealer pong" May 13 18:25:20 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 13 18:25:26 volumio volumio[923]: info: VolumeController::SetAlsaVolume85 May 13 18:25:26 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:26 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 18:25:26 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:26 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 13 18:25:26 volumio volumio[923]: SPOTIFY: SPOTIFY VOLUME 86 May 13 18:25:26 volumio volumio[923]: SPOTIFY: VOLUMIO VOLUME 85 May 13 18:25:26 volumio volumio[923]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 18:25:27 volumio go-librespot[4951]: time="2025-05-13T18:25:27+02:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:27 volumio volumio[923]: info: VolumeController::SetAlsaVolume100 May 13 18:25:27 volumio volumio[923]: info: CoreStateMachine::pushState May 13 18:25:27 volumio volumio[923]: info: CorePlayQueue::getTrack 1 May 13 18:25:27 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 18:25:27 volumio volumio[923]: info: CoreCommandRouter::volumioPushState May 13 18:25:27 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 13 18:25:27 volumio volumio[923]: SPOTIFY: SPOTIFY VOLUME 86 May 13 18:25:27 volumio volumio[923]: SPOTIFY: VOLUMIO VOLUME 100 May 13 18:25:27 volumio volumio[923]: SPOTIFY: DELTA VOLUME ENOUGH: true May 13 18:25:27 volumio volumio[923]: info: Setting Spotify Volume from Volumio: 100 May 13 18:25:28 volumio volumio[923]: SPOTIFY: SETTING SPOTIFY VOLUME 100 May 13 18:25:28 volumio volumio[923]: info: Sending Spotify command with payload to local API: /player/volume May 13 18:25:28 volumio go-librespot[4951]: time="2025-05-13T18:25:28+02:00" level=debug msg="update volume to 65535/65535" May 13 18:25:29 volumio go-librespot[4951]: time="2025-05-13T18:25:29+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 13 18:25:29 volumio go-librespot[4951]: time="2025-05-13T18:25:29+02:00" level=trace msg="emitting websocket event: volume" May 13 18:25:29 volumio volumio[923]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 13 18:25:29 volumio volumio[923]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 13 18:25:29 volumio volumio[923]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 13 18:25:29 volumio volumio[923]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 13 18:25:36 volumio go-librespot[4951]: time="2025-05-13T18:25:36+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update May 13 18:25:36 volumio go-librespot[4951]: time="2025-05-13T18:25:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" May 13 18:25:45 volumio go-librespot[4951]: time="2025-05-13T18:25:45+02:00" level=trace msg="sent dealer ping" May 13 18:25:45 volumio go-librespot[4951]: time="2025-05-13T18:25:45+02:00" level=trace msg="received dealer pong" May 13 18:25:47 volumio go-librespot[4951]: time="2025-05-13T18:25:47+02:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:25:50 volumio go-librespot[4951]: time="2025-05-13T18:25:50+02:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:26:04 volumio go-librespot[4951]: time="2025-05-13T18:26:04+02:00" level=debug msg="fetched chunk 8/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:26:15 volumio go-librespot[4951]: time="2025-05-13T18:26:15+02:00" level=trace msg="sent dealer ping" May 13 18:26:15 volumio go-librespot[4951]: time="2025-05-13T18:26:15+02:00" level=trace msg="received dealer pong" May 13 18:26:15 volumio go-librespot[4951]: time="2025-05-13T18:26:15+02:00" level=debug msg="fetched chunk 9/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: info: Retrieving Cloud Streaming UI May 13 18:26:25 volumio volumio[923]: info: Getting Tidal Cloud Configuration May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: info: Getting Qobuz Cloud Configuration May 13 18:26:25 volumio volumio[923]: info: Asking plugin for UI Config May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: info: Getting Spotify Cloud Configuration May 13 18:26:25 volumio volumio[923]: info: Asking plugin for UI Config May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: info: Saving Spotify Acccount May 13 18:26:25 volumio volumio[923]: info: Got Tidal Cloud Configuration May 13 18:26:25 volumio volumio[923]: info: Got it May 13 18:26:25 volumio volumio[923]: info: Got it May 13 18:26:25 volumio volumio[923]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 18:26:25 volumio volumio[923]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::volumioGetBrowseSources May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::volumioGetBrowseSources May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::volumioGetBrowseSources May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 13 18:26:25 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 13 18:26:27 volumio go-librespot[4951]: time="2025-05-13T18:26:27+02:00" level=debug msg="fetched chunk 10/19, size: 524288" uri="spotify:track:3vjnuagiopTRGWIBNaZJF0" May 13 18:26:27 volumio volumio[923]: info: Disabling MyMusic plugin upnp May 13 18:26:27 volumio sudo[7263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service May 13 18:26:27 volumio sudo[7263]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 18:26:27 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... May 13 18:26:27 volumio volumio[923]: error: Upnp client error: Error: This socket has been ended by the other party May 13 18:26:29 volumio volumio[923]: info: Enabling MyMusic plugin upnp May 13 18:26:29 volumio volumio[923]: info: Enabling plugin upnp May 13 18:26:29 volumio volumio[923]: info: Loading plugin "upnp"... May 13 18:26:29 volumio volumio[923]: info: [1747153589214] Starting Upmpd Daemon May 13 18:26:29 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 18:26:29 volumio volumio[923]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 18:26:29 volumio volumio[923]: Error: listen EADDRINUSE: address already in use :::6599 May 13 18:26:29 volumio volumio[923]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) May 13 18:26:29 volumio volumio[923]: at listenInCluster (net.js:1366:12) May 13 18:26:29 volumio volumio[923]: at Server.listen (net.js:1452:7) May 13 18:26:29 volumio volumio[923]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) May 13 18:26:29 volumio volumio[923]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) May 13 18:26:29 volumio volumio[923]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) May 13 18:26:29 volumio volumio[923]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 18:26:29 volumio volumio[923]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { May 13 18:26:29 volumio volumio[923]: code: 'EADDRINUSE', May 13 18:26:29 volumio volumio[923]: errno: -98, May 13 18:26:29 volumio volumio[923]: syscall: 'listen', May 13 18:26:29 volumio volumio[923]: address: '::', May 13 18:26:29 volumio volumio[923]: port: 6599 May 13 18:26:29 volumio volumio[923]: } May 13 18:26:29 volumio volumio[923]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 18:26:29 volumio sudo[7274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 18:25 May 13 18:26:29 volumio sudo[7274]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"