Mar 26 17:24:00 werkstatt volumio[1392]: info: Getting Spotify volume Mar 26 17:24:00 werkstatt volumio[1392]: info: Spotify volume: 86 Mar 26 17:24:00 werkstatt volumio[1392]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 26 17:24:00 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:00 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:00 werkstatt volumio[1392]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 26 17:24:01 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 26 17:24:01 werkstatt volumio[1392]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 26 17:24:01 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 26 17:24:01 werkstatt volumio[1392]: info: Creating Spotify config file Mar 26 17:24:01 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 17:24:01 werkstatt volumio[1392]: info: Spotify config file written Mar 26 17:24:01 werkstatt sudo[5134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 26 17:24:01 werkstatt sudo[5134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:24:02 werkstatt systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 26 17:24:02 werkstatt systemd[1]: go-librespot-daemon.service: Killing process 5117 (go-librespot) with signal SIGKILL. Mar 26 17:24:02 werkstatt volumio[1392]: info: Connection to go-librespot Websocket closed Mar 26 17:24:02 werkstatt systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 26 17:24:02 werkstatt volumio[1392]: info: Connection to go-librespot Websocket closed Mar 26 17:24:02 werkstatt systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 26 17:24:02 werkstatt systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 26 17:24:02 werkstatt go-librespot[5136]: go-librespot daemon starting... Mar 26 17:24:02 werkstatt sudo[5134]: pam_unix(sudo:session): session closed for user root Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="running go-librespot 0.7.1" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="app state loaded" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="zeroconf server listening on port 40031" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="obtained new client token: AAAIDxRIoCAlADDaPqj6/v0Y4ud8/O9CL36bl4EyTo+mPT78M4QC52dBTVIXBMJ8vHDwKU1VIGx/dLuePOODDKswflr16UnKNGVNiWNV3EVyF9+wywFA6XDlx/R3t3/c0oi+LH8bN/ByHnyisj8wsVYG8xf6DNd1kA1eGTCsIEOi3WfwoB75YVOIRMhB2heOUjdNDVW1EZdsXsRjpwHZDHD8SXm6Z3LhRK3fEObJbrRv1oJzPp/PQw8=" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="completed keyexchange" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="completed challenge" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="authenticated AP" username="11******20" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=info msg="authenticated Login5" username="11******20" Mar 26 17:24:02 werkstatt go-librespot[5137]: time="2026-03-26T17:24:02+01:00" level=debug msg="initializing zeroconf session" username="11******20" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="dealer connection opened" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=trace msg="starting accesspoint recv loop" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=trace msg="starting dealer recv loop" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=trace msg="received accesspoint ping" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="received connection id: MWI2MWVmNDMtYTJj...MjVBREFFMDc5Qg==" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 26 17:24:03 werkstatt go-librespot[5137]: time="2026-03-26T17:24:03+01:00" level=trace msg="received accesspoint pong ack" Mar 26 17:24:03 werkstatt volumio[1392]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 26 17:24:03 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 26 17:24:03 werkstatt volumio[1392]: info: Creating Spotify config file Mar 26 17:24:03 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 17:24:03 werkstatt volumio[1392]: info: Spotify config file written Mar 26 17:24:03 werkstatt sudo[5147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 26 17:24:03 werkstatt sudo[5147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:24:04 werkstatt systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 26 17:24:04 werkstatt systemd[1]: go-librespot-daemon.service: Killing process 5145 (go-librespot) with signal SIGKILL. Mar 26 17:24:04 werkstatt systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 26 17:24:04 werkstatt systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 26 17:24:04 werkstatt systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 26 17:24:04 werkstatt go-librespot[5149]: go-librespot daemon starting... Mar 26 17:24:04 werkstatt sudo[5147]: pam_unix(sudo:session): session closed for user root Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="running go-librespot 0.7.1" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="app state loaded" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="zeroconf server listening on port 41757" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="obtained new client token: AABJmOeuGL3lw0zhUVifKTJAT/iNMzgDQZuKRH8+Bi9s4zCTDbH9G68L6q7Untbe4Pu9lg2hPcFyZqMD6+7UGuXDZhYf/XnNguD1R6pkAjMm+hWK01xNPxmFsnOuEhiyGlLCnMQlVPK7rggqQq3+I61X/ZrBe60fc0rOQvgMP7Y/U0+H18U8hKLeFyEM2WKbCcNJ5sf2BYEqTt/rAmUKBUkVWpiy/NZMek6Jd0lncRubV55P8Hrx35c=" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="completed keyexchange" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="completed challenge" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="authenticated AP" username="11******20" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=info msg="authenticated Login5" username="11******20" Mar 26 17:24:04 werkstatt go-librespot[5150]: time="2026-03-26T17:24:04+01:00" level=debug msg="initializing zeroconf session" username="11******20" Mar 26 17:24:05 werkstatt volumio[1392]: info: Initializing connection to go-librespot Websocket Mar 26 17:24:05 werkstatt volumio[1392]: info: Connection to go-librespot Websocket established Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="new websocket client" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="dealer connection opened" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=trace msg="starting accesspoint recv loop" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=trace msg="starting dealer recv loop" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=trace msg="received accesspoint ping" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="received connection id: MjE2ZmVmODEtY2Yw...QUIxQkM4NDc1NQ==" Mar 26 17:24:05 werkstatt volumio[1392]: info: go-librespot daemon successfully initialized Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=trace msg="received accesspoint pong ack" Mar 26 17:24:05 werkstatt go-librespot[5150]: time="2026-03-26T17:24:05+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 26 17:24:07 werkstatt volumio[1392]: info: go-librespot daemon successfully initialized Mar 26 17:24:07 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:07 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:08 werkstatt volumio[1392]: info: Getting Spotify volume Mar 26 17:24:08 werkstatt volumio[1392]: info: Spotify volume: 100 Mar 26 17:24:08 werkstatt volumio[1392]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 26 17:24:08 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:08 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:08 werkstatt volumio[1392]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 26 17:24:08 werkstatt volumio[1392]: SPOTIFY: SPOTIFY VOLUME 100 Mar 26 17:24:08 werkstatt volumio[1392]: SPOTIFY: VOLUMIO VOLUME 86 Mar 26 17:24:08 werkstatt volumio[1392]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 26 17:24:08 werkstatt volumio[1392]: info: Setting Spotify Volume from Volumio: 86 Mar 26 17:24:08 werkstatt volumio[1392]: info: Initializing connection to go-librespot Websocket Mar 26 17:24:08 werkstatt go-librespot[5150]: time="2026-03-26T17:24:08+01:00" level=debug msg="new websocket client" Mar 26 17:24:08 werkstatt volumio[1392]: info: Connection to go-librespot Websocket established Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetQueue Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreStateMachine::getQueue Mar 26 17:24:09 werkstatt volumio[1392]: info: CorePlayQueue::getQueue Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 17:24:09 werkstatt volumio[1392]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 26 17:24:09 werkstatt volumio[1392]: info: Received Get System Version Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 17:24:09 werkstatt volumio[1392]: info: Received Get System Info Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:24:09 werkstatt volumio[1392]: info: Discovery: Getting this device information Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:09 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:09 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:24:09 werkstatt volumio[1392]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Mar 26 17:24:09 werkstatt volumio[1392]: info: Sending Spotify command with payload to local API: /player/volume Mar 26 17:24:09 werkstatt go-librespot[5150]: time="2026-03-26T17:24:09+01:00" level=debug msg="update volume requested to 56360/65535" Mar 26 17:24:09 werkstatt go-librespot[5150]: time="2026-03-26T17:24:09+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 26 17:24:09 werkstatt go-librespot[5150]: time="2026-03-26T17:24:09+01:00" level=trace msg="emitting websocket event: volume" Mar 26 17:24:09 werkstatt volumio[1392]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Mar 26 17:24:09 werkstatt volumio[1392]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Mar 26 17:24:09 werkstatt volumio[1392]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Mar 26 17:24:09 werkstatt volumio[1392]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Mar 26 17:24:10 werkstatt volumio[1392]: info: Initializing connection to go-librespot Websocket Mar 26 17:24:10 werkstatt go-librespot[5150]: time="2026-03-26T17:24:10+01:00" level=debug msg="new websocket client" Mar 26 17:24:10 werkstatt volumio[1392]: info: Connection to go-librespot Websocket established Mar 26 17:24:11 werkstatt volumio[1392]: info: Getting Spotify volume Mar 26 17:24:11 werkstatt volumio[1392]: info: Spotify volume: 86 Mar 26 17:24:11 werkstatt volumio[1392]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 26 17:24:11 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:11 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:11 werkstatt volumio[1392]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 26 17:24:13 werkstatt volumio[1392]: info: Getting Spotify volume Mar 26 17:24:13 werkstatt volumio[1392]: info: Spotify volume: 86 Mar 26 17:24:13 werkstatt volumio[1392]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 26 17:24:13 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:13 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:13 werkstatt volumio[1392]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 26 17:24:13 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:24:13 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:24:15 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:24:16 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:24:24 werkstatt volumio[1392]: info: Starting Uninstall of plugin user_interface - touch_display Mar 26 17:24:32 werkstatt volumio[1392]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: getUIConfig - wizardStep=0, wizardComplete=false, migrationState=none (cache=none, stepCache=0) Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: getUIConfig - checkMigration=true Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: OTA drift section hidden=true (driftDetected=false, wizardComplete=false) Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Section 1 - default hidden, checkMigration=true, migrationState=none Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Checking for migration... Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Starting migration detection... Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: volumioconfig.txt content length: 814 Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Found 6 lines in volumioconfig.txt Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: userconfig.txt content length: 90 Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Found 0 lines in userconfig.txt: [] Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Migration detection complete - needed: true, lines: 6 Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Migration check result - needed=true, lines=6 Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Migration needed - showing migration section Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Migration display text: volumioconfig.txt: dtoverlay=vc4-kms-v3d | volumioconfig.txt: dtoverlay=vc4-kms-v3d | volumioconfig.txt: dtoverlay=vc4-kms-v3d | volumioconfig.txt: dtoverlay=vc4-kms-v3d | volumioconfig.txt: hdmi_force_hotplug=1 | volumioconfig.txt: display_auto_detect=1 Mar 26 17:24:32 werkstatt volumio[1392]: info: pi_screen_setup: Resolving uiconf with migration section visible Mar 26 17:24:35 werkstatt go-librespot[5150]: time="2026-03-26T17:24:35+01:00" level=trace msg="sent dealer ping" Mar 26 17:24:35 werkstatt go-librespot[5150]: time="2026-03-26T17:24:35+01:00" level=trace msg="received dealer pong" Mar 26 17:24:38 werkstatt systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Mar 26 17:24:38 werkstatt systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Mar 26 17:24:38 werkstatt systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Mar 26 17:24:38 werkstatt systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Mar 26 17:25:01 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:25:01 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:25:05 werkstatt go-librespot[5150]: time="2026-03-26T17:25:05+01:00" level=trace msg="sent dealer ping" Mar 26 17:25:05 werkstatt go-librespot[5150]: time="2026-03-26T17:25:05+01:00" level=trace msg="received dealer pong" Mar 26 17:25:05 werkstatt volumio[1392]: info: Enabling plugin touch_display Mar 26 17:25:05 werkstatt volumio[1392]: info: Loading plugin "touch_display"... Mar 26 17:25:06 werkstatt volumio[1392]: info: PLUGIN START: touch_display Mar 26 17:25:06 werkstatt volumio[1392]: info: Loading i18n strings for locale de Mar 26 17:25:06 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 17:25:06 werkstatt sudo[5268]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 26 17:25:06 werkstatt sudo[5268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt sudo[5268]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:06 werkstatt sudo[5271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 26 17:25:06 werkstatt sudo[5271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt sudo[5273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 26 17:25:06 werkstatt volumio[1392]: info: touch_display: Backlight interface detected. Mar 26 17:25:06 werkstatt sudo[5273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt sudo[5276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 26 17:25:06 werkstatt sudo[5276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt volumio[1392]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 26 17:25:06 werkstatt systemd[1]: Stopping getty@tty1.service - Getty on tty1... Mar 26 17:25:06 werkstatt systemd[1]: getty@tty1.service: Deactivated successfully. Mar 26 17:25:06 werkstatt systemd[1]: Stopped getty@tty1.service - Getty on tty1. Mar 26 17:25:06 werkstatt sudo[5281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Mar 26 17:25:06 werkstatt sudo[5281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt sudo[5281]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:06 werkstatt volumio[1392]: info: touch_display: Raspberry Pi Foundation touch screen detected. Mar 26 17:25:06 werkstatt sudo[5284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Mar 26 17:25:06 werkstatt volumio[1392]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 26 17:25:06 werkstatt sudo[5284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt sudo[5284]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:06 werkstatt sudo[5286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 26 17:25:06 werkstatt sudo[5286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:06 werkstatt volumio[1392]: info: touch_display: File permissions for backlight brightness control set. Mar 26 17:25:06 werkstatt sudo[5286]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:06 werkstatt volumio[1392]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 26 17:25:06 werkstatt systemd[1]: Reloading. Mar 26 17:25:07 werkstatt volumio[1392]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 26 17:25:07 werkstatt volumio[1392]: info: touch_display: About to detect HDMI ports... Mar 26 17:25:07 werkstatt volumio[1392]: info: touch_display: X server not ready, cannot detect HDMI ports yet. Mar 26 17:25:08 werkstatt 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. Mar 26 17:25:08 werkstatt 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. Mar 26 17:25:08 werkstatt sudo[5273]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:08 werkstatt volumio[1392]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 26 17:25:08 werkstatt systemd[1]: Reloading. Mar 26 17:25:09 werkstatt 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. Mar 26 17:25:09 werkstatt 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. Mar 26 17:25:09 werkstatt sudo[5276]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:09 werkstatt volumio[1392]: info: touch_display: systemctl daemon-reload succeeded. Mar 26 17:25:09 werkstatt sudo[5328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 26 17:25:09 werkstatt sudo[5328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:09 werkstatt sudo[5271]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:09 werkstatt volumio[1392]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 26 17:25:09 werkstatt sudo[5328]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:09 werkstatt volumio[1392]: error: touch_display: Failed to start volumio-kiosk.service: Error: Command failed: /usr/bin/sudo /bin/systemctl start volumio-kiosk.service Mar 26 17:25:09 werkstatt volumio[1392]: Failed to start volumio-kiosk.service: Unit volumio-kiosk.service not found. Mar 26 17:25:09 werkstatt volumio[1392]: info: Error: Error Mar 26 17:25:21 werkstatt volumio[1392]: info: CALLMETHOD: user_interface touch_display saveScreensaverConf [object Object] Mar 26 17:25:21 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: touch_display , saveScreensaverConf Mar 26 17:25:21 werkstatt volumio[1392]: info: CoreCommandRouter::volumioGetState Mar 26 17:25:21 werkstatt volumio[1392]: info: CorePlayQueue::getTrack 0 Mar 26 17:25:21 werkstatt volumio[1392]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/Xundefined' Mar 26 17:25:26 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:25:26 werkstatt volumio[1392]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:25:31 werkstatt volumio[1392]: info: Starting Uninstall of plugin user_interface - touch_display Mar 26 17:25:31 werkstatt volumio[1392]: info: Uninstalling plugin touch_display Mar 26 17:25:31 werkstatt sudo[5362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 26 17:25:31 werkstatt sudo[5362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:31 werkstatt sudo[5362]: pam_unix(sudo:session): session closed for user root Mar 26 17:25:31 werkstatt sudo[5364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Mar 26 17:25:31 werkstatt volumio[1392]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 26 17:25:31 werkstatt sudo[5364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:31 werkstatt volumio[1392]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 17:25:31 werkstatt sudo[5366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Mar 26 17:25:31 werkstatt sudo[5366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:31 werkstatt volumio[1392]: TypeError: Cannot read properties of undefined (reading 'split') Mar 26 17:25:31 werkstatt volumio[1392]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Mar 26 17:25:31 werkstatt volumio[1392]: at ChildProcess.exithandler (node:child_process:413:7) Mar 26 17:25:31 werkstatt volumio[1392]: at ChildProcess.emit (node:events:514:28) Mar 26 17:25:31 werkstatt volumio[1392]: at maybeClose (node:internal/child_process:1105:16) Mar 26 17:25:31 werkstatt volumio[1392]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) Mar 26 17:25:31 werkstatt volumio[1392]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 17:25:31 werkstatt sudo[5369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Mar 26 17:25:31 werkstatt sudo[5369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 17:25:31 werkstatt systemd[1]: Reloading. Mar 26 17:25:32 werkstatt sudo[5404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 17:24' Mar 26 17:25:32 werkstatt sudo[5404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"