-- Logs begin at Mon 2025-09-15 17:20:38 CEST, end at Mon 2025-09-15 17:28:36 CEST. -- Sep 15 17:27:08 volumio volumio[831]: info: CALLMETHOD: system_hardware music_services_shield saveConfig [object Object] Sep 15 17:27:08 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: music_services_shield , saveConfig Sep 15 17:27:08 volumio volumio[831]: error: Failed callmethod call: TypeError: Cannot read property 'value' of undefined Sep 15 17:27:09 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 17:27:09 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 15 17:27:12 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:12 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:27:12 volumio volumio[831]: info: Prefetching next song Sep 15 17:27:12 volumio volumio[831]: info: [1757950032856] ControllerSpotify::prefetch Sep 15 17:27:12 volumio volumio[831]: info: Sending Spotify command with payload to local API: /player/add_to_queue Sep 15 17:27:12 volumio go-librespot[1426]: time="2025-09-15T17:27:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 15 17:27:12 volumio go-librespot[1426]: time="2025-09-15T17:27:12+02:00" level=debug msg="prefetching next track" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="selected format OGG_VORBIS_320 (71d39cc6547ef6b478fd31bb4fbba5ab5ab69660)" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="requested aes key for file 71d39cc6547ef6b478fd31bb4fbba5ab5ab69660, gid: 3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=trace msg="found 3 cdn urls" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="fetched first chunk of 24, total size is 12451441 bytes" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=info msg="prefetched track \"Piosenka o nocy\" (duration: 283621ms)" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="fetched chunk 1/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="fetched chunk 2/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:13 volumio go-librespot[1426]: time="2025-09-15T17:27:13+02:00" level=debug msg="fetched chunk 3/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:14 volumio go-librespot[1426]: time="2025-09-15T17:27:14+02:00" level=trace msg="sent dealer ping" Sep 15 17:27:14 volumio go-librespot[1426]: time="2025-09-15T17:27:14+02:00" level=trace msg="received dealer pong" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=trace msg="emitting websocket event: not_playing" Sep 15 17:27:16 volumio volumio[831]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:1lTr4adaGer4iCRahcaGuk","play_origin":"go-librespot"}} Sep 15 17:27:16 volumio volumio[831]: error: Failed to decode event: not_playing Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=trace msg="emitting websocket event: will_play" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=info msg="loaded track \"Piosenka o nocy\" (paused: false, position: 0ms, duration: 283621ms, prefetched: true)" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:16 volumio volumio[831]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","play_origin":"go-librespot"}} Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=trace msg="scheduling prefetch in 254s" Sep 15 17:27:16 volumio go-librespot[1426]: time="2025-09-15T17:27:16+02:00" level=trace msg="emitting websocket event: metadata" Sep 15 17:27:16 volumio volumio[831]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","name":"Piosenka o nocy","artist_names":["Niesamowita Sprawa"],"album_name":"Zwykłe Piosenki","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f53ce7b19ea877d446be429a","position":0,"duration":283621,"release_date":"year:2024 month:3 day:14","track_number":1,"disc_number":1}} Sep 15 17:27:17 volumio go-librespot[1426]: time="2025-09-15T17:27:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 15 17:27:17 volumio go-librespot[1426]: time="2025-09-15T17:27:17+02:00" level=trace msg="emitting websocket event: playing" Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","resume":false,"play_origin":"go-librespot"}} Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: PUSH STATE SPOTIFY Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: {"status":"play","service":"spop","title":"Piosenka o nocy","artist":"Niesamowita Sprawa","album":"Zwykłe Piosenki","albumart":"https://i.scdn.co/image/ab67616d00001e02f53ce7b19ea877d446be429a","uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::servicePushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Piosenka o nocy","artist":"Niesamowita Sprawa","album":"Zwykłe Piosenki","albumart":"https://i.scdn.co/image/ab67616d00001e02f53ce7b19ea877d446be429a","uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 15 17:27:17 volumio volumio[831]: verbose: CURRENT POSITION 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::syncState stateService play Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::syncState currentStatus play Sep 15 17:27:17 volumio volumio[831]: info: Received an update from plugin. extracting info from payload Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::pushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::volumioPushState Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::pushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::volumioPushState Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: PUSH STATE SPOTIFY Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: {"status":"play","service":"spop","title":"Piosenka o nocy","artist":"Niesamowita Sprawa","album":"Zwykłe Piosenki","albumart":"https://i.scdn.co/image/ab67616d00001e02f53ce7b19ea877d446be429a","uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::servicePushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Piosenka o nocy","artist":"Niesamowita Sprawa","album":"Zwykłe Piosenki","albumart":"https://i.scdn.co/image/ab67616d00001e02f53ce7b19ea877d446be429a","uri":"spotify:track:3rQ5jb4KAsJ52GcJag8oQZ","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 15 17:27:17 volumio volumio[831]: verbose: CURRENT POSITION 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::syncState stateService play Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::syncState currentStatus play Sep 15 17:27:17 volumio volumio[831]: info: Received an update from plugin. extracting info from payload Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::pushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::volumioPushState Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::pushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 1 Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::volumioPushState Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::startPlaybackTimer Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:27:17 volumio volumio[831]: info: CoreStateMachine::pushState Sep 15 17:27:17 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 17:27:17 volumio volumio[831]: info: CoreCommandRouter::volumioPushState Sep 15 17:27:17 volumio volumio[831]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 17:27:21 volumio volumio[831]: info: Starting Uninstall of plugin system_hardware - music_services_shield Sep 15 17:27:21 volumio volumio[831]: info: Uninstalling plugin music_services_shield Sep 15 17:27:22 volumio volumio[831]: info: Disabling plugin music_services_shield Sep 15 17:27:22 volumio volumio[831]: info: Checking if uninstall.sh is present Sep 15 17:27:22 volumio sudo[2973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Sep 15 17:27:22 volumio volumio[831]: info: Executing uninstall.sh Sep 15 17:27:22 volumio sudo[2973]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:22 volumio sudo[2976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/removeservice.sh Sep 15 17:27:22 volumio sudo[2976]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:22 volumio systemd[1]: musicservicesshield.service: Succeeded. Sep 15 17:27:22 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Sep 15 17:27:22 volumio systemd[1]: Reloading. Sep 15 17:27:22 volumio sudo[2985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_hardware/music_services_shield/uninstall.sh Sep 15 17:27:22 volumio sudo[2985]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:22 volumio sudo[2994]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/removeservice.sh Sep 15 17:27:22 volumio sudo[2994]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:23 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Sep 15 17:27:24 volumio sudo[3029]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/cset shield -r Sep 15 17:27:24 volumio sudo[3029]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:24 volumio sudo[3029]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:24 volumio sudo[2973]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:24 volumio volumio[831]: info: succeeded Sep 15 17:27:24 volumio systemd[1]: Reloading. Sep 15 17:27:25 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Sep 15 17:27:26 volumio sudo[2976]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:26 volumio volumio[831]: info: succeeded Sep 15 17:27:26 volumio systemd[1]: Reloading. Sep 15 17:27:27 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Sep 15 17:27:27 volumio sudo[2994]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:27 volumio sudo[3068]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get remove -y cpuset Sep 15 17:27:27 volumio sudo[3068]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:29 volumio go-librespot[1426]: time="2025-09-15T17:27:29+02:00" level=debug msg="fetched chunk 4/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:38 volumio sudo[3068]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:38 volumio sudo[2985]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:38 volumio volumio[831]: info: Uninstall script completed Sep 15 17:27:38 volumio volumio[831]: info: Removing plugin music_services_shield from configuration Sep 15 17:27:39 volumio volumio[831]: info: Successfully removed music_services_shield configuration files Sep 15 17:27:39 volumio volumio[831]: info: Plugin folders cleanup Sep 15 17:27:39 volumio volumio[831]: info: Scanning into folder /volumio/app/plugins/ Sep 15 17:27:39 volumio volumio[831]: info: Scanning category audio_interface Sep 15 17:27:39 volumio volumio[831]: info: Scanning category miscellanea Sep 15 17:27:39 volumio volumio[831]: info: Scanning category music_service Sep 15 17:27:39 volumio volumio[831]: info: Scanning category plugins.json Sep 15 17:27:39 volumio volumio[831]: info: Scanning category system_controller Sep 15 17:27:39 volumio volumio[831]: info: Scanning category user_interface Sep 15 17:27:39 volumio volumio[831]: info: Scanning into folder /data/plugins/ Sep 15 17:27:39 volumio volumio[831]: info: Scanning category music_service Sep 15 17:27:39 volumio volumio[831]: info: Scanning category system_hardware Sep 15 17:27:39 volumio volumio[831]: info: Cleaning folder for music_services_shield Sep 15 17:27:39 volumio volumio[831]: info: Scanning category user_interface Sep 15 17:27:39 volumio volumio[831]: info: Plugin folders cleanup completed Sep 15 17:27:39 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 17:27:39 volumio volumio[831]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.2.2","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"0.7.5","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true}] Sep 15 17:27:39 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 15 17:27:41 volumio go-librespot[1426]: time="2025-09-15T17:27:41+02:00" level=debug msg="fetched chunk 5/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:43 volumio go-librespot[1426]: time="2025-09-15T17:27:43+02:00" level=trace msg="received accesspoint ping" Sep 15 17:27:43 volumio go-librespot[1426]: time="2025-09-15T17:27:43+02:00" level=trace msg="received accesspoint pong ack" Sep 15 17:27:44 volumio go-librespot[1426]: time="2025-09-15T17:27:44+02:00" level=trace msg="sent dealer ping" Sep 15 17:27:44 volumio go-librespot[1426]: time="2025-09-15T17:27:44+02:00" level=trace msg="received dealer pong" Sep 15 17:27:53 volumio go-librespot[1426]: time="2025-09-15T17:27:53+02:00" level=debug msg="fetched chunk 6/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:27:56 volumio sudo[3206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i s/localhost:4004/localhost:3000/g /opt/volumiokiosk.sh Sep 15 17:27:56 volumio sudo[3206]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:56 volumio sudo[3206]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:56 volumio volumio[831]: [sudo] password for volumio: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl status volumio-kiosk Sep 15 17:27:56 volumio sudo[3209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status volumio-kiosk Sep 15 17:27:56 volumio sudo[3209]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:56 volumio sudo[3209]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:56 volumio volumio[831]: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl restart volumio-kiosk Sep 15 17:27:56 volumio sudo[3212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk Sep 15 17:27:56 volumio sudo[3212]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:27:57 volumio systemd[1]: Stopping Start Volumio Kiosk... Sep 15 17:27:57 volumio startx[833]: xinit: connection to X server lost Sep 15 17:27:57 volumio startx[833]: [1B blob data] Sep 15 17:27:57 volumio startx[833]: waiting for X server to shut down (II) Server terminated successfully (0). Closing log file. Sep 15 17:27:58 volumio startx[833]: xinit: unexpected signal 15 Sep 15 17:27:58 volumio systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Sep 15 17:27:58 volumio systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Sep 15 17:27:58 volumio systemd[1]: Stopped Start Volumio Kiosk. Sep 15 17:27:58 volumio systemd[1]: Started Start Volumio Kiosk. Sep 15 17:27:58 volumio sudo[3212]: pam_unix(sudo:session): session closed for user root Sep 15 17:27:58 volumio volumio[831]: warn: [now-playing] MyBackgroundMonitor stopped Sep 15 17:27:58 volumio volumio[831]: info: Disabling plugin now_playing Sep 15 17:27:58 volumio volumio[831]: info: Done. Sep 15 17:27:58 volumio startx[3220]: X.Org X Server 1.20.4 Sep 15 17:27:58 volumio startx[3220]: X Protocol Version 11, Revision 0 Sep 15 17:27:58 volumio startx[3220]: Build Operating System: Linux 5.10.0-10-amd64 x86_64 Debian Sep 15 17:27:58 volumio startx[3220]: Current Operating System: Linux volumio 6.6.32-volumio #2 SMP PREEMPT_DYNAMIC Wed May 29 23:04:42 CEST 2024 x86_64 Sep 15 17:27:58 volumio startx[3220]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=9d5aabb1-6695-4b37-89f7-df7a1cc2dabd bootpart=UUID=2F0B-D411 datapart=UUID=1008f151-d6e2-4e10-854a-a8c8e3462601 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no initrd=volumio.initrd Sep 15 17:27:58 volumio startx[3220]: Build Date: 18 December 2021 09:05:36AM Sep 15 17:27:58 volumio startx[3220]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Sep 15 17:27:58 volumio startx[3220]: Current version of pixman: 0.36.0 Sep 15 17:27:58 volumio startx[3220]: Before reporting problems, check http://wiki.x.org Sep 15 17:27:58 volumio startx[3220]: to make sure that you have the latest version. Sep 15 17:27:58 volumio startx[3220]: Markers: (--) probed, (**) from config file, (==) default setting, Sep 15 17:27:58 volumio startx[3220]: (++) from command line, (!!) notice, (II) informational, Sep 15 17:27:58 volumio startx[3220]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Sep 15 17:27:58 volumio startx[3220]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Sep 15 17:27:58 2025 Sep 15 17:27:58 volumio startx[3220]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Sep 15 17:27:58 volumio startx[3220]: (II) [KMS] Kernel modesetting enabled. Sep 15 17:27:59 volumio volumio[831]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ferrum_streaming_control_technology/volumio/buster/amd64 Sep 15 17:28:01 volumio volumio[831]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ferrum_streaming_control_technology/volumio/buster/amd64 Sep 15 17:28:01 volumio volumio[831]: info: Folder /tmp/plugins removed Sep 15 17:28:02 volumio volumio[831]: info: Check plugin dependencies Sep 15 17:28:02 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 17:28:02 volumio volumio[831]: info: Checking if plugin already exists Sep 15 17:28:02 volumio volumio[831]: info: Rename folder Sep 15 17:28:02 volumio volumio[831]: info: Folder /tmp/downloaded_plugin.zip removed Sep 15 17:28:02 volumio volumio[831]: info: Move to category Sep 15 17:28:02 volumio volumio[831]: info: Checking if install.sh is present Sep 15 17:28:02 volumio volumio[831]: info: Executing install.sh Sep 15 17:28:03 volumio sudo[3324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/user_interface/ferrum_streaming_control_technology/install.sh Sep 15 17:28:03 volumio sudo[3324]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 17:28:03 volumio sudo[3324]: pam_unix(sudo:session): session closed for user root Sep 15 17:28:03 volumio volumio[831]: info: Installing ferrum streaming control technology Dependencies Sep 15 17:28:03 volumio volumio[831]: info: Install script completed Sep 15 17:28:03 volumio volumio[831]: info: Adding reference to registry Sep 15 17:28:03 volumio volumio[831]: info: Done installing plugin. Sep 15 17:28:03 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 17:28:03 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 15 17:28:03 volumio volumio[831]: info: Folder /tmp/plugins removed Sep 15 17:28:03 volumio volumio[831]: info: Folder /tmp/downloaded_plugin.zip removed Sep 15 17:28:03 volumio volumio[831]: Plugin install end detected on script Sep 15 17:28:03 volumio volumio[831]: info: Folder /data/temp removed Sep 15 17:28:04 volumio go-librespot[1426]: time="2025-09-15T17:28:04+02:00" level=debug msg="fetched chunk 7/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:28:04 volumio volumio[831]: error: Failed to check for new versions for plugin Ferrum Streaming Control Technology: Error: Invalid argument not valid semver ('' received) Sep 15 17:28:04 volumio volumio[831]: info: Enabling plugin ferrum_streaming_control_technology Sep 15 17:28:04 volumio volumio[831]: info: Loading plugin "ferrum_streaming_control_technology"... Sep 15 17:28:05 volumio volumio[831]: error: !!!! WARNING !!!! Sep 15 17:28:05 volumio volumio[831]: error: The plugin user_interface/ferrum_streaming_control_technology failed to load, setting it to stopped. Error: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Sep 15 17:28:05 volumio volumio[831]: Require stack: Sep 15 17:28:05 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Sep 15 17:28:05 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/app/pluginmanager.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/app/index.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/index.js Sep 15 17:28:05 volumio volumio[831]: error: Stack trace: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Sep 15 17:28:05 volumio volumio[831]: Require stack: Sep 15 17:28:05 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Sep 15 17:28:05 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/app/pluginmanager.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/app/index.js Sep 15 17:28:05 volumio volumio[831]: - /volumio/index.js Sep 15 17:28:05 volumio volumio[831]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Sep 15 17:28:05 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Sep 15 17:28:05 volumio volumio[831]: at Module.require (internal/modules/cjs/loader.js:1003:19) Sep 15 17:28:05 volumio volumio[831]: at require (internal/modules/cjs/helpers.js:107:18) Sep 15 17:28:05 volumio volumio[831]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js:190:31) Sep 15 17:28:05 volumio volumio[831]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Sep 15 17:28:05 volumio volumio[831]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Sep 15 17:28:05 volumio volumio[831]: at Module.load (internal/modules/cjs/loader.js:979:32) Sep 15 17:28:05 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Sep 15 17:28:05 volumio volumio[831]: at Module.require (internal/modules/cjs/loader.js:1003:19) Sep 15 17:28:05 volumio volumio[831]: at require (internal/modules/cjs/helpers.js:107:18) Sep 15 17:28:05 volumio volumio[831]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/index.js:25:118) Sep 15 17:28:05 volumio volumio[831]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Sep 15 17:28:05 volumio volumio[831]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Sep 15 17:28:05 volumio volumio[831]: at Module.load (internal/modules/cjs/loader.js:979:32) Sep 15 17:28:05 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Sep 15 17:28:05 volumio volumio[831]: error: !!!! WARNING !!!! Sep 15 17:28:05 volumio volumio[831]: info: Done. Sep 15 17:28:12 volumio volumio[831]: info: Starting Uninstall of plugin user_interface - ferrum_streaming_control_technology Sep 15 17:28:12 volumio volumio[831]: info: Uninstalling plugin ferrum_streaming_control_technology Sep 15 17:28:14 volumio go-librespot[1426]: time="2025-09-15T17:28:14+02:00" level=trace msg="sent dealer ping" Sep 15 17:28:14 volumio go-librespot[1426]: time="2025-09-15T17:28:14+02:00" level=trace msg="received dealer pong" Sep 15 17:28:15 volumio go-librespot[1426]: time="2025-09-15T17:28:15+02:00" level=debug msg="fetched chunk 8/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:28:16 volumio volumio[831]: info: Enabling plugin ferrum_streaming_control_technology Sep 15 17:28:16 volumio volumio[831]: info: Loading plugin "ferrum_streaming_control_technology"... Sep 15 17:28:16 volumio volumio[831]: error: !!!! WARNING !!!! Sep 15 17:28:16 volumio volumio[831]: error: The plugin user_interface/ferrum_streaming_control_technology failed to load, setting it to stopped. Error: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Sep 15 17:28:16 volumio volumio[831]: Require stack: Sep 15 17:28:16 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Sep 15 17:28:16 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/app/pluginmanager.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/app/index.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/index.js Sep 15 17:28:16 volumio volumio[831]: error: Stack trace: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Sep 15 17:28:16 volumio volumio[831]: Require stack: Sep 15 17:28:16 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Sep 15 17:28:16 volumio volumio[831]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/app/pluginmanager.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/app/index.js Sep 15 17:28:16 volumio volumio[831]: - /volumio/index.js Sep 15 17:28:16 volumio volumio[831]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Sep 15 17:28:16 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Sep 15 17:28:16 volumio volumio[831]: at Module.require (internal/modules/cjs/loader.js:1003:19) Sep 15 17:28:16 volumio volumio[831]: at require (internal/modules/cjs/helpers.js:107:18) Sep 15 17:28:16 volumio volumio[831]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js:190:31) Sep 15 17:28:16 volumio volumio[831]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Sep 15 17:28:16 volumio volumio[831]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Sep 15 17:28:16 volumio volumio[831]: at Module.load (internal/modules/cjs/loader.js:979:32) Sep 15 17:28:16 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Sep 15 17:28:16 volumio volumio[831]: at Module.require (internal/modules/cjs/loader.js:1003:19) Sep 15 17:28:16 volumio volumio[831]: at require (internal/modules/cjs/helpers.js:107:18) Sep 15 17:28:16 volumio volumio[831]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/index.js:25:118) Sep 15 17:28:16 volumio volumio[831]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Sep 15 17:28:16 volumio volumio[831]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Sep 15 17:28:16 volumio volumio[831]: at Module.load (internal/modules/cjs/loader.js:979:32) Sep 15 17:28:16 volumio volumio[831]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Sep 15 17:28:16 volumio volumio[831]: error: !!!! WARNING !!!! Sep 15 17:28:16 volumio volumio[831]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Sep 15 17:28:18 volumio volumio[831]: info: Starting Uninstall of plugin user_interface - ferrum_streaming_control_technology Sep 15 17:28:18 volumio volumio[831]: info: Uninstalling plugin ferrum_streaming_control_technology Sep 15 17:28:18 volumio volumio[831]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Sep 15 17:28:21 volumio volumio[831]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Sep 15 17:28:23 volumio volumio[831]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::volumioGetState Sep 15 17:28:24 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 15 17:28:24 volumio volumio[831]: info: Listing playlists Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::volumioGetState Sep 15 17:28:24 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:28:24 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 15 17:28:24 volumio volumio[831]: info: Listing playlists Sep 15 17:28:26 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 17:28:26 volumio volumio[831]: info: Received Get System Info Sep 15 17:28:26 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 17:28:26 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 17:28:26 volumio volumio[831]: info: Discovery: Getting this device information Sep 15 17:28:26 volumio volumio[831]: info: CoreCommandRouter::volumioGetState Sep 15 17:28:26 volumio volumio[831]: info: CorePlayQueue::getTrack 2 Sep 15 17:28:26 volumio volumio[831]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 17:28:27 volumio go-librespot[1426]: time="2025-09-15T17:28:27+02:00" level=debug msg="fetched chunk 9/23, size: 524288" uri="spotify:track:3rQ5jb4KAsJ52GcJag8oQZ" Sep 15 17:28:29 volumio volumio[831]: info: Starting Uninstall of plugin user_interface - ferrum_streaming_control_technology Sep 15 17:28:29 volumio volumio[831]: info: Uninstalling plugin ferrum_streaming_control_technology Sep 15 17:28:35 volumio volumio[831]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/lastfm/volumio/buster/amd64 Sep 15 17:28:35 volumio volumio[831]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 17:28:35 volumio volumio[831]: TypeError: Cannot read property 'broadcastMessage' of null Sep 15 17:28:35 volumio volumio[831]: at /volumio/app/index.js:1534:32 Sep 15 17:28:35 volumio volumio[831]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Sep 15 17:28:35 volumio volumio[831]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Sep 15 17:28:35 volumio volumio[831]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Sep 15 17:28:35 volumio volumio[831]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Sep 15 17:28:35 volumio volumio[831]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Sep 15 17:28:35 volumio volumio[831]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1453:22) Sep 15 17:28:35 volumio volumio[831]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1209:47) Sep 15 17:28:35 volumio volumio[831]: at Socket.emit (events.js:400:28) Sep 15 17:28:35 volumio volumio[831]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Sep 15 17:28:35 volumio volumio[831]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 15 17:28:35 volumio volumio[831]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 17:28:36 volumio sudo[3654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-15 17:27 Sep 15 17:28:36 volumio sudo[3654]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"