Apr 13 22:54:00 studio volumio[1052]: info: Selecting previously unselected package libfftw3-bin.
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.143Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Preparing to unpack .../19-libfftw3-bin_3.3.10-1_amd64.deb ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.146Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Unpacking libfftw3-bin (3.3.10-1) ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.163Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Selecting previously unselected package libfftw3-dev:amd64.
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.370Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Preparing to unpack .../20-libfftw3-dev_3.3.10-1_amd64.deb ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.374Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Unpacking libfftw3-dev:amd64 (3.3.10-1) ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.397Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Selecting previously unselected package libjpeg62-turbo-dev:amd64.
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.931Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Preparing to unpack .../21-libjpeg62-turbo-dev_1%3a2.1.5-2_amd64.deb ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.934Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:00 studio volumio[1052]: info: Unpacking libjpeg62-turbo-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:00 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:00.955Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Selecting previously unselected package libjpeg-dev:amd64.
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.151Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Preparing to unpack .../22-libjpeg-dev_1%3a2.1.5-2_amd64.deb ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.155Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Unpacking libjpeg-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.172Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio go-librespot[4573]: time="2026-04-13T22:54:01-05:00" level=debug msg="fetched chunk 4/17, size: 524288" uri="spotify:track:65DbTqJKhbwqYbZ1Okr0rc"
Apr 13 22:54:01 studio volumio[1052]: info: Selecting previously unselected package libopusfile0:amd64.
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.305Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Preparing to unpack .../23-libopusfile0_0.12-4_amd64.deb ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.309Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Unpacking libopusfile0:amd64 (0.12-4) ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.326Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Selecting previously unselected package libportmidi0:amd64.
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.475Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Preparing to unpack .../24-libportmidi0_1%3a217-6.1_amd64.deb ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.479Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Unpacking libportmidi0:amd64 (1:217-6.1) ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.495Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Selecting previously unselected package zlib1g-dev:amd64.
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.627Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Preparing to unpack .../25-zlib1g-dev_1%3a1.2.13.dfsg-1_amd64.deb ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.631Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Unpacking zlib1g-dev:amd64 (1:1.2.13.dfsg-1) ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.646Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Selecting previously unselected package libpython3.11-dev:amd64.
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.822Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Preparing to unpack .../26-libpython3.11-dev_3.11.2-6+deb12u6_amd64.deb ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.826Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:01 studio volumio[1052]: info: Unpacking libpython3.11-dev:amd64 (3.11.2-6+deb12u6) ...
Apr 13 22:54:01 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:01.845Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Selecting previously unselected package libpython3-dev:amd64.
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.152Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Preparing to unpack .../27-libpython3-dev_3.11.2-1+b1_amd64.deb ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.157Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Unpacking libpython3-dev:amd64 (3.11.2-1+b1) ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.172Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioNext
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::next
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::stop
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::stPlaybackTimer
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::updateTrackBlock
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrackBlock
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 0
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 0
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::serviceStop
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 0
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::serviceStop
Apr 13 22:54:04 studio volumio[1052]: info: Spotify Stop
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: SPOTIFY STOP
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: {"status":"play","position":0,"title":"Choosin' Texas","artist":"Ella Langley","album":"Choosin' Texas","albumart":"https://i.scdn.co/image/ab67616d0000b27390958927fbba47a62c3e63f8","uri":"spotify:track:65DbTqJKhbwqYbZ1Okr0rc","trackType":"spotify","codec":"ogg","seek":0,"duration":232,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":41,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Apr 13 22:54:04 studio volumio[1052]: info: Sending Spotify command to local API: /player/pause
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.183Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_STOPPED positionMs=0 volume=41
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.183Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:65DbTqJKhbwqYbZ1Okr0rc title="Choosin' Texas"
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::play index undefined
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::startPlaybackTimer
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: [1776138844184] ControllerSpotify::clearAddPlayTrack
Apr 13 22:54:04 studio volumio[1052]: info: Sending Spotify command with payload to local API: /player/play
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::updateTrackBlock
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrackBlock
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="resolved context of track" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio volumio[1052]: info: Selecting previously unselected package libsdl2-image-2.0-0:amd64.
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.299Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Preparing to unpack .../28-libsdl2-image-2.0-0_2.6.3+dfsg-1_amd64.deb ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.302Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Unpacking libsdl2-image-2.0-0:amd64 (2.6.3+dfsg-1) ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.316Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="emitting websocket event: will_play"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","play_origin":"go-librespot"}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","play_origin":"go-librespot"}}
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="selected format OGG_VORBIS_320 (fdb63b43d232c9e12721ae146866b90a894c320e)" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="requested aes key for file fdb63b43d232c9e12721ae146866b90a894c320e, gid: 5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio volumio[1052]: info: Selecting previously unselected package libsdl2-mixer-2.0-0:amd64.
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.453Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Preparing to unpack .../29-libsdl2-mixer-2.0-0_2.6.2+dfsg-2_amd64.deb ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.457Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Unpacking libsdl2-mixer-2.0-0:amd64 (2.6.2+dfsg-2) ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.470Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio volumio[1052]: info: Selecting previously unselected package libsdl2-ttf-2.0-0:amd64.
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.622Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Preparing to unpack .../30-libsdl2-ttf-2.0-0_2.20.1+dfsg-2_amd64.deb ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.626Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Unpacking libsdl2-ttf-2.0-0:amd64 (2.20.1+dfsg-2) ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.643Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="fetched first chunk of 14, total size is 6944360 bytes" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=info msg="loaded track \"Rethink Some Things\" (paused: false, position: 0ms, duration: 165289ms, prefetched: false)" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="scheduling prefetch in 135s"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="emitting websocket event: metadata"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="pause track at 100ms"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","name":"Rethink Some Things","artist_names":["Luke Combs"],"album_name":"The Way I Am","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","position":0,"duration":165289,"release_date":"year:2026 month:3 day:20","track_number":10,"disc_number":1}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","name":"Rethink Some Things","artist_names":["Luke Combs"],"album_name":"The Way I Am","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","position":0,"duration":165289,"release_date":"year:2026 month:3 day:20","track_number":10,"disc_number":1}}
Apr 13 22:54:04 studio volumio[1052]: info: Selecting previously unselected package manpages-dev.
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.768Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Preparing to unpack .../31-manpages-dev_6.03-2_all.deb ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.772Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio volumio[1052]: info: Unpacking manpages-dev (6.03-2) ...
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.785Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="emitting websocket event: playing"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","resume":false,"play_origin":"go-librespot"}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","resume":false,"play_origin":"go-librespot"}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:04 studio volumio[1052]: info: Received an update from plugin. extracting info from payload
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.919Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=0 volume=41
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.919Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.919Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=0 volume=41
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.919Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:04 studio go-librespot[4573]: time="2026-04-13T22:54:04-05:00" level=trace msg="emitting websocket event: paused"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","play_origin":"go-librespot"}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.986Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=66 volume=41
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.986Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","play_origin":"go-librespot"}}
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:04 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:04 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:04 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:04 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:04 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.995Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=66 volume=41
Apr 13 22:54:04 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:04.995Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:04 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:05 studio go-librespot[4573]: time="2026-04-13T22:54:05-05:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:5LNgnMLXaoG9KRkL47KlZu"
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:05 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:05 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:05 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:05.216Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=316 volume=41
Apr 13 22:54:05 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:05.216Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d00001e02e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:05 studio volumio[1052]: verbose: CURRENT POSITION 1
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:05 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:05 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:05 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:05 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:05 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:05 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:05.220Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=316 volume=41
Apr 13 22:54:05 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:05.220Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:05 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:09 studio go-librespot[4573]: time="2026-04-13T22:54:09-05:00" level=trace msg="sent dealer ping"
Apr 13 22:54:09 studio go-librespot[4573]: time="2026-04-13T22:54:09-05:00" level=trace msg="received dealer pong"
Apr 13 22:54:13 studio volumio[1052]: info: Selecting previously unselected package python3.11-dev.
Apr 13 22:54:13 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:13.874Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:13 studio volumio[1052]: info: Preparing to unpack .../32-python3.11-dev_3.11.2-6+deb12u6_amd64.deb ...
Apr 13 22:54:13 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:13.879Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:13 studio volumio[1052]: info: Unpacking python3.11-dev (3.11.2-6+deb12u6) ...
Apr 13 22:54:13 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:13.895Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Selecting previously unselected package python3-dev.
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.003Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Preparing to unpack .../33-python3-dev_3.11.2-1+b1_amd64.deb ...
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.006Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Unpacking python3-dev (3.11.2-1+b1) ...
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.022Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Selecting previously unselected package python3-numpy.
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.146Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Preparing to unpack .../34-python3-numpy_1%3a1.24.2-1+deb12u1_amd64.deb ...
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.150Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/peppymeterbasic/volumio/bookworm/amd64
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.156Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:14 studio volumio[1052]: info: Unpacking python3-numpy (1:1.24.2-1+deb12u1) ...
Apr 13 22:54:14 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:14.177Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/peppymeterbasic/volumio/bookworm/amd64
Apr 13 22:54:15 studio volumio[1052]: info: Folder /tmp/plugins removed
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.276Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.332Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: Check plugin dependencies
Apr 13 22:54:15 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.341Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.342Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: Checking if plugin already exists
Apr 13 22:54:15 studio volumio[1052]: info: Rename folder
Apr 13 22:54:15 studio volumio[1052]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.350Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: Move to category
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.544Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: Checking if install.sh is present
Apr 13 22:54:15 studio volumio[1052]: info: Executing install.sh
Apr 13 22:54:15 studio sudo[5013]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/peppymeterbasic/install.sh
Apr 13 22:54:15 studio sudo[5013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:15 studio volumio[1052]: info: Installing peppyalsa plugin dependencies
Apr 13 22:54:15 studio volumio[1052]: info: Installing peppyalsa plugin dependencies
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.568Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.569Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio sudo[5017]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get update
Apr 13 22:54:15 studio sudo[5017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:15 studio volumio[1052]: info: Hit:1 http://deb.debian.org/debian bookworm InRelease
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.686Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:15 studio volumio[1052]: info: Hit:1 http://deb.debian.org/debian bookworm InRelease
Apr 13 22:54:15 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:15.686Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:16 studio volumio[1052]: info: Reading package lists...
Apr 13 22:54:16 studio volumio[1052]: info: Reading package lists...
Apr 13 22:54:16 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:16.923Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:16 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:16.923Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:16 studio sudo[5017]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:16 studio volumio[1052]: info: cloning peppymeter repo
Apr 13 22:54:16 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:16.939Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:16 studio volumio[1052]: info: cloning peppymeter repo
Apr 13 22:54:16 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:16.940Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio[1052]: info:
Apr 13 22:54:17 studio volumio[1052]: Selecting previously unselected package python3-pygame.
Apr 13 22:54:17 studio volumio[1052]: info:
Apr 13 22:54:17 studio volumio[1052]: Selecting previously unselected package python3-pygame.
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.255Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio[1052]: info: Preparing to unpack .../35-python3-pygame_2.1.2+dfsg-5+b1_amd64.deb ...
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.259Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.259Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio[1052]: info: Preparing to unpack .../35-python3-pygame_2.1.2+dfsg-5+b1_amd64.deb ...
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.263Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio[1052]: info: Unpacking python3-pygame (2.1.2+dfsg-5+b1) ...
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.323Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:17 studio volumio[1052]: info: Unpacking python3-pygame (2.1.2+dfsg-5+b1) ...
Apr 13 22:54:17 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:17.327Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up libsdl2-image-2.0-0:amd64 (2.6.3+dfsg-1) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.771Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up libsdl2-image-2.0-0:amd64 (2.6.3+dfsg-1) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.777Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up libabsl20220623:amd64 (20220623.1-1+deb12u2) ...
Apr 13 22:54:18 studio volumio[1052]: info: Setting up libabsl20220623:amd64 (20220623.1-1+deb12u2) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.830Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.832Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up manpages (6.03-2) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.885Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up manpages (6.03-2) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.888Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up fonts-freefont-ttf (20120503-10) ...
Apr 13 22:54:18 studio volumio[1052]: info: Setting up fonts-freefont-ttf (20120503-10) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.937Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.942Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio[1052]: info: Setting up linux-libc-dev:amd64 (6.1.159-1) ...
Apr 13 22:54:18 studio volumio[1052]: info: Setting up linux-libc-dev:amd64 (6.1.159-1) ...
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.995Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:18 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:18.995Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libfftw3-long3:amd64 (3.3.10-1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.045Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libfftw3-long3:amd64 (3.3.10-1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.050Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libtirpc-dev:amd64 (1.3.3+ds-1) ...
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libtirpc-dev:amd64 (1.3.3+ds-1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.101Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.102Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up rpcsvc-proto (1.4.3-1) ...
Apr 13 22:54:19 studio volumio[1052]: info: Setting up rpcsvc-proto (1.4.3-1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.153Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.155Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libfftw3-quad3:amd64 (3.3.10-1) ...
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libfftw3-quad3:amd64 (3.3.10-1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.203Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.204Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libportmidi0:amd64 (1:217-6.1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.254Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libportmidi0:amd64 (1:217-6.1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.257Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libgav1-1:amd64 (0.18.0-1+b1) ...
Apr 13 22:54:19 studio volumio[1052]: info: Setting up libgav1-1:amd64 (0.18.0-1+b1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.312Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.313Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio[1052]: info: Setting up python3-numpy (1:1.24.2-1+deb12u1) ...
Apr 13 22:54:19 studio volumio[1052]: info: Setting up python3-numpy (1:1.24.2-1+deb12u1) ...
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.359Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:19.363Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:19 studio sudo[5156]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chown -R volumio /data/plugins/user_interface/peppymeterbasic /data/INTERNAL/PeppyMeterBasic/Templates
Apr 13 22:54:19 studio sudo[5156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:19 studio sudo[5156]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:19 studio sudo[5159]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chgrp -R volumio /data/plugins/user_interface/peppymeterbasic /data/INTERNAL/PeppyMeterBasic/Templates
Apr 13 22:54:19 studio sudo[5159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:19 studio sudo[5159]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:19 studio sudo[5161]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get -yf install python3-pygame python3-pip python3-dev libjpeg-dev zlib1g-dev libfftw3-dev
Apr 13 22:54:19 studio sudo[5161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:19 studio sudo[5161]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:19 studio sudo[5166]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload
Apr 13 22:54:19 studio sudo[5166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:19 studio systemd[1]: Reloading.
Apr 13 22:54:20 studio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:20 studio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:20 studio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:20 studio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:20 studio sudo[5166]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:20 studio sudo[5186]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/peppymeterbasic/startpeppymeterbasic.sh
Apr 13 22:54:20 studio sudo[5186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:20 studio sudo[5186]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:20 studio sudo[5013]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:20 studio volumio[1052]: info: Install script completed
Apr 13 22:54:20 studio volumio[1052]: info: Adding reference to registry
Apr 13 22:54:20 studio volumio[1052]: info: Done installing plugin.
Apr 13 22:54:20 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 22:54:20 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 22:54:20 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:20.773Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:20 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:20.773Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:20 studio volumio[1052]: info: Folder /tmp/plugins removed
Apr 13 22:54:20 studio volumio[1052]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 13 22:54:20 studio volumio[1052]: info: Folder /data/temp removed
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libfftw3-double3:amd64 (3.3.10-1) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libfftw3-double3:amd64 (3.3.10-1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.308Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.311Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libnsl-dev:amd64 (1.3.0-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.358Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libnsl-dev:amd64 (1.3.0-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.361Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libcrypt-dev:amd64 (1:4.4.33-2) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libcrypt-dev:amd64 (1:4.4.33-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.418Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.419Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libsdl2-ttf-2.0-0:amd64 (2.20.1+dfsg-2) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libsdl2-ttf-2.0-0:amd64 (2.20.1+dfsg-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.473Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.474Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libc-dev-bin (2.36-9+deb12u13) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libc-dev-bin (2.36-9+deb12u13) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.527Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.528Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libyuv0:amd64 (0.0~git20230123.b2528b0-1) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libyuv0:amd64 (0.0~git20230123.b2528b0-1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.579Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.580Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libopusfile0:amd64 (0.12-4) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libopusfile0:amd64 (0.12-4) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.631Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.631Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up manpages-dev (6.03-2) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up manpages-dev (6.03-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.683Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.684Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libavif15:amd64 (0.11.1-1+deb12u1) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libavif15:amd64 (0.11.1-1+deb12u1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.736Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.737Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libfftw3-bin (3.3.10-1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.787Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libfftw3-bin (3.3.10-1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.791Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libsdl2-mixer-2.0-0:amd64 (2.6.2+dfsg-2) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libsdl2-mixer-2.0-0:amd64 (2.6.2+dfsg-2) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.841Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.842Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libgd3:amd64 (2.3.3-9) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up libgd3:amd64 (2.3.3-9) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.889Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.891Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio[1052]: info: Setting up python3-pygame (2.1.2+dfsg-5+b1) ...
Apr 13 22:54:21 studio volumio[1052]: info: Setting up python3-pygame (2.1.2+dfsg-5+b1) ...
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.949Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:21 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:21.951Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libc6-dev:amd64 (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.169Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libc6-dev:amd64 (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.171Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libfftw3-dev:amd64 (3.3.10-1) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libfftw3-dev:amd64 (3.3.10-1) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.224Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.226Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libc-devtools (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.273Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libc-devtools (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.280Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libexpat1-dev:amd64 (2.5.0-1+deb12u2) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libexpat1-dev:amd64 (2.5.0-1+deb12u2) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.335Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.335Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libjpeg62-turbo-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libjpeg62-turbo-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.389Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.390Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up zlib1g-dev:amd64 (1:1.2.13.dfsg-1) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up zlib1g-dev:amd64 (1:1.2.13.dfsg-1) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.444Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.447Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libjpeg-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libjpeg-dev:amd64 (1:2.1.5-2) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.492Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.493Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libpython3.11-dev:amd64 (3.11.2-6+deb12u6) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libpython3.11-dev:amd64 (3.11.2-6+deb12u6) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.551Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.552Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libpython3-dev:amd64 (3.11.2-1+b1) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up libpython3-dev:amd64 (3.11.2-1+b1) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.599Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.602Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up python3.11-dev (3.11.2-6+deb12u6) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.654Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up python3.11-dev (3.11.2-6+deb12u6) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.656Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Setting up python3-dev (3.11.2-1+b1) ...
Apr 13 22:54:22 studio volumio[1052]: info: Setting up python3-dev (3.11.2-1+b1) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.707Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.710Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio[1052]: info: Processing triggers for libc-bin (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio[1052]: info: Processing triggers for libc-bin (2.36-9+deb12u13) ...
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.758Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:22 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:22.759Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:23 studio volumio[1052]: info: Processing triggers for man-db (2.11.2-2) ...
Apr 13 22:54:23 studio volumio[1052]: info: Processing triggers for man-db (2.11.2-2) ...
Apr 13 22:54:23 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:23.083Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:23 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:23.084Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:23 studio volumio[1052]: info: Processing triggers for fontconfig (2.14.1-4) ...
Apr 13 22:54:23 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:23.549Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:23 studio volumio[1052]: info: Processing triggers for fontconfig (2.14.1-4) ...
Apr 13 22:54:23 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:23.551Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:23 studio sudo[4380]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:23 studio sudo[5234]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload
Apr 13 22:54:23 studio sudo[5234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:23 studio systemd[1]: Reloading.
Apr 13 22:54:24 studio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:24 studio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:24 studio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:24 studio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 13 22:54:24 studio sudo[5234]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:24 studio volumio[1052]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so
Apr 13 22:54:24 studio volumio[1052]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so.0
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.036Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.037Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio volumio[1052]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.039Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio volumio[1052]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so.0
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.043Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio sudo[5255]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/peppymeterbasic/startpeppymeterbasic.sh
Apr 13 22:54:24 studio sudo[5255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:24 studio sudo[5255]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:24 studio sudo[4230]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:24 studio volumio[1052]: Plugin install end detected on script
Apr 13 22:54:24 studio volumio[1052]: Plugin install end detected on script
Apr 13 22:54:24 studio volumio[1052]: info: Install script completed
Apr 13 22:54:24 studio volumio[1052]: info: Adding reference to registry
Apr 13 22:54:24 studio volumio[1052]: info: Done installing plugin.
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.412Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:24.413Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Apr 13 22:54:24 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 22:54:24 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 22:54:24 studio volumio[1052]: info: Folder /data/temp removed
Apr 13 22:54:24 studio volumio[1052]: info: Folder /tmp/plugins removed
Apr 13 22:54:24 studio volumio[1052]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 13 22:54:25 studio volumio[1052]: info: Enabling plugin peppymeterbasic
Apr 13 22:54:25 studio volumio[1052]: info: Loading plugin "peppymeterbasic"...
Apr 13 22:54:26 studio volumio[1052]: info: Preparing to generate the ALSA configuration file
Apr 13 22:54:26 studio volumio[1052]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Apr 13 22:54:26 studio volumio[1052]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 13 22:54:26 studio volumio[1052]: info: Reading ALSA contributions from plugins.
Apr 13 22:54:26 studio volumio[1052]: info: Asound.conf file written
Apr 13 22:54:26 studio sudo[5261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Apr 13 22:54:26 studio sudo[5261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5261]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: No state is present for card PCH
Apr 13 22:54:26 studio volumio[1052]: Found hardware: "HDA-Intel" "Realtek Generic" "HDA:10ec0269,1028047e,00100100 HDA:80862805,80860101,00100000" "0x1028" "0x047e"
Apr 13 22:54:26 studio volumio[1052]: Hardware is initialized using a generic method
Apr 13 22:54:26 studio volumio[1052]: No state is present for card PCH
Apr 13 22:54:26 studio volumio[1052]: info: Output device has changed, restarting MPD
Apr 13 22:54:26 studio volumio[1052]: info: Output device has changed, restarting Shairport Sync
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio sudo[5267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 13 22:54:26 studio sudo[5267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5267]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 13 22:54:26 studio sudo[5269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 13 22:54:26 studio volumio[1052]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio systemd[1]: Stopping mpd.service - Music Player Daemon...
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: setDeactiveState invoked
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:26 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:26 studio vtcs[3872]: [2026-04-13 22:54:26.103] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE
Apr 13 22:54:26 studio vtcs[3872]: [2026-04-13 22:54:26.104] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected
Apr 13 22:54:26 studio volumio[1052]: info: PLUGIN START: peppymeterbasic
Apr 13 22:54:26 studio systemd[1]: mpd.service: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 13 22:54:26 studio systemd[1]: mpd.socket: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 13 22:54:26 studio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 13 22:54:26 studio sudo[5279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Apr 13 22:54:26 studio sudo[5279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 13 22:54:26 studio volumio[1052]: info: Preparing to generate the ALSA configuration file
Apr 13 22:54:26 studio sudo[5283]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2
Apr 13 22:54:26 studio sudo[5283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: Done.
Apr 13 22:54:26 studio sudo[5286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Apr 13 22:54:26 studio sudo[5286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 13 22:54:26 studio sudo[5283]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service...
Apr 13 22:54:26 studio volumio[1052]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Apr 13 22:54:26 studio volumio[1052]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 13 22:54:26 studio volumio[1052]: info: Reading ALSA contributions from plugins.
Apr 13 22:54:26 studio systemd[1]: vtcs.service: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service.
Apr 13 22:54:26 studio volumio[1052]: info: snd_dummy loaded
Apr 13 22:54:26 studio volumio[1052]: info: MPD Permissions set
Apr 13 22:54:26 studio volumio[1052]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio sudo[5279]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Apr 13 22:54:26 studio sudo[5298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio (udev-worker)[5299]: controlC7: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 7' failed with exit code 99.
Apr 13 22:54:26 studio sudo[5286]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 13 22:54:26 studio sudo[5298]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio sudo[5292]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 13 22:54:26 studio sudo[5292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:26 studio sudo[5313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Apr 13 22:54:26 studio sudo[5292]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: Starting Shairport Sync
Apr 13 22:54:26 studio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Apr 13 22:54:26 studio qobuz-connect[3841]: 20260413 22:54:26.184 [3841.3841] INFO SampleApp: Stopping Local configuration server
Apr 13 22:54:26 studio volumio[1052]: info: Asound.conf file unchanged, so no further update is needed
Apr 13 22:54:26 studio volumio[1052]: info: Output device has changed, restarting MPD
Apr 13 22:54:26 studio volumio[1052]: info: Output device has changed, restarting Shairport Sync
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio sudo[5318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 13 22:54:26 studio sudo[5318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 13 22:54:26 studio sudo[5320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5320]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 13 22:54:26 studio sudo[5322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 13 22:54:26 studio volumio[1052]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: setDeactiveState invoked
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:26 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:26 studio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 13 22:54:26 studio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 13 22:54:26 studio systemd[1]: shairport-sync.service: Consumed 2.147s CPU time.
Apr 13 22:54:26 studio sudo[5334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Apr 13 22:54:26 studio sudo[5334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio sudo[5339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Apr 13 22:54:26 studio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 13 22:54:26 studio sudo[5339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5318]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio systemd[1]: mpd.service: Deactivated successfully.
Apr 13 22:54:26 studio sudo[5346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Apr 13 22:54:26 studio sudo[5346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: MPD Permissions set
Apr 13 22:54:26 studio volumio[1052]: info: Shairport-Sync Started
Apr 13 22:54:26 studio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio sudo[5334]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio systemd[1]: mpd.socket: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:54:26 studio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 13 22:54:26 studio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 13 22:54:26 studio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 13 22:54:26 studio sudo[5346]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:54:26 studio sudo[5373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Apr 13 22:54:26 studio sudo[5373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio volumio[1052]: info: Starting Shairport Sync
Apr 13 22:54:26 studio sudo[5339]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 13 22:54:26 studio sudo[5377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:26 studio sudo[5370]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 13 22:54:26 studio sudo[5370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 13 22:54:26 studio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 13 22:54:26 studio sudo[5370]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 13 22:54:26 studio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 13 22:54:26 studio sudo[5377]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: info: Shairport-Sync Started
Apr 13 22:54:26 studio qobuz-connect[3841]: 20260413 22:54:26.569 [3841.3841] INFO SampleApp: shat down connection on UNIX socket
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: setDeactiveState invoked
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:26 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:26 studio systemd[1]: qobuz-connect.service: Deactivated successfully.
Apr 13 22:54:26 studio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Apr 13 22:54:26 studio sudo[5373]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Apr 13 22:54:26 studio sudo[5313]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio volumio[1052]: info: Executing endpoint qc_getconfig
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.619 [5397.5397] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.620 [5397.5397] INFO VolumeManager: [0x55cb15777ba0]: Setting new playback volume: 75
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.620 [5397.5397] INFO VolumeManager: [0x55cb15777ba0]: Setting new mute state: 0
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.620 [5397.5397] INFO AudioStreamManager: [0x55cb15777700]: Setting new audio download buffer size: 1048576
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.620 [5397.5397] INFO QobuzConnect: [0x55cb15778bb0]: Client initialized!
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.620 [5397.5397] INFO SampleApp: Starting Avahi advertising, name: Studio, service name: _qobuz-connect._tcp
Apr 13 22:54:26 studio mpd[5381]: 2026-04-13T22:54:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Apr 13 22:54:26 studio volumio[1052]: info: QobuzConnect: QOBUZ Connect daemon connected
Apr 13 22:54:26 studio systemd[1]: Started mpd.service - Music Player Daemon.
Apr 13 22:54:26 studio sudo[5269]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio sudo[5322]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.626 [5397.5397] INFO LocalConfigManager: [0x55cb157771e0]: Starting Local Configuration server
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.626 [5397.5397] INFO SampleApp: Starting Local configuration server
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.626 [5397.5397] INFO SampleApp: Connected to UNIX socket client 0x55cb1574dbb0
Apr 13 22:54:26 studio volumio[1052]: error: updateQueue error: null
Apr 13 22:54:26 studio volumio[1052]: error: updateQueue error: null
Apr 13 22:54:26 studio qobuz-connect[5397]: 20260413 22:54:26.769 [5397.5397] INFO SampleApp: Playback volume changed: 75
Apr 13 22:54:26 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:26 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:28 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:28 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: TidalConnect service stoped!
Apr 13 22:54:29 studio volumio[1052]: info: TidalConnect service stoped!
Apr 13 22:54:29 studio volumio[1052]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Apr 13 22:54:29 studio volumio[1052]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect
Apr 13 22:54:29 studio sudo[5417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Apr 13 22:54:29 studio sudo[5417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:29 studio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Apr 13 22:54:29 studio sudo[5417]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:29 studio volumio[1052]: info: Executing endpoint tc_getconfig
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Apr 13 22:54:29 studio vtcs[5420]: STARTING TidalConnect services, version: 1.6.1
Apr 13 22:54:29 studio volumio[1052]: info: TidalConnect service stoped!
Apr 13 22:54:29 studio vtcs[5420]: STARTED TidalConnect services.
Apr 13 22:54:29 studio volumio[1052]: info: Executing endpoint tc_connect
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Apr 13 22:54:29 studio volumio[1052]: info: Connecting to TidalConnect
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:29 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:29 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:29 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:29 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:29 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:29 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:29 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:29 studio volumio[1052]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect
Apr 13 22:54:29 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:29.270Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=24274 volume=41
Apr 13 22:54:29 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:29.270Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=24274 volume=41
Apr 13 22:54:29 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:29.270Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:29 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:29.270Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:29 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:29 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:29 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:29 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:29 studio sudo[5437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:29 studio sudo[5437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:29 studio sudo[5439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:29 studio sudo[5439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:29 studio volumio[1052]: info: TidalConnect service stoped!
Apr 13 22:54:29 studio volumio[1052]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Apr 13 22:54:29 studio volumio[1052]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect
Apr 13 22:54:29 studio sudo[5452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Apr 13 22:54:29 studio sudo[5452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:29 studio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:54:29 studio sudo[5439]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:29 studio sudo[5437]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:29 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:29 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:29 studio sudo[5452]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:29 studio volumio[5455]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:29 studio volumio[5455]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:29 studio volumio[5455]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:30 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:30 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:30 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:30 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:30 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:30 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:32 studio volumio[1052]: info: TidalConnect service started!
Apr 13 22:54:32 studio volumio[1052]: info: TidalConnect service started!
Apr 13 22:54:32 studio volumio[1052]: info: CoreCommandRouter::volumioNext
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::next
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::stop
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::stPlaybackTimer
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::updateTrackBlock
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrackBlock
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:32 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:32 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:32 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:32 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:32 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::serviceStop
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrack 1
Apr 13 22:54:32 studio volumio[1052]: info: CoreCommandRouter::serviceStop
Apr 13 22:54:32 studio volumio[1052]: info: Spotify Stop
Apr 13 22:54:32 studio volumio[1052]: SPOTIFY: SPOTIFY STOP
Apr 13 22:54:32 studio volumio[1052]: SPOTIFY: {"status":"play","position":1,"title":"Rethink Some Things","artist":"Luke Combs","album":"The Way I Am","albumart":"https://i.scdn.co/image/ab67616d0000b273e07986c3e184a30283b94d61","uri":"spotify:track:5LNgnMLXaoG9KRkL47KlZu","trackType":"spotify","codec":"ogg","seek":24274,"duration":165,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":41,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Apr 13 22:54:32 studio volumio[1052]: info: Sending Spotify command to local API: /player/pause
Apr 13 22:54:32 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:32.977Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_STOPPED positionMs=0 volume=41
Apr 13 22:54:32 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:32.977Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:5LNgnMLXaoG9KRkL47KlZu title="Rethink Some Things"
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::play index undefined
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::startPlaybackTimer
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:32 studio volumio[1052]: info: [1776138872979] ControllerSpotify::clearAddPlayTrack
Apr 13 22:54:32 studio volumio[1052]: info: Sending Spotify command with payload to local API: /player/play
Apr 13 22:54:32 studio volumio[1052]: info: CoreStateMachine::updateTrackBlock
Apr 13 22:54:32 studio volumio[1052]: info: CorePlayQueue::getTrackBlock
Apr 13 22:54:32 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:32 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status stop
Apr 13 22:54:32 studio go-librespot[4573]: time="2026-04-13T22:54:32-05:00" level=debug msg="pause track at 547ms"
Apr 13 22:54:32 studio sudo[5471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Apr 13 22:54:32 studio sudo[5471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:32 studio systemd[1]: Stopping peppymeterbasic.service - peppymeterbasic Daemon...
Apr 13 22:54:33 studio systemd[1]: peppymeterbasic.service: Deactivated successfully.
Apr 13 22:54:33 studio systemd[1]: Stopped peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:33 studio sudo[5471]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:33 studio volumio[1052]: info: peppymeterbasic Daemon Stop
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="resolved context of track" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="emitting websocket event: will_play"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","play_origin":"go-librespot"}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","play_origin":"go-librespot"}}
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="selected format OGG_VORBIS_320 (c7f7615da7a55c2eb59af2ff62b6500a995535a5)" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="requested aes key for file c7f7615da7a55c2eb59af2ff62b6500a995535a5, gid: 0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="fetched first chunk of 13, total size is 6782579 bytes" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=info msg="loaded track \"20 Cigarettes\" (paused: false, position: 1ms, duration: 160901ms, prefetched: false)" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="scheduling prefetch in 131s"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="emitting websocket event: metadata"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","name":"20 Cigarettes","artist_names":["Morgan Wallen"],"album_name":"I’m The Problem","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","position":1,"duration":160901,"release_date":"year:2025 month:5 day:16","track_number":11,"disc_number":1}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","name":"20 Cigarettes","artist_names":["Morgan Wallen"],"album_name":"I’m The Problem","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","position":1,"duration":160901,"release_date":"year:2025 month:5 day:16","track_number":11,"disc_number":1}}
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="emitting websocket event: paused"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","play_origin":"go-librespot"}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.692Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_STOPPED positionMs=666 volume=41
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.692Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","play_origin":"go-librespot"}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: {"status":"pause","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState stateService pause
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.698Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_STOPPED positionMs=666 volume=41
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.698Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:33 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status stop
Apr 13 22:54:33 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status stop
Apr 13 22:54:33 studio sudo[5488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Apr 13 22:54:33 studio sudo[5488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:33 studio sudo[5491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Apr 13 22:54:33 studio sudo[5491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:33 studio sudo[5488]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:33 studio volumio[1052]: info: peppymeterbasic Daemon Stop
Apr 13 22:54:33 studio sudo[5491]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:33 studio volumio[1052]: info: peppymeterbasic Daemon Stop
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=trace msg="emitting websocket event: playing"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","resume":false,"play_origin":"go-librespot"}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","resume":false,"play_origin":"go-librespot"}}
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:33 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:33 studio volumio[1052]: info: Received an update from plugin. extracting info from payload
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:33 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:33 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:33 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.771Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.771Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.772Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:33 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:33.772Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:33 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:33 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:33 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:33 studio sudo[5494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:33 studio sudo[5494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:33 studio sudo[5496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:33 studio sudo[5496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:33 studio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:54:33 studio sudo[5494]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:33 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:33 studio sudo[5496]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:33 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:33 studio go-librespot[4573]: time="2026-04-13T22:54:33-05:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:34 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:34 studio volumio[1052]: info: Received an update from plugin. extracting info from payload
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.071Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.071Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.071Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.071Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:34 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:34 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: PUSH STATE SPOTIFY
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::servicePushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"20 Cigarettes","artist":"Morgan Wallen","album":"I’m The Problem","albumart":"https://i.scdn.co/image/ab67616d00001e0235ea219ce47813b5e2dc3745","uri":"spotify:track:0YsIYFRoxkmEvbKCwTp0Tg","trackType":"spotify","seek":1,"duration":160,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 13 22:54:34 studio volumio[1052]: verbose: CURRENT POSITION 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::syncState stateService play
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::syncState currentStatus play
Apr 13 22:54:34 studio volumio[1052]: info: Received an update from plugin. extracting info from payload
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:34 studio sudo[5507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:34 studio sudo[5507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreStateMachine::pushState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioPushState
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device
Apr 13 22:54:34 studio volumio[1052]: info: MRS: Pushing multiroomSync output
Apr 13 22:54:34 studio sudo[5509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:34 studio sudo[5509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:34 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:34 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.086Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.086Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.086Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" state=STATUS_PLAYING positionMs=1 volume=41
Apr 13 22:54:34 studio volumio5-onboarding[1587]: time=2026-04-14T03:54:34.087Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:57026 @ 0xc00042e690" id=spotify:track:0YsIYFRoxkmEvbKCwTp0Tg title="20 Cigarettes"
Apr 13 22:54:34 studio sudo[5507]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:34 studio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41
Apr 13 22:54:34 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:34 studio sudo[5509]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:34 studio volumio[1052]: info: PeppyMeterBasic ---peppymeterbasic status play
Apr 13 22:54:34 studio sudo[5513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:34 studio sudo[5513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:34 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:34 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:34 studio sudo[5516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service
Apr 13 22:54:34 studio sudo[5516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:54:34 studio sudo[5513]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:34 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:34 studio sudo[5516]: pam_unix(sudo:session): session closed for user root
Apr 13 22:54:34 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:54:34 studio volumio[5501]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:34 studio volumio[5501]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:35 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:35 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:35 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:35 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:35 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:35 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:39 studio go-librespot[4573]: time="2026-04-13T22:54:39-05:00" level=trace msg="sent dealer ping"
Apr 13 22:54:39 studio go-librespot[4573]: time="2026-04-13T22:54:39-05:00" level=trace msg="received dealer pong"
Apr 13 22:54:42 studio volumio[1052]: info: CoreCommandRouter::volumioGetQueue
Apr 13 22:54:42 studio volumio[1052]: info: CoreStateMachine::getQueue
Apr 13 22:54:42 studio volumio[1052]: info: CorePlayQueue::getQueue
Apr 13 22:54:45 studio go-librespot[4573]: time="2026-04-13T22:54:45-05:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:54:46 studio volumio[1052]: info: CoreCommandRouter::volumioGetState
Apr 13 22:54:46 studio volumio[1052]: info: CorePlayQueue::getTrack 2
Apr 13 22:54:48 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 22:54:48 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 22:54:48 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:48 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:48 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:48 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:48 studio volumio[1052]: info: Executing endpoint metavolumio
Apr 13 22:54:48 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 13 22:54:51 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:54:54 studio volumio[5501]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:54 studio volumio[5501]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:54 studio volumio[5501]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:54:56 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy [object Object]
Apr 13 22:54:56 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy
Apr 13 22:54:56 studio volumio[1052]: aaaaaaaaaaa 1280,400
Apr 13 22:54:56 studio volumio[1052]: info: PeppyMeterBasic ---1280400
Apr 13 22:54:56 studio volumio[1052]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then')
Apr 13 22:54:56 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:54:56 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:54:56 studio go-librespot[4573]: time="2026-04-13T22:54:56-05:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:55:09 studio go-librespot[4573]: time="2026-04-13T22:55:09-05:00" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:55:09 studio go-librespot[4573]: time="2026-04-13T22:55:09-05:00" level=trace msg="sent dealer ping"
Apr 13 22:55:09 studio go-librespot[4573]: time="2026-04-13T22:55:09-05:00" level=trace msg="received dealer pong"
Apr 13 22:55:10 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy1 [object Object]
Apr 13 22:55:10 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy1
Apr 13 22:55:10 studio volumio[1052]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then')
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------metertube
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------$basefolder
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------screensize1280x400
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------screenwidth
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------screenheight
Apr 13 22:55:10 studio volumio[1052]: info: PeppyMeterBasic -----------------------metersize30
Apr 13 22:55:10 studio volumio[1052]: error: PeppyMeterBasic ---Error writing config null
Apr 13 22:55:10 studio sudo[5608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppymeterbasic.service
Apr 13 22:55:10 studio sudo[5608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:10 studio systemd[1]: Stopping peppymeterbasic.service - peppymeterbasic Daemon...
Apr 13 22:55:10 studio systemd[1]: peppymeterbasic.service: Deactivated successfully.
Apr 13 22:55:10 studio systemd[1]: Stopped peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:55:10 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:10 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:10 studio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:55:10 studio sudo[5608]: pam_unix(sudo:session): session closed for user root
Apr 13 22:55:10 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:55:10 studio volumio[5612]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:55:10 studio volumio[5612]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:55:10 studio volumio[5612]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:55:19 studio systemd[1]: peppymeterbasic.service: Deactivated successfully.
Apr 13 22:55:21 studio go-librespot[4573]: time="2026-04-13T22:55:21-05:00" level=debug msg="fetched chunk 7/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:55:22 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy1 [object Object]
Apr 13 22:55:22 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy1
Apr 13 22:55:22 studio volumio[1052]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then')
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------meterblack-white
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------$basefolder
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------screensize1280x400
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------screenwidth
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------screenheight
Apr 13 22:55:22 studio volumio[1052]: info: PeppyMeterBasic -----------------------metersize30
Apr 13 22:55:22 studio volumio[1052]: error: PeppyMeterBasic ---Error writing config null
Apr 13 22:55:22 studio sudo[5650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppymeterbasic.service
Apr 13 22:55:22 studio sudo[5650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:22 studio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon.
Apr 13 22:55:22 studio sudo[5650]: pam_unix(sudo:session): session closed for user root
Apr 13 22:55:22 studio volumio[1052]: info: peppymeterbasic Daemon Started
Apr 13 22:55:22 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:22 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:22 studio volumio[5654]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:55:22 studio volumio[5654]: libpng warning: iCCP: known incorrect sRGB profile
Apr 13 22:55:26 studio systemd[1]: peppymeterbasic.service: Deactivated successfully.
Apr 13 22:55:32 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic updatelist
Apr 13 22:55:32 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , updatelist
Apr 13 22:55:32 studio volumio[1052]: info: PeppyMeterBasic --- wget 'https://github.com/balbuze/Meter-peppymeter/raw/main/meterslist.txt'
Apr 13 22:55:33 studio volumio[1052]: --2026-04-13 22:55:32-- https://github.com/balbuze/Meter-peppymeter/raw/main/meterslist.txt
Apr 13 22:55:33 studio volumio[1052]: Resolving github.com (github.com)... 140.82.114.3
Apr 13 22:55:33 studio volumio[1052]: Connecting to github.com (github.com)|140.82.114.3|:443... connected.
Apr 13 22:55:33 studio volumio[1052]: HTTP request sent, awaiting response... 302 Found
Apr 13 22:55:33 studio volumio[1052]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/meterslist.txt [following]
Apr 13 22:55:33 studio volumio[1052]: --2026-04-13 22:55:33-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/meterslist.txt
Apr 13 22:55:33 studio volumio[1052]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.108.133, 185.199.109.133, 185.199.110.133, ...
Apr 13 22:55:33 studio volumio[1052]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.108.133|:443... connected.
Apr 13 22:55:33 studio volumio[1052]: HTTP request sent, awaiting response... 200 OK
Apr 13 22:55:33 studio volumio[1052]: Length: 362 [text/plain]
Apr 13 22:55:33 studio volumio[1052]: Saving to: ‘/data/plugins/user_interface/peppymeterbasic/meterslist.txt’
Apr 13 22:55:33 studio volumio[1052]: 0K 100% 48.9M=0s
Apr 13 22:55:33 studio volumio[1052]: 2026-04-13 22:55:33 (48.9 MB/s) - ‘/data/plugins/user_interface/peppymeterbasic/meterslist.txt’ saved [362/362]
Apr 13 22:55:33 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:33 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:34 studio go-librespot[4573]: time="2026-04-13T22:55:34-05:00" level=debug msg="fetched chunk 8/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:55:37 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object]
Apr 13 22:55:37 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter
Apr 13 22:55:38 studio volumio[1052]: --2026-04-13 22:55:37-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/1920x720-balbuze.zip
Apr 13 22:55:38 studio volumio[1052]: Resolving github.com (github.com)... 140.82.114.3
Apr 13 22:55:38 studio volumio[1052]: Connecting to github.com (github.com)|140.82.114.3|:443... connected.
Apr 13 22:55:38 studio volumio[1052]: HTTP request sent, awaiting response... 302 Found
Apr 13 22:55:38 studio volumio[1052]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x720-balbuze.zip [following]
Apr 13 22:55:38 studio volumio[1052]: --2026-04-13 22:55:37-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x720-balbuze.zip
Apr 13 22:55:38 studio volumio[1052]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.111.133, 185.199.110.133, 185.199.109.133, ...
Apr 13 22:55:38 studio volumio[1052]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.111.133|:443... connected.
Apr 13 22:55:38 studio volumio[1052]: HTTP request sent, awaiting response... 200 OK
Apr 13 22:55:38 studio volumio[1052]: Length: 4572047 (4.4M) [application/zip]
Apr 13 22:55:38 studio volumio[1052]: Saving to: ‘/tmp/1920x720-balbuze.zip’
Apr 13 22:55:38 studio volumio[1052]: 0K .......... .......... .......... .......... .......... 1% 3.25M 1s
Apr 13 22:55:38 studio volumio[1052]: 50K .......... .......... .......... .......... .......... 2% 7.15M 1s
Apr 13 22:55:38 studio volumio[1052]: 100K .......... .......... .......... .......... .......... 3% 5.34M 1s
Apr 13 22:55:38 studio volumio[1052]: 150K .......... .......... .......... .......... .......... 4% 5.71M 1s
Apr 13 22:55:38 studio volumio[1052]: 200K .......... .......... .......... .......... .......... 5% 1.17M 1s
Apr 13 22:55:38 studio volumio[1052]: 250K .......... .......... .......... .......... .......... 6% 327M 1s
Apr 13 22:55:38 studio volumio[1052]: 300K .......... .......... .......... .......... .......... 7% 308M 1s
Apr 13 22:55:38 studio volumio[1052]: 350K .......... .......... .......... .......... .......... 8% 281M 1s
Apr 13 22:55:38 studio volumio[1052]: 400K .......... .......... .......... .......... .......... 10% 11.9M 1s
Apr 13 22:55:38 studio volumio[1052]: 450K .......... .......... .......... .......... .......... 11% 5.90M 1s
Apr 13 22:55:38 studio volumio[1052]: 500K .......... .......... .......... .......... .......... 12% 5.56M 1s
Apr 13 22:55:38 studio volumio[1052]: 550K .......... .......... .......... .......... .......... 13% 5.80M 1s
Apr 13 22:55:38 studio volumio[1052]: 600K .......... .......... .......... .......... .......... 14% 4.06M 1s
Apr 13 22:55:38 studio volumio[1052]: 650K .......... .......... .......... .......... .......... 15% 5.79M 1s
Apr 13 22:55:38 studio volumio[1052]: 700K .......... .......... .......... .......... .......... 16% 5.76M 1s
Apr 13 22:55:38 studio volumio[1052]: 750K .......... .......... .......... .......... .......... 17% 5.53M 1s
Apr 13 22:55:38 studio volumio[1052]: 800K .......... .......... .......... .......... .......... 19% 5.52M 1s
Apr 13 22:55:38 studio volumio[1052]: 850K .......... .......... .......... .......... .......... 20% 5.82M 1s
Apr 13 22:55:38 studio volumio[1052]: 900K .......... .......... .......... .......... .......... 21% 5.70M 1s
Apr 13 22:55:38 studio volumio[1052]: 950K .......... .......... .......... .......... .......... 22% 5.73M 1s
Apr 13 22:55:38 studio volumio[1052]: 1000K .......... .......... .......... .......... .......... 23% 4.08M 1s
Apr 13 22:55:38 studio volumio[1052]: 1050K .......... .......... .......... .......... .......... 24% 5.79M 1s
Apr 13 22:55:38 studio volumio[1052]: 1100K .......... .......... .......... .......... .......... 25% 5.79M 1s
Apr 13 22:55:38 studio volumio[1052]: 1150K .......... .......... .......... .......... .......... 26% 5.67M 1s
Apr 13 22:55:38 studio volumio[1052]: 1200K .......... .......... .......... .......... .......... 27% 5.46M 1s
Apr 13 22:55:38 studio volumio[1052]: 1250K .......... .......... .......... .......... .......... 29% 5.76M 1s
Apr 13 22:55:38 studio volumio[1052]: 1300K .......... .......... .......... .......... .......... 30% 5.57M 1s
Apr 13 22:55:38 studio volumio[1052]: 1350K .......... .......... .......... .......... .......... 31% 5.56M 1s
Apr 13 22:55:38 studio volumio[1052]: 1400K .......... .......... .......... .......... .......... 32% 1.74M 1s
Apr 13 22:55:38 studio volumio[1052]: 1450K .......... .......... .......... .......... .......... 33% 138M 1s
Apr 13 22:55:38 studio volumio[1052]: 1500K .......... .......... .......... .......... .......... 34% 148M 1s
Apr 13 22:55:38 studio volumio[1052]: 1550K .......... .......... .......... .......... .......... 35% 5.96M 1s
Apr 13 22:55:38 studio volumio[1052]: 1600K .......... .......... .......... .......... .......... 36% 5.55M 1s
Apr 13 22:55:38 studio volumio[1052]: 1650K .......... .......... .......... .......... .......... 38% 5.42M 1s
Apr 13 22:55:38 studio volumio[1052]: 1700K .......... .......... .......... .......... .......... 39% 5.80M 0s
Apr 13 22:55:38 studio volumio[1052]: 1750K .......... .......... .......... .......... .......... 40% 5.54M 0s
Apr 13 22:55:38 studio volumio[1052]: 1800K .......... .......... .......... .......... .......... 41% 4.25M 0s
Apr 13 22:55:38 studio volumio[1052]: 1850K .......... .......... .......... .......... .......... 42% 5.79M 0s
Apr 13 22:55:38 studio volumio[1052]: 1900K .......... .......... .......... .......... .......... 43% 5.74M 0s
Apr 13 22:55:38 studio volumio[1052]: 1950K .......... .......... .......... .......... .......... 44% 5.69M 0s
Apr 13 22:55:38 studio volumio[1052]: 2000K .......... .......... .......... .......... .......... 45% 5.41M 0s
Apr 13 22:55:38 studio volumio[1052]: 2050K .......... .......... .......... .......... .......... 47% 5.75M 0s
Apr 13 22:55:38 studio volumio[1052]: 2100K .......... .......... .......... .......... .......... 48% 5.62M 0s
Apr 13 22:55:38 studio volumio[1052]: 2150K .......... .......... .......... .......... .......... 49% 5.59M 0s
Apr 13 22:55:38 studio volumio[1052]: 2200K .......... .......... .......... .......... .......... 50% 4.35M 0s
Apr 13 22:55:38 studio volumio[1052]: 2250K .......... .......... .......... .......... .......... 51% 5.55M 0s
Apr 13 22:55:38 studio volumio[1052]: 2300K .......... .......... .......... .......... .......... 52% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 2350K .......... .......... .......... .......... .......... 53% 5.26M 0s
Apr 13 22:55:38 studio volumio[1052]: 2400K .......... .......... .......... .......... .......... 54% 5.94M 0s
Apr 13 22:55:38 studio volumio[1052]: 2450K .......... .......... .......... .......... .......... 55% 5.56M 0s
Apr 13 22:55:38 studio volumio[1052]: 2500K .......... .......... .......... .......... .......... 57% 5.74M 0s
Apr 13 22:55:38 studio volumio[1052]: 2550K .......... .......... .......... .......... .......... 58% 5.59M 0s
Apr 13 22:55:38 studio volumio[1052]: 2600K .......... .......... .......... .......... .......... 59% 4.26M 0s
Apr 13 22:55:38 studio volumio[1052]: 2650K .......... .......... .......... .......... .......... 60% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 2700K .......... .......... .......... .......... .......... 61% 5.47M 0s
Apr 13 22:55:38 studio volumio[1052]: 2750K .......... .......... .......... .......... .......... 62% 5.56M 0s
Apr 13 22:55:38 studio volumio[1052]: 2800K .......... .......... .......... .......... .......... 63% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 2850K .......... .......... .......... .......... .......... 64% 5.76M 0s
Apr 13 22:55:38 studio volumio[1052]: 2900K .......... .......... .......... .......... .......... 66% 5.56M 0s
Apr 13 22:55:38 studio volumio[1052]: 2950K .......... .......... .......... .......... .......... 67% 5.55M 0s
Apr 13 22:55:38 studio volumio[1052]: 3000K .......... .......... .......... .......... .......... 68% 5.71M 0s
Apr 13 22:55:38 studio volumio[1052]: 3050K .......... .......... .......... .......... .......... 69% 4.10M 0s
Apr 13 22:55:38 studio volumio[1052]: 3100K .......... .......... .......... .......... .......... 70% 5.78M 0s
Apr 13 22:55:38 studio volumio[1052]: 3150K .......... .......... .......... .......... .......... 71% 5.56M 0s
Apr 13 22:55:38 studio volumio[1052]: 3200K .......... .......... .......... .......... .......... 72% 5.75M 0s
Apr 13 22:55:38 studio volumio[1052]: 3250K .......... .......... .......... .......... .......... 73% 5.74M 0s
Apr 13 22:55:38 studio volumio[1052]: 3300K .......... .......... .......... .......... .......... 75% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 3350K .......... .......... .......... .......... .......... 76% 5.60M 0s
Apr 13 22:55:38 studio volumio[1052]: 3400K .......... .......... .......... .......... .......... 77% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 3450K .......... .......... .......... .......... .......... 78% 4.18M 0s
Apr 13 22:55:38 studio volumio[1052]: 3500K .......... .......... .......... .......... .......... 79% 5.59M 0s
Apr 13 22:55:38 studio volumio[1052]: 3550K .......... .......... .......... .......... .......... 80% 5.53M 0s
Apr 13 22:55:38 studio volumio[1052]: 3600K .......... .......... .......... .......... .......... 81% 5.81M 0s
Apr 13 22:55:38 studio volumio[1052]: 3650K .......... .......... .......... .......... .......... 82% 5.72M 0s
Apr 13 22:55:38 studio volumio[1052]: 3700K .......... .......... .......... .......... .......... 83% 5.73M 0s
Apr 13 22:55:38 studio volumio[1052]: 3750K .......... .......... .......... .......... .......... 85% 5.56M 0s
Apr 13 22:55:38 studio volumio[1052]: 3800K .......... .......... .......... .......... .......... 86% 5.38M 0s
Apr 13 22:55:38 studio volumio[1052]: 3850K .......... .......... .......... .......... .......... 87% 4.40M 0s
Apr 13 22:55:38 studio volumio[1052]: 3900K .......... .......... .......... .......... .......... 88% 5.71M 0s
Apr 13 22:55:38 studio volumio[1052]: 3950K .......... .......... .......... .......... .......... 89% 5.45M 0s
Apr 13 22:55:38 studio volumio[1052]: 4000K .......... .......... .......... .......... .......... 90% 5.75M 0s
Apr 13 22:55:38 studio volumio[1052]: 4050K .......... .......... .......... .......... .......... 91% 5.66M 0s
Apr 13 22:55:38 studio volumio[1052]: 4100K .......... .......... .......... .......... .......... 92% 5.60M 0s
Apr 13 22:55:38 studio volumio[1052]: 4150K .......... .......... .......... .......... .......... 94% 5.59M 0s
Apr 13 22:55:38 studio volumio[1052]: 4200K .......... .......... .......... .......... .......... 95% 5.72M 0s
Apr 13 22:55:38 studio volumio[1052]: 4250K .......... .......... .......... .......... .......... 96% 4.28M 0s
Apr 13 22:55:38 studio volumio[1052]: 4300K .......... .......... .......... .......... .......... 97% 5.74M 0s
Apr 13 22:55:38 studio volumio[1052]: 4350K .......... .......... .......... .......... .......... 98% 5.54M 0s
Apr 13 22:55:38 studio volumio[1052]: 4400K .......... .......... .......... .......... .......... 99% 5.55M 0s
Apr 13 22:55:38 studio volumio[1052]: 4450K .......... .... 100% 16.4M=0.8s
Apr 13 22:55:38 studio volumio[1052]: 2026-04-13 22:55:38 (5.40 MB/s) - ‘/tmp/1920x720-balbuze.zip’ saved [4572047/4572047]
Apr 13 22:55:39 studio sudo[5719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:39 studio sudo[5719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:39 studio sudo[5719]: pam_unix(sudo:session): session closed for user root
Apr 13 22:55:39 studio volumio[1052]: info: PeppyMeterBasic ---message miniunzip -o /tmp/1920x720-balbuze.zip -d /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:39 studio go-librespot[4573]: time="2026-04-13T22:55:39-05:00" level=trace msg="received accesspoint ping"
Apr 13 22:55:39 studio go-librespot[4573]: time="2026-04-13T22:55:39-05:00" level=trace msg="received accesspoint pong ack"
Apr 13 22:55:39 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:39 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:39 studio go-librespot[4573]: time="2026-04-13T22:55:39-05:00" level=trace msg="sent dealer ping"
Apr 13 22:55:39 studio go-librespot[4573]: time="2026-04-13T22:55:39-05:00" level=trace msg="received dealer pong"
Apr 13 22:55:46 studio go-librespot[4573]: time="2026-04-13T22:55:46-05:00" level=debug msg="fetched chunk 9/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
Apr 13 22:55:46 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object]
Apr 13 22:55:46 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter
Apr 13 22:55:47 studio volumio[1052]: --2026-04-13 22:55:46-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/1920x1080-balbuze.zip
Apr 13 22:55:47 studio volumio[1052]: Resolving github.com (github.com)... 140.82.114.4
Apr 13 22:55:47 studio volumio[1052]: Connecting to github.com (github.com)|140.82.114.4|:443... connected.
Apr 13 22:55:47 studio volumio[1052]: HTTP request sent, awaiting response... 302 Found
Apr 13 22:55:47 studio volumio[1052]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x1080-balbuze.zip [following]
Apr 13 22:55:47 studio volumio[1052]: --2026-04-13 22:55:46-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x1080-balbuze.zip
Apr 13 22:55:47 studio volumio[1052]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.108.133, 185.199.111.133, 185.199.110.133, ...
Apr 13 22:55:47 studio volumio[1052]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.108.133|:443... connected.
Apr 13 22:55:47 studio volumio[1052]: HTTP request sent, awaiting response... 200 OK
Apr 13 22:55:47 studio volumio[1052]: Length: 663981 (648K) [application/zip]
Apr 13 22:55:47 studio volumio[1052]: Saving to: ‘/tmp/1920x1080-balbuze.zip’
Apr 13 22:55:47 studio volumio[1052]: 0K .......... .......... .......... .......... .......... 7% 3.61M 0s
Apr 13 22:55:47 studio volumio[1052]: 50K .......... .......... .......... .......... .......... 15% 5.74M 0s
Apr 13 22:55:47 studio volumio[1052]: 100K .......... .......... .......... .......... .......... 23% 5.78M 0s
Apr 13 22:55:47 studio volumio[1052]: 150K .......... .......... .......... .......... .......... 30% 1.93M 0s
Apr 13 22:55:47 studio volumio[1052]: 200K .......... .......... .......... .......... .......... 38% 13.9M 0s
Apr 13 22:55:47 studio volumio[1052]: 250K .......... .......... .......... .......... .......... 46% 9.69M 0s
Apr 13 22:55:47 studio volumio[1052]: 300K .......... .......... .......... .......... .......... 53% 8.09M 0s
Apr 13 22:55:47 studio volumio[1052]: 350K .......... .......... .......... .......... .......... 61% 14.4M 0s
Apr 13 22:55:47 studio volumio[1052]: 400K .......... .......... .......... .......... .......... 69% 4.18M 0s
Apr 13 22:55:47 studio volumio[1052]: 450K .......... .......... .......... .......... .......... 77% 5.71M 0s
Apr 13 22:55:47 studio volumio[1052]: 500K .......... .......... .......... .......... .......... 84% 5.76M 0s
Apr 13 22:55:47 studio volumio[1052]: 550K .......... .......... .......... .......... .......... 92% 5.58M 0s
Apr 13 22:55:47 studio volumio[1052]: 600K .......... .......... .......... .......... ........ 100% 6.53M=0.1s
Apr 13 22:55:47 studio volumio[1052]: 2026-04-13 22:55:47 (5.34 MB/s) - ‘/tmp/1920x1080-balbuze.zip’ saved [663981/663981]
Apr 13 22:55:47 studio sudo[5752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:47 studio sudo[5752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:47 studio sudo[5752]: pam_unix(sudo:session): session closed for user root
Apr 13 22:55:47 studio volumio[1052]: info: PeppyMeterBasic ---message miniunzip -o /tmp/1920x1080-balbuze.zip -d /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:47 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:47 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:54 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object]
Apr 13 22:55:54 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter
Apr 13 22:55:55 studio volumio[1052]: --2026-04-13 22:55:54-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/1920x1080-balbuze.zip
Apr 13 22:55:55 studio volumio[1052]: Resolving github.com (github.com)... 140.82.114.4
Apr 13 22:55:55 studio volumio[1052]: Connecting to github.com (github.com)|140.82.114.4|:443... connected.
Apr 13 22:55:55 studio volumio[1052]: HTTP request sent, awaiting response... 302 Found
Apr 13 22:55:55 studio volumio[1052]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x1080-balbuze.zip [following]
Apr 13 22:55:55 studio volumio[1052]: --2026-04-13 22:55:55-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1920x1080-balbuze.zip
Apr 13 22:55:55 studio volumio[1052]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.109.133, 185.199.108.133, 185.199.111.133, ...
Apr 13 22:55:55 studio volumio[1052]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.109.133|:443... connected.
Apr 13 22:55:55 studio volumio[1052]: HTTP request sent, awaiting response... 200 OK
Apr 13 22:55:55 studio volumio[1052]: Length: 663981 (648K) [application/zip]
Apr 13 22:55:55 studio volumio[1052]: Saving to: ‘/tmp/1920x1080-balbuze.zip’
Apr 13 22:55:55 studio volumio[1052]: 0K .......... .......... .......... .......... .......... 7% 3.98M 0s
Apr 13 22:55:55 studio volumio[1052]: 50K .......... .......... .......... .......... .......... 15% 5.65M 0s
Apr 13 22:55:55 studio volumio[1052]: 100K .......... .......... .......... .......... .......... 23% 5.69M 0s
Apr 13 22:55:55 studio volumio[1052]: 150K .......... .......... .......... .......... .......... 30% 2.03M 0s
Apr 13 22:55:55 studio volumio[1052]: 200K .......... .......... .......... .......... .......... 38% 10.2M 0s
Apr 13 22:55:55 studio volumio[1052]: 250K .......... .......... .......... .......... .......... 46% 10.8M 0s
Apr 13 22:55:55 studio volumio[1052]: 300K .......... .......... .......... .......... .......... 53% 9.17M 0s
Apr 13 22:55:55 studio volumio[1052]: 350K .......... .......... .......... .......... .......... 61% 11.3M 0s
Apr 13 22:55:55 studio volumio[1052]: 400K .......... .......... .......... .......... .......... 69% 4.07M 0s
Apr 13 22:55:55 studio volumio[1052]: 450K .......... .......... .......... .......... .......... 77% 5.76M 0s
Apr 13 22:55:55 studio volumio[1052]: 500K .......... .......... .......... .......... .......... 84% 5.61M 0s
Apr 13 22:55:55 studio volumio[1052]: 550K .......... .......... .......... .......... .......... 92% 6.28M 0s
Apr 13 22:55:55 studio volumio[1052]: 600K .......... .......... .......... .......... ........ 100% 5.86M=0.1s
Apr 13 22:55:55 studio volumio[1052]: 2026-04-13 22:55:55 (5.39 MB/s) - ‘/tmp/1920x1080-balbuze.zip’ saved [663981/663981]
Apr 13 22:55:55 studio sudo[5787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:55 studio sudo[5787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:55 studio sudo[5787]: pam_unix(sudo:session): session closed for user root
Apr 13 22:55:55 studio volumio[1052]: info: PeppyMeterBasic ---message miniunzip -o /tmp/1920x1080-balbuze.zip -d /data/INTERNAL/PeppyMeterBasic/Templates/
Apr 13 22:55:55 studio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 22:55:55 studio volumio[1052]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:55:56 studio volumio[1052]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object]
Apr 13 22:55:56 studio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter
Apr 13 22:55:57 studio volumio[1052]: --2026-04-13 22:55:56-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/Choose
Apr 13 22:55:57 studio volumio[1052]: Resolving github.com (github.com)... 140.82.114.4
Apr 13 22:55:57 studio volumio[1052]: Connecting to github.com (github.com)|140.82.114.4|:443... connected.
Apr 13 22:55:57 studio volumio[1052]: HTTP request sent, awaiting response... 404 Not Found
Apr 13 22:55:57 studio volumio[1052]: 2026-04-13 22:55:56 ERROR 404: Not Found.
Apr 13 22:55:57 studio volumio[1052]: --2026-04-13 22:55:56-- http://a/
Apr 13 22:55:57 studio volumio[1052]: Resolving a (a)... failed: Device or resource busy.
Apr 13 22:55:57 studio volumio[1052]: wget: unable to resolve host address ‘a’
Apr 13 22:55:57 studio volumio[1052]: --2026-04-13 22:55:56-- http://packet.zip/
Apr 13 22:55:57 studio volumio[1052]: Resolving packet.zip (packet.zip)... 162.255.119.167
Apr 13 22:55:57 studio volumio[1052]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected.
Apr 13 22:55:57 studio volumio[1052]: HTTP request sent, awaiting response... 302 Found
Apr 13 22:55:57 studio volumio[1052]: Location: http://www.packet.zip/ [following]
Apr 13 22:55:57 studio volumio[1052]: --2026-04-13 22:55:57-- http://www.packet.zip/
Apr 13 22:55:57 studio volumio[1052]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19
Apr 13 22:55:57 studio volumio[1052]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected.
Apr 13 22:55:57 studio volumio[1052]: HTTP request sent, awaiting response... 403 Forbidden
Apr 13 22:55:57 studio volumio[1052]: 2026-04-13 22:55:57 ERROR 403: Forbidden.
Apr 13 22:55:57 studio volumio[1052]: error: PeppyMeterBasic --- An error occurs while downloading or installing Meters
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove 'a': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove 'packet.zip*': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 22:55:57 studio volumio[1052]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip*
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove 'a': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: /bin/rm: cannot remove 'packet.zip*': No such file or directory
Apr 13 22:55:57 studio volumio[1052]: at checkExecSyncError (node:child_process:887:11)
Apr 13 22:55:57 studio volumio[1052]: at execSync (node:child_process:959:15)
Apr 13 22:55:57 studio volumio[1052]: at /data/plugins/user_interface/peppymeterbasic/index.js:710:19
Apr 13 22:55:57 studio volumio[1052]: at new Promise ()
Apr 13 22:55:57 studio volumio[1052]: at peppymeterbasic.dlmeter (/data/plugins/user_interface/peppymeterbasic/index.js:685:12)
Apr 13 22:55:57 studio volumio[1052]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32)
Apr 13 22:55:57 studio volumio[1052]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42)
Apr 13 22:55:57 studio volumio[1052]: at Socket.emit (node:events:514:28)
Apr 13 22:55:57 studio volumio[1052]: at /volumio/node_modules/socket.io/lib/socket.js:503:12
Apr 13 22:55:57 studio volumio[1052]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) {
Apr 13 22:55:57 studio volumio[1052]: status: 1,
Apr 13 22:55:57 studio volumio[1052]: signal: null,
Apr 13 22:55:57 studio volumio[1052]: output: [
Apr 13 22:55:57 studio volumio[1052]: null,
Apr 13 22:55:57 studio volumio[1052]: ,
Apr 13 22:55:57 studio volumio[1052]:
Apr 13 22:55:57 studio volumio[1052]: ],
Apr 13 22:55:57 studio volumio[1052]: pid: 5798,
Apr 13 22:55:57 studio volumio[1052]: stdout: ,
Apr 13 22:55:57 studio volumio[1052]: stderr:
Apr 13 22:55:57 studio volumio[1052]: }
Apr 13 22:55:57 studio volumio[1052]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 22:55:57 studio sudo[5814]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-13 22:54'
Apr 13 22:55:57 studio sudo[5814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:55:57 studio go-librespot[4573]: time="2026-04-13T22:55:57-05:00" level=debug msg="fetched chunk 10/12, size: 524288" uri="spotify:track:0YsIYFRoxkmEvbKCwTp0Tg"
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"