-- Logs begin at Thu 2019-02-14 19:12:00 JST, end at Sat 2025-05-31 16:16:35 JST. -- May 31 16:15:14 volumiopi systemd-timedated[1025]: Changed local time to Sat May 31 16:15:14 2025 May 31 16:15:14 volumiopi sudo[1023]: pam_unix(sudo:session): session closed for user root May 31 16:15:14 volumiopi volumio-time-update[595]: volumio-time-update-util: System time updated successfully. May 31 16:15:14 volumiopi systemd[1]: Starting Daily apt download activities... May 31 16:15:14 volumiopi systemd[1]: Starting Daily man-db regeneration... May 31 16:15:14 volumiopi systemd[1]: Started Volumio Time Update Utility. May 31 16:15:14 volumiopi systemd[1]: Reached target Multi-User System. May 31 16:15:14 volumiopi systemd[1]: Reached target Graphical Interface. May 31 16:15:14 volumiopi systemd[1]: Starting Update UTMP about System Runlevel Changes... May 31 16:15:14 volumiopi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 31 16:15:14 volumiopi systemd[1]: Started Update UTMP about System Runlevel Changes. May 31 16:15:14 volumiopi systemd[1]: man-db.service: Succeeded. May 31 16:15:14 volumiopi systemd[1]: Started Daily man-db regeneration. May 31 16:15:14 volumiopi nmbd[748]: [2025/05/31 16:15:14.797494, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 31 16:15:14 volumiopi nmbd[748]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.121 for name WORKGROUP<1d>. May 31 16:15:14 volumiopi nmbd[748]: This response was from IP 192.168.1.61, reporting an IP address of 192.168.1.61. May 31 16:15:16 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:15:16 volumiopi volumio[988]: info: ----- Volumio3 ---- May 31 16:15:16 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:15:16 volumiopi volumio[988]: info: ----- System startup ---- May 31 16:15:16 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:15:18 volumiopi volumio[988]: info: MYVOLUMIO Environment detected May 31 16:15:19 volumiopi volumio[988]: info: Plugin folders cleanup May 31 16:15:19 volumiopi volumio[988]: info: Scanning into folder /volumio/app/plugins/ May 31 16:15:19 volumiopi volumio[988]: info: Scanning category audio_interface May 31 16:15:19 volumiopi volumio[988]: info: Scanning category miscellanea May 31 16:15:19 volumiopi volumio[988]: info: Scanning category music_service May 31 16:15:19 volumiopi volumio[988]: info: Scanning category plugins.json May 31 16:15:19 volumiopi volumio[988]: info: Scanning category system_controller May 31 16:15:19 volumiopi volumio[988]: info: Scanning category user_interface May 31 16:15:19 volumiopi volumio[988]: info: Scanning into folder /data/plugins/ May 31 16:15:19 volumiopi volumio[988]: info: Scanning category audio_interface May 31 16:15:19 volumiopi volumio[988]: info: Scanning category music_service May 31 16:15:19 volumiopi volumio[988]: info: Scanning category system_controller May 31 16:15:19 volumiopi volumio[988]: info: Scanning category user_interface May 31 16:15:19 volumiopi volumio[988]: info: Plugin folders cleanup completed May 31 16:15:19 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:15:19 volumiopi volumio[988]: info: ----- Core plugins startup ---- May 31 16:15:19 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:15:19 volumiopi volumio[988]: info: Loading plugins from folder /volumio/app/plugins/ May 31 16:15:19 volumiopi volumio[988]: info: Adding plugin upnp to MyMusic Plugins May 31 16:15:19 volumiopi volumio[988]: info: Adding plugin airplay_emulation to MyMusic Plugins May 31 16:15:19 volumiopi volumio[988]: info: Adding plugin upnp_browser to MyMusic Plugins May 31 16:15:19 volumiopi volumio[988]: info: Loading plugins from folder /data/plugins/ May 31 16:15:19 volumiopi volumio[988]: info: Loading plugin "system"... May 31 16:15:19 volumiopi volumio[988]: info: Loading plugin "appearance"... May 31 16:15:19 volumiopi systemd[1]: systemd-hostnamed.service: Succeeded. May 31 16:15:20 volumiopi systemd[1]: apt-daily.service: Succeeded. May 31 16:15:20 volumiopi systemd[1]: Started Daily apt download activities. May 31 16:15:21 volumiopi systemd[1]: Starting Daily apt upgrade and clean activities... May 31 16:15:22 volumiopi volumio[988]: info: Loading plugin "network"... May 31 16:15:22 volumiopi volumio[988]: info: Refreshing Cached IP Addresses May 31 16:15:22 volumiopi volumio-remote-updater[594]: [2025-05-31 16:15:22] [connect] Successful connection May 31 16:15:22 volumiopi sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 31 16:15:22 volumiopi sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:22 volumiopi sudo[1120]: pam_unix(sudo:session): session closed for user root May 31 16:15:22 volumiopi sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 31 16:15:22 volumiopi sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:22 volumiopi sudo[1122]: pam_unix(sudo:session): session closed for user root May 31 16:15:22 volumiopi volumio[988]: info: Loading plugin "services"... May 31 16:15:22 volumiopi volumio[988]: info: Loading plugin "alsa_controller"... May 31 16:15:22 volumiopi sudo[1131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 31 16:15:22 volumiopi sudo[1131]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:23 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "wizard"... May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "networkfs"... May 31 16:15:23 volumiopi volumio[988]: info: Starting Udev Watcher for removable devices May 31 16:15:23 volumiopi sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.150/music /mnt/NAS/music May 31 16:15:23 volumiopi sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:23 volumiopi volumio[988]: info: Ignoring mount for partition: boot May 31 16:15:23 volumiopi volumio[988]: info: Ignoring mount for partition: volumio May 31 16:15:23 volumiopi volumio[988]: info: Ignoring mount for partition: volumio_data May 31 16:15:23 volumiopi volumio[988]: info: Mounting Device 1618-3A66 May 31 16:15:23 volumiopi sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/1618-3A66 -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 31 16:15:23 volumiopi sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:23 volumiopi kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 31 16:15:23 volumiopi kernel: Key type cifs.spnego registered May 31 16:15:23 volumiopi kernel: Key type cifs.idmap registered May 31 16:15:23 volumiopi 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. May 31 16:15:23 volumiopi kernel: CIFS: Attempting to mount //192.168.1.150/music May 31 16:15:23 volumiopi kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 31 16:15:23 volumiopi sudo[1156]: pam_unix(sudo:session): session closed for user root May 31 16:15:23 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "volumio_command_line_client"... May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "upnp"... May 31 16:15:23 volumiopi volumio[988]: info: [1748675723833] Starting Upmpd Daemon May 31 16:15:23 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "my_music"... May 31 16:15:23 volumiopi volumio[988]: info: Loading plugin "mpd"... May 31 16:15:24 volumiopi systemd[1]: apt-daily-upgrade.service: Succeeded. May 31 16:15:24 volumiopi systemd[1]: Started Daily apt upgrade and clean activities. May 31 16:15:24 volumiopi systemd[1]: Startup finished in 16.829s (kernel) + 48.322s (userspace) = 1min 5.151s. May 31 16:15:24 volumiopi volumio[988]: info: Loading plugin "upnp_browser"... May 31 16:15:25 volumiopi kernel: cryptd: max_cpu_qlen set to 1000 May 31 16:15:25 volumiopi volumio[988]: info: Loading plugin "alarm-clock"... May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "airplay_emulation"... May 31 16:15:26 volumiopi volumio[988]: info: Starting Shairport Sync May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "last_100"... May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "webradio"... May 31 16:15:26 volumiopi sudo[1146]: pam_unix(sudo:session): session closed for user root May 31 16:15:26 volumiopi sudo[1131]: pam_unix(sudo:session): session closed for user root May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "i2s_dacs"... May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "volumiodiscovery"... May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** For more information see May 31 16:15:26 volumiopi node[988]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 16:15:26 volumiopi volumio[988]: *** WARNING *** For more information see May 31 16:15:26 volumiopi node[988]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 16:15:26 volumiopi node[988]: *** WARNING *** For more information see May 31 16:15:26 volumiopi node[988]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 31 16:15:26 volumiopi node[988]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 16:15:26 volumiopi node[988]: *** WARNING *** For more information see May 31 16:15:26 volumiopi volumio[988]: info: Applying required configuration parameters for plugin volumiodiscovery May 31 16:15:26 volumiopi volumio[988]: info: Discovery: Started advertising with name: VolumioPi May 31 16:15:26 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 16:15:26 volumiopi volumio[988]: info: Plugin bandcamp is not enabled May 31 16:15:26 volumiopi volumio[988]: info: Plugin calmradio is not enabled May 31 16:15:26 volumiopi volumio[988]: info: Plugin jellyfin is not enabled May 31 16:15:26 volumiopi volumio[988]: info: Loading plugin "jellyfin_server"... May 31 16:15:27 volumiopi volumio[988]: info: Plugin mixcloud is not enabled May 31 16:15:27 volumiopi volumio[988]: info: Plugin soundcloud is not enabled May 31 16:15:27 volumiopi volumio[988]: info: Loading plugin "spop"... May 31 16:15:30 volumiopi volumio[988]: info: Loading plugin "squeezelite_mc"... May 31 16:15:32 volumiopi volumio[988]: info: Loading plugin "youtube2"... May 31 16:15:35 volumiopi volumio[988]: info: Loading plugin "ytcr"... May 31 16:15:37 volumiopi volumio-remote-updater[594]: [2025-05-31 16:15:37] [connect] Successful connection May 31 16:15:40 volumiopi volumio[988]: info: Loading plugin "ytmusic"... May 31 16:15:43 volumiopi volumio[988]: info: Loading plugin "autostart"... May 31 16:15:43 volumiopi volumio[988]: info: Applying required configuration parameters for plugin autostart May 31 16:15:43 volumiopi volumio[988]: info: AutoStart - onVolumioStart - read config.json May 31 16:15:43 volumiopi volumio[988]: info: Loading plugin "now_playing"... May 31 16:15:44 volumiopi systemd[1]: systemd-timedated.service: Succeeded. May 31 16:15:47 volumiopi volumio[988]: info: Loading plugin "outputs"... May 31 16:15:47 volumiopi volumio[988]: info: Loading plugin "albumart"... May 31 16:15:47 volumiopi volumio[988]: info: Plugin example_plugin is not enabled May 31 16:15:47 volumiopi volumio[988]: info: Loading plugin "inputs"... May 31 16:15:47 volumiopi volumio[988]: info: Loading plugin "updater_comm"... May 31 16:15:48 volumiopi volumio[988]: info: Plugin mpdemulation is not enabled May 31 16:15:48 volumiopi volumio[988]: info: Loading plugin "rest_api"... May 31 16:15:48 volumiopi volumio[988]: info: Loading plugin "websocket"... May 31 16:15:48 volumiopi volumio[988]: info: Starting Socket.io Server version 2.3.0 May 31 16:15:48 volumiopi volumio[988]: info: Loading plugin "fusiondsp"... May 31 16:15:48 volumiopi volumio[988]: Forking 3 albumart workers May 31 16:15:48 volumiopi volumio[988]: info: Applying required configuration parameters for plugin fusiondsp May 31 16:15:49 volumiopi volumio[988]: info: Plugin 80s80s is not enabled May 31 16:15:49 volumiopi volumio[988]: info: Plugin RoonBridge is not enabled May 31 16:15:49 volumiopi volumio[988]: info: Loading plugin "jp_radio"... May 31 16:15:49 volumiopi volumio[988]: Starting albumart workers May 31 16:15:50 volumiopi volumio[988]: Starting albumart workers May 31 16:15:50 volumiopi volumio[988]: Starting albumart workers May 31 16:15:51 volumiopi volumio[988]: info: Loading plugin "lms"... May 31 16:15:52 volumiopi volumio[988]: info: Loading plugin "minidlna"... May 31 16:15:52 volumiopi volumio[988]: info: Applying required configuration parameters for plugin minidlna May 31 16:15:52 volumiopi volumio[988]: info: Plugin motherearthradio is not enabled May 31 16:15:52 volumiopi volumio[988]: info: Plugin pandora is not enabled May 31 16:15:52 volumiopi volumio[988]: info: Plugin personal_radio is not enabled May 31 16:15:52 volumiopi volumio[988]: info: Loading plugin "podcast"... May 31 16:15:52 volumiopi volumio-remote-updater[594]: [2025-05-31 16:15:52] [connect] Successful connection May 31 16:15:53 volumiopi volumio[988]: info: ControllerPodcast::constructor May 31 16:15:53 volumiopi volumio[988]: info: Plugin rad357pl is not enabled May 31 16:15:53 volumiopi volumio[988]: info: Plugin radio_paradise is not enabled May 31 16:15:53 volumiopi volumio[988]: info: Plugin swarmstation is not enabled May 31 16:15:53 volumiopi volumio[988]: info: Plugin volusonic is not enabled May 31 16:15:53 volumiopi volumio[988]: info: Loading plugin "backup_restore"... May 31 16:15:54 volumiopi volumio[988]: info: Applying required configuration parameters for plugin backup_restore May 31 16:15:54 volumiopi volumio[988]: info: Loading plugin "Systeminfo"... May 31 16:15:54 volumiopi ntpd[792]: Soliciting pool server 162.159.200.123 May 31 16:15:54 volumiopi volumio[988]: info: Plugin randomizer is not enabled May 31 16:15:54 volumiopi volumio[988]: info: Loading plugin "touch_display"... May 31 16:15:55 volumiopi ntpd[792]: Soliciting pool server 129.250.35.251 May 31 16:15:55 volumiopi volumio[988]: info: Applying required configuration parameters for plugin touch_display May 31 16:15:55 volumiopi volumio[988]: info: Loading i18n strings for locale ja May 31 16:15:55 volumiopi volumio[988]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:55 volumiopi volumio[988]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:55 volumiopi volumio[988]: Updating browse sources language May 31 16:15:55 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::initPlayerControls May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 16:15:56 volumiopi volumio[988]: Express server listening on port 3000 May 31 16:15:56 volumiopi volumio[988]: [Metrics] WebUI: 42s 519.34ms May 31 16:15:56 volumiopi volumio[988]: info: CoreStateMachine::resetVolumioState May 31 16:15:56 volumiopi ntpd[792]: Soliciting pool server 160.16.113.133 May 31 16:15:56 volumiopi volumio[988]: info: CoreStateMachine::getcurrentVolume May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::volumioRetrievevolume May 31 16:15:56 volumiopi sudo[1368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 31 16:15:56 volumiopi sudo[1368]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:56 volumiopi sudo[1368]: pam_unix(sudo:session): session closed for user root May 31 16:15:56 volumiopi sudo[1371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 31 16:15:56 volumiopi sudo[1371]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:56 volumiopi sudo[1371]: pam_unix(sudo:session): session closed for user root May 31 16:15:56 volumiopi volumio[988]: info: Volumio Network Manager: Network status updated: 2 May 31 16:15:56 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:15:56 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:15:56 volumiopi volumio[988]: info: CoreStateMachine::updateTrackBlock May 31 16:15:56 volumiopi volumio[988]: info: CorePlayQueue::getTrackBlock May 31 16:15:56 volumiopi volumio[988]: info: CoreCommandRouter::volumioRetrievevolume May 31 16:15:57 volumiopi volumio-remote-updater[594]: [2025-05-31 16:15:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748675752 101 May 31 16:15:57 volumiopi volumio[988]: 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: 1 May 31 16:15:57 volumiopi volumio[988]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 31 16:15:57 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:15:57 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:15:57 volumiopi volumio[988]: info: Reloading queue from file May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:15:57 volumiopi ntpd[792]: Soliciting pool server 45.76.211.39 May 31 16:15:57 volumiopi volumio[988]: info: CoreStateMachine::setRepeat null single undefined May 31 16:15:57 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:15:57 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:15:57 volumiopi volumio[988]: info: CoreStateMachine::setRandom null May 31 16:15:57 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:15:57 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:15:57 volumiopi volumio[988]: info: Setting Device type: Raspberry PI May 31 16:15:57 volumiopi volumio[988]: info: Completed loading Core Plugins May 31 16:15:57 volumiopi volumio[988]: info: Preparing to generate the ALSA configuration file May 31 16:15:57 volumiopi volumio[988]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 16:15:57 volumiopi volumio[988]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 31 16:15:57 volumiopi volumio[988]: info: Reading ALSA contributions from plugins. May 31 16:15:57 volumiopi sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 31 16:15:57 volumiopi sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:57 volumiopi ntpd[792]: Soliciting pool server 162.159.200.1 May 31 16:15:57 volumiopi volumio[988]: info: Discovery: adding 312eef85-7f60-4bdb-9865-815eb2763960 May 31 16:15:57 volumiopi volumio[988]: info: Discovery: Found device VolumioPi May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:15:57 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:57 volumiopi volumio[988]: info: Discovery: this is already registered, 312eef85-7f60-4bdb-9865-815eb2763960 May 31 16:15:57 volumiopi volumio[988]: info: Discovery: Found device Volumio May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:15:57 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:15:57 volumiopi systemd[1]: Started UPnP Renderer front-end to MPD. May 31 16:15:57 volumiopi sudo[1386]: pam_unix(sudo:session): session closed for user root May 31 16:15:57 volumiopi volumio[988]: info: Asound.conf file unchanged, so no further update is needed May 31 16:15:57 volumiopi volumio[988]: info: Output device has changed, restarting MPD May 31 16:15:57 volumiopi sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 16:15:57 volumiopi sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:57 volumiopi sudo[1390]: pam_unix(sudo:session): session closed for user root May 31 16:15:57 volumiopi volumio[988]: info: Output device has changed, restarting Shairport Sync May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:57 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:15:58 volumiopi sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 16:15:58 volumiopi sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:58 volumiopi systemd[1]: Stopping Music Player Daemon... May 31 16:15:58 volumiopi volumio[988]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 16:15:58 volumiopi volumio[988]: info: ___________ START PLUGINS ___________ May 31 16:15:58 volumiopi volumio[988]: info: ControllerMpd::onStart: Initializing MPD May 31 16:15:58 volumiopi volumio[988]: info: Creating MPD Configuration file May 31 16:15:58 volumiopi sudo[1399]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 16:15:58 volumiopi sudo[1399]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:58 volumiopi sudo[1399]: pam_unix(sudo:session): session closed for user root May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:58 volumiopi volumio[988]: info: [1748675758229] CoreMusicLibrary::Adding element DLNAサーバー May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:58 volumiopi sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 16:15:58 volumiopi sudo[1402]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:15:58 volumiopi systemd[1]: mpd.service: Succeeded. May 31 16:15:58 volumiopi systemd[1]: Stopped Music Player Daemon. May 31 16:15:58 volumiopi volumio[988]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:15:58 volumiopi systemd[1]: Starting Music Player Daemon... May 31 16:15:58 volumiopi ntpd[792]: Soliciting pool server 108.160.132.224 May 31 16:15:58 volumiopi volumio[988]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:58 volumiopi volumio[988]: info: [1748675758513] CoreMusicLibrary::Adding element Last_100 May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:58 volumiopi volumio[988]: info: [1748675758520] CoreMusicLibrary::Adding element Webradio May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 16:15:58 volumiopi volumio[988]: info: Initializing BBC Radios May 31 16:15:58 volumiopi ntpd[792]: Soliciting pool server 167.179.119.205 May 31 16:15:58 volumiopi sudo[1407]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 16:15:58 volumiopi sudo[1407]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:15:58 volumiopi sudo[1407]: pam_unix(sudo:session): session closed for user root May 31 16:15:58 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl start jellyfin || true May 31 16:15:58 volumiopi sudo[1424]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start jellyfin May 31 16:15:58 volumiopi sudo[1424]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:58 volumiopi volumio[988]: info: Creating Spotify config file May 31 16:15:58 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:58 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:15:58 volumiopi systemd[1]: Starting Jellyfin... May 31 16:15:58 volumiopi systemd[1]: Started Jellyfin. May 31 16:15:58 volumiopi sudo[1424]: pam_unix(sudo:session): session closed for user root May 31 16:15:59 volumiopi volumio[988]: info: [squeezelite_mc] Starting proxy server... May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:59 volumiopi volumio[988]: info: [1748675759060] CoreMusicLibrary::Adding element YouTube2 May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube2 May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:59 volumiopi volumio[988]: info: [1748675759197] CoreMusicLibrary::Adding element YouTube Music May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube2 May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube Music May 31 16:15:59 volumiopi volumio[988]: info: AutoStart - onStart May 31 16:15:59 volumiopi volumio[988]: info: [now-playing] ConfigUpdater: config is up to date. May 31 16:15:59 volumiopi volumio[988]: info: Loading i18n strings for locale ja May 31 16:15:59 volumiopi volumio[988]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi volumio[988]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:15:59 volumiopi volumio[988]: info: FusionDsp - mixtype--------------------- Software May 31 16:15:59 volumiopi ntpd[792]: Soliciting pool server 45.77.20.103 May 31 16:15:59 volumiopi ntpd[792]: Soliciting pool server 45.77.20.103 May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:59 volumiopi volumio[988]: info: [1748675759502] CoreMusicLibrary::Adding element RADIKO May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube2 May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube Music May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source RADIKO May 31 16:15:59 volumiopi volumio[988]: info: Loading i18n strings for locale ja May 31 16:15:59 volumiopi ntpd[792]: Soliciting pool server 202.181.103.212 May 31 16:15:59 volumiopi volumio[988]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi volumio[988]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi sudo[1433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 31 16:15:59 volumiopi sudo[1433]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:15:59 volumiopi systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:15:59 volumiopi volumio[988]: info: [1748675759703] CoreMusicLibrary::Adding element Podcast May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube2 May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source YouTube Music May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source RADIKO May 31 16:15:59 volumiopi volumio[988]: Cannot find translation for source Podcast May 31 16:15:59 volumiopi systemd[1]: Starting Logitech Media Server Daemon... May 31 16:15:59 volumiopi volumio[988]: info: Loading i18n strings for locale ja May 31 16:15:59 volumiopi volumio[988]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi volumio[988]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 16:15:59 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 16:15:59 volumiopi systemd[1]: Started Logitech Media Server Daemon. May 31 16:15:59 volumiopi volumio[988]: info: Volumio Calling Home May 31 16:15:59 volumiopi sudo[1433]: pam_unix(sudo:session): session closed for user root May 31 16:15:59 volumiopi systemd[1439]: logitechmediaserver.service: Failed to execute command: No such file or directory May 31 16:15:59 volumiopi systemd[1439]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 31 16:15:59 volumiopi systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 31 16:15:59 volumiopi systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 31 16:16:00 volumiopi volumio[988]: info: [squeezelite_mc] Proxy server started on port 44183 May 31 16:16:00 volumiopi volumio[988]: info: Preparing to generate the ALSA configuration file May 31 16:16:00 volumiopi sudo[1444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service May 31 16:16:00 volumiopi sudo[1444]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:00 volumiopi sudo[1446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service May 31 16:16:00 volumiopi sudo[1446]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:00 volumiopi sudo[1449]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload May 31 16:16:00 volumiopi sudo[1449]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:00 volumiopi ntpd[792]: Soliciting pool server 129.250.35.250 May 31 16:16:00 volumiopi ntpd[792]: Soliciting pool server 23.81.40.154 May 31 16:16:00 volumiopi systemd[1]: Reloading. May 31 16:16:01 volumiopi 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. May 31 16:16:01 volumiopi volumio[988]: info: CoreCommandRouter::volumioRetrievevolume May 31 16:16:01 volumiopi volumio[988]: info: [now-playing] App is listening on port 4004. May 31 16:16:01 volumiopi ntpd[792]: Soliciting pool server 172.237.12.44 May 31 16:16:01 volumiopi ntpd[792]: Soliciting pool server 2606:4700:f1::123 May 31 16:16:02 volumiopi ntpd[792]: receive: Unexpected origin timestamp 0xebe52b31.736609e5 does not match aorg 0000000000.00000000 from server@129.250.35.251 xmt 0xebe52b32.a01a3396 May 31 16:16:02 volumiopi ntpd[792]: receive: Unexpected origin timestamp 0xebe52b31.735a5675 does not match aorg 0000000000.00000000 from server@23.81.40.154 xmt 0xebe52b32.a025fd82 May 31 16:16:02 volumiopi volumio[988]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds May 31 16:16:02 volumiopi volumio[988]: info: Upmpdcli Daemon Started May 31 16:16:02 volumiopi volumio[988]: info: camilladsp spawned new process with pid 1478, instance 1, run: true May 31 16:16:02 volumiopi volumio[988]: info: camilladsp service started and running in background, instance 1 May 31 16:16:02 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:03 volumiopi volumio[988]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA May 31 16:16:03 volumiopi volumio[988]: info: FusionDsp loaded May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 16:16:03 volumiopi volumio[988]: info: FusionDsp - Reporting Fusion DSP Enabled May 31 16:16:03 volumiopi volumio[988]: info: Adding Signal Path Element [object Object] May 31 16:16:03 volumiopi volumio[988]: info: Adding fusiondspeq DSP Signal Path Element May 31 16:16:03 volumiopi sudo[1482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 31 16:16:03 volumiopi volumio[988]: info: FusionDsp - ---- installed callbackRead May 31 16:16:03 volumiopi sudo[1482]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:03 volumiopi volumio[988]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 31 16:16:03 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:16:03 volumiopi volumio[988]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 16:16:03 volumiopi volumio[988]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 31 16:16:03 volumiopi volumio[988]: info: Reading ALSA contributions from plugins. May 31 16:16:03 volumiopi volumio[988]: error: touch_display: Error detecting backlight interface: Error: ENOENT: no such file or directory, scandir '/sys/class/backlight/' May 31 16:16:03 volumiopi systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. May 31 16:16:03 volumiopi mpd[1422]: May 31 16:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:16:03 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:03 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:16:03 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:16:03 volumiopi volumio[988]: info: [squeezelite_mc] Server discovery started May 31 16:16:03 volumiopi volumio[988]: info: [squeezelite_mc] Player finder started May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:03 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:03 volumiopi volumio[988]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true May 31 16:16:03 volumiopi volumio[988]: info: minidlna: Found miniDLNA version 1.2.1 May 31 16:16:03 volumiopi volumio[988]: info: minidlna: Starting minidlna.service May 31 16:16:03 volumiopi volumio[988]: info: logitechmediaserver started May 31 16:16:03 volumiopi ntpd[792]: Soliciting pool server 103.131.151.20 May 31 16:16:03 volumiopi volumio[988]: info: MPD Permissions set May 31 16:16:03 volumiopi volumio[988]: info: MPD Permissions set May 31 16:16:03 volumiopi sudo[1495]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service May 31 16:16:03 volumiopi sudo[1495]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:03 volumiopi systemd[1]: Started Music Player Daemon. May 31 16:16:03 volumiopi sudo[1449]: pam_unix(sudo:session): session closed for user root May 31 16:16:03 volumiopi sudo[1402]: pam_unix(sudo:session): session closed for user root May 31 16:16:03 volumiopi sudo[1393]: pam_unix(sudo:session): session closed for user root May 31 16:16:03 volumiopi volumio[988]: error: FusionDsp - WebSocket error: [object Object] May 31 16:16:03 volumiopi volumio[988]: error: [squeezelite_mc] Could not query supported ALSA formats for card 2 because device is busy May 31 16:16:03 volumiopi volumio[988]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumiopi","dsdFormat":null,"card":"2","mixerType":"Software","mixer":"SoftMaster"} May 31 16:16:03 volumiopi volumio[988]: 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 May 31 16:16:03 volumiopi volumio[988]: info: Volumio called home May 31 16:16:03 volumiopi systemd[1]: Reloading. May 31 16:16:03 volumiopi volumio[988]: info: Spotify config file written May 31 16:16:03 volumiopi sudo[1444]: pam_unix(sudo:session): session closed for user root May 31 16:16:04 volumiopi sudo[1501]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 31 16:16:04 volumiopi sudo[1501]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:04 volumiopi volumio[988]: Upnp client error: Error: This socket has been ended by the other party May 31 16:16:04 volumiopi sudo[1499]: 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 May 31 16:16:04 volumiopi sudo[1499]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:04 volumiopi volumio[988]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 31 16:16:04 volumiopi volumio[988]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 31 16:16:04 volumiopi sudo[1499]: pam_unix(sudo:session): session closed for user root May 31 16:16:04 volumiopi volumio[988]: info: touch_display: systemctl daemon-reload succeeded. May 31 16:16:04 volumiopi sudo[1519]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service May 31 16:16:04 volumiopi sudo[1519]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:04 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi sudo[1529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin May 31 16:16:04 volumiopi sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:16:04 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:04 volumiopi 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. May 31 16:16:05 volumiopi volumio[988]: info: [squeezelite_mc] Executing alsactl -L -R nrestore May 31 16:16:05 volumiopi volumio[988]: info: touch_display: systemctl stop getty@tty1.service succeeded. May 31 16:16:05 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:16:05 volumiopi sudo[1550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore May 31 16:16:05 volumiopi sudo[1550]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:05 volumiopi systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. May 31 16:16:05 volumiopi sudo[1550]: pam_unix(sudo:session): session closed for user root May 31 16:16:05 volumiopi volumio[988]: error: MPD error: The expression evaluated to a falsy value: May 31 16:16:05 volumiopi volumio[988]: assert.ok(self.idling) May 31 16:16:05 volumiopi volumio[988]: error: The expression evaluated to a falsy value: May 31 16:16:05 volumiopi volumio[988]: assert.ok(self.idling) May 31 16:16:05 volumiopi volumio[988]: info: MPD running with PID1422 May 31 16:16:05 volumiopi volumio[988]: ,establishing connection May 31 16:16:05 volumiopi sudo[1446]: pam_unix(sudo:session): session closed for user root May 31 16:16:05 volumiopi volumio[988]: info: touch_display: No Raspberry Pi Foundation touch screen detected. May 31 16:16:05 volumiopi sudo[1555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf May 31 16:16:05 volumiopi sudo[1555]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:05 volumiopi volumio[988]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 31 16:16:05 volumiopi volumio[988]: SPOTIFY: BQBpBMs9FdS_gV7SXAy6caIGztepP698qGQ52lynRXLjhCF9k6hrqWw6eGccRbSubMeimKfyZjrQZ-SM6MYFdTJ0eTeyiHVOaDNhZ0_3jW5itbx8tt5WV5vWW3xTSdMzpptrb1FLHZUElGXVD6ILlhhO4rp_J_UmMBatZrCZ-YCBxBMLZzDfNOADWB2lOxADbqMT2OjUqm81bCskqkouyCEKlRjSZwhNLGhvx_Oa_8WBBmWZhzg894fwOCpbiKyfs1N-cbaydHKC4MCGveZPKE7BZPzB-IcmfSr0R9GlNNIO2fc May 31 16:16:05 volumiopi volumio[988]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 31 16:16:05 volumiopi volumio[988]: info: New Spotify access token = BQBpBMs9FdS_gV7SXAy6caIGztepP698qGQ52lynRXLjhCF9k6hrqWw6eGccRbSubMeimKfyZjrQZ-SM6MYFdTJ0eTeyiHVOaDNhZ0_3jW5itbx8tt5WV5vWW3xTSdMzpptrb1FLHZUElGXVD6ILlhhO4rp_J_UmMBatZrCZ-YCBxBMLZzDfNOADWB2lOxADbqMT2OjUqm81bCskqkouyCEKlRjSZwhNLGhvx_Oa_8WBBmWZhzg894fwOCpbiKyfs1N-cbaydHKC4MCGveZPKE7BZPzB-IcmfSr0R9GlNNIO2fc May 31 16:16:05 volumiopi volumio[988]: info: Spotify credentials grant success - running version from March 24, 2019 May 31 16:16:05 volumiopi sudo[1555]: pam_unix(sudo:session): session closed for user root May 31 16:16:05 volumiopi volumio[988]: error: updateQueue error: null May 31 16:16:05 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:16:05 volumiopi volumio[988]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service May 31 16:16:06 volumiopi volumio[988]: info: Starting Shairport Sync May 31 16:16:06 volumiopi volumio[988]: info: Starting Shairport Sync May 31 16:16:06 volumiopi systemd[1]: Started Volumio Kiosk. May 31 16:16:06 volumiopi sudo[1519]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi volumio[988]: info: Starting Shairport Sync May 31 16:16:06 volumiopi systemd[1]: Started go-librespot Daemon. May 31 16:16:06 volumiopi sudo[1562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 16:16:06 volumiopi sudo[1562]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:06 volumiopi go-librespot[1566]: Librespot-go daemon starting... May 31 16:16:06 volumiopi systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. May 31 16:16:06 volumiopi sudo[1501]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi sudo[1564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 16:16:06 volumiopi sudo[1564]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:06 volumiopi systemd[1]: Started FusionDsp Daemon. May 31 16:16:06 volumiopi sudo[1482]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi sudo[1495]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi sudo[1582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 16:16:06 volumiopi sudo[1582]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:06 volumiopi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 16:16:06 volumiopi sudo[1529]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi sudo[1560]: 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 May 31 16:16:06 volumiopi sudo[1560]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:06 volumiopi systemd[1]: shairport-sync.service: Succeeded. May 31 16:16:06 volumiopi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 16:16:06 volumiopi sudo[1560]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 16:16:06 volumiopi sudo[1564]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi sudo[1562]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 16:16:06 volumiopi systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 31 16:16:06 volumiopi systemd[1]: shairport-sync.service: Succeeded. May 31 16:16:06 volumiopi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 16:16:06 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:16:06 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:06 volumiopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 16:16:06 volumiopi sudo[1582]: pam_unix(sudo:session): session closed for user root May 31 16:16:06 volumiopi volumio[988]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. May 31 16:16:06 volumiopi volumio[988]: info: touch_display: systemctl disable getty@tty1.service succeeded. May 31 16:16:06 volumiopi volumio[988]: error: updateQueue error: null May 31 16:16:07 volumiopi volumio[988]: info: Shairport-Sync Started May 31 16:16:07 volumiopi volumio[988]: Error adding Membership: Error: addMembership EINVAL May 31 16:16:07 volumiopi volumio[988]: info: Shairport-Sync Started May 31 16:16:07 volumiopi volumio[988]: info: Shairport-Sync Started May 31 16:16:07 volumiopi volumio[988]: info: minidlna: systemctl start minidlna.service succeeded. May 31 16:16:07 volumiopi volumio[988]: info: touch_display: systemctl start volumio-kiosk.service succeeded. May 31 16:16:07 volumiopi volumio[988]: info: touch_display: Volumio Kiosk started. May 31 16:16:07 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:16:07 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:07 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true May 31 16:16:07 volumiopi volumio[988]: info: Asound.conf file unchanged, so no further update is needed May 31 16:16:07 volumiopi volumio[988]: info: Output device has changed, restarting MPD May 31 16:16:07 volumiopi sudo[1622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload May 31 16:16:07 volumiopi sudo[1622]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:07 volumiopi volumio[988]: info: Output device has changed, restarting Shairport Sync May 31 16:16:07 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:07 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:16:07 volumiopi startx[1558]: X.Org X Server 1.20.4 May 31 16:16:07 volumiopi startx[1558]: X Protocol Version 11, Revision 0 May 31 16:16:07 volumiopi startx[1558]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian May 31 16:16:07 volumiopi startx[1558]: Current Operating System: Linux volumiopi 6.6.62-v7+ #1816 SMP Mon Nov 18 15:30:49 GMT 2024 armv7l May 31 16:16:07 volumiopi startx[1558]: 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=640 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=0c3a77ec-ae84-4f1b-8028-c61cc251ffe5 imgfile=/volumio_current.sqsh bootpart=UUID=41CA-9A8B datapart=UUID=0324d53a-d066-482b-b659-eb98af2b49e7 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 May 31 16:16:07 volumiopi startx[1558]: Build Date: 04 April 2023 07:50:56AM May 31 16:16:07 volumiopi startx[1558]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) May 31 16:16:07 volumiopi startx[1558]: Current version of pixman: 0.36.0 May 31 16:16:07 volumiopi startx[1558]: Before reporting problems, check http://wiki.x.org May 31 16:16:07 volumiopi startx[1558]: to make sure that you have the latest version. May 31 16:16:07 volumiopi startx[1558]: Markers: (--) probed, (**) from config file, (==) default setting, May 31 16:16:07 volumiopi startx[1558]: (++) from command line, (!!) notice, (II) informational, May 31 16:16:07 volumiopi startx[1558]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. May 31 16:16:07 volumiopi startx[1558]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat May 31 16:16:07 2025 May 31 16:16:07 volumiopi sudo[1625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 16:16:07 volumiopi volumio[1388]: Generating RSA private key, 4096 bit long modulus (2 primes) May 31 16:16:07 volumiopi sudo[1625]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:07 volumiopi sudo[1625]: pam_unix(sudo:session): session closed for user root May 31 16:16:07 volumiopi sudo[1628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 16:16:07 volumiopi sudo[1628]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:07 volumiopi systemd[1]: Reloading. May 31 16:16:07 volumiopi volumio[988]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 16:16:07 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:16:07 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:07 volumiopi startx[1558]: (==) Using config directory: "/etc/X11/xorg.conf.d" May 31 16:16:07 volumiopi startx[1558]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" May 31 16:16:07 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true May 31 16:16:07 volumiopi volumio[988]: info: MPD Permissions set May 31 16:16:07 volumiopi volumio[988]: info: touch_display: X display number found: 0 May 31 16:16:07 volumiopi go-librespot[1566]: time="2025-05-31T16:16:07+09:00" level=info msg="generated new device id: 9337d785e25da1149cab7ecae15c37f2908afd4c" May 31 16:16:07 volumiopi sudo[1654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin May 31 16:16:07 volumiopi go-librespot[1566]: time="2025-05-31T16:16:07+09:00" level=debug msg="stored credentials found for 31jhxtvriozhj7aseuqslb7fe3uy" May 31 16:16:08 volumiopi sudo[1654]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:08 volumiopi volumio[988]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:08 volumiopi volumio[988]: info: Starting Shairport Sync May 31 16:16:08 volumiopi sudo[1665]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 16:16:08 volumiopi sudo[1665]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:08 volumiopi 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. May 31 16:16:08 volumiopi volumio[988]: info: JP_Radio::premium logged in - Member Type:%s May 31 16:16:09 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 16:16:09 volumiopi volumio[988]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true May 31 16:16:09 volumiopi volumio[988]: SPOTIFY: User informations: {"country":"JP","display_name":"Takashi Kudoh","email":"weltall.tk@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31jhxtvriozhj7aseuqslb7fe3uy"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31jhxtvriozhj7aseuqslb7fe3uy","id":"31jhxtvriozhj7aseuqslb7fe3uy","images":[],"product":"free","type":"user","uri":"spotify:user:31jhxtvriozhj7aseuqslb7fe3uy"} May 31 16:16:09 volumiopi volumio[988]: info: Spotify Successfully logged in May 31 16:16:09 volumiopi volumio[988]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 16:16:09 volumiopi volumio[988]: info: [1748675769273] CoreMusicLibrary::Adding element Spotify May 31 16:16:09 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 16:16:09 volumiopi volumio[988]: Cannot find translation for source YouTube2 May 31 16:16:09 volumiopi volumio[988]: Cannot find translation for source YouTube Music May 31 16:16:09 volumiopi volumio[988]: Cannot find translation for source RADIKO May 31 16:16:09 volumiopi volumio[988]: Cannot find translation for source Podcast May 31 16:16:09 volumiopi volumio[988]: Cannot find translation for source Spotify May 31 16:16:09 volumiopi volumio[988]: error: [squeezelite_mc] Could not query supported ALSA formats for card 2 because device is busy May 31 16:16:10 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:16:10 volumiopi volumio[988]: info: JP_Radio::getting stations May 31 16:16:10 volumiopi volumio[988]: info: go-librespot daemon successfully initialized May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="zeroconf server listening on port 45075" May 31 16:16:10 volumiopi systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. May 31 16:16:10 volumiopi volumio[988]: info: [yt-cast-receiver] DIAL server listening on port 8098 May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="obtained new client token: AABl+cbi1O7FmWR1LvKvALbrvonMk2Cze2VA398dbt9YrOBoLBdOL9hZ5cT5Nc0kc5cfhw9+wHeJxucFVcrevnZOINY2kdjiqi5pDqP2eAxkGt2cgXfn8ZkrZQWSczLUaBg2AxTbqZzr7rckP76CLih3mpMIINJ27DeVqcizJ1vtp1260Hvhbe6WBE6Zh9S2dXcJAs9WO0k8lrYHglUS2qaozcvjVS6BgRv9cPjKoQ+cBNUstygprMqEypgs" May 31 16:16:10 volumiopi sudo[1622]: pam_unix(sudo:session): session closed for user root May 31 16:16:10 volumiopi systemd[1]: Configuration file /etc/systemd/system/jellyfin.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. May 31 16:16:10 volumiopi go-librespot[1566]: time="2025-05-31T16:16:10+09:00" level=debug msg="completed keyexchange" May 31 16:16:11 volumiopi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 16:16:11 volumiopi systemd[1]: Stopping Music Player Daemon... May 31 16:16:11 volumiopi systemd[1]: shairport-sync.service: Succeeded. May 31 16:16:11 volumiopi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 16:16:11 volumiopi sudo[1654]: pam_unix(sudo:session): session closed for user root May 31 16:16:11 volumiopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 16:16:11 volumiopi systemd[1]: mpd.service: Succeeded. May 31 16:16:11 volumiopi systemd[1]: Stopped Music Player Daemon. May 31 16:16:11 volumiopi sudo[1665]: pam_unix(sudo:session): session closed for user root May 31 16:16:11 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:11 volumiopi systemd[1]: Starting Music Player Daemon... May 31 16:16:11 volumiopi go-librespot[1566]: time="2025-05-31T16:16:11+09:00" level=debug msg="completed challenge" May 31 16:16:11 volumiopi go-librespot[1566]: time="2025-05-31T16:16:11+09:00" level=debug msg="authenticated as 31jhxtvriozhj7aseuqslb7fe3uy" May 31 16:16:11 volumiopi sudo[1671]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 16:16:11 volumiopi sudo[1671]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:11 volumiopi sudo[1673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:11 volumiopi sudo[1673]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:11 volumiopi sudo[1671]: pam_unix(sudo:session): session closed for user root May 31 16:16:12 volumiopi volumio[988]: info: Shairport-Sync Started May 31 16:16:12 volumiopi volumio[988]: info: touch_display: X display number found: 0 May 31 16:16:12 volumiopi sudo[1673]: pam_unix(sudo:session): session closed for user root May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="authenticated as 31jhxtvriozhj7aseuqslb7fe3uy" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="dealer connection opened" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="initializing zeroconf session, username: 31jhxtvriozhj7aseuqslb7fe3uy" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="autoplay enabled: false" May 31 16:16:12 volumiopi go-librespot[1566]: time="2025-05-31T16:16:12+09:00" level=debug msg="received connection id: NzIyZjFlNDctNDJiOS00MjBmLWIwMDctNTk2MDVhNjc1NmFhK2RlYWxlcit0Y3A6Ly8wYWM5NDhmYi5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArQzRCRDAwQUZBMzY1NUU0ODM1QzQ2RTAxOENBNkRERjE4MUIyOTlBNERFOEYzOTc3QkQ2RTNDMzhDQzIwN0I2QQ==" May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:10] [INF] [1] Main: Jellyfin version: 10.9.6 May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Environment Variables: ["[JELLYFIN_LOG_DIR, /opt/jellyfin/log]"] May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Arguments: ["/opt/jellyfin/jellyfin_10.9.6/jellyfin.dll", "-d", "/opt/jellyfin/data", "-C", "/opt/jellyfin/cache", "-c", "/opt/jellyfin/config", "-l", "/opt/jellyfin/log", "--ffmpeg", "/usr/lib/jellyfin-ffmpeg/ffmpeg"] May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Operating system: Raspbian GNU/Linux 10 (buster) May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Architecture: Arm May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: 64-Bit Process: False May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: User Interactive: True May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Processor count: 4 May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Program data path: /opt/jellyfin/data May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Log directory path: /opt/jellyfin/log May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Config directory path: /opt/jellyfin/config May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Cache path: /opt/jellyfin/cache May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Web resources path: /opt/jellyfin/jellyfin_10.9.6/jellyfin-web May 31 16:16:13 volumiopi jellyfin[1426]: [16:16:13] [INF] [1] Main: Application directory: /opt/jellyfin/jellyfin_10.9.6/ May 31 16:16:13 volumiopi go-librespot[1566]: time="2025-05-31T16:16:13+09:00" level=debug msg="put connect state because NEW_DEVICE" May 31 16:16:15 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true May 31 16:16:15 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true May 31 16:16:15 volumiopi volumio[988]: info: Initializing connection to go-librespot Websocket May 31 16:16:15 volumiopi sudo[1723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite May 31 16:16:15 volumiopi sudo[1723]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:15 volumiopi sudo[1725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin May 31 16:16:15 volumiopi sudo[1725]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:15 volumiopi systemd[1]: Starting Squeezelite lightweight headless Squeezebox emulator... May 31 16:16:15 volumiopi kernel: process '/opt/squeezelite/squeezelite' started with executable stack May 31 16:16:15 volumiopi systemd[1]: Started Squeezelite lightweight headless Squeezebox emulator. May 31 16:16:15 volumiopi sudo[1723]: pam_unix(sudo:session): session closed for user root May 31 16:16:15 volumiopi sudo[1725]: pam_unix(sudo:session): session closed for user root May 31 16:16:15 volumiopi mpd[1676]: May 31 16:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 16:16:16 volumiopi systemd[1]: Started Music Player Daemon. May 31 16:16:16 volumiopi sudo[1628]: pam_unix(sudo:session): session closed for user root May 31 16:16:16 volumiopi go-librespot[1566]: time="2025-05-31T16:16:16+09:00" level=debug msg="new websocket client" May 31 16:16:16 volumiopi volumio[988]: info: touch_display: Setting screensaver timeout to 240 seconds. May 31 16:16:16 volumiopi volumio[988]: info: Connection to go-librespot Websocket established May 31 16:16:17 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true May 31 16:16:17 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:17 volumiopi sudo[1767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin May 31 16:16:17 volumiopi volumio[1388]: ........................++++ May 31 16:16:17 volumiopi sudo[1767]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:18 volumiopi volumio[988]: info: camilladsp spawned new process with pid 1770, instance 1, run: true May 31 16:16:18 volumiopi volumio[988]: error: updateQueue error: null May 31 16:16:18 volumiopi sudo[1769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:18 volumiopi sudo[1769]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:18 volumiopi sudo[1767]: pam_unix(sudo:session): session closed for user root May 31 16:16:18 volumiopi sudo[1769]: pam_unix(sudo:session): session closed for user root May 31 16:16:18 volumiopi jellyfin[1426]: [16:16:18] [INF] [1] Jellyfin.Server.Migrations.MigrationRunner: Marking following migrations as applied because this is a fresh install: ["CreateNetworkConfiguration", "MigrateMusicBrainzTimeout", "MigrateNetworkConfiguration"] May 31 16:16:18 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:19 volumiopi volumio[988]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true May 31 16:16:19 volumiopi sudo[1782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:19 volumiopi sudo[1782]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:19 volumiopi sudo[1784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin May 31 16:16:19 volumiopi sudo[1784]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:19 volumiopi sudo[1784]: pam_unix(sudo:session): session closed for user root May 31 16:16:19 volumiopi sudo[1782]: pam_unix(sudo:session): session closed for user root May 31 16:16:19 volumiopi volumio[988]: info: Getting Spotify volume May 31 16:16:19 volumiopi jellyfin[1426]: [16:16:19] [INF] [1] Emby.Server.Implementations.AppBase.BaseConfigurationManager: Setting cache path: /opt/jellyfin/cache May 31 16:16:20 volumiopi volumio[988]: info: Spotify volume: 100 May 31 16:16:20 volumiopi volumio[988]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 31 16:16:20 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetState May 31 16:16:20 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:20 volumiopi volumio[988]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 May 31 16:16:20 volumiopi volumio[988]: SPOTIFY: SPOTIFY VOLUME 100 May 31 16:16:20 volumiopi volumio[988]: SPOTIFY: VOLUMIO VOLUME 96 May 31 16:16:20 volumiopi volumio[988]: SPOTIFY: DELTA VOLUME ENOUGH: true May 31 16:16:20 volumiopi volumio[988]: info: Setting Spotify Volume from Volumio: 96 May 31 16:16:20 volumiopi volumio[988]: info: AutoStart - Plugin is starting May 31 16:16:20 volumiopi volumio[988]: info: CoreCommandRouter::volumioGetQueue May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::getQueue May 31 16:16:20 volumiopi volumio[988]: info: CorePlayQueue::getQueue May 31 16:16:20 volumiopi volumio[988]: info: AutoStart - start playing May 31 16:16:20 volumiopi volumio[988]: info: AutoStart - start playing with no specific position May 31 16:16:20 volumiopi volumio[988]: info: CoreCommandRouter::volumioPlay May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::play index 0 May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::stop May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::play index undefined May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 16:16:20 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:20 volumiopi volumio[988]: info: CoreStateMachine::startPlaybackTimer May 31 16:16:20 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:20 volumiopi volumio[988]: verbose: ControllerMpd::clearAddPlayTracks NAS/music/music-2/Amazon Music/Nickelback/Dark Horse/01-02- Burn It To The Ground [Explicit].mp3 May 31 16:16:20 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand stop May 31 16:16:20 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:20 volumiopi volumio[988]: info: sendMpdCommand stop took 67 milliseconds May 31 16:16:20 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand clear May 31 16:16:20 volumiopi volumio[988]: info: May 31 16:16:20 volumiopi volumio[988]: ---------------------------- MPD announces system playlist update May 31 16:16:20 volumiopi volumio[988]: info: Ignoring MPD Status Update May 31 16:16:20 volumiopi volumio[988]: info: sendMpdCommand clear took 9 milliseconds May 31 16:16:20 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand add "NAS/music/music-2/Amazon Music/Nickelback/Dark Horse/01-02- Burn It To The Ground [Explicit].mp3" May 31 16:16:20 volumiopi volumio[988]: error: updateQueue error: null May 31 16:16:20 volumiopi volumio[988]: info: May 31 16:16:20 volumiopi volumio[988]: ---------------------------- MPD announces system playlist update May 31 16:16:20 volumiopi volumio[988]: info: Ignoring MPD Status Update May 31 16:16:20 volumiopi volumio[988]: info: ------------------------------ 17ms May 31 16:16:20 volumiopi volumio[988]: info: sendMpdCommand add "NAS/music/music-2/Amazon Music/Nickelback/Dark Horse/01-02- Burn It To The Ground [Explicit].mp3" took 12 milliseconds May 31 16:16:20 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand play May 31 16:16:20 volumiopi volumio[988]: info: ------------------------------ 15ms May 31 16:16:20 volumiopi volumio[988]: info: sendMpdCommand play took 9 milliseconds May 31 16:16:20 volumiopi sudo[1805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:20 volumiopi sudo[1805]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:20 volumiopi sudo[1805]: pam_unix(sudo:session): session closed for user root May 31 16:16:21 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:21 volumiopi volumio[988]: info: May 31 16:16:21 volumiopi volumio[988]: ---------------------------- MPD announces state update: player May 31 16:16:21 volumiopi volumio[988]: info: ControllerMpd::getState May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand status May 31 16:16:21 volumiopi volumio[988]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 31 16:16:21 volumiopi volumio[988]: info: FusionDsp - ---- read samplerate from file: 44100 May 31 16:16:21 volumiopi volumio[988]: info: camilladsp stopping service pid 1770... May 31 16:16:21 volumiopi sudo[1814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:21 volumiopi sudo[1814]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:21 volumiopi sudo[1814]: pam_unix(sudo:session): session closed for user root May 31 16:16:21 volumiopi volumio[988]: info: camilladsp service terminated, instance 1 May 31 16:16:21 volumiopi volumio[988]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 31 16:16:21 volumiopi volumio[988]: info: camilladsp service started and running in background, instance 1 May 31 16:16:21 volumiopi volumio[988]: info: May 31 16:16:21 volumiopi volumio[988]: ---------------------------- MPD announces state update: player May 31 16:16:21 volumiopi volumio[988]: info: sendMpdCommand status took 211 milliseconds May 31 16:16:21 volumiopi volumio[988]: info: ControllerMpd::getState May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand status May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::parseState May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 16:16:21 volumiopi volumio[988]: info: sendMpdCommand status took 12 milliseconds May 31 16:16:21 volumiopi volumio[988]: info: sendMpdCommand playlistinfo took 10 milliseconds May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::parseState May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::parseTrackInfo May 31 16:16:21 volumiopi volumio[988]: info: ControllerMpd::pushState May 31 16:16:21 volumiopi volumio[988]: info: CoreCommandRouter::servicePushState May 31 16:16:21 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:21 volumiopi volumio[988]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"32 Kbps","isStreaming":false,"title":"Burn It To The Ground [Explicit]","artist":"Nickelback","album":"Dark Horse","uri":"NAS/music/music-2/Amazon Music/Nickelback/Dark Horse/01-02- Burn It To The Ground [Explicit].mp3","trackType":"mp3"} May 31 16:16:21 volumiopi volumio[988]: verbose: CURRENT POSITION 0 May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::syncState stateService play May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::syncState currentStatus stop May 31 16:16:21 volumiopi volumio[988]: info: ------------------------------ 254ms May 31 16:16:21 volumiopi volumio[988]: info: camilladsp spawned new process with pid 1820, instance 1, run: true May 31 16:16:21 volumiopi volumio[988]: info: sendMpdCommand playlistinfo took 78 milliseconds May 31 16:16:21 volumiopi volumio[988]: verbose: ControllerMpd::parseTrackInfo May 31 16:16:21 volumiopi volumio[988]: info: ControllerMpd::pushState May 31 16:16:21 volumiopi volumio[988]: info: CoreCommandRouter::servicePushState May 31 16:16:21 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:21 volumiopi volumio[988]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"32 Kbps","isStreaming":false,"title":"Burn It To The Ground [Explicit]","artist":"Nickelback","album":"Dark Horse","uri":"NAS/music/music-2/Amazon Music/Nickelback/Dark Horse/01-02- Burn It To The Ground [Explicit].mp3","trackType":"mp3"} May 31 16:16:21 volumiopi volumio[988]: verbose: CURRENT POSITION 0 May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::syncState stateService play May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::syncState currentStatus play May 31 16:16:21 volumiopi volumio[988]: info: Received an update from plugin. extracting info from payload May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:16:21 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:21 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 16:16:21 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:16:21 volumiopi volumio[988]: info: CoreStateMachine::pushState May 31 16:16:21 volumiopi volumio[988]: info: CorePlayQueue::getTrack 0 May 31 16:16:21 volumiopi volumio[988]: info: CoreCommandRouter::volumioPushState May 31 16:16:21 volumiopi volumio[988]: info: ------------------------------ 185ms May 31 16:16:21 volumiopi volumio[988]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 May 31 16:16:21 volumiopi volumio[988]: SPOTIFY: SETTING SPOTIFY VOLUME 96 May 31 16:16:21 volumiopi volumio[988]: info: Sending Spotify command with payload to local API: /player/volume May 31 16:16:21 volumiopi volumio[988]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request May 31 16:16:21 volumiopi volumio[988]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 31 16:16:22 volumiopi sudo[1829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 31 16:16:22 volumiopi sudo[1829]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 16:16:22 volumiopi sudo[1829]: pam_unix(sudo:session): session closed for user root May 31 16:16:22 volumiopi volumio[988]: info: Completed starting Core Plugins May 31 16:16:22 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:16:22 volumiopi volumio[988]: info: ----- MyVolumio plugins startup ---- May 31 16:16:22 volumiopi volumio[988]: info: ------------------------------------------- May 31 16:16:22 volumiopi volumio[988]: info: [MyVolumio PluginManager] Fetching plans data.... May 31 16:16:22 volumiopi jellyfin[1426]: [16:16:22] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loading assemblies May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Defined LAN subnets: ["127.0.0.1/8", "10.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16"] May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Defined LAN exclusions: [] May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Used LAN subnets: ["127.0.0.1/8", "10.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16"] May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Filtered interface addresses: ["127.0.0.1", "192.168.1.121"] May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Bind Addresses ["0.0.0.0"] May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Remote IP filter is Allowlist May 31 16:16:25 volumiopi jellyfin[1426]: [16:16:25] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Filtered subnets: [] May 31 16:16:26 volumiopi wpa_supplicant[895]: RRM: Ignoring radio measurement request: Not RRM network May 31 16:16:28 volumiopi dhcpcd[681]: wlan0: carrier lost May 31 16:16:28 volumiopi wpa_supplicant[895]: wlan0: Associated with 00:11:32:a5:09:f6 May 31 16:16:28 volumiopi wpa_supplicant[895]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:11:32:a5:09:f6 completed [id=0 id_str=] May 31 16:16:28 volumiopi wpa_supplicant[895]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 31 16:16:29 volumiopi avahi-daemon[597]: Withdrawing address record for 192.168.1.121 on wlan0. May 31 16:16:29 volumiopi avahi-daemon[597]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.121. May 31 16:16:29 volumiopi avahi-daemon[597]: Interface wlan0.IPv4 no longer relevant for mDNS. May 31 16:16:29 volumiopi dhcpcd[681]: wlan0: deleting route to 192.168.1.0/24 May 31 16:16:29 volumiopi dhcpcd[681]: wlan0: deleting default route via 192.168.1.1 May 31 16:16:29 volumiopi volumio[988]: info: Discovery: A device disappeared from network May 31 16:16:29 volumiopi volumio[988]: info: Discovery: Device volumio disappeared from network May 31 16:16:29 volumiopi volumio[988]: info: Discovery: A device disappeared from network May 31 16:16:29 volumiopi volumio[1388]: ....................................++++ May 31 16:16:29 volumiopi volumio[1388]: e is 65537 (0x010001) May 31 16:16:29 volumiopi dhcpcd[681]: wlan0: carrier acquired May 31 16:16:29 volumiopi volumio[1388]: writing RSA key May 31 16:16:29 volumiopi dhcpcd[681]: wlan0: IAID eb:ff:ed:67 May 31 16:16:29 volumiopi dhcpcd[681]: wlan0: probing address 192.168.1.121/24 May 31 16:16:30 volumiopi dhcpcd[681]: wlan0: soliciting an IPv6 router May 31 16:16:30 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 16:16:30 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 16:16:30 volumiopi volumio[988]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 16:16:30 volumiopi ntpd[792]: Deleting interface #3 wlan0, 192.168.1.121#123, interface stats: received=86, sent=88, dropped=0, active_time=78 secs May 31 16:16:30 volumiopi ntpd[792]: 103.131.151.20 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 172.237.12.44 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 23.81.40.154 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 129.250.35.250 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 202.181.103.212 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 45.77.20.103 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 167.179.119.205 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 108.160.132.224 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 162.159.200.1 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 45.76.211.39 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 160.16.113.133 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 129.250.35.251 local addr 192.168.1.121 -> May 31 16:16:30 volumiopi ntpd[792]: 162.159.200.123 local addr 192.168.1.121 -> May 31 16:16:33 volumiopi volumio[988]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 16:16:33 volumiopi volumio[988]: Error: send ENETUNREACH 255.255.255.255:3483 May 31 16:16:33 volumiopi volumio[988]: at doSend (dgram.js:692:16) May 31 16:16:33 volumiopi volumio[988]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 31 16:16:33 volumiopi volumio[988]: at afterDns (dgram.js:638:5) May 31 16:16:33 volumiopi volumio[988]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 31 16:16:33 volumiopi volumio[988]: errno: -101, May 31 16:16:33 volumiopi volumio[988]: code: 'ENETUNREACH', May 31 16:16:33 volumiopi volumio[988]: syscall: 'send', May 31 16:16:33 volumiopi volumio[988]: address: '255.255.255.255', May 31 16:16:33 volumiopi volumio[988]: port: 3483 May 31 16:16:33 volumiopi volumio[988]: } May 31 16:16:33 volumiopi volumio[988]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 16:16:34 volumiopi dhcpcd[681]: wlan0: using static address 192.168.1.121/24 May 31 16:16:34 volumiopi avahi-daemon[597]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.121. May 31 16:16:34 volumiopi dhcpcd[681]: wlan0: adding route to 192.168.1.0/24 May 31 16:16:34 volumiopi dhcpcd[681]: wlan0: adding default route via 192.168.1.1 May 31 16:16:34 volumiopi avahi-daemon[597]: New relevant interface wlan0.IPv4 for mDNS. May 31 16:16:34 volumiopi avahi-daemon[597]: Registering new address record for 192.168.1.121 on wlan0.IPv4. May 31 16:16:35 volumiopi sudo[1993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-31 16:15 May 31 16:16:35 volumiopi sudo[1993]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"