-- Logs begin at Sun 2026-01-11 15:07:25 EET, end at Sun 2026-01-11 15:09:23 EET. -- Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: SME: Trying to authenticate with d0:ee:07:61:ac:86 (SSID='WIFI5' freq=5180 MHz) Jan 11 15:08:00 volumio2 kernel: wlan0: authenticate with d0:ee:07:61:ac:86 Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: Trying to associate with d0:ee:07:61:ac:86 (SSID='WIFI5' freq=5180 MHz) Jan 11 15:08:00 volumio2 kernel: wlan0: send auth to d0:ee:07:61:ac:86 (try 1/3) Jan 11 15:08:00 volumio2 kernel: wlan0: authenticated Jan 11 15:08:00 volumio2 kernel: wlan0: associate with d0:ee:07:61:ac:86 (try 1/3) Jan 11 15:08:00 volumio2 kernel: wlan0: RX AssocResp from d0:ee:07:61:ac:86 (capab=0x831 status=0 aid=1) Jan 11 15:08:00 volumio2 kernel: wlan0: associated Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: Associated with d0:ee:07:61:ac:86 Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 11 15:08:00 volumio2 volumio[1272]: info: Loading plugin "network"... Jan 11 15:08:00 volumio2 volumio[1272]: info: Refreshing Cached IP Addresses Jan 11 15:08:00 volumio2 sudo[1506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 15:08:00 volumio2 sudo[1506]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:00 volumio2 sudo[1508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 15:08:00 volumio2 sudo[1508]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:00 volumio2 sudo[1506]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:00 volumio2 sudo[1508]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:00 volumio2 volumio[1272]: info: Loading plugin "services"... Jan 11 15:08:00 volumio2 volumio[1272]: info: Loading plugin "alsa_controller"... Jan 11 15:08:00 volumio2 sudo[1526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 15:08:00 volumio2 sudo[1526]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: WPA: Key negotiation completed with d0:ee:07:61:ac:86 [PTK=CCMP GTK=CCMP] Jan 11 15:08:00 volumio2 wpa_supplicant[1187]: wlan0: CTRL-EVENT-CONNECTED - Connection to d0:ee:07:61:ac:86 completed [id=0 id_str=] Jan 11 15:08:00 volumio2 dhcpcd[848]: wlan0: carrier acquired Jan 11 15:08:00 volumio2 dhcpcd[848]: wlan0: IAID 24:d6:1b:da Jan 11 15:08:01 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "wizard"... Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "networkfs"... Jan 11 15:08:01 volumio2 volumio[1272]: info: Starting Udev Watcher for removable devices Jan 11 15:08:01 volumio2 volumio[1272]: info: Ignoring mount for partition: boot Jan 11 15:08:01 volumio2 volumio[1272]: info: Ignoring mount for partition: volumio Jan 11 15:08:01 volumio2 volumio[1272]: info: Ignoring mount for partition: volumio_data Jan 11 15:08:01 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "volumio_command_line_client"... Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "upnp"... Jan 11 15:08:01 volumio2 volumio[1272]: info: [1768136881146] Starting Upmpd Daemon Jan 11 15:08:01 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "my_music"... Jan 11 15:08:01 volumio2 volumio-remote-updater[757]: [2026-01-11 15:08:01] [connect] Successful connection Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "mpd"... Jan 11 15:08:01 volumio2 dhcpcd[848]: wlan0: rebinding lease of 192.168.1.51 Jan 11 15:08:01 volumio2 dhcpcd[848]: wlan0: soliciting an IPv6 router Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "upnp_browser"... Jan 11 15:08:01 volumio2 volumio[1272]: info: Loading plugin "alarm-clock"... Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "airplay_emulation"... Jan 11 15:08:02 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "last_100"... Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "webradio"... Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "i2s_dacs"... Jan 11 15:08:02 volumio2 volumio[1272]: info: I2S DAC not set, start Auto-detection Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "volumiodiscovery"... Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** For more information see Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 15:08:02 volumio2 volumio[1272]: *** WARNING *** For more information see Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** For more information see Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 15:08:02 volumio2 node[1272]: *** WARNING *** For more information see Jan 11 15:08:02 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 15:08:02 volumio2 volumio[1272]: info: Discovery: Started advertising with name: Volumio2 Jan 11 15:08:02 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "jellyfin"... Jan 11 15:08:02 volumio2 volumio[1272]: info: Loading plugin "jellyfin_server"... Jan 11 15:08:03 volumio2 volumio[1272]: info: Loading plugin "spop"... Jan 11 15:08:03 volumio2 kernel: rtw_8821ce 0000:03:00.0: timed out to flush queue 2 Jan 11 15:08:03 volumio2 kernel: rtw_8821ce 0000:03:00.0: timed out to flush queue 2 Jan 11 15:08:03 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:08:03 volumio2 volumio-time-update[774]: volumio-time-update-util: Date not found in response Jan 11 15:08:03 volumio2 volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Jan 11 15:08:04 volumio2 volumio[1272]: info: Loading plugin "squeezelite_mc"... Jan 11 15:08:04 volumio2 volumio[1272]: info: Loading plugin "youtube2"... Jan 11 15:08:04 volumio2 dhcpcd[848]: wlan0: probing address 192.168.1.51/24 Jan 11 15:08:05 volumio2 volumio[1272]: info: Loading plugin "ytcr"... Jan 11 15:08:07 volumio2 volumio[1272]: info: Loading plugin "ytmusic"... Jan 11 15:08:07 volumio2 volumio[1272]: info: Loading plugin "now_playing"... Jan 11 15:08:08 volumio2 volumio[1272]: info: Loading plugin "outputs"... Jan 11 15:08:08 volumio2 volumio[1272]: info: Loading plugin "albumart"... Jan 11 15:08:08 volumio2 volumio[1272]: info: Plugin example_plugin is not enabled Jan 11 15:08:08 volumio2 volumio[1272]: info: Loading plugin "inputs"... Jan 11 15:08:08 volumio2 volumio[1272]: info: Loading plugin "updater_comm"... Jan 11 15:08:08 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:08:08 volumio2 volumio-time-update[774]: volumio-time-update-util: Date not found in response Jan 11 15:08:08 volumio2 volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Jan 11 15:08:08 volumio2 volumio[1272]: Forking 1 albumart workers Jan 11 15:08:09 volumio2 volumio[1272]: info: Plugin mpdemulation is not enabled Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "rest_api"... Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "websocket"... Jan 11 15:08:09 volumio2 volumio[1272]: info: Starting Socket.io Server version 2.3.0 Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "fusiondsp"... Jan 11 15:08:09 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin fusiondsp Jan 11 15:08:09 volumio2 volumio[1272]: Starting albumart workers Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "RoonBridge"... Jan 11 15:08:09 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin RoonBridge Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "dstmmix"... Jan 11 15:08:09 volumio2 dhcpcd[848]: wlan0: leased 192.168.1.51 for 86400 seconds Jan 11 15:08:09 volumio2 avahi-daemon[752]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.51. Jan 11 15:08:09 volumio2 dhcpcd[848]: wlan0: adding route to 192.168.1.0/24 Jan 11 15:08:09 volumio2 dhcpcd[848]: wlan0: adding default route via 192.168.1.1 Jan 11 15:08:09 volumio2 avahi-daemon[752]: New relevant interface wlan0.IPv4 for mDNS. Jan 11 15:08:09 volumio2 avahi-daemon[752]: Registering new address record for 192.168.1.51 on wlan0.IPv4. Jan 11 15:08:09 volumio2 sudo[1526]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:09 volumio2 volumio[1272]: info: Loading plugin "minidlna"... Jan 11 15:08:09 volumio2 ntpd[1090]: ntpd exiting on signal 15 (Terminated) Jan 11 15:08:09 volumio2 systemd[1]: Stopping Network Time Service... Jan 11 15:08:09 volumio2 systemd[1]: ntp.service: Succeeded. Jan 11 15:08:09 volumio2 systemd[1]: Stopped Network Time Service. Jan 11 15:08:09 volumio2 systemd[1]: Starting Network Time Service... Jan 11 15:08:09 volumio2 ntpd[1690]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 11 15:08:09 volumio2 ntpd[1690]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jan 11 15:08:09 volumio2 ntpd[1696]: proto: precision = 0.084 usec (-23) Jan 11 15:08:09 volumio2 systemd[1]: Started Network Time Service. Jan 11 15:08:09 volumio2 ntpd[1696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 11 15:08:09 volumio2 ntpd[1696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 11 15:08:09 volumio2 ntpd[1696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1111 days ago Jan 11 15:08:09 volumio2 ntpd[1696]: Listen and drop on 0 v6wildcard [::]:123 Jan 11 15:08:09 volumio2 ntpd[1696]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 11 15:08:09 volumio2 ntpd[1696]: Listen normally on 2 lo 127.0.0.1:123 Jan 11 15:08:09 volumio2 ntpd[1696]: Listen normally on 3 wlan0 192.168.1.51:123 Jan 11 15:08:09 volumio2 ntpd[1696]: Listening on routing socket on fd #20 for interface updates Jan 11 15:08:09 volumio2 ntpd[1696]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 11 15:08:09 volumio2 ntpd[1696]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 11 15:08:09 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin minidlna Jan 11 15:08:10 volumio2 volumio[1272]: info: Plugin plexamp is not enabled Jan 11 15:08:10 volumio2 volumio[1272]: info: Loading plugin "squeezelite"... Jan 11 15:08:10 volumio2 volumio[1272]: info: [Squeezelite] Initiated plugin Jan 11 15:08:10 volumio2 volumio[1272]: info: Loading plugin "volroon"... Jan 11 15:08:10 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin volroon Jan 11 15:08:10 volumio2 volumio[1272]: info: Loading plugin "volusonic"... Jan 11 15:08:11 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin volusonic Jan 11 15:08:11 volumio2 volumio[1272]: info: Loading plugin "backup_restore"... Jan 11 15:08:11 volumio2 nmbd[1049]: [2026/01/11 15:08:11.185067, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 15:08:11 volumio2 nmbd[1049]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 11 15:08:11 volumio2 systemd[1]: Started Samba NMB Daemon. Jan 11 15:08:11 volumio2 systemd[1]: Starting Samba Winbind Daemon... Jan 11 15:08:11 volumio2 winbindd[1712]: [2026/01/11 15:08:11.355593, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 11 15:08:11 volumio2 winbindd[1712]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 11 15:08:11 volumio2 winbindd[1712]: [2026/01/11 15:08:11.358666, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 15:08:11 volumio2 systemd[1]: Started Samba Winbind Daemon. Jan 11 15:08:11 volumio2 winbindd[1712]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 11 15:08:11 volumio2 systemd[1]: Starting Samba SMB Daemon... Jan 11 15:08:11 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin backup_restore Jan 11 15:08:11 volumio2 volumio[1272]: info: Loading plugin "crossfader_switch"... Jan 11 15:08:11 volumio2 systemd[1]: Started Samba SMB Daemon. Jan 11 15:08:11 volumio2 smbd[1717]: [2026/01/11 15:08:11.603222, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 15:08:11 volumio2 smbd[1717]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 11 15:08:11 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin crossfader_switch Jan 11 15:08:11 volumio2 volumio[1272]: info: Loading plugin "Systeminfo"... Jan 11 15:08:11 volumio2 volumio[1272]: info: Loading plugin "peppymeterbasic"... Jan 11 15:08:12 volumio2 volumio[1272]: info: Loading plugin "peppyspectrum"... Jan 11 15:08:12 volumio2 volumio[1272]: info: Loading plugin "randomizer"... Jan 11 15:08:12 volumio2 volumio[1272]: info: Applying required configuration parameters for plugin randomizer Jan 11 15:08:12 volumio2 volumio[1272]: info: Loading i18n strings for locale ua Jan 11 15:08:12 volumio2 volumio[1272]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key DOWNLOAD. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. Jan 11 15:08:12 volumio2 volumio[1272]: Updating browse sources language Jan 11 15:08:12 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::initPlayerControls Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: Express server listening on port 3000 Jan 11 15:08:13 volumio2 volumio[1272]: [Metrics] WebUI: 15s 784.23ms Jan 11 15:08:13 volumio2 volumio[1272]: info: Setting Device type: x86 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::resetVolumioState Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::getcurrentVolume Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:13 volumio2 sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 15:08:13 volumio2 sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 sudo[1733]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 sudo[1737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 15:08:13 volumio2 volumio[1272]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jan 11 15:08:13 volumio2 volumio[1272]: info: Completed loading Core Plugins Jan 11 15:08:13 volumio2 sudo[1737]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 volumio[1272]: info: Preparing to generate the ALSA configuration file Jan 11 15:08:13 volumio2 sudo[1737]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 volumio[1272]: info: Volumio Network Manager: Network status updated: 0 Jan 11 15:08:13 volumio2 volumio[1272]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jan 11 15:08:13 volumio2 volumio[1272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 15:08:13 volumio2 volumio[1272]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:13 volumio2 volumio[1272]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:13 volumio2 volumio[1272]: info: Reading ALSA contributions from plugins. Jan 11 15:08:13 volumio2 volumio[1272]: info: VolumeController:: Volume=100 Mute =false Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::pushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioPushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::updateTrackBlock Jan 11 15:08:13 volumio2 volumio[1272]: info: CorePlayQueue::getTrackBlock Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 15:08:13 volumio2 volumio[1272]: info: Reloading queue from file Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::setRepeat null single undefined Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::pushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioPushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::setRandom null Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::pushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioPushState Jan 11 15:08:13 volumio2 volumio[1272]: info: VolumeController:: Volume=100 Mute =false Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreStateMachine::pushState Jan 11 15:08:13 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioPushState Jan 11 15:08:13 volumio2 volumio[1272]: info: Asound.conf file unchanged, so no further update is needed Jan 11 15:08:13 volumio2 volumio[1272]: info: Output device has changed, restarting MPD Jan 11 15:08:13 volumio2 sudo[1750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 15:08:13 volumio2 sudo[1750]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 systemd[1]: Started UPnP Renderer front-end to MPD. Jan 11 15:08:13 volumio2 sudo[1750]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 sudo[1754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 15:08:13 volumio2 sudo[1754]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 sudo[1754]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 volumio[1272]: info: Output device has changed, restarting Shairport Sync Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:13 volumio2 sudo[1757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 15:08:13 volumio2 sudo[1757]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 systemd[1]: Listening on mpd.socket. Jan 11 15:08:13 volumio2 systemd[1]: Starting Music Player Daemon... Jan 11 15:08:13 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Jan 11 15:08:13 volumio2 sudo[1762]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 15:08:13 volumio2 sudo[1762]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 sudo[1762]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 11 15:08:13 volumio2 sudo[1762]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: volroon::Output device has changed Jan 11 15:08:13 volumio2 volumio[1272]: info: ___________ START PLUGINS ___________ Jan 11 15:08:13 volumio2 volumio[1272]: info: ControllerMpd::onStart: Initializing MPD Jan 11 15:08:13 volumio2 volumio[1272]: info: Creating MPD Configuration file Jan 11 15:08:13 volumio2 sudo[1768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 15:08:13 volumio2 sudo[1768]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 sudo[1768]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:13 volumio2 volumio[1272]: info: [1768136893804] CoreMusicLibrary::Adding element Media Servers Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:13 volumio2 sudo[1771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 15:08:13 volumio2 sudo[1771]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:13 volumio2 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:13 volumio2 systemd[1]: mpd.service: Succeeded. Jan 11 15:08:13 volumio2 systemd[1]: Stopped Music Player Daemon. Jan 11 15:08:13 volumio2 systemd[1]: Starting Music Player Daemon... Jan 11 15:08:13 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:13 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:08:13 volumio2 sudo[1773]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 15:08:13 volumio2 sudo[1773]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:13 volumio2 sudo[1773]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 11 15:08:13 volumio2 sudo[1773]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:13 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:13 volumio2 volumio[1272]: info: [1768136893976] CoreMusicLibrary::Adding element Last_100 Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:13 volumio2 volumio[1272]: info: [1768136893979] CoreMusicLibrary::Adding element Webradio Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:13 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 15:08:13 volumio2 volumio[1272]: info: Initializing BBC Radios Jan 11 15:08:14 volumio2 volumio[1272]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:08:14 volumio2 volumio[1272]: info: Discovery: Getting this device information Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:14 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:14 volumio2 volumio[1272]: info: [1768136894096] CoreMusicLibrary::Adding element Jellyfin Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:14 volumio2 volumio[1272]: info: [jellyfin] Initialized plugin with device info: {"id":"01a5e55c-dda8-49b3-ab3b-5c5bd763a7d0","host":"http://192.168.1.51","name":"Volumio2","type":"device","serviceName":"Volumio","state":{"status":"stop","volume":100,"mute":false,"artist":"Áóìáîêñ","track":"Ñàìîëüîò³ê","albumart":"http://192.168.1.51/albumart?cacheid=153&web=%C3%81%C3%B3%C3%AC%C3%A1%C3%AE%C3%AA%C3%B1/%C3%91%C3%A5%C3%B0%C3%A5%C3%A4%C3%AD%C2%B3%C3%A9%20%C3%A2%C2%B3%C3%AA/extralarge&path=%2FINTERNAL%2F%D0%9C%D1%83%D0%B7%D1%8B%D0%BA%D0%B0%2F%D0%91%D1%83%D0%BC%D0%B1%D0%BE%D0%BA%D1%81%2F%D0%91%D1%83%D0%BC%D0%B1%D0%BE%D0%BA%D1%81%20-%20%D0%A1%D0%B5%D1%80%D0%B5%D0%B4%D0%BD%D1%96%D0%B9%20%D0%B2%D1%96%D0%BA%2C2011&metadata=false"}} Jan 11 15:08:14 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl start jellyfin || true Jan 11 15:08:14 volumio2 sudo[1797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start jellyfin Jan 11 15:08:14 volumio2 sudo[1797]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:14 volumio2 volumio[1272]: info: Creating Spotify config file Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:14 volumio2 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. Jan 11 15:08:14 volumio2 systemd[1]: Starting Jellyfin... Jan 11 15:08:14 volumio2 systemd[1]: Started Jellyfin. Jan 11 15:08:14 volumio2 sudo[1797]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:14 volumio2 volumio[1272]: info: [squeezelite_mc] Starting proxy server... Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:14 volumio2 volumio[1272]: info: [1768136894259] CoreMusicLibrary::Adding element YouTube2 Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:14 volumio2 volumio[1272]: info: [1768136894293] CoreMusicLibrary::Adding element YouTube Music Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:14 volumio2 volumio[1272]: Cannot find translation for source YouTube Music Jan 11 15:08:14 volumio2 volumio[1272]: info: [now-playing] ConfigUpdater: config is up to date. Jan 11 15:08:14 volumio2 volumio[1272]: info: Loading i18n strings for locale ua Jan 11 15:08:14 volumio2 volumio[1272]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key DOWNLOAD. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:14 volumio2 volumio[1272]: info: FusionDsp - mixtype--------------------- Hardware Jan 11 15:08:14 volumio2 sudo[1802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 11 15:08:14 volumio2 sudo[1802]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:08:14 volumio2 volumio[1272]: info: Loading i18n strings for locale ua Jan 11 15:08:14 volumio2 volumio[1272]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:14 volumio2 systemd[1]: Started RoonBridge. Jan 11 15:08:14 volumio2 sudo[1809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Jan 11 15:08:14 volumio2 sudo[1802]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:14 volumio2 sudo[1809]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key DOWNLOAD. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:14 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. Jan 11 15:08:14 volumio2 systemd[1]: Stopping Logitech Media Server... Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Jan 11 15:08:14 volumio2 systemd[1]: logitechmediaserver.service: Succeeded. Jan 11 15:08:14 volumio2 systemd[1]: Stopped Logitech Media Server. Jan 11 15:08:14 volumio2 systemd[1]: Started Logitech Media Server. Jan 11 15:08:14 volumio2 sudo[1809]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:14 volumio2 sudo[1825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 15:08:14 volumio2 sudo[1825]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:14 volumio2 systemd[1]: Reloading. Jan 11 15:08:14 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:15 volumio2 sudo[1840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 11 15:08:15 volumio2 sudo[1840]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:15 volumio2 volumio[1272]: info: volroon::Roon API Services Started Jan 11 15:08:15 volumio2 volumio[1272]: info: Loading i18n strings for locale ua Jan 11 15:08:15 volumio2 volumio[1272]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key DOWNLOAD. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. Jan 11 15:08:15 volumio2 volumio[1272]: Updating browse sources language Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube Music Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube Music Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:15 volumio2 volumio[1272]: info: [1768136895421] CoreMusicLibrary::Adding element Volusonic Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube Music Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Volusonic Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 15:08:15 volumio2 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. Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 15:08:15 volumio2 volumio[1272]: info: [1768136895673] CoreMusicLibrary::Adding element Randomizer Jan 11 15:08:15 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Jellyfin Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube2 Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source YouTube Music Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Volusonic Jan 11 15:08:15 volumio2 volumio[1272]: Cannot find translation for source Randomizer Jan 11 15:08:15 volumio2 volumio[1272]: info: Volumio Calling Home Jan 11 15:08:15 volumio2 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. Jan 11 15:08:15 volumio2 systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jan 11 15:08:15 volumio2 volumio[1272]: info: [squeezelite_mc] Proxy server started on port 38047 Jan 11 15:08:15 volumio2 volumio[1272]: info: Preparing to generate the ALSA configuration file Jan 11 15:08:15 volumio2 mpd[1785]: Jan 11 15:08 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 15:08:16 volumio2 volumio[1272]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 15:08:16 volumio2 volumio[1272]: info: [now-playing] App is listening on port 4004. Jan 11 15:08:16 volumio2 volumio[1272]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.021 Warn: get lock file path: /tmp/.rnbgem0- Jan 11 15:08:16 volumio2 sudo[1825]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:16 volumio2 volumio[1272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 15:08:16 volumio2 volumio[1272]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:16 volumio2 volumio[1272]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:16 volumio2 volumio[1272]: info: Reading ALSA contributions from plugins. Jan 11 15:08:16 volumio2 volumio-remote-updater[757]: [2026-01-11 15:08:16] [connect] Successful connection Jan 11 15:08:16 volumio2 sudo[1840]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:16 volumio2 volumio[1272]: info: [jellyfin-poller] Polled http://192.168.1.51:8096/web/index.html#/home.htm: offline Jan 11 15:08:16 volumio2 volumio[1272]: info: minidlna: Found miniDLNA version 1.2.1 Jan 11 15:08:16 volumio2 volumio[1272]: info: minidlna: Starting minidlna.service Jan 11 15:08:16 volumio2 volumio[1272]: info: logitechmediaserver started Jan 11 15:08:16 volumio2 sudo[1853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jan 11 15:08:16 volumio2 sudo[1853]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:16 volumio2 volumio[1272]: info: MPD Permissions set Jan 11 15:08:16 volumio2 volumio[1272]: info: MPD Permissions set Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.594 Trace: [childprocess] using unix child process Jan 11 15:08:16 volumio2 volumio[1272]: info: Upmpdcli Daemon Started Jan 11 15:08:16 volumio2 systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Jan 11 15:08:16 volumio2 sudo[1853]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.735 Debug: PathForResource, filename: ../.update Jan 11 15:08:16 volumio2 systemd[1]: Started Music Player Daemon. Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.784 Debug: PathForResource, candidate: /data/plugins/music_service/volroon/RoonBridge/Bridge/../.update Jan 11 15:08:16 volumio2 sudo[1771]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:16 volumio2 sudo[1757]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:16 volumio2 volroon[1810]: Initializing Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.809 Debug: PathForResource, filename: RAATServer Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.810 Debug: PathForResource, candidate: /data/plugins/music_service/volroon/RoonBridge/Bridge/RAATServer Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.811 Debug: PathForResource, filename: RoonBridgeHelper Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.811 Debug: PathForResource, candidate: /data/plugins/music_service/volroon/RoonBridge/Bridge/RoonBridgeHelper Jan 11 15:08:16 volumio2 volumio[1272]: info: camilladsp spawned new process with pid 1870, instance 1, run: true Jan 11 15:08:16 volumio2 volumio[1272]: info: camilladsp service started and running in background, instance 1 Jan 11 15:08:16 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.874 Info: Starting /data/plugins/music_service/volroon/RoonBridge/Bridge/RoonBridgeHelper Jan 11 15:08:16 volumio2 volroon[1810]: 00:00:00.963 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/volroon/RoonBridge/Bridge/RAATServer Jan 11 15:08:16 volumio2 volumio[1272]: cannot open device 'volumioHw': Device or resource busy Jan 11 15:08:16 volumio2 volumio[1272]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jan 11 15:08:16 volumio2 volumio[1272]: cannot open device 'volumioHw': Device or resource busy Jan 11 15:08:17 volumio2 volumio[1272]: info: FusionDsp loaded Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:08:17 volumio2 sudo[1893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 11 15:08:17 volumio2 sudo[1893]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:17 volumio2 volumio[1272]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 11 15:08:17 volumio2 volumio[1272]: info: Adding Signal Path Element [object Object] Jan 11 15:08:17 volumio2 volumio[1272]: info: Adding fusiondspeq DSP Signal Path Element Jan 11 15:08:17 volumio2 volumio[1272]: info: FusionDsp - ---- installed callbackRead Jan 11 15:08:17 volumio2 volumio[1272]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 11 15:08:17 volumio2 volroon[1810]: Not Running (.o) Jan 11 15:08:17 volumio2 systemd[1]: Started FusionDsp Daemon. Jan 11 15:08:17 volumio2 sudo[1893]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:17 volumio2 volumio[1272]: info: minidlna: systemctl start minidlna.service succeeded. Jan 11 15:08:17 volumio2 volumio[1272]: info: VolumeController:: Volume=100 Mute =false Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:17 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreStateMachine::pushState Jan 11 15:08:17 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::volumioPushState Jan 11 15:08:17 volumio2 volumio[1272]: info: [squeezelite_mc] Server discovery started Jan 11 15:08:17 volumio2 volumio[1272]: info: [squeezelite_mc] Player finder started Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:17 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 15:08:17 volumio2 volumio[1272]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 15:08:17 volumio2 volumio[1272]: info: ::Roon Bridge has successfully started Jan 11 15:08:17 volumio2 volumio[1272]: info: squeezelite reloaded Jan 11 15:08:17 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true Jan 11 15:08:17 volumio2 sudo[1905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart squeezelite Jan 11 15:08:17 volumio2 sudo[1905]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:18 volumio2 volumio[1272]: info: Spotify config file written Jan 11 15:08:18 volumio2 systemd[1]: Starting Squeezelite lightweight headless Squeezebox emulator... Jan 11 15:08:18 volumio2 systemd[1]: Started Squeezelite lightweight headless Squeezebox emulator. Jan 11 15:08:18 volumio2 sudo[1905]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:18 volumio2 sudo[1908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin Jan 11 15:08:18 volumio2 sudo[1908]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:17] [INF] [1] Main: Jellyfin version: 10.9.6 Jan 11 15:08:18 volumio2 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. Jan 11 15:08:18 volumio2 volumio[1272]: Upnp client error: Error: This socket has been ended by the other party Jan 11 15:08:18 volumio2 sudo[1913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 15:08:18 volumio2 sudo[1908]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:18 volumio2 sudo[1913]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Environment Variables: ["[JELLYFIN_LOG_DIR, /opt/jellyfin/log]"] Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [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"] Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Operating system: Debian GNU/Linux 10 (buster) Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Architecture: X64 Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: 64-Bit Process: True Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: User Interactive: True Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Processor count: 2 Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Program data path: /opt/jellyfin/data Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Log directory path: /opt/jellyfin/log Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Config directory path: /opt/jellyfin/config Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Cache path: /opt/jellyfin/cache Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Web resources path: /opt/jellyfin/jellyfin_10.9.6/jellyfin-web Jan 11 15:08:18 volumio2 jellyfin[1799]: [15:08:18] [INF] [1] Main: Application directory: /opt/jellyfin/jellyfin_10.9.6/ Jan 11 15:08:18 volumio2 systemd[1]: Started go-librespot Daemon. Jan 11 15:08:18 volumio2 go-librespot[1918]: Librespot-go daemon starting... Jan 11 15:08:18 volumio2 sudo[1913]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:18 volumio2 volumio-remote-updater[757]: [2026-01-11 15:08:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1768136896 101 Jan 11 15:08:18 volumio2 volumio[1272]: 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 Jan 11 15:08:18 volumio2 volumio[1272]: info: MPD running with PID1785 Jan 11 15:08:18 volumio2 volumio[1272]: ,establishing connection Jan 11 15:08:18 volumio2 volumio[1272]: error: [squeezelite_mc] Could not query supported ALSA formats for card 5 because device is busy Jan 11 15:08:18 volumio2 volroon[1810]: Running Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 go-librespot[1918]: time="2026-01-11T15:08:18+02:00" level=info msg="generated new device id: 2c09515bef9898f1777ed6c0410d2ad103f5dc18" Jan 11 15:08:18 volumio2 go-librespot[1918]: time="2026-01-11T15:08:18+02:00" level=debug msg="stored credentials found for 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:18 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 15:08:19 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:19 volumio2 volumio[1272]: info: No need to fix Spotify hosts Jan 11 15:08:19 volumio2 volumio[1272]: error: MPD error: The expression evaluated to a falsy value: Jan 11 15:08:19 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:19 volumio2 volumio[1272]: error: The expression evaluated to a falsy value: Jan 11 15:08:19 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:19 volumio2 volumio[1272]: error: MPD error: The expression evaluated to a falsy value: Jan 11 15:08:19 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:19 volumio2 volumio[1272]: error: The expression evaluated to a falsy value: Jan 11 15:08:19 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:19 volumio2 volumio[1272]: info: squeezelite started Jan 11 15:08:19 volumio2 volumio[1272]: info: camilladsp spawned new process with pid 1946, instance 1, run: true Jan 11 15:08:19 volumio2 volumio[1272]: error: updateQueue error: null Jan 11 15:08:19 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:19 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:19 volumio2 volroon[1810]: 00:00:00.072 Warn: get lock file path: /tmp/.rnbhgem0- Jan 11 15:08:19 volumio2 sudo[1957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:19 volumio2 sudo[1957]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:19 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:19 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:19 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:19 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:19 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:19 volumio2 sudo[1957]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:19 volumio2 sudo[1960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:19 volumio2 sudo[1960]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:20 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:20 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:20 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:20 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:20 volumio2 sudo[1960]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:20 volumio2 sudo[1965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:20 volumio2 sudo[1965]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:20 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true Jan 11 15:08:20 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:20 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:20 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:20 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:20 volumio2 sudo[1965]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:20 volumio2 volumio[1272]: info: Shairport-Sync Started Jan 11 15:08:20 volumio2 volumio[1272]: Error adding Membership: Error: addMembership EINVAL Jan 11 15:08:20 volumio2 volumio[1272]: info: Shairport-Sync Started Jan 11 15:08:20 volumio2 volumio[1272]: info: Shairport-Sync Started Jan 11 15:08:20 volumio2 volumio[1272]: info: Asound.conf file unchanged, so no further update is needed Jan 11 15:08:20 volumio2 volumio[1272]: info: Output device has changed, restarting MPD Jan 11 15:08:20 volumio2 sudo[1972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin Jan 11 15:08:20 volumio2 sudo[1972]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:20 volumio2 sudo[1972]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:20 volumio2 sudo[1977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 15:08:20 volumio2 sudo[1977]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:20 volumio2 sudo[1977]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:20 volumio2 volumio[1272]: info: Output device has changed, restarting Shairport Sync Jan 11 15:08:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:20 volumio2 jellyfin[1799]: [15:08:20] [INF] [1] Emby.Server.Implementations.AppBase.BaseConfigurationManager: Setting cache path: /opt/jellyfin/cache Jan 11 15:08:20 volumio2 sudo[1980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 15:08:20 volumio2 sudo[1980]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:20 volumio2 systemd[1]: Stopping Music Player Daemon... Jan 11 15:08:20 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Jan 11 15:08:21 volumio2 systemd[1]: mpd.service: Succeeded. Jan 11 15:08:21 volumio2 systemd[1]: Stopped Music Player Daemon. Jan 11 15:08:21 volumio2 systemd[1]: Starting Music Player Daemon... Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 volumio[1272]: info: volroon::Output device has changed Jan 11 15:08:21 volumio2 volumio[1272]: info: Preparing to generate the ALSA configuration file Jan 11 15:08:21 volumio2 jellyfin[1799]: [15:08:21] [INF] [1] Emby.Server.Implementations.ApplicationHost: Loading assemblies Jan 11 15:08:21 volumio2 sudo[1997]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 15:08:21 volumio2 sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:21 volumio2 sudo[1997]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:21 volumio2 volumio[1753]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 11 15:08:21 volumio2 sudo[2021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 15:08:21 volumio2 sudo[2021]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:21 volumio2 volumio[1272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 15:08:21 volumio2 volumio[1272]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:21 volumio2 volumio[1272]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:21 volumio2 volumio[1272]: info: Reading ALSA contributions from plugins. Jan 11 15:08:21 volumio2 volumio[1272]: info: Volumio Network Manager: Network status updated: 2 Jan 11 15:08:21 volumio2 volumio[1272]: error: Upnp client error: Error: This socket has been ended by the other party Jan 11 15:08:21 volumio2 volumio[1272]: info: MPD Permissions set Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 sudo[2024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:21 volumio2 sudo[2024]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:21 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 15:08:22 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:22 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:22 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true Jan 11 15:08:22 volumio2 sudo[2033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:22 volumio2 sudo[2033]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:22 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:22 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:22 volumio2 volumio[1272]: info: Asound.conf file unchanged, so no further update is needed Jan 11 15:08:22 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:22 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:22 volumio2 sudo[2033]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:22 volumio2 volumio[1272]: info: Output device has changed, restarting MPD Jan 11 15:08:22 volumio2 sudo[2036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin Jan 11 15:08:22 volumio2 sudo[2036]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:22 volumio2 sudo[2036]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:22 volumio2 sudo[2042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 15:08:22 volumio2 sudo[2042]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:22 volumio2 sudo[2042]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:22 volumio2 volumio[1272]: info: Output device has changed, restarting Shairport Sync Jan 11 15:08:22 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:22 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:22 volumio2 sudo[2046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 15:08:22 volumio2 sudo[2046]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:22 volumio2 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:22 volumio2 systemd[1]: mpd.service: Succeeded. Jan 11 15:08:22 volumio2 systemd[1]: Stopped Music Player Daemon. Jan 11 15:08:22 volumio2 systemd[1]: Starting Music Player Daemon... Jan 11 15:08:22 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:22 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [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"] Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Defined LAN exclusions: [] Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [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"] Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Filtered interface addresses: ["127.0.0.1", "192.168.1.51"] Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Bind Addresses ["0.0.0.0"] Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Remote IP filter is Allowlist Jan 11 15:08:23 volumio2 jellyfin[1799]: [15:08:23] [INF] [1] Jellyfin.Networking.Manager.NetworkManager: Filtered subnets: [] Jan 11 15:08:23 volumio2 sudo[2054]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 15:08:23 volumio2 sudo[2054]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:23 volumio2 sudo[2054]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: volroon::Output device has changed Jan 11 15:08:23 volumio2 volumio[1272]: info: Preparing to generate the ALSA configuration file Jan 11 15:08:23 volumio2 volumio[1272]: info: go-librespot daemon successfully initialized Jan 11 15:08:23 volumio2 volumio[1272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 15:08:23 volumio2 volumio[1272]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:23 volumio2 volumio[1272]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 15:08:23 volumio2 volumio[1272]: info: Reading ALSA contributions from plugins. Jan 11 15:08:23 volumio2 volumio[1272]: info: MPD Permissions set Jan 11 15:08:23 volumio2 volumio[1272]: info: Shairport-Sync Started Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 15:08:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:23 volumio2 volumio[1272]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jan 11 15:08:23 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:23 volumio2 volumio[1272]: info: Asound.conf file unchanged, so no further update is needed Jan 11 15:08:23 volumio2 volumio[1272]: info: Output device has changed, restarting MPD Jan 11 15:08:23 volumio2 sudo[2074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:23 volumio2 sudo[2074]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:23 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:23 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:23 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:23 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:23 volumio2 sudo[2077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 15:08:23 volumio2 sudo[2077]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:23 volumio2 sudo[2074]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:24 volumio2 sudo[2077]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:24 volumio2 volumio[1272]: info: Output device has changed, restarting Shairport Sync Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:24 volumio2 sudo[2082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 15:08:24 volumio2 sudo[2082]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:24 volumio2 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:24 volumio2 systemd[1]: mpd.service: Succeeded. Jan 11 15:08:24 volumio2 systemd[1]: Stopped Music Player Daemon. Jan 11 15:08:24 volumio2 systemd[1]: Starting Music Player Daemon... Jan 11 15:08:24 volumio2 volumio[1272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Jan 11 15:08:24 volumio2 sudo[2088]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 15:08:24 volumio2 sudo[2088]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:24 volumio2 sudo[2088]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:24 volumio2 volumio[1272]: info: volroon::Output device has changed Jan 11 15:08:24 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 volumio[1272]: error: MPD error: Error: This socket has been ended by the other party Jan 11 15:08:24 volumio2 volumio[1272]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 11 15:08:24 volumio2 sudo[2097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin Jan 11 15:08:24 volumio2 sudo[2097]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:24 volumio2 volumio[1272]: info: MPD Permissions set Jan 11 15:08:24 volumio2 volumio[1272]: info: Shairport-Sync Started Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:24 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:24 volumio2 sudo[2097]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:25 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:25 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 15:08:25 volumio2 volroon[1810]: 00:00:09.200 Warn: exception starting raatserver: System.Net.Sockets.SocketException (0x80004005): Connection refused Jan 11 15:08:25 volumio2 volroon[1810]: at System.Net.Sockets.TcpClient..ctor (System.String hostname, System.Int32 port) [0x0006d] in <08911f3881ec4a92acc8fdc4d13b73bf>:0 Jan 11 15:08:25 volumio2 volroon[1810]: at Sooloos.RAATServer.ConnectOrStartAndWaitForExit (System.String path, System.String args, System.Action`1[T] status, Base.ChildProcess& p) [0x00165] in <5529660cb9214b5a92e49e1607b30d50>:0 Jan 11 15:08:25 volumio2 volroon[1810]: Not Running (.o) Jan 11 15:08:25 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:25 volumio2 volroon[1810]: 00:00:09.274 Debug: PathForResource, filename: ../.update Jan 11 15:08:25 volumio2 volumio[1272]: info: Starting Shairport Sync Jan 11 15:08:25 volumio2 volroon[1810]: 00:00:09.289 Debug: PathForResource, candidate: /data/plugins/music_service/volroon/RoonBridge/Bridge/../.update Jan 11 15:08:25 volumio2 sudo[2106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 15:08:25 volumio2 sudo[2106]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:25 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 15:08:25 volumio2 volumio[1272]: error: Upnp client error: Error: This socket has been ended by the other party Jan 11 15:08:25 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jan 11 15:08:25 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:25 volumio2 systemd[1]: shairport-sync.service: Start request repeated too quickly. Jan 11 15:08:25 volumio2 systemd[1]: shairport-sync.service: Failed with result 'start-limit-hit'. Jan 11 15:08:25 volumio2 systemd[1]: Failed to start Shairport Sync - AirPlay Audio Receiver. Jan 11 15:08:25 volumio2 sudo[2106]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:25 volumio2 volumio[1272]: info: Shairport-sync error: Error: Command failed: /usr/bin/sudo /bin/systemctl restart shairport-sync Jan 11 15:08:25 volumio2 volumio[1272]: Job for shairport-sync.service failed. Jan 11 15:08:25 volumio2 volumio[1272]: See "systemctl status shairport-sync.service" and "journalctl -xe" for details. Jan 11 15:08:25 volumio2 volumio[1272]: info: [jellyfin_server] Executing /usr/bin/sudo /bin/systemctl status jellyfin || true Jan 11 15:08:25 volumio2 sudo[2109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status jellyfin Jan 11 15:08:25 volumio2 sudo[2109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:25 volumio2 sudo[2109]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:25 volumio2 volumio[1753]: ........................................................................................++++ Jan 11 15:08:26 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:08:26 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 15:08:26 volumio2 volumio[1272]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 15:08:26 volumio2 volumio[1272]: error: [squeezelite_mc] Could not query supported ALSA formats for card 5 because device is busy Jan 11 15:08:26 volumio2 volumio[1272]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 11 15:08:26 volumio2 volumio[1272]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 15:08:26 volumio2 volumio[1272]: info: Initializing connection to go-librespot Websocket Jan 11 15:08:26 volumio2 volumio[1753]: ........++++ Jan 11 15:08:26 volumio2 volumio[1753]: e is 65537 (0x010001) Jan 11 15:08:26 volumio2 sudo[2117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 15:08:26 volumio2 sudo[2117]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:26 volumio2 volumio[1753]: writing RSA key Jan 11 15:08:26 volumio2 sudo[2117]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:26 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 11 15:08:26 volumio2 mpd[2092]: Jan 11 15:08 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 15:08:27 volumio2 volroon[1810]: 00:00:11.297 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/volroon/RoonBridge/Bridge/RAATServer Jan 11 15:08:27 volumio2 volroon[1810]: Running Jan 11 15:08:27 volumio2 volumio[1272]: Upnp client error: Error: This socket has been ended by the other party Jan 11 15:08:27 volumio2 systemd[1]: Started Music Player Daemon. Jan 11 15:08:27 volumio2 sudo[1980]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:27 volumio2 sudo[2046]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:27 volumio2 systemd[1]: Started MPD Monitor Service. Jan 11 15:08:27 volumio2 sudo[2082]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:27 volumio2 sudo[2021]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:27 volumio2 sudo[2024]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:27 volumio2 mpd_monitor.sh[2148]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 15:08:27 volumio2 volumio[1272]: info: Successfully started MPD Monitor Jan 11 15:08:27 volumio2 volumio[1272]: info: Successfully started MPD Monitor Jan 11 15:08:27 volumio2 volumio[1272]: error: MPD error: The expression evaluated to a falsy value: Jan 11 15:08:27 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:27 volumio2 volumio[1272]: error: The expression evaluated to a falsy value: Jan 11 15:08:27 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:27 volumio2 volumio[1272]: error: MPD error: The expression evaluated to a falsy value: Jan 11 15:08:27 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:27 volumio2 volumio[1272]: error: The expression evaluated to a falsy value: Jan 11 15:08:27 volumio2 volumio[1272]: assert.ok(self.idling) Jan 11 15:08:27 volumio2 volumio[1272]: error: updateQueue error: null Jan 11 15:08:28 volumio2 ntpd[1696]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 11 15:08:30 volumio2 sudo[2322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 15:08:30 volumio2 sudo[2322]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:30 volumio2 systemd[1]: Stopping MPD Monitor Service... Jan 11 15:08:30 volumio2 systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:30 volumio2 systemd[1]: mpd_monitor.service: Succeeded. Jan 11 15:08:30 volumio2 systemd[1]: Stopped MPD Monitor Service. Jan 11 15:08:31 volumio2 sudo[2335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 15:08:31 volumio2 systemd[1]: Started MPD Monitor Service. Jan 11 15:08:31 volumio2 sudo[2322]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:31 volumio2 mpd_monitor.sh[2337]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 15:08:31 volumio2 sudo[2335]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:31 volumio2 volumio[1272]: info: Successfully started MPD Monitor Jan 11 15:08:31 volumio2 systemd[1]: Stopping MPD Monitor Service... Jan 11 15:08:31 volumio2 systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:31 volumio2 systemd[1]: mpd_monitor.service: Succeeded. Jan 11 15:08:31 volumio2 systemd[1]: Stopped MPD Monitor Service. Jan 11 15:08:31 volumio2 sudo[2348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 15:08:31 volumio2 sudo[2348]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:08:31 volumio2 systemd[1]: Started MPD Monitor Service. Jan 11 15:08:31 volumio2 sudo[2335]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:31 volumio2 mpd_monitor.sh[2353]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 15:08:31 volumio2 volumio[1272]: info: Successfully started MPD Monitor Jan 11 15:08:31 volumio2 systemd[1]: Stopping MPD Monitor Service... Jan 11 15:08:31 volumio2 systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Jan 11 15:08:31 volumio2 systemd[1]: mpd_monitor.service: Succeeded. Jan 11 15:08:31 volumio2 systemd[1]: Stopped MPD Monitor Service. Jan 11 15:08:31 volumio2 systemd[1]: Started MPD Monitor Service. Jan 11 15:08:31 volumio2 sudo[2348]: pam_unix(sudo:session): session closed for user root Jan 11 15:08:31 volumio2 mpd_monitor.sh[2366]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 15:08:31 volumio2 volumio[1272]: info: Successfully started MPD Monitor Jan 11 15:08:31 volumio2 volumio[1272]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jan 11 15:08:31 volumio2 volumio-time-update[774]: volumio-time-update-util: Date not found in response Jan 11 15:08:31 volumio2 volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Jan 11 15:08:32 volumio2 volumio[1272]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Jan 11 15:08:32 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 11 15:08:32 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 11 15:08:32 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 11 15:08:32 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 11 15:08:32 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetVisibleSources Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:33 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 11 15:08:33 volumio2 volumio[1272]: info: Received Get System Info Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:08:33 volumio2 volumio[1272]: info: Discovery: Getting this device information Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:33 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:33 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:33 volumio2 volumio[1272]: info: Listing playlists Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:08:33 volumio2 volumio[1272]: info: Received Get System Info Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:08:33 volumio2 volumio[1272]: info: Discovery: Getting this device information Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:33 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:33 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 11 15:08:33 volumio2 volumio[1272]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 11 15:08:35 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 11 15:08:36 volumio2 go-librespot[1918]: time="2026-01-11T15:08:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jan 11 15:08:36 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 15:08:36 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 15:08:36 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:08:39 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 15:08:39 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 11 15:08:39 volumio2 systemd[1]: Stopped go-librespot Daemon. Jan 11 15:08:39 volumio2 systemd[1]: Started go-librespot Daemon. Jan 11 15:08:39 volumio2 go-librespot[2448]: Librespot-go daemon starting... Jan 11 15:08:39 volumio2 go-librespot[2448]: time="2026-01-11T15:08:39+02:00" level=info msg="generated new device id: 9950b008327b051b02aa57785c0bb9406609aded" Jan 11 15:08:39 volumio2 go-librespot[2448]: time="2026-01-11T15:08:39+02:00" level=debug msg="stored credentials found for 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:08:41 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 11 15:08:44 volumio2 volumio[1272]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.874&uuid=ed70a44c887eefde0eab7e68ff9950f7" http://updates.volumio.org/downloader-v1/track-device Jan 11 15:08:44 volumio2 volumio[1272]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 11 15:08:44 volumio2 volumio[1272]: Dload Upload Total Spent Left Speed Jan 11 15:08:44 volumio2 volumio[1272]: [1.5K blob data] Jan 11 15:08:44 volumio2 volumio[1272]: retrying in 5 seconds, trial 0 Jan 11 15:08:44 volumio2 volumio[1272]: info: Volumio Calling Home Jan 11 15:08:44 volumio2 volumio[1272]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jan 11 15:08:44 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:44 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 15:08:44 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:08:44 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 11 15:08:45 volumio2 volumio[1272]: error: Plugin music_service ytcr failed to complete 'onStart' in a timely fashion Jan 11 15:08:45 volumio2 volumio[1272]: info: ------------------------------------------- Jan 11 15:08:45 volumio2 volumio[1272]: info: ----- MyVolumio plugins startup ---- Jan 11 15:08:45 volumio2 volumio[1272]: info: ------------------------------------------- Jan 11 15:08:45 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 15:08:46 volumio2 volumio[1272]: info: [jellyfin-poller] Polled http://192.168.1.51:8096/web/index.html#/home.htm: offline Jan 11 15:08:46 volumio2 ntpd[1696]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 11 15:08:47 volumio2 volumio[1272]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.51","name":"volumio2","ver":"8.5.2","uuid":"2177359a-299b-470a-aaa3-3cf6cb2ca85c","jsonPort":"9000","cliPort":"9090"} Jan 11 15:08:48 volumio2 volumio[1272]: info: [squeezelite_mc] Notification listener started Jan 11 15:08:48 volumio2 volumio[1272]: info: [squeezelite_mc] Getting players connected to volumio2 (192.168.1.51) Jan 11 15:08:48 volumio2 volumio[1272]: info: [squeezelite_mc] Players connected to volumio2 (192.168.1.51): [{"id":"c0:4b:24:d6:1b:da","uuid":null,"ip":"192.168.1.51","name":"volumio2","server":{"ip":"192.168.1.51","name":"volumio2","ver":"8.5.2","uuid":"2177359a-299b-470a-aaa3-3cf6cb2ca85c","jsonPort":"9000","cliPort":"9090"}}] Jan 11 15:08:48 volumio2 volumio[1272]: info: [squeezelite_mc] Player found: {"id":"c0:4b:24:d6:1b:da","uuid":null,"ip":"192.168.1.51","name":"volumio2","server":{"ip":"192.168.1.51","name":"volumio2","ver":"8.5.2","uuid":"2177359a-299b-470a-aaa3-3cf6cb2ca85c","jsonPort":"9000","cliPort":"9090"}} Jan 11 15:08:49 volumio2 volumio[1272]: (node:1272) UnhandledPromiseRejectionWarning: TypeError: Cannot read property '0' of undefined Jan 11 15:08:49 volumio2 volumio[1272]: at PlayerStatusMonitor._PlayerStatusMonitor_parsePlayerStatusResult (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:180:37) Jan 11 15:08:49 volumio2 volumio[1272]: at PlayerStatusMonitor._PlayerStatusMonitor_getStatusAndEmit (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:118:129) Jan 11 15:08:49 volumio2 volumio[1272]: at runMicrotasks () Jan 11 15:08:49 volumio2 volumio[1272]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Jan 11 15:08:49 volumio2 volumio[1272]: at async PlayerStatusMonitor.start (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:47:9) Jan 11 15:08:49 volumio2 volumio[1272]: at async PlayerFinder. (/data/plugins/music_service/squeezelite_mc/dist/index.js:686:13) Jan 11 15:08:49 volumio2 volumio[1272]: (Use `node --trace-warnings ...` to show where the warning was created) Jan 11 15:08:49 volumio2 volumio[1272]: (node:1272) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) Jan 11 15:08:49 volumio2 volumio[1272]: (node:1272) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Jan 11 15:08:49 volumio2 volumio[1272]: info: Discovery: adding 01a5e55c-dda8-49b3-ab3b-5c5bd763a7d0 Jan 11 15:08:49 volumio2 volumio[1272]: info: Discovery: Found device Volumio2 Jan 11 15:08:49 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:08:49 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:08:55 volumio2 volumio-time-update[774]: volumio-time-update-util: Date not found in response Jan 11 15:08:55 volumio2 volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Jan 11 15:08:57 volumio2 go-librespot[2448]: time="2026-01-11T15:08:57+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jan 11 15:08:57 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 15:08:57 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 15:09:00 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:09:00 volumio2 systemd[1]: Starting Clean php session files... Jan 11 15:09:00 volumio2 systemd[1]: phpsessionclean.service: Succeeded. Jan 11 15:09:00 volumio2 systemd[1]: Started Clean php session files. Jan 11 15:09:01 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 15:09:01 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 11 15:09:01 volumio2 systemd[1]: Stopped go-librespot Daemon. Jan 11 15:09:01 volumio2 systemd[1]: Started go-librespot Daemon. Jan 11 15:09:01 volumio2 go-librespot[2558]: Librespot-go daemon starting... Jan 11 15:09:01 volumio2 go-librespot[2558]: time="2026-01-11T15:09:01+02:00" level=info msg="generated new device id: c8d6c8418f5bedeb79ae04236be6bdc0570ec4ab" Jan 11 15:09:01 volumio2 go-librespot[2558]: time="2026-01-11T15:09:01+02:00" level=debug msg="stored credentials found for 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:09:04 volumio2 ntpd[1696]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 11 15:09:05 volumio2 volumio[1272]: error: MyVolumio Plugin failed to start in a timely fashion Jan 11 15:09:05 volumio2 volumio[1272]: [Metrics] CommandRouter: 67s 745.46ms Jan 11 15:09:05 volumio2 volumio[1272]: info: CoreCommandRouter::volumiosetStartupVolume Jan 11 15:09:05 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 15:09:05 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:09:05 volumio2 volumio[1272]: info: CoreCommandRouter::Close All Modals sent Jan 11 15:09:05 volumio2 volumio[1272]: info: CoreCommandRouter::Close All Modals sent Jan 11 15:09:06 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 11 15:09:06 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 11 15:09:06 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 11 15:09:07 volumio2 volumio[1272]: error: [yt-cast-receiver] (YouTube) Failed to obtain lounge token with screen Id from stored MDX context (oornnbsnv2ra9r8f4htbalg0qt): Jan 11 15:09:07 volumio2 volumio[1272]: (ConnectionError) (YouTube) Connection error in getting lounge token Jan 11 15:09:07 volumio2 volumio[1272]: Error info: { Jan 11 15:09:07 volumio2 volumio[1272]: url: 'https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch' Jan 11 15:09:07 volumio2 volumio[1272]: } Jan 11 15:09:07 volumio2 volumio[1272]: --->(FetchError) request to https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch failed, reason: getaddrinfo ENOTFOUND www.youtube.com Jan 11 15:09:07 volumio2 volumio[1272]: Stack trace: Jan 11 15:09:07 volumio2 volumio[1272]: ConnectionError: (YouTube) Connection error in getting lounge token Jan 11 15:09:07 volumio2 volumio[1272]: at Session._Session_getLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:435:15) Jan 11 15:09:07 volumio2 volumio[1272]: at runMicrotasks () Jan 11 15:09:07 volumio2 volumio[1272]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Jan 11 15:09:07 volumio2 volumio[1272]: at async Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:131:31) Jan 11 15:09:07 volumio2 volumio[1272]: at async Promise.all (index 0) Jan 11 15:09:07 volumio2 volumio[1272]: at async YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:110:13) Jan 11 15:09:07 volumio2 volumio[1272]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Jan 11 15:09:07 volumio2 volumio[1272]: Going to generate fresh screen Id and try again... Jan 11 15:09:08 volumio2 volumio[1272]: error: [yt-cast-receiver] (YouTube Music) Failed to obtain lounge token with screen Id from stored MDX context (6qo02smcqsr5d8pjac53ve6cl0): Jan 11 15:09:08 volumio2 volumio[1272]: (ConnectionError) (YouTube Music) Connection error in getting lounge token Jan 11 15:09:08 volumio2 volumio[1272]: Error info: { Jan 11 15:09:08 volumio2 volumio[1272]: url: 'https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch' Jan 11 15:09:08 volumio2 volumio[1272]: } Jan 11 15:09:08 volumio2 volumio[1272]: --->(FetchError) request to https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch failed, reason: getaddrinfo ENOTFOUND www.youtube.com Jan 11 15:09:08 volumio2 volumio[1272]: Stack trace: Jan 11 15:09:08 volumio2 volumio[1272]: ConnectionError: (YouTube Music) Connection error in getting lounge token Jan 11 15:09:08 volumio2 volumio[1272]: at Session._Session_getLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:435:15) Jan 11 15:09:08 volumio2 volumio[1272]: at runMicrotasks () Jan 11 15:09:08 volumio2 volumio[1272]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Jan 11 15:09:08 volumio2 volumio[1272]: at async Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:131:31) Jan 11 15:09:08 volumio2 volumio[1272]: at async Promise.all (index 1) Jan 11 15:09:08 volumio2 volumio[1272]: at async YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:110:13) Jan 11 15:09:08 volumio2 volumio[1272]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Jan 11 15:09:08 volumio2 volumio[1272]: Going to generate fresh screen Id and try again... Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 11 15:09:08 volumio2 volumio[1272]: info: camilladsp stopping service pid 1946... Jan 11 15:09:08 volumio2 volumio[1272]: info: camilladsp service terminated, instance 1 Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 11 15:09:08 volumio2 volumio[1272]: info: camilladsp service started and running in background, instance 1 Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 11 15:09:08 volumio2 volumio[1272]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 11 15:09:08 volumio2 volumio[1272]: info: camilladsp spawned new process with pid 2585, instance 1, run: true Jan 11 15:09:09 volumio2 jellyfin[1799]: [15:09:09] [INF] [1] Emby.Server.Implementations.Plugins.PluginManager: Loaded plugin: TMDb 10.9.6.0 Jan 11 15:09:09 volumio2 jellyfin[1799]: [15:09:09] [INF] [1] Emby.Server.Implementations.Plugins.PluginManager: Loaded plugin: Studio Images 10.9.6.0 Jan 11 15:09:09 volumio2 jellyfin[1799]: [15:09:09] [INF] [1] Emby.Server.Implementations.Plugins.PluginManager: Loaded plugin: OMDb 10.9.6.0 Jan 11 15:09:09 volumio2 jellyfin[1799]: [15:09:09] [INF] [1] Emby.Server.Implementations.Plugins.PluginManager: Loaded plugin: MusicBrainz 10.9.6.0 Jan 11 15:09:09 volumio2 jellyfin[1799]: [15:09:09] [INF] [1] Emby.Server.Implementations.Plugins.PluginManager: Loaded plugin: AudioDB 10.9.6.0 Jan 11 15:09:10 volumio2 jellyfin[1799]: [15:09:10] [INF] [1] Main: Kestrel is listening on 0.0.0.0 Jan 11 15:09:11 volumio2 jellyfin[1799]: [15:09:11] [INF] [1] Jellyfin.Networking.PortForwardingHost: Starting NAT discovery Jan 11 15:09:12 volumio2 volumio[1272]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.874&uuid=ed70a44c887eefde0eab7e68ff9950f7" http://updates.volumio.org/downloader-v1/track-device Jan 11 15:09:12 volumio2 volumio[1272]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 11 15:09:12 volumio2 volumio[1272]: Dload Upload Total Spent Left Speed Jan 11 15:09:12 volumio2 volumio[1272]: [1.5K blob data] Jan 11 15:09:12 volumio2 volumio[1272]: retrying in 5 seconds, trial 1 Jan 11 15:09:12 volumio2 volumio[1272]: info: Volumio Calling Home Jan 11 15:09:12 volumio2 volumio[1272]: info: BOOT COMPLETED Jan 11 15:09:13 volumio2 jellyfin[1799]: [15:09:13] [WRN] [1] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: The WebRootPath was not found: /wwwroot. Static files may be unavailable. Jan 11 15:09:13 volumio2 jellyfin[1799]: [15:09:13] [INF] [1] Emby.Server.Implementations.ApplicationHost: Running startup tasks Jan 11 15:09:13 volumio2 jellyfin[1799]: [15:09:13] [INF] [1] Emby.Server.Implementations.ScheduledTasks.TaskManager: Daily trigger for Створити Trickplay-зображення set to fire at 2026-01-12 03:00:00.000 +02:00, which is 11:50:46.7302163 from now. Jan 11 15:09:13 volumio2 jellyfin[1799]: [15:09:13] [INF] [1] Emby.Server.Implementations.ScheduledTasks.TaskManager: Daily trigger for Створити ескізи розділів set to fire at 2026-01-12 02:00:00.000 +02:00, which is 10:50:46.7063369 from now. Jan 11 15:09:13 volumio2 jellyfin[1799]: [15:09:13] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Found ffmpeg version 6.0.1 Jan 11 15:09:14 volumio2 volumio[1272]: info: camilladsp spawned new process with pid 2620, instance 1, run: true Jan 11 15:09:14 volumio2 jellyfin[1799]: [15:09:14] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available decoders: ["libdav1d", "av1", "av1_cuvid", "av1_qsv", "h264", "h264_qsv", "h264_cuvid", "hevc", "hevc_qsv", "hevc_cuvid", "mpeg2video", "mpeg2_qsv", "mpeg2_cuvid", "mpeg4", "mpeg4_cuvid", "msmpeg4", "vc1_qsv", "vc1_cuvid", "vp8", "libvpx", "vp8_cuvid", "vp8_qsv", "vp9", "libvpx-vp9", "vp9_cuvid", "vp9_qsv", "aac", "ac3", "dca", "flac", "mp3", "truehd"] Jan 11 15:09:14 volumio2 jellyfin[1799]: [15:09:14] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available encoders: ["libsvtav1", "av1_nvenc", "av1_qsv", "av1_amf", "av1_vaapi", "libx264", "h264_amf", "h264_nvenc", "h264_qsv", "h264_v4l2m2m", "h264_vaapi", "libx265", "hevc_amf", "hevc_nvenc", "hevc_qsv", "hevc_vaapi", "mjpeg_qsv", "mjpeg_vaapi", "mpeg4", "msmpeg4", "libvpx", "libvpx-vp9", "aac", "libfdk_aac", "ac3", "alac", "dca", "flac", "libmp3lame", "libopus", "truehd", "libvorbis", "srt"] Jan 11 15:09:14 volumio2 jellyfin[1799]: [15:09:14] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available filters: ["deinterlace_qsv", "deinterlace_vaapi", "hwupload_cuda", "hwupload_vaapi", "libplacebo", "overlay_opencl", "overlay_qsv", "overlay_vaapi", "overlay_vulkan", "overlay_cuda", "procamp_vaapi", "scale_cuda", "scale_opencl", "scale_qsv", "scale_vaapi", "scale_vulkan", "tonemap_cuda", "tonemap_opencl", "tonemap_vaapi", "vpp_qsv", "yadif_cuda", "zscale", "alphasrc"] Jan 11 15:09:15 volumio2 jellyfin[1799]: [15:09:15] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: Available hwaccel types: ["cuda", "vaapi", "qsv", "drm", "opencl", "vulkan"] Jan 11 15:09:15 volumio2 volumio[1272]: info: Volumio called home Jan 11 15:09:16 volumio2 jellyfin[1799]: [15:09:16] [INF] [1] MediaBrowser.MediaEncoding.Encoder.MediaEncoder: FFmpeg: /usr/lib/jellyfin-ffmpeg/ffmpeg Jan 11 15:09:16 volumio2 jellyfin[1799]: [15:09:16] [INF] [13] Emby.Server.Implementations.ScheduledTasks.TaskManager: Очистити колекції і списки відтворення Completed after 0 minute(s) and 0 seconds Jan 11 15:09:16 volumio2 jellyfin[1799]: [15:09:16] [INF] [1] Emby.Server.Implementations.ApplicationHost: ServerId: 84aa2766180e43ba989ef1e637e024d0 Jan 11 15:09:16 volumio2 jellyfin[1799]: [15:09:16] [INF] [1] Emby.Server.Implementations.ApplicationHost: Core startup complete Jan 11 15:09:16 volumio2 jellyfin[1799]: [15:09:16] [INF] [1] Main: Startup complete 0:01:00.4396861 Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 15:09:16 volumio2 go-librespot[2558]: time="2026-01-11T15:09:16+02:00" level=debug msg="new websocket client" Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 11 15:09:16 volumio2 volumio[1272]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 11 15:09:16 volumio2 volumio[1272]: info: Connection to go-librespot Websocket established Jan 11 15:09:16 volumio2 volumio[1272]: info: [jellyfin-poller] Polled http://192.168.1.51:8096/web/index.html#/home.htm: offline (system info unavailable) Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 11 15:09:16 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jan 11 15:09:16 volumio2 volumio[1272]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 11 15:09:17 volumio2 ntpd[1696]: Soliciting pool server 91.231.182.17 Jan 11 15:09:17 volumio2 ntpd[1696]: Soliciting pool server 217.156.67.138 Jan 11 15:09:17 volumio2 volumio[1272]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 11 15:09:17 volumio2 ntpd[1696]: Soliciting pool server 91.236.251.14 Jan 11 15:09:17 volumio2 ntpd[1696]: Soliciting pool server 91.236.251.34 Jan 11 15:09:18 volumio2 jellyfin[1799]: [15:09:18] [INF] [12] Emby.Server.Implementations.ScheduledTasks.TaskManager: Оновити плагіни Completed after 0 minute(s) and 1 seconds Jan 11 15:09:18 volumio2 volumio-time-update[774]: volumio-time-update-util: Date not found in response Jan 11 15:09:18 volumio2 volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin bluetooth to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin multiroom to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin metavolumio to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin cd_controller to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 11 15:09:18 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 11 15:09:18 volumio2 ntpd[1696]: Soliciting pool server 188.191.239.24 Jan 11 15:09:18 volumio2 ntpd[1696]: Soliciting pool server 217.12.206.12 Jan 11 15:09:18 volumio2 ntpd[1696]: Soliciting pool server 91.236.251.13 Jan 11 15:09:19 volumio2 volumio[1272]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 11 15:09:19 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 11 15:09:19 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:09:19 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:09:19 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:09:19 volumio2 volumio[1272]: info: Starting MyVolumio Remote Streaming Endpoints Jan 11 15:09:19 volumio2 volumio[1272]: info: MyVolumio login type: Token Jan 11 15:09:19 volumio2 ntpd[1696]: Soliciting pool server 162.159.200.1 Jan 11 15:09:19 volumio2 volumio[1272]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 11 15:09:19 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 11 15:09:19 volumio2 go-librespot[2558]: time="2026-01-11T15:09:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jan 11 15:09:19 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 15:09:19 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 15:09:19 volumio2 ntpd[1696]: Soliciting pool server 78.30.216.96 Jan 11 15:09:19 volumio2 ntpd[1696]: Soliciting pool server 91.209.24.19 Jan 11 15:09:19 volumio2 ntpd[1696]: Soliciting pool server 94.158.46.150 Jan 11 15:09:19 volumio2 volumio[1272]: info: Starting Streaming Service Transparent Proxy Jan 11 15:09:20 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 11 15:09:20 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 11 15:09:20 volumio2 volumio[1272]: info: Streaming services startup Jan 11 15:09:20 volumio2 volumio[1272]: info: Starting Streaming Daemon Jan 11 15:09:20 volumio2 sudo[2668]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 11 15:09:20 volumio2 sudo[2668]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:09:20 volumio2 sudo[2668]: pam_unix(sudo:session): session closed for user root Jan 11 15:09:20 volumio2 volumio[1272]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 11 15:09:20 volumio2 jellyfin[1799]: [15:09:20] [INF] [15] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory /data/INTERNAL/Музыка Jan 11 15:09:20 volumio2 volumio[1272]: info: Getting Spotify volume Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:09:20 volumio2 volumio[1272]: info: Received Get System Info Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:09:20 volumio2 volumio[1272]: info: Discovery: Getting this device information Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:09:20 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:09:20 volumio2 volumio[1272]: (node:1272) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 15:09:20 volumio2 volumio[1272]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jan 11 15:09:20 volumio2 volumio[1272]: (node:1272) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 5) Jan 11 15:09:20 volumio2 volumio[1272]: error: Cannot start Volumio Streaming Daemon Jan 11 15:09:20 volumio2 volumio[1272]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 11 15:09:20 volumio2 volumio[1272]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 11 15:09:20 volumio2 volumio[1272]: info: Connection to go-librespot Websocket closed Jan 11 15:09:20 volumio2 volumio[1272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:09:20 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:09:20 volumio2 volumio[1272]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 11 15:09:20 volumio2 volumio[1272]: SPOTIFY: SPOTIFY VOLUME undefined Jan 11 15:09:20 volumio2 volumio[1272]: SPOTIFY: VOLUMIO VOLUME 100 Jan 11 15:09:20 volumio2 volumio[1272]: info: Aligning Spotify Volume to Volumio Volume Jan 11 15:09:20 volumio2 volumio[1272]: info: CoreCommandRouter::volumioGetState Jan 11 15:09:20 volumio2 volumio[1272]: info: CorePlayQueue::getTrack 0 Jan 11 15:09:20 volumio2 volumio[1272]: info: Setting Spotify Volume from Volumio: 100 Jan 11 15:09:20 volumio2 volumio[1272]: error: MyVolumio Custom Token format not valid, refreshing it Jan 11 15:09:20 volumio2 ntpd[1696]: Soliciting pool server 91.236.251.38 Jan 11 15:09:21 volumio2 volumio[1272]: STREAMING PROXY: Starting server on port 3245 Jan 11 15:09:21 volumio2 volumio[1272]: Node JS runtime: 14 Jan 11 15:09:21 volumio2 volumio[1272]: info: MyVolumio login type: Token Jan 11 15:09:21 volumio2 volumio[1272]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 11 15:09:21 volumio2 ntpd[1696]: Soliciting pool server 91.236.251.234 Jan 11 15:09:22 volumio2 volumio[1272]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 11 15:09:22 volumio2 volumio[1272]: info: Sending Spotify command with payload to local API: /player/volume Jan 11 15:09:22 volumio2 volumio[1272]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 15:09:22 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 11 15:09:22 volumio2 volumio[1272]: info: MyVolumio login type: Token Jan 11 15:09:22 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 15:09:22 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 11 15:09:22 volumio2 systemd[1]: Stopped go-librespot Daemon. Jan 11 15:09:22 volumio2 systemd[1]: Started go-librespot Daemon. Jan 11 15:09:22 volumio2 go-librespot[2691]: Librespot-go daemon starting... Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=info msg="generated new device id: c7c091aaee120b709dcdd7d76594f111877a6609" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="stored credentials found for 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="zeroconf server listening on port 42175" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="obtained new client token: AABzAq5JmLNbR+NueMgW7JgJCBAtXqwhwC2+/ue3a2Ov9Biaxm/PWbmaVAmmb4DbU+dsYnK02XUa7i0wdJQgp7Ktgh3gQk+viZ7OGIi4fg10KcHiYqkAQjbJpJCqeQH7gPNfMqP3qVI7UuHydgcBv5h6w03CiUASFDSZY9+lZSsAXouuFEklPjgfZ/gt4pitjo73gqY8gcwD22E7VOahdZSzVQztbaW8OueUsSoIPC8lTscQ1fXZFxMOHes3" Jan 11 15:09:22 volumio2 volumio[1272]: info: MyVolumio token set successfully Jan 11 15:09:22 volumio2 volumio[1272]: info: MYVOLUMIO: Adding device Jan 11 15:09:22 volumio2 volumio[1272]: info: MYVOLUMIO: Evaluating Server Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Jan 11 15:09:22 volumio2 go-librespot[2691]: time="2026-01-11T15:09:22+02:00" level=debug msg="completed keyexchange" Jan 11 15:09:22 volumio2 ntpd[1696]: Soliciting pool server 2001:67c:440:824:91:236:251:24 Jan 11 15:09:23 volumio2 volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Jan 11 15:09:23 volumio2 volumio-time-update[774]: volumio-time-update-util: Setting system time to: 2026-01-11 15:09:23 Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="completed challenge" Jan 11 15:09:23 volumio2 sudo[2722]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-01-11 15:09:23 Jan 11 15:09:23 volumio2 sudo[2722]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:09:23 volumio2 volumio[1272]: info: MyVolumio status changed Jan 11 15:09:23 volumio2 volumio[1272]: info: Streaming services startup Jan 11 15:09:23 volumio2 volumio[1272]: info: Starting Streaming Daemon Jan 11 15:09:23 volumio2 volumio[1272]: info: Removing browser output: myVolumio user plan is not superstar Jan 11 15:09:23 volumio2 volumio[1272]: info: Removing audio output: Jan 11 15:09:23 volumio2 volumio[1272]: info: Stoppping Tunnel 1 Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="authenticated as 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:09:23 volumio2 volumio[1272]: info: Initializing connection to go-librespot Websocket Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="new websocket client" Jan 11 15:09:23 volumio2 volumio[1272]: info: Connection to go-librespot Websocket established Jan 11 15:09:23 volumio2 sudo[2728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 11 15:09:23 volumio2 sudo[2726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 11 15:09:23 volumio2 sudo[2726]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:09:23 volumio2 sudo[2728]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 15:09:23 volumio2 dbus-daemon[771]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.18' (uid=0 pid=2723 comm="timedatectl set-time 2026-01-11 15:09:23 ") Jan 11 15:09:23 volumio2 systemd[1]: Starting Time & Date Service... Jan 11 15:09:23 volumio2 sudo[2726]: pam_unix(sudo:session): session closed for user root Jan 11 15:09:23 volumio2 volumio[1272]: error: Cannot start Volumio Streaming Daemon Jan 11 15:09:23 volumio2 volumio[1272]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 11 15:09:23 volumio2 volumio[1272]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 11 15:09:23 volumio2 sudo[2728]: pam_unix(sudo:session): session closed for user root Jan 11 15:09:23 volumio2 volumio[1272]: info: Remote SSH Stopped Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="authenticated as 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:09:23 volumio2 dbus-daemon[771]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 11 15:09:23 volumio2 systemd[1]: Started Time & Date Service. Jan 11 15:09:23 volumio2 systemd-timedated[2731]: Changed local time to Sun Jan 11 15:09:23 2026 Jan 11 15:09:23 volumio2 sudo[2722]: pam_unix(sudo:session): session closed for user root Jan 11 15:09:23 volumio2 volumio-time-update[774]: volumio-time-update-util: System time updated successfully. Jan 11 15:09:23 volumio2 systemd[1]: Started Volumio Time Update Utility. Jan 11 15:09:23 volumio2 systemd[1]: Reached target Multi-User System. Jan 11 15:09:23 volumio2 systemd[1]: Reached target Graphical Interface. Jan 11 15:09:23 volumio2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 11 15:09:23 volumio2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 11 15:09:23 volumio2 systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 11 15:09:23 volumio2 systemd[1]: Startup finished in 5.387s (firmware) + 2.596s (loader) + 8.468s (kernel) + 1min 58.210s (userspace) = 2min 14.661s. Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="dealer connection opened" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="initializing zeroconf session, username: 31jxmlwjw63hm3cpzjfc7mx4zev4" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="autoplay enabled: false" Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="received connection id: MWU5YzFjZmMtZjQ3ZC00ZTVjLTgzNzMtZjJjNDEzMTFiYTQ5K2RlYWxlcit0Y3A6Ly8wYWNhNDA2Yi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNjZCQjVGNkY5NkU2N0FFMEZFODQzMENENUI4NTc5OUE5QkE3NkY4RUJBQzU2REJGNkIyMTg1OENEM0NFODUxMw==" Jan 11 15:09:23 volumio2 volumio[1272]: error: Failed to ping endpoint au1.myvolumio.org : unknown error Jan 11 15:09:23 volumio2 volumio[1272]: info: Setting Geolocation for MyVolumio to eu7 Jan 11 15:09:23 volumio2 volumio[1272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 15:09:23 volumio2 volumio[1272]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 15:09:23 volumio2 volumio[1272]: Error: Unable to resolve or reject the same promise twice Jan 11 15:09:23 volumio2 volumio[1272]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 11 15:09:23 volumio2 volumio[1272]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jan 11 15:09:23 volumio2 volumio[1272]: at Socket.emit (events.js:412:35) Jan 11 15:09:23 volumio2 volumio[1272]: at endReadableNT (internal/streams/readable.js:1333:12) Jan 11 15:09:23 volumio2 volumio[1272]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jan 11 15:09:23 volumio2 volumio[1272]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 15:09:23 volumio2 go-librespot[2691]: time="2026-01-11T15:09:23+02:00" level=debug msg="put connect state because NEW_DEVICE" Jan 11 15:09:23 volumio2 sudo[2744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-11 15:08 Jan 11 15:09:23 volumio2 sudo[2744]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 07:31:13 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="674d725e3f749f2a23785c9f94a28aa3"