-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2025-01-21 20:48:08 CET. -- Jan 21 20:47:00 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:00] [connect] Successful connection Jan 21 20:47:00 volumio-jh wpa_supplicant[853]: wlan0: Trying to associate with SSID 'UBI3' Jan 21 20:47:00 volumio-jh wpa_supplicant[853]: wlan0: Associated with d0:21:f9:80:23:7a Jan 21 20:47:00 volumio-jh wpa_supplicant[853]: wlan0: CTRL-EVENT-CONNECTED - Connection to d0:21:f9:80:23:7a completed [id=1 id_str=] Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: carrier acquired Jan 21 20:47:00 volumio-jh wpa_supplicant[853]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: connected to Access Point `UBI3' Jan 21 20:47:00 volumio-jh wpa_supplicant[853]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: IAID eb:52:a5:a8 Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: carrier lost Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: carrier acquired Jan 21 20:47:00 volumio-jh dhcpcd[913]: wlan0: IAID eb:52:a5:a8 Jan 21 20:47:01 volumio-jh dhcpcd[913]: wlan0: soliciting an IPv6 router Jan 21 20:47:01 volumio-jh volumio[1040]: info: MYVOLUMIO Environment detected Jan 21 20:47:01 volumio-jh volumio[1040]: info: Plugin folders cleanup Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning into folder /volumio/app/plugins/ Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category audio_interface Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category miscellanea Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category music_service Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category plugins.json Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category system_controller Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category user_interface Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning into folder /data/plugins/ Jan 21 20:47:01 volumio-jh volumio[1040]: info: Scanning category music_service Jan 21 20:47:01 volumio-jh volumio[1040]: info: Plugin folders cleanup completed Jan 21 20:47:01 volumio-jh volumio[1040]: info: ------------------------------------------- Jan 21 20:47:01 volumio-jh volumio[1040]: info: ----- Core plugins startup ---- Jan 21 20:47:01 volumio-jh volumio[1040]: info: ------------------------------------------- Jan 21 20:47:01 volumio-jh volumio[1040]: info: Loading plugins from folder /volumio/app/plugins/ Jan 21 20:47:01 volumio-jh volumio[1040]: info: Adding plugin upnp to MyMusic Plugins Jan 21 20:47:01 volumio-jh volumio[1040]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 21 20:47:01 volumio-jh volumio[1040]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 21 20:47:01 volumio-jh volumio[1040]: info: Loading plugins from folder /data/plugins/ Jan 21 20:47:01 volumio-jh volumio[1040]: info: Loading plugin "system"... Jan 21 20:47:01 volumio-jh volumio[1040]: info: Loading plugin "appearance"... Jan 21 20:47:01 volumio-jh dhcpcd[913]: wlan0: rebinding lease of 192.168.23.65 Jan 21 20:47:01 volumio-jh dhcpcd[913]: wlan0: probing address 192.168.23.65/24 Jan 21 20:47:03 volumio-jh volumio[1040]: info: Loading plugin "network"... Jan 21 20:47:03 volumio-jh volumio[1040]: info: Refreshing Cached IP Addresses Jan 21 20:47:03 volumio-jh sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:03 volumio-jh sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:03 volumio-jh sudo[1140]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:03 volumio-jh sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:03 volumio-jh sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:03 volumio-jh sudo[1142]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:03 volumio-jh volumio[1040]: info: Loading plugin "services"... Jan 21 20:47:03 volumio-jh volumio[1040]: info: Loading plugin "alsa_controller"... Jan 21 20:47:03 volumio-jh sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 21 20:47:03 volumio-jh sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:03 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:03 volumio-jh volumio[1040]: info: Loading plugin "wizard"... Jan 21 20:47:03 volumio-jh volumio[1040]: info: Loading plugin "networkfs"... Jan 21 20:47:03 volumio-jh volumio[1040]: info: Starting Udev Watcher for removable devices Jan 21 20:47:03 volumio-jh volumio[1040]: info: Ignoring mount for partition: boot Jan 21 20:47:03 volumio-jh volumio[1040]: info: Ignoring mount for partition: volumio Jan 21 20:47:03 volumio-jh volumio[1040]: info: Ignoring mount for partition: volumio_data Jan 21 20:47:03 volumio-jh volumio[1040]: error: Cannot associate FS Label, not mounting Jan 21 20:47:03 volumio-jh volumio[1040]: info: Mounting Device SYSTEM Jan 21 20:47:03 volumio-jh sudo[1169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/SYSTEM -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:03 volumio-jh sudo[1169]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:03 volumio-jh kernel: FAT-fs (sda2): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Jan 21 20:47:03 volumio-jh sudo[1169]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:03 volumio-jh kernel: FAT-fs (sda2): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 21 20:47:03 volumio-jh volumio[1040]: info: Mounting Device Local_Disk Jan 21 20:47:03 volumio-jh sudo[1176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda3 /mnt/USB/Local_Disk -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:03 volumio-jh sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:04 volumio-jh ntfs-3g[1179]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:04 volumio-jh ntfs-3g[1179]: Mounted /dev/sda3 (Read-Write, label "Local Disk", NTFS 3.1) Jan 21 20:47:04 volumio-jh ntfs-3g[1179]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:04 volumio-jh ntfs-3g[1179]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda3,blkdev,blksize=4096 Jan 21 20:47:04 volumio-jh ntfs-3g[1179]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:04 volumio-jh sudo[1176]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:04 volumio-jh volumio[1040]: info: Mounting Device Windows_RE_tools Jan 21 20:47:04 volumio-jh sudo[1184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda4 /mnt/USB/Windows_RE_tools -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:04 volumio-jh sudo[1184]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:04 volumio-jh sudo[1151]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:04 volumio-jh ntfs-3g[1187]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:04 volumio-jh ntfs-3g[1187]: Mounted /dev/sda4 (Read-Write, label "Windows RE tools", NTFS 3.1) Jan 21 20:47:04 volumio-jh ntfs-3g[1187]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:04 volumio-jh ntfs-3g[1187]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda4,blkdev,blksize=4096 Jan 21 20:47:04 volumio-jh ntfs-3g[1187]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:04 volumio-jh sudo[1184]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:04 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:04 volumio-jh volumio[1040]: info: Loading plugin "volumio_command_line_client"... Jan 21 20:47:04 volumio-jh volumio[1040]: info: Loading plugin "upnp"... Jan 21 20:47:04 volumio-jh volumio[1040]: info: [1737488824511] Starting Upmpd Daemon Jan 21 20:47:04 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:04 volumio-jh volumio[1040]: info: Loading plugin "my_music"... Jan 21 20:47:04 volumio-jh volumio[1040]: info: Loading plugin "mpd"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "upnp_browser"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "alarm-clock"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "airplay_emulation"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Starting Shairport Sync Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "last_100"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "webradio"... Jan 21 20:47:05 volumio-jh volumio[1040]: info: Loading plugin "i2s_dacs"... Jan 21 20:47:06 volumio-jh volumio[1040]: info: Loading plugin "volumiodiscovery"... Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** For more information see Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:06 volumio-jh volumio[1040]: *** WARNING *** For more information see Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** For more information see Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:06 volumio-jh node[1040]: *** WARNING *** For more information see Jan 21 20:47:06 volumio-jh volumio[1040]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 21 20:47:06 volumio-jh volumio[1040]: info: Discovery: Started advertising with name: Volumio-JH Jan 21 20:47:06 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:06 volumio-jh volumio[1040]: info: Loading plugin "spop"... Jan 21 20:47:07 volumio-jh dhcpcd[913]: wlan0: leased 192.168.23.65 for 604800 seconds Jan 21 20:47:07 volumio-jh avahi-daemon[580]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.23.65. Jan 21 20:47:07 volumio-jh avahi-daemon[580]: New relevant interface wlan0.IPv4 for mDNS. Jan 21 20:47:07 volumio-jh dhcpcd[913]: wlan0: adding route to 192.168.23.0/24 Jan 21 20:47:07 volumio-jh avahi-daemon[580]: Registering new address record for 192.168.23.65 on wlan0.IPv4. Jan 21 20:47:07 volumio-jh dhcpcd[913]: wlan0: adding default route via 192.168.23.1 Jan 21 20:47:08 volumio-jh systemd[1]: systemd-timedated.service: Succeeded. Jan 21 20:47:14 volumio-jh volumio[1040]: info: Loading plugin "outputs"... Jan 21 20:47:14 volumio-jh volumio[1040]: info: Loading plugin "albumart"... Jan 21 20:47:14 volumio-jh volumio[1040]: info: Plugin example_plugin is not enabled Jan 21 20:47:14 volumio-jh volumio[1040]: info: Loading plugin "inputs"... Jan 21 20:47:14 volumio-jh volumio[1040]: info: Loading plugin "updater_comm"... Jan 21 20:47:14 volumio-jh volumio[1040]: info: Plugin mpdemulation is not enabled Jan 21 20:47:14 volumio-jh volumio[1040]: info: Loading plugin "rest_api"... Jan 21 20:47:15 volumio-jh volumio[1040]: info: Loading plugin "websocket"... Jan 21 20:47:15 volumio-jh volumio[1040]: info: Starting Socket.io Server version 2.3.0 Jan 21 20:47:15 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:15] [connect] Successful connection Jan 21 20:47:15 volumio-jh volumio[1040]: info: Loading i18n strings for locale de Jan 21 20:47:15 volumio-jh volumio[1040]: Updating browse sources language Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:15 volumio-jh volumio[1040]: Forking 3 albumart workers Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::initPlayerControls Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:15 volumio-jh volumio[1040]: Express server listening on port 3000 Jan 21 20:47:15 volumio-jh volumio[1040]: [Metrics] WebUI: 16s 725.26ms Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreStateMachine::resetVolumioState Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreStateMachine::getcurrentVolume Jan 21 20:47:15 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:47:15 volumio-jh volumio[1040]: info: Volumio Network Manager: Network status updated: 1 Jan 21 20:47:16 volumio-jh sudo[1265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:16 volumio-jh sudo[1265]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:16 volumio-jh sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:16 volumio-jh sudo[1265]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:16 volumio-jh sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:16 volumio-jh sudo[1263]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:16 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1737488835 101 Jan 21 20:47:16 volumio-jh volumio[1040]: 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 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::pushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::updateTrackBlock Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrackBlock Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:47:16 volumio-jh volumio[1040]: Starting albumart workers Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:16 volumio-jh volumio[1040]: info: Reloading queue from file Jan 21 20:47:16 volumio-jh volumio[1040]: Starting albumart workers Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::setRepeat false single undefined Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::pushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::setRandom false Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::pushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreStateMachine::pushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:16 volumio-jh volumio[1040]: info: Setting Device type: Raspberry PI Jan 21 20:47:16 volumio-jh volumio[1040]: info: Completed loading Core Plugins Jan 21 20:47:16 volumio-jh volumio[1040]: info: Preparing to generate the ALSA configuration file Jan 21 20:47:16 volumio-jh sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 21 20:47:16 volumio-jh sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:16 volumio-jh volumio[1040]: info: Discovery: adding 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:47:16 volumio-jh volumio[1040]: info: Discovery: Found device Volumio-JH Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh volumio[1040]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 21 20:47:16 volumio-jh volumio[1040]: info: Reading ALSA contributions from plugins. Jan 21 20:47:16 volumio-jh volumio[1040]: info: Discovery: this is already registered, 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:47:16 volumio-jh volumio[1040]: info: Discovery: Found device Volumio-JH Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:16 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:16 volumio-jh systemd[1]: Started UPnP Renderer front-end to MPD. Jan 21 20:47:16 volumio-jh sudo[1282]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:16 volumio-jh volumio[1040]: info: Upmpdcli Daemon Started Jan 21 20:47:16 volumio-jh volumio[1040]: Starting albumart workers Jan 21 20:47:16 volumio-jh volumio[1040]: info: Asound.conf file written Jan 21 20:47:16 volumio-jh sudo[1286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 21 20:47:16 volumio-jh sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:16 volumio-jh sudo[1286]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:16 volumio-jh volumio[1040]: info: Output device has changed, restarting MPD Jan 21 20:47:16 volumio-jh volumio[1040]: info: Output device has changed, restarting Shairport Sync Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:16 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:16 volumio-jh sudo[1291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:47:16 volumio-jh sudo[1291]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:17 volumio-jh sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:47:17 volumio-jh sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:17 volumio-jh volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:17 volumio-jh volumio[1040]: info: ___________ START PLUGINS ___________ Jan 21 20:47:17 volumio-jh volumio[1040]: info: ControllerMpd::onStart: Initializing MPD Jan 21 20:47:17 volumio-jh volumio[1040]: info: Creating MPD Configuration file Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:17 volumio-jh volumio[1040]: info: [1737488837158] CoreMusicLibrary::Adding element Medienserver Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:17 volumio-jh sudo[1291]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:17 volumio-jh sudo[1300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:47:17 volumio-jh sudo[1300]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:17 volumio-jh sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:47:17 volumio-jh sudo[1300]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:17 volumio-jh sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:17 volumio-jh volumio[1040]: info: [1737488837431] CoreMusicLibrary::Adding element Last_100 Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:17 volumio-jh volumio[1040]: info: [1737488837436] CoreMusicLibrary::Adding element Webradio Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:17 volumio-jh volumio[1040]: info: Initializing BBC Radios Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: Creating Spotify config file Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:17 volumio-jh volumio[1040]: info: Volumio Calling Home Jan 21 20:47:17 volumio-jh volumio[1040]: info: MPD Permissions set Jan 21 20:47:17 volumio-jh volumio[1040]: info: MPD Permissions set Jan 21 20:47:17 volumio-jh volumio[1040]: info: Volumio called home Jan 21 20:47:17 volumio-jh volumio[1040]: info: Spotify config file written Jan 21 20:47:17 volumio-jh sudo[1349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 21 20:47:17 volumio-jh sudo[1349]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:17 volumio-jh volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 21 20:47:17 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:18 volumio-jh volumio[1040]: info: No need to fix Spotify hosts Jan 21 20:47:18 volumio-jh systemd[1]: Started go-librespot Daemon. Jan 21 20:47:18 volumio-jh go-librespot[1352]: Librespot-go daemon starting... Jan 21 20:47:18 volumio-jh sudo[1349]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:18 volumio-jh volumio[1040]: info: Starting Shairport Sync Jan 21 20:47:18 volumio-jh volumio[1040]: info: Starting Shairport Sync Jan 21 20:47:18 volumio-jh volumio[1040]: info: Starting Shairport Sync Jan 21 20:47:18 volumio-jh sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:18 volumio-jh sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:18 volumio-jh sudo[1364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:18 volumio-jh sudo[1364]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:18 volumio-jh sudo[1367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:18 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:18 volumio-jh sudo[1367]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:18 volumio-jh volumio[1040]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:47:18 volumio-jh volumio[1040]: SPOTIFY: BQCQKZbwjqtYchYqowmFsiDqbXPkqhJQHJHww832GDomeeNcCCm5wY9d0wzq0KTAmBpOu3bZldVsZz-cJfSjSwMyqiOK8ojlH4i0a2I15uUjez3YleVE-Kdk8MMi-jcxi5IKjRgZhm-yI5lGJ9Tg1gVL1u26Ee8HeuNKnFV-1IB_XZmg8zuSYNgWte2UIS3bewTON4QtV40633Bg2rjaDrYL7jRbYaXuUGUhYz89YpskDu67Iale5sIY3IxyzV0 Jan 21 20:47:18 volumio-jh volumio[1040]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:47:18 volumio-jh volumio[1040]: info: New Spotify access token = BQCQKZbwjqtYchYqowmFsiDqbXPkqhJQHJHww832GDomeeNcCCm5wY9d0wzq0KTAmBpOu3bZldVsZz-cJfSjSwMyqiOK8ojlH4i0a2I15uUjez3YleVE-Kdk8MMi-jcxi5IKjRgZhm-yI5lGJ9Tg1gVL1u26Ee8HeuNKnFV-1IB_XZmg8zuSYNgWte2UIS3bewTON4QtV40633Bg2rjaDrYL7jRbYaXuUGUhYz89YpskDu67Iale5sIY3IxyzV0 Jan 21 20:47:18 volumio-jh volumio[1040]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 21 20:47:18 volumio-jh volumio[1040]: SPOTIFY: User informations: {"country":"DE","display_name":"jochen.heinze","email":"jochen@heinze.gr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jochen.heinze"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/jochen.heinze","id":"jochen.heinze","images":[],"product":"premium","type":"user","uri":"spotify:user:jochen.heinze"} Jan 21 20:47:18 volumio-jh volumio[1040]: info: Spotify Successfully logged in Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:18 volumio-jh volumio[1040]: info: [1737488838589] CoreMusicLibrary::Adding element Spotify Jan 21 20:47:18 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:18 volumio-jh volumio[1040]: Cannot find translation for source Spotify Jan 21 20:47:19 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:19+01:00" level=info msg="generated new device id: e8d4a2c6f963b177396d3cd9b7d737659ab4e33c" Jan 21 20:47:19 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:19+01:00" level=debug msg="stored credentials found for jochen.heinze" Jan 21 20:47:20 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 21 20:47:20 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 21 20:47:20 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 21 20:47:20 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:20+01:00" level=debug msg="zeroconf server listening on port 40469" Jan 21 20:47:20 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:20+01:00" level=debug msg="obtained new client token: AADkVlSiRRxkoDfn23NpFaIXKCamAW+eJwJrMQGvy0zoCWD2YbPSWGfwfxb5AW2s7DdSAYuVQH5inkEhA4eRQh+7chwXlb8Mp2XyIVLCDJq0wtPFYCKv9fX4TbCPWm3SF6TYH7vorQZC11pn4xpEy9OCLtgs0K0IQycBkv56GlSeTo3MHTQGjSOWmyrplB5b26BkF/2mz57rI4/axdLQAljmMnS6N5uoI8M77aRDzk0f5hz7Npi9YACEs8um" Jan 21 20:47:21 volumio-jh sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:21 volumio-jh sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:21 volumio-jh sudo[1378]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:21 volumio-jh sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:21 volumio-jh sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:21 volumio-jh volumio[1040]: info: go-librespot daemon successfully initialized Jan 21 20:47:21 volumio-jh sudo[1380]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:21 volumio-jh volumio[1040]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 3 Jan 21 20:47:21 volumio-jh sudo[1384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:21 volumio-jh sudo[1384]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:21 volumio-jh sudo[1384]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:21 volumio-jh sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:21 volumio-jh sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:21 volumio-jh sudo[1386]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:21 volumio-jh volumio[1040]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 4 Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:22 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 21 20:47:22 volumio-jh volumio[1040]: info: Received Get System Info Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:47:22 volumio-jh volumio[1040]: info: Discovery: Getting this device information Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:22 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:22 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:22 volumio-jh volumio[1040]: info: Listing playlists Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 21 20:47:22 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:22 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:23 volumio-jh volumio[1040]: info: Volumio Network Manager: Network status updated: 3 Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 21 20:47:23 volumio-jh volumio[1040]: info: Received Get System Info Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:47:23 volumio-jh volumio[1040]: info: Discovery: Getting this device information Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:23 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:47:23 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 21 20:47:24 volumio-jh volumio[1040]: info: Initializing connection to go-librespot Websocket Jan 21 20:47:24 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:24+01:00" level=debug msg="new websocket client" Jan 21 20:47:24 volumio-jh volumio[1040]: info: Connection to go-librespot Websocket established Jan 21 20:47:24 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 21 20:47:24 volumio-jh systemd-udevd[367]: Spawned process '/bin/bash -c '/usr/local/bin/volumio usbattach'' [509] is taking longer than 59s to complete Jan 21 20:47:24 volumio-jh systemd-udevd[355]: pcmC5D0p: Worker [367] processing SEQNUM=1946 is taking a long time Jan 21 20:47:25 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 21 20:47:25 volumio-jh volumio[1040]: info: Received Get System Info Jan 21 20:47:25 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:47:25 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:47:25 volumio-jh volumio[1040]: info: Discovery: Getting this device information Jan 21 20:47:25 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:25 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:25 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:47:26 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 21 20:47:27 volumio-jh volumio[1040]: info: Getting Spotify volume Jan 21 20:47:27 volumio-jh volumio[1040]: 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 21 20:47:27 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:27 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:27 volumio-jh volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 21 20:47:27 volumio-jh volumio[1040]: SPOTIFY: SPOTIFY VOLUME undefined Jan 21 20:47:27 volumio-jh volumio[1040]: SPOTIFY: VOLUMIO VOLUME 100 Jan 21 20:47:27 volumio-jh volumio[1040]: info: Aligning Spotify Volume to Volumio Volume Jan 21 20:47:27 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:27 volumio-jh volumio[1040]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:27 volumio-jh volumio[1040]: info: Setting Spotify Volume from Volumio: 100 Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 21 20:47:28 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 21 20:47:28 volumio-jh volumio[1040]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 21 20:47:28 volumio-jh volumio[1040]: info: Sending Spotify command with payload to local API: /player/volume Jan 21 20:47:28 volumio-jh volumio[1040]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Jan 21 20:47:31 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:32 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 21 20:47:34 volumio-jh volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Jan 21 20:47:34 volumio-jh volumio[1040]: verbose: ControllerMpd::sendMpdCommand update Jan 21 20:47:34 volumio-jh volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:47:34 volumio-jh volumio[1040]: TypeError: Cannot read property 'then' of undefined Jan 21 20:47:34 volumio-jh volumio[1040]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Jan 21 20:47:34 volumio-jh volumio[1040]: at ControllerMpd.updateDb (/volumio/app/plugins/music_service/mpd/index.js:1899:15) Jan 21 20:47:34 volumio-jh volumio[1040]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Jan 21 20:47:34 volumio-jh volumio[1040]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1085:26) Jan 21 20:47:34 volumio-jh volumio[1040]: at Socket.emit (events.js:315:20) Jan 21 20:47:34 volumio-jh volumio[1040]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 21 20:47:34 volumio-jh volumio[1040]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jan 21 20:47:34 volumio-jh volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:47:35 volumio-jh sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-21 20:46 Jan 21 20:47:35 volumio-jh sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:35 volumio-jh sudo[1443]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 21 20:47:35 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 21 20:47:35 volumio-jh go-librespot[1352]: time="2025-01-21T20:47:35+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jan 21 20:47:35 volumio-jh systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 21 20:47:35 volumio-jh sudo[1364]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh sudo[1302]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh ntfs-3g[1187]: Unmounting /dev/sda4 (Windows RE tools) Jan 21 20:47:35 volumio-jh ntfs-3g[1179]: Unmounting /dev/sda3 (Local Disk) Jan 21 20:47:35 volumio-jh sudo[1362]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh sudo[1367]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh sudo[1293]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:35 volumio-jh systemd[1]: media-Windows_RE_tools.mount: Succeeded. Jan 21 20:47:35 volumio-jh systemd[1]: media-Local_Disk.mount: Succeeded. Jan 21 20:47:35 volumio-jh systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 21 20:47:35 volumio-jh systemd[1]: Started dynamicswap service. Jan 21 20:47:35 volumio-jh systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 21 20:47:35 volumio-jh systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jan 21 20:47:35 volumio-jh systemd[1]: Stopped Volumio Backend Module. Jan 21 20:47:35 volumio-jh systemd[1]: Started Volumio Backend Module. Jan 21 20:47:35 volumio-jh systemd[1]: dynamicswap.service: Succeeded. Jan 21 20:47:37 volumio-jh volumio[1454]: info: ------------------------------------------- Jan 21 20:47:37 volumio-jh volumio[1454]: info: ----- Volumio3 ---- Jan 21 20:47:37 volumio-jh volumio[1454]: info: ------------------------------------------- Jan 21 20:47:37 volumio-jh volumio[1454]: info: ----- System startup ---- Jan 21 20:47:37 volumio-jh volumio[1454]: info: ------------------------------------------- Jan 21 20:47:38 volumio-jh volumio[1454]: info: MYVOLUMIO Environment detected Jan 21 20:47:38 volumio-jh volumio[1454]: info: Plugin folders cleanup Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning into folder /volumio/app/plugins/ Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category audio_interface Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category miscellanea Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category music_service Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category plugins.json Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category system_controller Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category user_interface Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning into folder /data/plugins/ Jan 21 20:47:38 volumio-jh volumio[1454]: info: Scanning category music_service Jan 21 20:47:38 volumio-jh volumio[1454]: info: Plugin folders cleanup completed Jan 21 20:47:38 volumio-jh volumio[1454]: info: ------------------------------------------- Jan 21 20:47:38 volumio-jh volumio[1454]: info: ----- Core plugins startup ---- Jan 21 20:47:38 volumio-jh volumio[1454]: info: ------------------------------------------- Jan 21 20:47:38 volumio-jh volumio[1454]: info: Loading plugins from folder /volumio/app/plugins/ Jan 21 20:47:38 volumio-jh volumio[1454]: info: Adding plugin upnp to MyMusic Plugins Jan 21 20:47:38 volumio-jh volumio[1454]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 21 20:47:38 volumio-jh volumio[1454]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 21 20:47:38 volumio-jh volumio[1454]: info: Loading plugins from folder /data/plugins/ Jan 21 20:47:38 volumio-jh volumio[1454]: info: Loading plugin "system"... Jan 21 20:47:38 volumio-jh volumio[1454]: info: Loading plugin "appearance"... Jan 21 20:47:39 volumio-jh volumio[1454]: info: Loading plugin "network"... Jan 21 20:47:39 volumio-jh volumio[1454]: info: Refreshing Cached IP Addresses Jan 21 20:47:39 volumio-jh sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:39 volumio-jh sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:39 volumio-jh sudo[1477]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:39 volumio-jh sudo[1479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:39 volumio-jh sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:39 volumio-jh sudo[1479]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:39 volumio-jh volumio[1454]: info: Loading plugin "services"... Jan 21 20:47:39 volumio-jh volumio[1454]: info: Loading plugin "alsa_controller"... Jan 21 20:47:39 volumio-jh sudo[1488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 21 20:47:39 volumio-jh sudo[1488]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:39 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:39 volumio-jh volumio[1454]: info: Loading plugin "wizard"... Jan 21 20:47:39 volumio-jh volumio[1454]: info: Loading plugin "networkfs"... Jan 21 20:47:39 volumio-jh volumio[1454]: info: Starting Udev Watcher for removable devices Jan 21 20:47:39 volumio-jh volumio[1454]: info: Ignoring mount for partition: boot Jan 21 20:47:39 volumio-jh volumio[1454]: info: Ignoring mount for partition: volumio Jan 21 20:47:39 volumio-jh volumio[1454]: info: Ignoring mount for partition: volumio_data Jan 21 20:47:39 volumio-jh volumio[1454]: error: Cannot associate FS Label, not mounting Jan 21 20:47:39 volumio-jh volumio[1454]: info: Mounting Device SYSTEM Jan 21 20:47:39 volumio-jh sudo[1506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/SYSTEM -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:39 volumio-jh sudo[1506]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:40 volumio-jh sudo[1506]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:40 volumio-jh volumio[1454]: mount: /media/SYSTEM: /dev/sda2 already mounted on /media/SYSTEM. Jan 21 20:47:40 volumio-jh volumio[1454]: error: Failed to mount SYSTEM: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda2" "/mnt/USB/SYSTEM" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:40 volumio-jh volumio[1454]: mount: /media/SYSTEM: /dev/sda2 already mounted on /media/SYSTEM. Jan 21 20:47:40 volumio-jh volumio[1454]: info: Mounting Device Local_Disk Jan 21 20:47:40 volumio-jh sudo[1512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda3 /mnt/USB/Local_Disk -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:40 volumio-jh sudo[1512]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:40 volumio-jh ntfs-3g[1515]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:40 volumio-jh ntfs-3g[1515]: Mounted /dev/sda3 (Read-Write, label "Local Disk", NTFS 3.1) Jan 21 20:47:40 volumio-jh ntfs-3g[1515]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:40 volumio-jh ntfs-3g[1515]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda3,blkdev,blksize=4096 Jan 21 20:47:40 volumio-jh ntfs-3g[1515]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:40 volumio-jh sudo[1512]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:40 volumio-jh volumio[1454]: info: Mounting Device Windows_RE_tools Jan 21 20:47:40 volumio-jh sudo[1520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda4 /mnt/USB/Windows_RE_tools -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:40 volumio-jh sudo[1520]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:40 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:40] [connect] Successful connection Jan 21 20:47:40 volumio-jh ntfs-3g[1523]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:40 volumio-jh ntfs-3g[1523]: Mounted /dev/sda4 (Read-Write, label "Windows RE tools", NTFS 3.1) Jan 21 20:47:40 volumio-jh ntfs-3g[1523]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:40 volumio-jh ntfs-3g[1523]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda4,blkdev,blksize=4096 Jan 21 20:47:40 volumio-jh ntfs-3g[1523]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:40 volumio-jh sudo[1520]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:40 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:40 volumio-jh volumio[1454]: info: Loading plugin "volumio_command_line_client"... Jan 21 20:47:40 volumio-jh volumio[1454]: info: Loading plugin "upnp"... Jan 21 20:47:40 volumio-jh volumio[1454]: info: [1737488860556] Starting Upmpd Daemon Jan 21 20:47:40 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:40 volumio-jh volumio[1454]: info: Loading plugin "my_music"... Jan 21 20:47:40 volumio-jh volumio[1454]: info: Loading plugin "mpd"... Jan 21 20:47:40 volumio-jh sudo[1488]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:40 volumio-jh volumio[1454]: info: Loading plugin "upnp_browser"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "alarm-clock"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "airplay_emulation"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Starting Shairport Sync Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "last_100"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "webradio"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "i2s_dacs"... Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "volumiodiscovery"... Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** For more information see Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:41 volumio-jh volumio[1454]: *** WARNING *** For more information see Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** For more information see Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:41 volumio-jh node[1454]: *** WARNING *** For more information see Jan 21 20:47:41 volumio-jh volumio[1454]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 21 20:47:41 volumio-jh volumio[1454]: info: Discovery: Started advertising with name: Volumio-JH Jan 21 20:47:41 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:41 volumio-jh volumio[1454]: info: Loading plugin "spop"... Jan 21 20:47:42 volumio-jh volumio[1454]: info: Loading plugin "outputs"... Jan 21 20:47:42 volumio-jh volumio[1454]: info: Loading plugin "albumart"... Jan 21 20:47:42 volumio-jh volumio[1454]: info: Plugin example_plugin is not enabled Jan 21 20:47:42 volumio-jh volumio[1454]: info: Loading plugin "inputs"... Jan 21 20:47:42 volumio-jh volumio[1454]: info: Loading plugin "updater_comm"... Jan 21 20:47:43 volumio-jh volumio[1454]: info: Plugin mpdemulation is not enabled Jan 21 20:47:43 volumio-jh volumio[1454]: info: Loading plugin "rest_api"... Jan 21 20:47:43 volumio-jh volumio[1454]: info: Loading plugin "websocket"... Jan 21 20:47:43 volumio-jh volumio[1454]: info: Starting Socket.io Server version 2.3.0 Jan 21 20:47:43 volumio-jh volumio[1454]: info: Loading i18n strings for locale de Jan 21 20:47:43 volumio-jh volumio[1454]: Updating browse sources language Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:43 volumio-jh volumio[1454]: Forking 3 albumart workers Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::initPlayerControls Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:43 volumio-jh volumio[1454]: Express server listening on port 3000 Jan 21 20:47:43 volumio-jh volumio[1454]: [Metrics] WebUI: 6s 369.08ms Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreStateMachine::resetVolumioState Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreStateMachine::getcurrentVolume Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:47:43 volumio-jh volumio[1454]: info: Volumio Network Manager: Network status updated: 3 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 3 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 4 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 5 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 6 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 21 20:47:43 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1737488860 101 Jan 21 20:47:43 volumio-jh volumio[1454]: 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: 8 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 9 Jan 21 20:47:43 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 10 Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreStateMachine::pushState Jan 21 20:47:43 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:43 volumio-jh volumio[1454]: info: CoreStateMachine::updateTrackBlock Jan 21 20:47:43 volumio-jh volumio[1454]: info: CorePlayQueue::getTrackBlock Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 11 Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 12 Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 13 Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 14 Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 15 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:44 volumio-jh volumio[1454]: info: Reloading queue from file Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 16 Jan 21 20:47:44 volumio-jh volumio[1454]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 17 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreStateMachine::pushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreStateMachine::setRepeat false single undefined Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreStateMachine::pushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreStateMachine::setRandom false Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreStateMachine::pushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioPushState Jan 21 20:47:44 volumio-jh volumio[1454]: info: Setting Device type: Raspberry PI Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: Received Get System Info Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: Getting this device information Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetVisibleSources Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 21 20:47:44 volumio-jh volumio[1454]: info: Received Get System Info Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: Getting this device information Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: Listing playlists Jan 21 20:47:44 volumio-jh volumio[1454]: Starting albumart workers Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 21 20:47:44 volumio-jh volumio[1454]: Starting albumart workers Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: adding 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: Found device Volumio-JH Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: this is already registered, 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:47:44 volumio-jh volumio[1454]: info: Discovery: Found device Volumio-JH Jan 21 20:47:44 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:44 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:44 volumio-jh volumio[1454]: Starting albumart workers Jan 21 20:47:45 volumio-jh volumio[1454]: info: Completed loading Core Plugins Jan 21 20:47:45 volumio-jh volumio[1454]: info: Preparing to generate the ALSA configuration file Jan 21 20:47:45 volumio-jh volumio[1454]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 21 20:47:45 volumio-jh volumio[1454]: info: Reading ALSA contributions from plugins. Jan 21 20:47:45 volumio-jh volumio[1454]: info: Asound.conf file unchanged, so no further update is needed Jan 21 20:47:45 volumio-jh volumio[1454]: info: Output device has changed, restarting MPD Jan 21 20:47:45 volumio-jh volumio[1454]: info: Output device has changed, restarting Shairport Sync Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:45 volumio-jh sudo[1576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:47:45 volumio-jh sudo[1576]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:45 volumio-jh sudo[1578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:47:45 volumio-jh sudo[1578]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:45 volumio-jh sudo[1576]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:45 volumio-jh volumio[1454]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:45 volumio-jh volumio[1454]: info: ___________ START PLUGINS ___________ Jan 21 20:47:45 volumio-jh volumio[1454]: info: ControllerMpd::onStart: Initializing MPD Jan 21 20:47:45 volumio-jh volumio[1454]: info: Creating MPD Configuration file Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:45 volumio-jh volumio[1454]: info: [1737488865278] CoreMusicLibrary::Adding element Medienserver Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:45 volumio-jh sudo[1585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:47:45 volumio-jh sudo[1585]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:45 volumio-jh sudo[1585]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:45 volumio-jh sudo[1587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:47:45 volumio-jh sudo[1587]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:45 volumio-jh volumio[1454]: info: [1737488865567] CoreMusicLibrary::Adding element Last_100 Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:45 volumio-jh volumio[1454]: info: [1737488865571] CoreMusicLibrary::Adding element Webradio Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:45 volumio-jh volumio[1454]: info: Initializing BBC Radios Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: Creating Spotify config file Jan 21 20:47:45 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:45 volumio-jh volumio[1454]: info: Volumio Calling Home Jan 21 20:47:46 volumio-jh volumio[1454]: info: MPD Permissions set Jan 21 20:47:46 volumio-jh volumio[1454]: info: MPD Permissions set Jan 21 20:47:46 volumio-jh volumio[1454]: info: Volumio called home Jan 21 20:47:46 volumio-jh volumio[1454]: info: Spotify config file written Jan 21 20:47:46 volumio-jh sudo[1634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 21 20:47:46 volumio-jh sudo[1634]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:46 volumio-jh systemd[1]: Stopping go-librespot Daemon... Jan 21 20:47:46 volumio-jh systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jan 21 20:47:46 volumio-jh systemd[1]: go-librespot-daemon.service: Succeeded. Jan 21 20:47:46 volumio-jh systemd[1]: Stopped go-librespot Daemon. Jan 21 20:47:46 volumio-jh volumio[1454]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh systemd[1]: Started go-librespot Daemon. Jan 21 20:47:46 volumio-jh go-librespot[1636]: Librespot-go daemon starting... Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh sudo[1634]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=info msg="generated new device id: fafb844cde3d71e01eeda92d08961df673a5dd6e" Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="stored credentials found for jochen.heinze" Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:47:46 volumio-jh volumio[1454]: info: No need to fix Spotify hosts Jan 21 20:47:46 volumio-jh volumio[1454]: info: Starting Shairport Sync Jan 21 20:47:46 volumio-jh volumio[1454]: info: Starting Shairport Sync Jan 21 20:47:46 volumio-jh volumio[1454]: info: Starting Shairport Sync Jan 21 20:47:46 volumio-jh sudo[1653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:46 volumio-jh sudo[1653]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:46 volumio-jh sudo[1655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:46 volumio-jh sudo[1655]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioGetState Jan 21 20:47:46 volumio-jh volumio[1454]: info: CorePlayQueue::getTrack 0 Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="zeroconf server listening on port 42911" Jan 21 20:47:46 volumio-jh volumio[1454]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:47:46 volumio-jh volumio[1454]: SPOTIFY: BQBySzo9sbEjPz8abhAVuT_zbOM0aEvPpHm7lNkaY_iyVJt5XxNadN1Hz5QOyCzbh4-O2R0UUD3s99BB2v2Ele7PmY120M7vjC5OoUX_wZwANzngjw87McRWZKyeJnVXY109D5MeQE9rElTs4YmyavzkH5egvyl6gdjFrloPrP8JnU1gNR9loMhKKSGnh20QhEKHhsU8m9bvq11UDvDZCVp-vS9ek1w0zRUZ6cU6_RKAwwmHt3c2cgpwGOwpXvc Jan 21 20:47:46 volumio-jh volumio[1454]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:47:46 volumio-jh volumio[1454]: info: New Spotify access token = BQBySzo9sbEjPz8abhAVuT_zbOM0aEvPpHm7lNkaY_iyVJt5XxNadN1Hz5QOyCzbh4-O2R0UUD3s99BB2v2Ele7PmY120M7vjC5OoUX_wZwANzngjw87McRWZKyeJnVXY109D5MeQE9rElTs4YmyavzkH5egvyl6gdjFrloPrP8JnU1gNR9loMhKKSGnh20QhEKHhsU8m9bvq11UDvDZCVp-vS9ek1w0zRUZ6cU6_RKAwwmHt3c2cgpwGOwpXvc Jan 21 20:47:46 volumio-jh volumio[1454]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 21 20:47:46 volumio-jh sudo[1657]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:47:46 volumio-jh sudo[1657]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:46 volumio-jh go-librespot[1636]: time="2025-01-21T20:47:46+01:00" level=debug msg="obtained new client token: AAB5YNUxmLnJaSE76GxQu+jBboiw+KtfPvb7QeJ59h7SM6a3YWVGdTXUEA6ArtXZWGyVPInZ5YO2MBoL1h5TpCLCMoj8ViJUBtMjpuUBMZTijBnQziQ4mkls2CMpj4oGfzSe8aTWHqtX5muWgVBwPbuxvEIVTk+gIZrdeNtmudbePfQxIMviAPTv+qX2pnEPB/ARD4nbaMn+WPeHmHQI7FogpWyScZNGJ142To752iobnzMIpEPjOw7xkbnvHGQ=" Jan 21 20:47:46 volumio-jh volumio[1454]: SPOTIFY: User informations: {"country":"DE","display_name":"jochen.heinze","email":"jochen@heinze.gr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jochen.heinze"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/jochen.heinze","id":"jochen.heinze","images":[],"product":"premium","type":"user","uri":"spotify:user:jochen.heinze"} Jan 21 20:47:46 volumio-jh volumio[1454]: info: Spotify Successfully logged in Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:47:46 volumio-jh volumio[1454]: info: [1737488866745] CoreMusicLibrary::Adding element Spotify Jan 21 20:47:46 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:47:46 volumio-jh volumio[1454]: Cannot find translation for source Spotify Jan 21 20:47:47 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:47 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:48 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:48 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 21 20:47:48 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:49 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:49 volumio-jh volumio[1454]: info: go-librespot daemon successfully initialized Jan 21 20:47:49 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:50 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:50 volumio-jh sudo[1677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:50 volumio-jh sudo[1677]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:50 volumio-jh sudo[1677]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:50 volumio-jh sudo[1679]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:50 volumio-jh sudo[1679]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:50 volumio-jh sudo[1679]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:50 volumio-jh sudo[1683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 21 20:47:50 volumio-jh sudo[1683]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:50 volumio-jh sudo[1683]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:50 volumio-jh volumio[1454]: info: Upmpdcli Daemon Started Jan 21 20:47:50 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:51 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:51 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:47:51 volumio-jh volumio[1454]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Jan 21 20:47:51 volumio-jh volumio[1454]: verbose: ControllerMpd::sendMpdCommand update Jan 21 20:47:51 volumio-jh volumio[1454]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:47:51 volumio-jh volumio[1454]: TypeError: Cannot read property 'then' of undefined Jan 21 20:47:51 volumio-jh volumio[1454]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Jan 21 20:47:51 volumio-jh volumio[1454]: at ControllerMpd.updateDb (/volumio/app/plugins/music_service/mpd/index.js:1899:15) Jan 21 20:47:51 volumio-jh volumio[1454]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Jan 21 20:47:51 volumio-jh volumio[1454]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1085:26) Jan 21 20:47:51 volumio-jh volumio[1454]: at Socket.emit (events.js:315:20) Jan 21 20:47:51 volumio-jh volumio[1454]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 21 20:47:51 volumio-jh volumio[1454]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jan 21 20:47:51 volumio-jh volumio[1454]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:47:52 volumio-jh sudo[1694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-21 20:46 Jan 21 20:47:52 volumio-jh sudo[1694]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:52 volumio-jh sudo[1694]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 21 20:47:52 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 21 20:47:52 volumio-jh systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 21 20:47:52 volumio-jh ntfs-3g[1523]: Unmounting /dev/sda4 (Windows RE tools) Jan 21 20:47:52 volumio-jh sudo[1657]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh ntfs-3g[1515]: Unmounting /dev/sda3 (Local Disk) Jan 21 20:47:52 volumio-jh sudo[1653]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh sudo[1587]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh systemd[1]: media-Windows_RE_tools.mount: Succeeded. Jan 21 20:47:52 volumio-jh sudo[1655]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh systemd[1]: media-Local_Disk.mount: Succeeded. Jan 21 20:47:52 volumio-jh sudo[1578]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:52 volumio-jh systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 21 20:47:52 volumio-jh systemd[1]: Started dynamicswap service. Jan 21 20:47:52 volumio-jh systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 21 20:47:52 volumio-jh systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jan 21 20:47:52 volumio-jh systemd[1]: Stopped Volumio Backend Module. Jan 21 20:47:52 volumio-jh systemd[1]: Started Volumio Backend Module. Jan 21 20:47:52 volumio-jh systemd[1]: dynamicswap.service: Succeeded. Jan 21 20:47:54 volumio-jh volumio[1703]: info: ------------------------------------------- Jan 21 20:47:54 volumio-jh volumio[1703]: info: ----- Volumio3 ---- Jan 21 20:47:54 volumio-jh volumio[1703]: info: ------------------------------------------- Jan 21 20:47:54 volumio-jh volumio[1703]: info: ----- System startup ---- Jan 21 20:47:54 volumio-jh volumio[1703]: info: ------------------------------------------- Jan 21 20:47:55 volumio-jh volumio[1703]: info: MYVOLUMIO Environment detected Jan 21 20:47:55 volumio-jh volumio[1703]: info: Plugin folders cleanup Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning into folder /volumio/app/plugins/ Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category audio_interface Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category miscellanea Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category music_service Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category plugins.json Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category system_controller Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category user_interface Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning into folder /data/plugins/ Jan 21 20:47:55 volumio-jh volumio[1703]: info: Scanning category music_service Jan 21 20:47:55 volumio-jh volumio[1703]: info: Plugin folders cleanup completed Jan 21 20:47:55 volumio-jh volumio[1703]: info: ------------------------------------------- Jan 21 20:47:55 volumio-jh volumio[1703]: info: ----- Core plugins startup ---- Jan 21 20:47:55 volumio-jh volumio[1703]: info: ------------------------------------------- Jan 21 20:47:55 volumio-jh volumio[1703]: info: Loading plugins from folder /volumio/app/plugins/ Jan 21 20:47:55 volumio-jh volumio[1703]: info: Adding plugin upnp to MyMusic Plugins Jan 21 20:47:55 volumio-jh volumio[1703]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 21 20:47:55 volumio-jh volumio[1703]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 21 20:47:55 volumio-jh volumio[1703]: info: Loading plugins from folder /data/plugins/ Jan 21 20:47:55 volumio-jh volumio[1703]: info: Loading plugin "system"... Jan 21 20:47:55 volumio-jh volumio[1703]: info: Loading plugin "appearance"... Jan 21 20:47:56 volumio-jh volumio[1703]: info: Loading plugin "network"... Jan 21 20:47:56 volumio-jh volumio[1703]: info: Refreshing Cached IP Addresses Jan 21 20:47:56 volumio-jh sudo[1725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:47:56 volumio-jh sudo[1725]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:56 volumio-jh sudo[1725]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:56 volumio-jh sudo[1727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:47:56 volumio-jh sudo[1727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:56 volumio-jh sudo[1727]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:56 volumio-jh volumio[1703]: info: Loading plugin "services"... Jan 21 20:47:56 volumio-jh volumio[1703]: info: Loading plugin "alsa_controller"... Jan 21 20:47:56 volumio-jh sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 21 20:47:56 volumio-jh sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:57 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "wizard"... Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "networkfs"... Jan 21 20:47:57 volumio-jh volumio[1703]: info: Starting Udev Watcher for removable devices Jan 21 20:47:57 volumio-jh volumio[1703]: info: Ignoring mount for partition: boot Jan 21 20:47:57 volumio-jh volumio[1703]: info: Ignoring mount for partition: volumio Jan 21 20:47:57 volumio-jh volumio[1703]: info: Ignoring mount for partition: volumio_data Jan 21 20:47:57 volumio-jh volumio[1703]: error: Cannot associate FS Label, not mounting Jan 21 20:47:57 volumio-jh volumio[1703]: info: Mounting Device SYSTEM Jan 21 20:47:57 volumio-jh sudo[1754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/SYSTEM -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh sudo[1754]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:57 volumio-jh sudo[1754]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:57 volumio-jh volumio[1703]: mount: /media/SYSTEM: /dev/sda2 already mounted on /media/SYSTEM. Jan 21 20:47:57 volumio-jh volumio[1703]: error: Failed to mount SYSTEM: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda2" "/mnt/USB/SYSTEM" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh volumio[1703]: mount: /media/SYSTEM: /dev/sda2 already mounted on /media/SYSTEM. Jan 21 20:47:57 volumio-jh volumio[1703]: info: Mounting Device Local_Disk Jan 21 20:47:57 volumio-jh sudo[1760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda3 /mnt/USB/Local_Disk -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh sudo[1760]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:57 volumio-jh ntfs-3g[1763]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:57 volumio-jh ntfs-3g[1763]: Mounted /dev/sda3 (Read-Write, label "Local Disk", NTFS 3.1) Jan 21 20:47:57 volumio-jh ntfs-3g[1763]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh ntfs-3g[1763]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda3,blkdev,blksize=4096 Jan 21 20:47:57 volumio-jh ntfs-3g[1763]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:57 volumio-jh sudo[1760]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:57 volumio-jh volumio[1703]: info: Mounting Device Windows_RE_tools Jan 21 20:47:57 volumio-jh sudo[1768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda4 /mnt/USB/Windows_RE_tools -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh sudo[1768]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:47:57 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:47:57] [connect] Successful connection Jan 21 20:47:57 volumio-jh ntfs-3g[1771]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 21 20:47:57 volumio-jh ntfs-3g[1771]: Mounted /dev/sda4 (Read-Write, label "Windows RE tools", NTFS 3.1) Jan 21 20:47:57 volumio-jh ntfs-3g[1771]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 21 20:47:57 volumio-jh ntfs-3g[1771]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda4,blkdev,blksize=4096 Jan 21 20:47:57 volumio-jh ntfs-3g[1771]: Global ownership and permissions enforced, configuration type 7 Jan 21 20:47:57 volumio-jh sudo[1768]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:57 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "volumio_command_line_client"... Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "upnp"... Jan 21 20:47:57 volumio-jh volumio[1703]: info: [1737488877760] Starting Upmpd Daemon Jan 21 20:47:57 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "my_music"... Jan 21 20:47:57 volumio-jh volumio[1703]: info: Loading plugin "mpd"... Jan 21 20:47:57 volumio-jh sudo[1740]: pam_unix(sudo:session): session closed for user root Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "upnp_browser"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "alarm-clock"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "airplay_emulation"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Starting Shairport Sync Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "last_100"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "webradio"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "i2s_dacs"... Jan 21 20:47:58 volumio-jh volumio[1703]: info: Loading plugin "volumiodiscovery"... Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** For more information see Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:58 volumio-jh volumio[1703]: *** WARNING *** For more information see Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** For more information see Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 21 20:47:58 volumio-jh node[1703]: *** WARNING *** For more information see Jan 21 20:47:58 volumio-jh volumio[1703]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 21 20:48:00 volumio-jh volumio[1703]: info: Discovery: Started advertising with name: Volumio-JH Jan 21 20:48:00 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 21 20:48:00 volumio-jh volumio[1703]: info: Loading plugin "spop"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "outputs"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "albumart"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Plugin example_plugin is not enabled Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "inputs"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "updater_comm"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Plugin mpdemulation is not enabled Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "rest_api"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading plugin "websocket"... Jan 21 20:48:01 volumio-jh volumio[1703]: info: Starting Socket.io Server version 2.3.0 Jan 21 20:48:01 volumio-jh volumio[1703]: info: Loading i18n strings for locale de Jan 21 20:48:01 volumio-jh volumio[1703]: Updating browse sources language Jan 21 20:48:01 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:02 volumio-jh volumio[1703]: Forking 3 albumart workers Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::initPlayerControls Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: Express server listening on port 3000 Jan 21 20:48:02 volumio-jh volumio[1703]: [Metrics] WebUI: 7s 791.39ms Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::resetVolumioState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::getcurrentVolume Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:48:02 volumio-jh volumio[1703]: info: Volumio Network Manager: Network status updated: 3 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 3 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 4 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 5 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 6 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 21 20:48:02 volumio-jh volumio-remote-updater[597]: [2025-01-21 20:48:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1737488877 101 Jan 21 20:48:02 volumio-jh volumio[1703]: 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: 8 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 9 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::pushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioPushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::updateTrackBlock Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrackBlock Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioRetrievevolume Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 10 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 11 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 12 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 13 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 14 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:02 volumio-jh volumio[1703]: info: Reloading queue from file Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 15 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.65 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 16 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::pushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioPushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: Setting Device type: Raspberry PI Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::setRepeat false single undefined Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::pushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioPushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::setRandom false Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreStateMachine::pushState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioPushState Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 17 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 18 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 19 Jan 21 20:48:02 volumio-jh volumio[1703]: verbose: New Socket.io Connection to 192.168.23.61 from 192.168.23.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:134.0) Gecko/20100101 Firefox/134.0 Engine version: 3 Transport: polling Total Clients: 20 Jan 21 20:48:02 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:02 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: Received Get System Info Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: Getting this device information Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetVisibleSources Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 21 20:48:03 volumio-jh volumio[1703]: info: Received Get System Info Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: Getting this device information Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: Listing playlists Jan 21 20:48:03 volumio-jh volumio[1703]: Starting albumart workers Jan 21 20:48:03 volumio-jh volumio[1703]: Starting albumart workers Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: adding 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: Found device Volumio-JH Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: this is already registered, 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 21 20:48:03 volumio-jh volumio[1703]: info: Discovery: Found device Volumio-JH Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:03 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: Completed loading Core Plugins Jan 21 20:48:03 volumio-jh volumio[1703]: info: Preparing to generate the ALSA configuration file Jan 21 20:48:03 volumio-jh volumio[1703]: Starting albumart workers Jan 21 20:48:03 volumio-jh volumio[1703]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 21 20:48:03 volumio-jh volumio[1703]: info: Reading ALSA contributions from plugins. Jan 21 20:48:03 volumio-jh volumio[1703]: info: Asound.conf file unchanged, so no further update is needed Jan 21 20:48:03 volumio-jh volumio[1703]: info: Output device has changed, restarting MPD Jan 21 20:48:03 volumio-jh sudo[1824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:48:03 volumio-jh sudo[1824]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:03 volumio-jh volumio[1703]: info: Output device has changed, restarting Shairport Sync Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:03 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:03 volumio-jh sudo[1824]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:03 volumio-jh sudo[1826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:48:03 volumio-jh sudo[1826]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:03 volumio-jh volumio[1703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:48:03 volumio-jh volumio[1703]: info: ___________ START PLUGINS ___________ Jan 21 20:48:03 volumio-jh volumio[1703]: info: ControllerMpd::onStart: Initializing MPD Jan 21 20:48:03 volumio-jh volumio[1703]: info: Creating MPD Configuration file Jan 21 20:48:03 volumio-jh sudo[1838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 21 20:48:03 volumio-jh sudo[1838]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:48:04 volumio-jh volumio[1703]: info: [1737488884010] CoreMusicLibrary::Adding element Medienserver Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:04 volumio-jh sudo[1838]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:04 volumio-jh sudo[1844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 21 20:48:04 volumio-jh sudo[1844]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:48:04 volumio-jh volumio[1703]: info: [1737488884277] CoreMusicLibrary::Adding element Last_100 Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:48:04 volumio-jh volumio[1703]: info: [1737488884283] CoreMusicLibrary::Adding element Webradio Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:48:04 volumio-jh volumio[1703]: info: Initializing BBC Radios Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: Creating Spotify config file Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: Volumio Calling Home Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 21 20:48:04 volumio-jh volumio[1703]: info: MPD Permissions set Jan 21 20:48:04 volumio-jh volumio[1703]: info: MPD Permissions set Jan 21 20:48:04 volumio-jh volumio[1703]: info: Volumio called home Jan 21 20:48:04 volumio-jh volumio[1703]: info: Spotify config file written Jan 21 20:48:04 volumio-jh sudo[1882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 21 20:48:04 volumio-jh sudo[1882]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:04 volumio-jh systemd[1]: Stopping go-librespot Daemon... Jan 21 20:48:04 volumio-jh systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jan 21 20:48:04 volumio-jh systemd[1]: go-librespot-daemon.service: Succeeded. Jan 21 20:48:04 volumio-jh systemd[1]: Stopped go-librespot Daemon. Jan 21 20:48:04 volumio-jh volumio[1703]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh systemd[1]: Started go-librespot Daemon. Jan 21 20:48:04 volumio-jh go-librespot[1884]: Librespot-go daemon starting... Jan 21 20:48:04 volumio-jh sudo[1882]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:04+01:00" level=info msg="generated new device id: 6b22a4d1b0785a72e4bb59ea35bb14a4c748eaa9" Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:04+01:00" level=debug msg="stored credentials found for jochen.heinze" Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 21 20:48:04 volumio-jh volumio[1703]: info: No need to fix Spotify hosts Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:05 volumio-jh volumio[1703]: info: Starting Shairport Sync Jan 21 20:48:05 volumio-jh volumio[1703]: info: Starting Shairport Sync Jan 21 20:48:05 volumio-jh volumio[1703]: info: Starting Shairport Sync Jan 21 20:48:05 volumio-jh sudo[1901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:48:05 volumio-jh sudo[1901]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:05 volumio-jh sudo[1903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:48:05 volumio-jh sudo[1903]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:05 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 21 20:48:05 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 21 20:48:05 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioGetState Jan 21 20:48:05 volumio-jh volumio[1703]: info: CorePlayQueue::getTrack 0 Jan 21 20:48:05 volumio-jh sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 21 20:48:05 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:05+01:00" level=debug msg="zeroconf server listening on port 33081" Jan 21 20:48:05 volumio-jh sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:05 volumio-jh volumio[1703]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:48:05 volumio-jh volumio[1703]: SPOTIFY: BQD4AMQzRY7KWg2wa_A_PRq5cNeEQIyPN2UCNE1-3ojsZviuWzC0pM9gUkvzxLcAwA_2Ozr6fFI8Kn9U-O68DjP3HCQSOiL0StXQGl2Fx-FUpzq82CDDIxFVeGipE0rReTRU8pbzdO0uRj_e7j4ZTmfSBOAC1jXJdOWQVzrhUJbAQ3KFdlUAZE_LOvmCKLNua6OvImCukib6JMI3_PIS_hYkRZWNBYRc52hq09cI89dU56XCoTFABDSgAsSV0rE Jan 21 20:48:05 volumio-jh volumio[1703]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 21 20:48:05 volumio-jh volumio[1703]: info: New Spotify access token = BQD4AMQzRY7KWg2wa_A_PRq5cNeEQIyPN2UCNE1-3ojsZviuWzC0pM9gUkvzxLcAwA_2Ozr6fFI8Kn9U-O68DjP3HCQSOiL0StXQGl2Fx-FUpzq82CDDIxFVeGipE0rReTRU8pbzdO0uRj_e7j4ZTmfSBOAC1jXJdOWQVzrhUJbAQ3KFdlUAZE_LOvmCKLNua6OvImCukib6JMI3_PIS_hYkRZWNBYRc52hq09cI89dU56XCoTFABDSgAsSV0rE Jan 21 20:48:05 volumio-jh volumio[1703]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 21 20:48:05 volumio-jh go-librespot[1884]: time="2025-01-21T20:48:05+01:00" level=debug msg="obtained new client token: AAA6/LfBnS2c2obQ4QSQcAZEHe+4//5eCVD/okmJDXfz9ZYdibyfbObjh0l3/IvJCtY68wynxMbllwvMEpMlNzluxCvG8ePBm1+9w6Z0M29ByG6gEpKA5D9Cn7Uffv0eYTc249ez3VW82QEien4TUiI5GWUJVPPshiu/J8AqtHVqR04NACuss+HgFgPate3aEbuTbvgPbz/L7+Cw24420iU5LimJ1axphEQYMvM+CGfYlFb/bVGvEIliWT5e" Jan 21 20:48:05 volumio-jh volumio[1703]: SPOTIFY: User informations: {"country":"DE","display_name":"jochen.heinze","email":"jochen@heinze.gr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jochen.heinze"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/jochen.heinze","id":"jochen.heinze","images":[],"product":"premium","type":"user","uri":"spotify:user:jochen.heinze"} Jan 21 20:48:05 volumio-jh volumio[1703]: info: Spotify Successfully logged in Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 21 20:48:05 volumio-jh volumio[1703]: info: [1737488885416] CoreMusicLibrary::Adding element Spotify Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 21 20:48:05 volumio-jh volumio[1703]: Cannot find translation for source Spotify Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:05 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:06 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:06 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:07 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:07 volumio-jh sudo[1925]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 21 20:48:07 volumio-jh sudo[1925]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:07 volumio-jh sudo[1925]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:07 volumio-jh sudo[1927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 21 20:48:07 volumio-jh sudo[1927]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:07 volumio-jh sudo[1927]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:07 volumio-jh sudo[1931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 21 20:48:07 volumio-jh sudo[1931]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 21 20:48:07 volumio-jh volumio[1703]: info: CALLMETHOD: miscellanea albumart clearAlbumartCache Jan 21 20:48:07 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: albumart , clearAlbumartCache Jan 21 20:48:07 volumio-jh sudo[1931]: pam_unix(sudo:session): session closed for user root Jan 21 20:48:07 volumio-jh volumio[1703]: info: Upmpdcli Daemon Started Jan 21 20:48:08 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 21 20:48:08 volumio-jh volumio[1703]: info: CoreCommandRouter::executeOnPlugin: mpd , rebuildAlbumCache Jan 21 20:48:08 volumio-jh volumio[1703]: info: Rebuild Album cache Jan 21 20:48:08 volumio-jh volumio[1703]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:48:08 volumio-jh volumio[1703]: TypeError: Cannot read property 'sendCommand' of undefined Jan 21 20:48:08 volumio-jh volumio[1703]: at /volumio/app/plugins/music_service/mpd/index.js:2987:22 Jan 21 20:48:08 volumio-jh volumio[1703]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jan 21 20:48:08 volumio-jh volumio[1703]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 21 20:48:08 volumio-jh sudo[1944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-21 20:47 Jan 21 20:48:08 volumio-jh sudo[1944]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"