-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2025-03-08 12:51:27 CET. -- Mar 08 12:50:55 tirion systemd-timedated[1046]: Changed local time to Sat Mar 8 12:50:55 2025 Mar 08 12:50:55 tirion sudo[1044]: pam_unix(sudo:session): session closed for user root Mar 08 12:50:55 tirion volumio-time-update[598]: volumio-time-update-util: System time updated successfully. Mar 08 12:50:55 tirion systemd[1]: Starting Daily man-db regeneration... Mar 08 12:50:55 tirion systemd[1]: Starting Daily apt download activities... Mar 08 12:50:55 tirion systemd[1]: Started Volumio Time Update Utility. Mar 08 12:50:55 tirion systemd[1]: Reached target Multi-User System. Mar 08 12:50:55 tirion systemd[1]: Reached target Graphical Interface. Mar 08 12:50:55 tirion systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 08 12:50:55 tirion systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 08 12:50:55 tirion systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 08 12:50:55 tirion systemd[1]: man-db.service: Succeeded. Mar 08 12:50:55 tirion systemd[1]: Started Daily man-db regeneration. Mar 08 12:50:56 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:50:56 tirion volumio[1011]: info: ----- Volumio3 ---- Mar 08 12:50:56 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:50:56 tirion volumio[1011]: info: ----- System startup ---- Mar 08 12:50:56 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:50:56 tirion systemd[1]: systemd-fsckd.service: Succeeded. Mar 08 12:50:58 tirion sh[519]: timed out Mar 08 12:50:58 tirion dhcpcd[562]: timed out Mar 08 12:50:58 tirion sh[519]: dhcpcd exited Mar 08 12:50:58 tirion dhcpcd[562]: dhcpcd exited Mar 08 12:50:58 tirion sh[519]: ifup: failed to bring up eth0 Mar 08 12:50:58 tirion systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Mar 08 12:50:58 tirion systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Mar 08 12:50:58 tirion volumio[1011]: info: MYVOLUMIO Environment detected Mar 08 12:50:58 tirion volumio[1011]: info: Plugin folders cleanup Mar 08 12:50:58 tirion volumio[1011]: info: Scanning into folder /volumio/app/plugins/ Mar 08 12:50:58 tirion volumio[1011]: info: Scanning category audio_interface Mar 08 12:50:58 tirion volumio[1011]: info: Scanning category miscellanea Mar 08 12:50:58 tirion volumio[1011]: info: Scanning category music_service Mar 08 12:50:58 tirion volumio[1011]: info: Scanning category plugins.json Mar 08 12:50:59 tirion volumio[1011]: info: Scanning category system_controller Mar 08 12:50:59 tirion volumio[1011]: info: Scanning category user_interface Mar 08 12:50:59 tirion volumio[1011]: info: Scanning into folder /data/plugins/ Mar 08 12:50:59 tirion volumio[1011]: info: Scanning category music_service Mar 08 12:50:59 tirion volumio[1011]: info: Scanning category system_controller Mar 08 12:50:59 tirion volumio[1011]: info: Scanning category user_interface Mar 08 12:50:59 tirion volumio[1011]: info: Plugin folders cleanup completed Mar 08 12:50:59 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:50:59 tirion volumio[1011]: info: ----- Core plugins startup ---- Mar 08 12:50:59 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:50:59 tirion volumio[1011]: info: Loading plugins from folder /volumio/app/plugins/ Mar 08 12:50:59 tirion volumio[1011]: info: Adding plugin upnp to MyMusic Plugins Mar 08 12:50:59 tirion volumio[1011]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 08 12:50:59 tirion volumio[1011]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 08 12:50:59 tirion volumio[1011]: info: Loading plugins from folder /data/plugins/ Mar 08 12:50:59 tirion volumio[1011]: info: Loading plugin "system"... Mar 08 12:50:59 tirion volumio[1011]: info: Loading plugin "appearance"... Mar 08 12:51:00 tirion systemd[1]: apt-daily.service: Succeeded. Mar 08 12:51:00 tirion systemd[1]: Started Daily apt download activities. Mar 08 12:51:00 tirion systemd[1]: Starting Daily apt upgrade and clean activities... Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "network"... Mar 08 12:51:01 tirion volumio[1011]: info: Refreshing Cached IP Addresses Mar 08 12:51:01 tirion sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 08 12:51:01 tirion sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:01 tirion sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 08 12:51:01 tirion sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:01 tirion sudo[1140]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "services"... Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "alsa_controller"... Mar 08 12:51:01 tirion sudo[1142]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:01 tirion sudo[1150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 08 12:51:01 tirion sudo[1150]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:01 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "wizard"... Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "networkfs"... Mar 08 12:51:01 tirion sudo[1166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Elrond,password=regeis,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.26/Music/Music /mnt/NAS/Music Mar 08 12:51:01 tirion sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:01 tirion volumio[1011]: info: Starting Udev Watcher for removable devices Mar 08 12:51:01 tirion sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Elrond,password=regeis,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.26/Public/Shared Audiobooks /mnt/NAS/Audiobooks Mar 08 12:51:01 tirion sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:01 tirion volumio[1011]: info: Ignoring mount for partition: boot Mar 08 12:51:01 tirion volumio[1011]: info: Ignoring mount for partition: volumio Mar 08 12:51:01 tirion volumio[1011]: info: Ignoring mount for partition: volumio_data Mar 08 12:51:01 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "volumio_command_line_client"... Mar 08 12:51:01 tirion systemd[1]: systemd-hostnamed.service: Succeeded. Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "upnp"... Mar 08 12:51:01 tirion volumio[1011]: info: [1741434661492] Starting Upmpd Daemon Mar 08 12:51:01 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "my_music"... Mar 08 12:51:01 tirion volumio[1011]: info: Loading plugin "mpd"... Mar 08 12:51:01 tirion volumio-remote-updater[630]: [2025-03-08 12:51:01] [connect] Successful connection Mar 08 12:51:01 tirion kernel: Key type cifs.spnego registered Mar 08 12:51:01 tirion kernel: Key type cifs.idmap registered Mar 08 12:51:01 tirion kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Mar 08 12:51:01 tirion kernel: CIFS: Attempting to mount //192.168.178.26/Music/Music Mar 08 12:51:02 tirion sudo[1150]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:02 tirion kernel: cryptd: max_cpu_qlen set to 1000 Mar 08 12:51:02 tirion kernel: CIFS: Attempting to mount //192.168.178.26/Public/Shared Audiobooks Mar 08 12:51:02 tirion sudo[1166]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:02 tirion volumio[1011]: info: Loading plugin "upnp_browser"... Mar 08 12:51:02 tirion sudo[1168]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:03 tirion kernel: hwmon hwmon1: Undervoltage detected! Mar 08 12:51:03 tirion volumio[1011]: info: Loading plugin "alarm-clock"... Mar 08 12:51:03 tirion systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 08 12:51:03 tirion systemd[1]: Started Daily apt upgrade and clean activities. Mar 08 12:51:03 tirion systemd[1]: Startup finished in 14.475s (kernel) + 42.696s (userspace) = 57.172s. Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "airplay_emulation"... Mar 08 12:51:04 tirion volumio[1011]: info: Starting Shairport Sync Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "last_100"... Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "webradio"... Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "i2s_dacs"... Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "volumiodiscovery"... Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** For more information see Mar 08 12:51:04 tirion node[1011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 12:51:04 tirion volumio[1011]: *** WARNING *** For more information see Mar 08 12:51:04 tirion node[1011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 12:51:04 tirion node[1011]: *** WARNING *** For more information see Mar 08 12:51:04 tirion node[1011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 08 12:51:04 tirion node[1011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 12:51:04 tirion node[1011]: *** WARNING *** For more information see Mar 08 12:51:04 tirion volumio[1011]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 08 12:51:04 tirion volumio[1011]: info: Discovery: Started advertising with name: Tirion Mar 08 12:51:04 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 12:51:04 tirion volumio[1011]: info: Loading plugin "spop"... Mar 08 12:51:06 tirion volumio[1011]: info: Loading plugin "squeezelite_mc"... Mar 08 12:51:07 tirion kernel: hwmon hwmon1: Voltage normalised Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "outputs"... Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "albumart"... Mar 08 12:51:08 tirion volumio[1011]: info: Plugin example_plugin is not enabled Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "inputs"... Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "updater_comm"... Mar 08 12:51:08 tirion volumio[1011]: info: Plugin mpdemulation is not enabled Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "rest_api"... Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "websocket"... Mar 08 12:51:08 tirion volumio[1011]: info: Starting Socket.io Server version 2.3.0 Mar 08 12:51:08 tirion volumio[1011]: info: Loading plugin "audiophonicsonoff"... Mar 08 12:51:08 tirion volumio[1011]: Forking 3 albumart workers Mar 08 12:51:09 tirion volumio[1011]: info: Applying required configuration parameters for plugin audiophonicsonoff Mar 08 12:51:09 tirion volumio[1011]: info: Audiophonics on/off initiated Mar 08 12:51:09 tirion volumio[1011]: info: Loading plugin "touch_display"... Mar 08 12:51:09 tirion volumio[1011]: Starting albumart workers Mar 08 12:51:09 tirion volumio[1011]: info: Applying required configuration parameters for plugin touch_display Mar 08 12:51:09 tirion volumio[1011]: Starting albumart workers Mar 08 12:51:09 tirion volumio[1011]: Starting albumart workers Mar 08 12:51:10 tirion volumio[1011]: info: Loading i18n strings for locale de Mar 08 12:51:10 tirion volumio[1011]: Updating browse sources language Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::initPlayerControls Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 12:51:10 tirion volumio[1011]: Express server listening on port 3000 Mar 08 12:51:10 tirion volumio[1011]: [Metrics] WebUI: 15s 880.75ms Mar 08 12:51:10 tirion volumio[1011]: info: CoreStateMachine::resetVolumioState Mar 08 12:51:10 tirion volumio[1011]: info: CoreStateMachine::getcurrentVolume Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::volumioRetrievevolume Mar 08 12:51:10 tirion volumio[1011]: info: Volumio Network Manager: Network status updated: 2 Mar 08 12:51:10 tirion volumio[1011]: info: CoreStateMachine::pushState Mar 08 12:51:10 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::volumioPushState Mar 08 12:51:10 tirion volumio[1011]: info: CoreStateMachine::updateTrackBlock Mar 08 12:51:10 tirion volumio[1011]: info: CorePlayQueue::getTrackBlock Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::volumioRetrievevolume Mar 08 12:51:10 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 12:51:10 tirion volumio[1011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: Reloading queue from file Mar 08 12:51:11 tirion volumio[1011]: info: CoreStateMachine::pushState Mar 08 12:51:11 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioPushState Mar 08 12:51:11 tirion volumio[1011]: info: CoreStateMachine::setRepeat null single undefined Mar 08 12:51:11 tirion volumio[1011]: info: CoreStateMachine::pushState Mar 08 12:51:11 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioPushState Mar 08 12:51:11 tirion volumio[1011]: info: CoreStateMachine::setRandom null Mar 08 12:51:11 tirion volumio[1011]: info: CoreStateMachine::pushState Mar 08 12:51:11 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioPushState Mar 08 12:51:11 tirion volumio[1011]: info: Setting Device type: Raspberry PI Mar 08 12:51:11 tirion volumio[1011]: info: Completed loading Core Plugins Mar 08 12:51:11 tirion volumio[1011]: info: Preparing to generate the ALSA configuration file Mar 08 12:51:11 tirion volumio[1011]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 08 12:51:11 tirion volumio[1011]: info: Reading ALSA contributions from plugins. Mar 08 12:51:11 tirion volumio[1011]: info: Asound.conf file unchanged, so no further update is needed Mar 08 12:51:11 tirion volumio[1011]: info: Output device has changed, restarting MPD Mar 08 12:51:11 tirion volumio[1011]: info: Output device has changed, restarting Shairport Sync Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:11 tirion sudo[1337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 08 12:51:11 tirion sudo[1337]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1337]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:11 tirion sudo[1339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 08 12:51:11 tirion sudo[1339]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion systemd[1]: Stopping Music Player Daemon... Mar 08 12:51:11 tirion volumio[1011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 12:51:11 tirion volumio[1011]: info: ___________ START PLUGINS ___________ Mar 08 12:51:11 tirion volumio[1011]: info: ControllerMpd::onStart: Initializing MPD Mar 08 12:51:11 tirion volumio[1011]: info: Creating MPD Configuration file Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 12:51:11 tirion volumio[1011]: info: [1741434671360] CoreMusicLibrary::Adding element Medienserver Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 12:51:11 tirion sudo[1346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 08 12:51:11 tirion sudo[1348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 08 12:51:11 tirion sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1346]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1346]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 12:51:11 tirion volumio[1011]: info: [1741434671502] CoreMusicLibrary::Adding element Last_100 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 12:51:11 tirion volumio[1011]: info: [1741434671505] CoreMusicLibrary::Adding element Webradio Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 12:51:11 tirion volumio[1011]: info: Initializing BBC Radios Mar 08 12:51:11 tirion systemd[1]: mpd.service: Succeeded. Mar 08 12:51:11 tirion systemd[1]: Stopped Music Player Daemon. Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:11 tirion volumio[1011]: info: Creating Spotify config file Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:11 tirion systemd[1]: Starting Music Player Daemon... Mar 08 12:51:11 tirion volumio[1011]: info: [squeezelite_mc] Starting proxy server... Mar 08 12:51:11 tirion volumio[1011]: info: Configuring GPIO pins Mar 08 12:51:11 tirion volumio[1011]: error: Plugin audiophonicsonoff failed to start! Error: EINVAL: invalid argument, write Mar 08 12:51:11 tirion volumio[1011]: info: Loading i18n strings for locale de Mar 08 12:51:11 tirion kernel: export_store: invalid GPIO 4 Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 12:51:11 tirion volumio[1011]: info: Volumio Calling Home Mar 08 12:51:11 tirion volumio[1011]: info: [squeezelite_mc] Proxy server started on port 46093 Mar 08 12:51:11 tirion sudo[1360]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 08 12:51:11 tirion sudo[1360]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1360]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:11 tirion sudo[1374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 08 12:51:11 tirion sudo[1374]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 08 12:51:11 tirion sudo[1376]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion sudo[1379]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 08 12:51:11 tirion sudo[1379]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:11 tirion systemd[1]: Reloading. Mar 08 12:51:11 tirion volumio[1011]: info: CoreCommandRouter::volumioRetrievevolume Mar 08 12:51:12 tirion sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 08 12:51:12 tirion volumio[1011]: info: Discovery: adding 57cbe41f-6a12-449e-9102-7d9c8be47501 Mar 08 12:51:12 tirion volumio[1011]: info: Discovery: Found device Tirion Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:12 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:12 tirion sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion sudo[1389]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion sudo[1400]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 08 12:51:12 tirion sudo[1400]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: touch_display: Backlight interface detected. Mar 08 12:51:12 tirion sudo[1400]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion volumio[1011]: info: CoreStateMachine::pushState Mar 08 12:51:12 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::volumioPushState Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Server discovery started Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Player finder started Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 08 12:51:12 tirion volumio[1011]: info: MPD Permissions set Mar 08 12:51:12 tirion volumio[1011]: info: MPD Permissions set Mar 08 12:51:12 tirion volumio[1011]: info: Volumio called home Mar 08 12:51:12 tirion volumio[1011]: info: Spotify config file written Mar 08 12:51:12 tirion volumio[1011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 08 12:51:12 tirion sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 08 12:51:12 tirion sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["S16_LE","S24_LE","S32_LE"] Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"tirion","dsdFormat":null,"card":"1","mixerType":"Software","mixer":"SoftMaster"} Mar 08 12:51:12 tirion 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. Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion sudo[1414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Mar 08 12:51:12 tirion sudo[1414]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 12:51:12 tirion volumio[1011]: info: No need to fix Spotify hosts Mar 08 12:51:12 tirion sudo[1414]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion volumio[1011]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Mar 08 12:51:12 tirion sudo[1426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Mar 08 12:51:12 tirion sudo[1426]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: touch_display: Raspberry Pi Foundation touch screen detected. Mar 08 12:51:12 tirion sudo[1428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Mar 08 12:51:12 tirion sudo[1428]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: Starting Shairport Sync Mar 08 12:51:12 tirion sudo[1432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 08 12:51:12 tirion sudo[1432]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: Starting Shairport Sync Mar 08 12:51:12 tirion sudo[1428]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion sudo[1432]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion sudo[1426]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:12 tirion sudo[1435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 12:51:12 tirion sudo[1435]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 12:51:12 tirion sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion sudo[1440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 08 12:51:12 tirion sudo[1440]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 12:51:12 tirion sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:12 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:12 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:13 tirion sudo[1379]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:13 tirion sudo[1374]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:13 tirion systemd[1]: Reloading. Mar 08 12:51:13 tirion volumio[1011]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Mar 08 12:51:13 tirion volumio[1011]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 08 12:51:13 tirion volumio[1011]: info: touch_display: File permissions for backlight brightness control set. Mar 08 12:51:13 tirion volumio[1011]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 08 12:51:13 tirion volumio[1011]: info: touch_display: systemctl daemon-reload succeeded. Mar 08 12:51:13 tirion sudo[1448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Mar 08 12:51:13 tirion sudo[1448]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:13 tirion sudo[1464]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 08 12:51:13 tirion sudo[1464]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:13 tirion sudo[1448]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:13 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Mar 08 12:51:13 tirion sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 08 12:51:13 tirion sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:13 tirion 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. Mar 08 12:51:13 tirion mpd[1373]: Mar 08 12:51 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 08 12:51:14 tirion sudo[1376]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:14 tirion volumio[1011]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 08 12:51:14 tirion systemd[1]: Started Music Player Daemon. Mar 08 12:51:14 tirion sudo[1339]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:14 tirion sudo[1348]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:14 tirion systemd[1]: Reloading. Mar 08 12:51:14 tirion volumio[1011]: error: MPD error: The expression evaluated to a falsy value: Mar 08 12:51:14 tirion volumio[1011]: assert.ok(self.idling) Mar 08 12:51:14 tirion volumio[1011]: error: The expression evaluated to a falsy value: Mar 08 12:51:14 tirion volumio[1011]: assert.ok(self.idling) Mar 08 12:51:14 tirion volumio[1011]: info: MPD running with PID1373 Mar 08 12:51:14 tirion volumio[1011]: ,establishing connection Mar 08 12:51:14 tirion volumio[1011]: error: updateQueue error: null Mar 08 12:51:14 tirion 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. Mar 08 12:51:15 tirion sudo[1470]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion systemd[1]: Started go-librespot Daemon. Mar 08 12:51:15 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:15 tirion sudo[1410]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion go-librespot[1489]: Librespot-go daemon starting... Mar 08 12:51:15 tirion systemd[1]: Started Volumio Kiosk. Mar 08 12:51:15 tirion sudo[1464]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 08 12:51:15 tirion systemd[1]: Started UPnP Renderer front-end to MPD. Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 08 12:51:15 tirion sudo[1440]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: Volumio Kiosk started. Mar 08 12:51:15 tirion systemd[1]: shairport-sync.service: Succeeded. Mar 08 12:51:15 tirion systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 08 12:51:15 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:15 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:15 tirion sudo[1494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:15 tirion sudo[1494]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:15 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:15 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:15 tirion systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 08 12:51:15 tirion sudo[1435]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion sudo[1443]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion sudo[1437]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion volumio[1011]: info: Upmpdcli Daemon Started Mar 08 12:51:15 tirion volumio[1011]: info: Shairport-Sync Started Mar 08 12:51:15 tirion volumio[1011]: Error adding Membership: Error: addMembership EINVAL Mar 08 12:51:15 tirion volumio[1011]: info: Shairport-Sync Started Mar 08 12:51:15 tirion volumio[1011]: info: Shairport-Sync Started Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: Mar 08 12:51:15 tirion sudo[1494]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion sudo[1535]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Mar 08 12:51:15 tirion sudo[1535]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:15 tirion systemd[1]: Starting Squeezelite lightweight headless Squeezebox emulator... Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion volumio[1493]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 08 12:51:15 tirion kernel: process '/opt/squeezelite/squeezelite' started with executable stack Mar 08 12:51:15 tirion systemd[1]: Started Squeezelite lightweight headless Squeezebox emulator. Mar 08 12:51:15 tirion sudo[1535]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 08 12:51:15 tirion startx[1490]: X.Org X Server 1.20.4 Mar 08 12:51:15 tirion startx[1490]: X Protocol Version 11, Revision 0 Mar 08 12:51:15 tirion startx[1490]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Mar 08 12:51:15 tirion startx[1490]: Current Operating System: Linux tirion 6.6.62-v7+ #1816 SMP Mon Nov 18 15:30:49 GMT 2024 armv7l Mar 08 12:51:15 tirion startx[1490]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=8543fa12-4125-4451-a534-cec5480e0606 imgfile=/volumio_current.sqsh bootpart=UUID=9C48-E5A3 datapart=UUID=f7cca1c6-391b-47a8-9c19-3b1948539def uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Mar 08 12:51:15 tirion startx[1490]: Build Date: 04 April 2023 07:50:56AM Mar 08 12:51:15 tirion startx[1490]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Mar 08 12:51:15 tirion startx[1490]: Current version of pixman: 0.36.0 Mar 08 12:51:15 tirion startx[1490]: Before reporting problems, check http://wiki.x.org Mar 08 12:51:15 tirion startx[1490]: to make sure that you have the latest version. Mar 08 12:51:15 tirion startx[1490]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 08 12:51:15 tirion startx[1490]: (++) from command line, (!!) notice, (II) informational, Mar 08 12:51:15 tirion startx[1490]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 08 12:51:15 tirion startx[1490]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Mar 8 12:51:15 2025 Mar 08 12:51:15 tirion volumio[1011]: info: touch_display: X display number found: 0 Mar 08 12:51:15 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:16 tirion startx[1490]: (==) Using config directory: "/etc/X11/xorg.conf.d" Mar 08 12:51:16 tirion startx[1490]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 08 12:51:16 tirion sudo[1562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:16 tirion sudo[1562]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:16 tirion sudo[1562]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:16 tirion volumio-remote-updater[630]: [2025-03-08 12:51:16] [connect] Successful connection Mar 08 12:51:16 tirion volumio-remote-updater[630]: [2025-03-08 12:51:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741434676 101 Mar 08 12:51:16 tirion volumio[1011]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Mar 08 12:51:16 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:16 tirion go-librespot[1489]: time="2025-03-08T12:51:16+01:00" level=info msg="generated new device id: 0f7ae7beab4a19888380fceebc5acebb0e4fc848" Mar 08 12:51:16 tirion sudo[1571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:16 tirion sudo[1571]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:16 tirion sudo[1571]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:17 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:17 tirion sudo[1574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:17 tirion sudo[1574]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:17 tirion sudo[1574]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:17 tirion go-librespot[1489]: time="2025-03-08T12:51:17+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-gae2.spotify.com:80]" Mar 08 12:51:17 tirion go-librespot[1489]: time="2025-03-08T12:51:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 08 12:51:17 tirion go-librespot[1489]: time="2025-03-08T12:51:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 08 12:51:17 tirion go-librespot[1489]: time="2025-03-08T12:51:17+01:00" level=debug msg="zeroconf server listening on port 45141" Mar 08 12:51:17 tirion kernel: hwmon hwmon1: Undervoltage detected! Mar 08 12:51:17 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:18 tirion sudo[1580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:18 tirion sudo[1580]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:18 tirion sudo[1580]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:18 tirion volumio[1011]: info: go-librespot daemon successfully initialized Mar 08 12:51:18 tirion volumio[1011]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Mar 08 12:51:18 tirion sudo[1583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Mar 08 12:51:18 tirion sudo[1583]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:18 tirion sudo[1583]: pam_unix(sudo:session): session closed for user root Mar 08 12:51:18 tirion volumio[1011]: info: Completed starting Core Plugins Mar 08 12:51:18 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:51:18 tirion volumio[1011]: info: ----- MyVolumio plugins startup ---- Mar 08 12:51:18 tirion volumio[1011]: info: ------------------------------------------- Mar 08 12:51:18 tirion volumio[1011]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 08 12:51:19 tirion volumio[1011]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 08 12:51:20 tirion volumio[1011]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 08 12:51:20 tirion go-librespot[1489]: time="2025-03-08T12:51:20+01:00" level=debug msg="obtained new client token: AACwdCZbMuLwfs9AOcMf3Uqw0w6mAVJ/hFQ3g1Fvllh/iLz+ubHSR1rYJ9wSnfUkKkSxOCeafaoicxt6CNstIp57f2s3nG+ULcDlRzC9+sh0Tt/tNNd0LycE5tS8VXFxND+nNBfz8ImwD6v9+MEmmvLr4LvhSt4cpMtdipsipqec3D9mcfr0lvqirRmsduL0c08tEQIJO4apCoA4xA0LhEj+43gW1/i5T4st1w06+M2fDKEPsoVeQZFbNHo3Cw==" Mar 08 12:51:21 tirion go-librespot[1489]: time="2025-03-08T12:51:21+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 08 12:51:21 tirion volumio[1011]: info: Initializing connection to go-librespot Websocket Mar 08 12:51:21 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:21 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:21 tirion go-librespot[1489]: time="2025-03-08T12:51:21+01:00" level=debug msg="new websocket client" Mar 08 12:51:21 tirion go-librespot[1489]: time="2025-03-08T12:51:21+01:00" level=debug msg="completed keyexchange" Mar 08 12:51:22 tirion volumio[1011]: info: Connection to go-librespot Websocket established Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="completed challenge" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="authenticated as esderkiller" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="authenticated as esderkiller" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="dealer connection opened" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=info msg="accepted zeroconf user esderkiller from Nigger" Mar 08 12:51:22 tirion go-librespot[1489]: time="2025-03-08T12:51:22+01:00" level=debug msg="received connection id: ODZhODk3NzEtZDQzZS00YWVhLWEwMzAtNWY2MDMzNGVmMjEzK2RlYWxlcit0Y3A6Ly8wYWNhNThlNi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNUMwQTMwMEYyNjIzQUZFQTBDQzZCMDk0RDREQTdDMEQyMUVCQzIzNEREMjc2MTYyNDI1OThDMTdCRjY5MkZBNQ==" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="autoplay enabled: false" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="handling transfer player command from 029fd74db268a12d47137db17715db9e8851f800" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="resolved context of track" uri="spotify:album:2HHxFXnn36pzHvJ5KMyhdJ" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=trace msg="fetched new page 0 with 20 items (list: 20)" uri="spotify:album:2HHxFXnn36pzHvJ5KMyhdJ" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="loading track (paused: true, position: 118830ms)" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=trace msg="emitting websocket event: will_play" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="selected format OGG_VORBIS_320 (b7690a7e2ee9e90d3a6f5bb81cf201437bfd2103)" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="requested aes key for file b7690a7e2ee9e90d3a6f5bb81cf201437bfd2103, gid: 1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1667" Mar 08 12:51:23 tirion go-librespot[1489]: time="2025-03-08T12:51:23+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1277" Mar 08 12:51:24 tirion go-librespot[1489]: time="2025-03-08T12:51:24+01:00" level=debug msg="fetched first chunk of 16, total size is 7920752 bytes" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:24 tirion go-librespot[1489]: time="2025-03-08T12:51:24+01:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Mar 08 12:51:24 tirion go-librespot[1489]: time="2025-03-08T12:51:24+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:24 tirion go-librespot[1489]: time="2025-03-08T12:51:24+01:00" level=debug msg="fetched chunk 15/15, size: 56432" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion systemd[1]: systemd-timedated.service: Succeeded. Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="fetched chunk 12/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="fetched chunk 13/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="fetched chunk 14/15, size: 524288" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=trace msg="seek to 118830ms (diff: 43ms, samples: 5240403, bytes: 6595491)" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="created new output device" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=info msg="loaded track \"Gewittergeräusche mit Regen, Teil 13 (2024 Remaster)\" (paused: true, position: 118830ms, duration: 142386ms, prefetched: false)" uri="spotify:track:1sMLeEGHrfpeoELxd9mpdL" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=trace msg="emitting websocket event: metadata" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=trace msg="emitting websocket event: active" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="sending successful reply for dealer request" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 08 12:51:25 tirion volumio[1011]: info: Listing playlists Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 12:51:25 tirion go-librespot[1489]: time="2025-03-08T12:51:25+01:00" level=trace msg="emitting websocket event: paused" Mar 08 12:51:25 tirion volumio[1011]: info: Getting Spotify volume Mar 08 12:51:25 tirion volumio[1011]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1sMLeEGHrfpeoELxd9mpdL","play_origin":"playlist"}} Mar 08 12:51:25 tirion volumio[1011]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1sMLeEGHrfpeoELxd9mpdL","name":"Gewittergeräusche mit Regen, Teil 13 (2024 Remaster)","artist_names":["Regengeräusche Orchester von TraxLab"],"album_name":"Regen und Gewitter (2024 Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b194e509e246f5df615d16e4","position":118830,"duration":142386,"release_date":"year:2024 month:1 day:8","track_number":13,"disc_number":1}} Mar 08 12:51:25 tirion volumio[1011]: SPOTIFY: received: {"type":"active","data":null} Mar 08 12:51:25 tirion volumio[1011]: info: Aligning Spotify Volume to Volumio Volume Mar 08 12:51:25 tirion volumio[1011]: info: CoreCommandRouter::volumioGetState Mar 08 12:51:25 tirion volumio[1011]: info: CorePlayQueue::getTrack 0 Mar 08 12:51:25 tirion volumio[1011]: info: Setting Spotify Volume from Volumio: 4 Mar 08 12:51:25 tirion volumio[1011]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1sMLeEGHrfpeoELxd9mpdL","play_origin":"playlist"}} Mar 08 12:51:25 tirion volumio[1011]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 08 12:51:25 tirion volumio[1011]: TypeError: Cannot read property 'service' of undefined Mar 08 12:51:25 tirion volumio[1011]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Mar 08 12:51:25 tirion volumio[1011]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) Mar 08 12:51:25 tirion volumio[1011]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Mar 08 12:51:25 tirion volumio[1011]: at WebSocket.emit (events.js:315:20) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.emit (events.js:315:20) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Mar 08 12:51:25 tirion volumio[1011]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Mar 08 12:51:25 tirion volumio[1011]: at writeOrBuffer (internal/streams/writable.js:358:12) Mar 08 12:51:25 tirion volumio[1011]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Mar 08 12:51:25 tirion volumio[1011]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Mar 08 12:51:25 tirion volumio[1011]: at Socket.emit (events.js:315:20) Mar 08 12:51:25 tirion volumio[1011]: at addChunk (internal/streams/readable.js:309:12) Mar 08 12:51:25 tirion volumio[1011]: at readableAddChunk (internal/streams/readable.js:284:9) Mar 08 12:51:25 tirion volumio[1011]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 08 12:51:26 tirion go-librespot[1489]: time="2025-03-08T12:51:26+01:00" level=debug msg="update volume to 64880/65535" Mar 08 12:51:26 tirion go-librespot[1489]: time="2025-03-08T12:51:26+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 08 12:51:26 tirion go-librespot[1489]: time="2025-03-08T12:51:26+01:00" level=trace msg="emitting websocket event: volume" Mar 08 12:51:26 tirion go-librespot[1489]: time="2025-03-08T12:51:26+01:00" level=debug msg="update volume to 61603/65535" Mar 08 12:51:27 tirion go-librespot[1489]: time="2025-03-08T12:51:27+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 08 12:51:27 tirion go-librespot[1489]: time="2025-03-08T12:51:27+01:00" level=trace msg="emitting websocket event: volume" Mar 08 12:51:27 tirion sudo[1704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-08 12:50 Mar 08 12:51:27 tirion sudo[1704]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 12:51:27 tirion go-librespot[1489]: time="2025-03-08T12:51:27+01:00" level=debug msg="update volume to 57015/65535" PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"