-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2025-01-15 21:40:03 CET. -- Jan 15 21:39:15 volumio-jh systemd-timedated[916]: Changed local time to Wed Jan 15 21:39:15 2025 Jan 15 21:39:15 volumio-jh sudo[914]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:15 volumio-jh volumio-time-update[590]: volumio-time-update-util: System time updated successfully. Jan 15 21:39:15 volumio-jh systemd[1]: Started Volumio Time Update Utility. Jan 15 21:39:15 volumio-jh wireless.js[589]: trying... Jan 15 21:39:15 volumio-jh sudo[918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 15 21:39:15 volumio-jh sudo[918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:15 volumio-jh sudo[918]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:16 volumio-jh wireless.js[589]: trying... Jan 15 21:39:16 volumio-jh sudo[921]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 15 21:39:16 volumio-jh sudo[921]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:16 volumio-jh sudo[921]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:17 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:17] [info] asio async_connect error: system:111 (Connection refused) Jan 15 21:39:17 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:17] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 15 21:39:17 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:17] [error] handle_connect error: Underlying Transport Error Jan 15 21:39:17 volumio-jh wireless.js[589]: trying... Jan 15 21:39:17 volumio-jh sudo[924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 15 21:39:17 volumio-jh sudo[924]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:17 volumio-jh sudo[924]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:18 volumio-jh wireless.js[589]: trying... Jan 15 21:39:18 volumio-jh sudo[927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 15 21:39:18 volumio-jh sudo[927]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:18 volumio-jh sudo[927]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:18 volumio-jh dhcpcd[886]: wlan0: leased 192.168.23.65 for 604800 seconds Jan 15 21:39:18 volumio-jh avahi-daemon[571]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.23.65. Jan 15 21:39:18 volumio-jh dhcpcd[886]: wlan0: adding route to 192.168.23.0/24 Jan 15 21:39:18 volumio-jh dhcpcd[886]: wlan0: adding default route via 192.168.23.1 Jan 15 21:39:18 volumio-jh avahi-daemon[571]: New relevant interface wlan0.IPv4 for mDNS. Jan 15 21:39:18 volumio-jh avahi-daemon[571]: Registering new address record for 192.168.23.65 on wlan0.IPv4. Jan 15 21:39:19 volumio-jh wireless.js[589]: trying... Jan 15 21:39:19 volumio-jh sudo[949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 15 21:39:19 volumio-jh sudo[949]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:19 volumio-jh sudo[949]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:19 volumio-jh wireless.js[589]: Connected to: ----UBI3 Jan 15 21:39:19 volumio-jh wireless.js[589]: ---- Jan 15 21:39:19 volumio-jh sudo[952]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 21:39:19 volumio-jh sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:19 volumio-jh sudo[952]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:19 volumio-jh wireless.js[589]: ... joined AP, wlan0 IPv4 is 192.168.23.65, ipV6 is undefined Jan 15 21:39:19 volumio-jh wireless.js[589]: It's done! AP Jan 15 21:39:19 volumio-jh systemd[1]: Started Wireless Services. Jan 15 21:39:19 volumio-jh kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 15 21:39:19 volumio-jh systemd[1]: Started Volumio Backend Module. Jan 15 21:39:19 volumio-jh systemd[1]: Started Volumio Cpu Tweaker. Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: Setting RT Priority for mpd Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: pid 35's current scheduling policy: SCHED_OTHER Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: pid 35's current scheduling priority: 0 Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: Setting MPD Affinity Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: pid 3's current affinity mask: f Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jan 15 21:39:19 volumio-jh volumio-cpu-tweak[958]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jan 15 21:39:19 volumio-jh systemd[1]: volumio_cpu_tweak.service: Succeeded. Jan 15 21:39:24 volumio-jh volumio[957]: info: ------------------------------------------- Jan 15 21:39:24 volumio-jh volumio[957]: info: ----- Volumio3 ---- Jan 15 21:39:24 volumio-jh volumio[957]: info: ------------------------------------------- Jan 15 21:39:24 volumio-jh volumio[957]: info: ----- System startup ---- Jan 15 21:39:24 volumio-jh volumio[957]: info: ------------------------------------------- Jan 15 21:39:26 volumio-jh volumio[957]: info: MYVOLUMIO Environment detected Jan 15 21:39:26 volumio-jh volumio[957]: info: Plugin folders cleanup Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning into folder /volumio/app/plugins/ Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category audio_interface Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category miscellanea Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category music_service Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category plugins.json Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category system_controller Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category user_interface Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning into folder /data/plugins/ Jan 15 21:39:26 volumio-jh volumio[957]: info: Scanning category music_service Jan 15 21:39:26 volumio-jh volumio[957]: info: Plugin folders cleanup completed Jan 15 21:39:26 volumio-jh volumio[957]: info: ------------------------------------------- Jan 15 21:39:26 volumio-jh volumio[957]: info: ----- Core plugins startup ---- Jan 15 21:39:26 volumio-jh volumio[957]: info: ------------------------------------------- Jan 15 21:39:26 volumio-jh volumio[957]: info: Loading plugins from folder /volumio/app/plugins/ Jan 15 21:39:26 volumio-jh volumio[957]: info: Adding plugin upnp to MyMusic Plugins Jan 15 21:39:26 volumio-jh volumio[957]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 15 21:39:26 volumio-jh volumio[957]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 15 21:39:26 volumio-jh volumio[957]: info: Loading plugins from folder /data/plugins/ Jan 15 21:39:26 volumio-jh volumio[957]: info: Loading plugin "system"... Jan 15 21:39:26 volumio-jh volumio[957]: info: Loading plugin "appearance"... Jan 15 21:39:27 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:27] [connect] Successful connection Jan 15 21:39:28 volumio-jh volumio[957]: info: Loading plugin "network"... Jan 15 21:39:28 volumio-jh volumio[957]: info: Refreshing Cached IP Addresses Jan 15 21:39:28 volumio-jh sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 21:39:28 volumio-jh sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh sudo[990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 21:39:28 volumio-jh sudo[990]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh sudo[988]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:28 volumio-jh sudo[990]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:28 volumio-jh volumio[957]: info: Loading plugin "services"... Jan 15 21:39:28 volumio-jh volumio[957]: info: Loading plugin "alsa_controller"... Jan 15 21:39:28 volumio-jh sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 15 21:39:28 volumio-jh sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 21:39:28 volumio-jh volumio[957]: info: Loading plugin "wizard"... Jan 15 21:39:28 volumio-jh volumio[957]: info: Loading plugin "networkfs"... Jan 15 21:39:28 volumio-jh volumio[957]: info: Starting Udev Watcher for removable devices Jan 15 21:39:28 volumio-jh sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=jheinze,password=Libelle24$,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.23.20/Tidal /mnt/NAS/Musik-neu Jan 15 21:39:28 volumio-jh sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh volumio[957]: info: Ignoring mount for partition: boot Jan 15 21:39:28 volumio-jh volumio[957]: info: Ignoring mount for partition: volumio Jan 15 21:39:28 volumio-jh volumio[957]: info: Ignoring mount for partition: volumio_data Jan 15 21:39:28 volumio-jh volumio[957]: error: Cannot associate FS Label, not mounting Jan 15 21:39:28 volumio-jh volumio[957]: info: Mounting Device SYSTEM Jan 15 21:39:28 volumio-jh sudo[1023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/SYSTEM -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 15 21:39:28 volumio-jh sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh kernel: FAT-fs (sda2): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Jan 15 21:39:28 volumio-jh kernel: FAT-fs (sda2): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 15 21:39:28 volumio-jh sudo[1023]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:28 volumio-jh kernel: Key type cifs.spnego registered Jan 15 21:39:28 volumio-jh kernel: Key type cifs.idmap registered Jan 15 21:39:28 volumio-jh kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 15 21:39:28 volumio-jh kernel: CIFS: Attempting to mount //192.168.23.20/Tidal Jan 15 21:39:28 volumio-jh volumio[957]: info: Mounting Device Local_Disk Jan 15 21:39:28 volumio-jh sudo[1042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda3 /mnt/USB/Local_Disk -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 15 21:39:28 volumio-jh sudo[1042]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:28 volumio-jh sudo[1014]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:29 volumio-jh ntfs-3g[1051]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 15 21:39:29 volumio-jh ntfs-3g[1051]: Mounted /dev/sda3 (Read-Write, label "Local Disk", NTFS 3.1) Jan 15 21:39:29 volumio-jh ntfs-3g[1051]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 15 21:39:29 volumio-jh ntfs-3g[1051]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda3,blkdev,blksize=4096 Jan 15 21:39:29 volumio-jh ntfs-3g[1051]: Global ownership and permissions enforced, configuration type 7 Jan 15 21:39:29 volumio-jh sudo[1042]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:29 volumio-jh volumio[957]: info: Mounting Device Windows_RE_tools Jan 15 21:39:29 volumio-jh sudo[1056]: 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 15 21:39:29 volumio-jh sudo[1056]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:29 volumio-jh sudo[999]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:29 volumio-jh ntfs-3g[1059]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 15 21:39:29 volumio-jh ntfs-3g[1059]: Mounted /dev/sda4 (Read-Write, label "Windows RE tools", NTFS 3.1) Jan 15 21:39:29 volumio-jh ntfs-3g[1059]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 15 21:39:29 volumio-jh ntfs-3g[1059]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda4,blkdev,blksize=4096 Jan 15 21:39:29 volumio-jh ntfs-3g[1059]: Global ownership and permissions enforced, configuration type 7 Jan 15 21:39:29 volumio-jh sudo[1056]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:29 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 21:39:29 volumio-jh volumio[957]: info: Loading plugin "volumio_command_line_client"... Jan 15 21:39:29 volumio-jh volumio[957]: info: Loading plugin "upnp"... Jan 15 21:39:29 volumio-jh volumio[957]: info: [1736973569263] Starting Upmpd Daemon Jan 15 21:39:29 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 21:39:29 volumio-jh volumio[957]: info: Loading plugin "my_music"... Jan 15 21:39:29 volumio-jh volumio[957]: info: Loading plugin "mpd"... Jan 15 21:39:29 volumio-jh systemd[1]: systemd-fsckd.service: Succeeded. Jan 15 21:39:29 volumio-jh volumio[957]: info: Loading plugin "upnp_browser"... Jan 15 21:39:30 volumio-jh volumio[957]: info: Loading plugin "alarm-clock"... Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "airplay_emulation"... Jan 15 21:39:31 volumio-jh volumio[957]: info: Starting Shairport Sync Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "last_100"... Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "webradio"... Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "i2s_dacs"... Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "volumiodiscovery"... Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** For more information see Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 21:39:31 volumio-jh volumio[957]: *** WARNING *** For more information see Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** For more information see Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 21:39:31 volumio-jh node[957]: *** WARNING *** For more information see Jan 15 21:39:31 volumio-jh volumio[957]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 15 21:39:31 volumio-jh volumio[957]: info: Discovery: Started advertising with name: Volumio-JH Jan 15 21:39:31 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 21:39:31 volumio-jh volumio[957]: info: Loading plugin "spop"... Jan 15 21:39:33 volumio-jh volumio[957]: info: Loading plugin "outputs"... Jan 15 21:39:33 volumio-jh volumio[957]: info: Loading plugin "albumart"... Jan 15 21:39:33 volumio-jh volumio[957]: info: Plugin example_plugin is not enabled Jan 15 21:39:33 volumio-jh volumio[957]: info: Loading plugin "inputs"... Jan 15 21:39:33 volumio-jh volumio[957]: info: Loading plugin "updater_comm"... Jan 15 21:39:34 volumio-jh volumio[957]: info: Plugin mpdemulation is not enabled Jan 15 21:39:34 volumio-jh volumio[957]: info: Loading plugin "rest_api"... Jan 15 21:39:34 volumio-jh volumio[957]: info: Loading plugin "websocket"... Jan 15 21:39:34 volumio-jh volumio[957]: info: Starting Socket.io Server version 2.3.0 Jan 15 21:39:34 volumio-jh volumio[957]: info: Loading i18n strings for locale de Jan 15 21:39:34 volumio-jh volumio[957]: Updating browse sources language Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:34 volumio-jh volumio[957]: Forking 3 albumart workers Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::initPlayerControls Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:34 volumio-jh volumio[957]: Express server listening on port 3000 Jan 15 21:39:34 volumio-jh volumio[957]: [Metrics] WebUI: 11s 235.53ms Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreStateMachine::resetVolumioState Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreStateMachine::getcurrentVolume Jan 15 21:39:34 volumio-jh volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 21:39:34 volumio-jh volumio[957]: info: Volumio Network Manager: Network status updated: 3 Jan 15 21:39:35 volumio-jh volumio[957]: Starting albumart workers Jan 15 21:39:35 volumio-jh volumio[957]: 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 15 21:39:35 volumio-jh volumio[957]: Starting albumart workers Jan 15 21:39:35 volumio-jh volumio[957]: 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: 2 Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::pushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 21:39:35 volumio-jh volumio[957]: Starting albumart workers Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioPushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::updateTrackBlock Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrackBlock Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 21:39:35 volumio-jh volumio[957]: info: Reloading queue from file Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::setRepeat false single undefined Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::pushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioPushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::setRandom false Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::pushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioPushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreStateMachine::pushState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioPushState Jan 15 21:39:35 volumio-jh volumio[957]: info: Setting Device type: Raspberry PI Jan 15 21:39:35 volumio-jh volumio[957]: info: Completed loading Core Plugins Jan 15 21:39:35 volumio-jh volumio[957]: info: Preparing to generate the ALSA configuration file Jan 15 21:39:35 volumio-jh volumio[957]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 15 21:39:35 volumio-jh volumio[957]: info: Reading ALSA contributions from plugins. Jan 15 21:39:35 volumio-jh volumio[957]: info: Discovery: adding 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 15 21:39:35 volumio-jh volumio[957]: info: Discovery: Found device Volumio-JH Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: Discovery: this is already registered, 5080bb03-65ab-4a8c-b489-c34fbd6bad1c Jan 15 21:39:35 volumio-jh volumio[957]: info: Discovery: Found device Volumio-JH Jan 15 21:39:35 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:35 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:35 volumio-jh volumio[957]: info: Asound.conf file written Jan 15 21:39:35 volumio-jh sudo[1112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 15 21:39:35 volumio-jh sudo[1112]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:36 volumio-jh sudo[1112]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:36 volumio-jh volumio[957]: info: Output device has changed, restarting MPD Jan 15 21:39:36 volumio-jh volumio[957]: info: Output device has changed, restarting Shairport Sync Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:36 volumio-jh systemd[1]: systemd-hostnamed.service: Succeeded. Jan 15 21:39:36 volumio-jh sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 21:39:36 volumio-jh sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:36 volumio-jh sudo[1117]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:36 volumio-jh sudo[1119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 21:39:36 volumio-jh sudo[1119]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:36 volumio-jh volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 15 21:39:36 volumio-jh volumio[957]: info: ___________ START PLUGINS ___________ Jan 15 21:39:36 volumio-jh volumio[957]: info: ControllerMpd::onStart: Initializing MPD Jan 15 21:39:36 volumio-jh volumio[957]: info: Creating MPD Configuration file Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 21:39:36 volumio-jh volumio[957]: info: [1736973576359] CoreMusicLibrary::Adding element Medienserver Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:36 volumio-jh sudo[1133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 21:39:36 volumio-jh sudo[1133]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:36 volumio-jh sudo[1133]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:36 volumio-jh sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 21:39:36 volumio-jh sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:36 volumio-jh volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 21:39:36 volumio-jh volumio[957]: info: [1736973576573] CoreMusicLibrary::Adding element Last_100 Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 21:39:36 volumio-jh volumio[957]: info: [1736973576578] CoreMusicLibrary::Adding element Webradio Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 21:39:36 volumio-jh volumio[957]: info: Initializing BBC Radios Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 21:39:36 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: Creating Spotify config file Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: Volumio Calling Home Jan 15 21:39:38 volumio-jh volumio[957]: 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 15 21:39:38 volumio-jh volumio[957]: info: MPD Permissions set Jan 15 21:39:38 volumio-jh volumio[957]: info: Volumio called home Jan 15 21:39:38 volumio-jh volumio[957]: info: Spotify config file written Jan 15 21:39:38 volumio-jh volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 15 21:39:38 volumio-jh sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh sudo[1191]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 21:39:38 volumio-jh volumio[957]: info: No need to fix Spotify hosts Jan 15 21:39:38 volumio-jh systemd[1]: Started go-librespot Daemon. Jan 15 21:39:38 volumio-jh go-librespot[1201]: Librespot-go daemon starting... Jan 15 21:39:38 volumio-jh sudo[1191]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:38 volumio-jh volumio[957]: info: Starting Shairport Sync Jan 15 21:39:38 volumio-jh volumio[957]: info: Starting Shairport Sync Jan 15 21:39:38 volumio-jh volumio[957]: info: Starting Shairport Sync Jan 15 21:39:38 volumio-jh sudo[1204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 15 21:39:38 volumio-jh sudo[1204]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh sudo[1206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 15 21:39:39 volumio-jh sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:39 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:39 volumio-jh sudo[1209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 15 21:39:39 volumio-jh sudo[1209]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh volumio[957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 15 21:39:39 volumio-jh volumio[957]: SPOTIFY: BQBPC0ZJk53rm9p35qsscLB5XjjPatzmrgcAP58LzYAB-XO8-4jjQMkYvU2aH2uEaTVex2q-HGoTiH5BRW-SGB0V_sJ1VlwGTt-NYBV90Yxal9OHn8gmajRXGXctAkzrMQC-iQg5BY8zk6K0GiC1FWu20DJVOxLxUAtN5loBDahxrIr8z6d3qohCMU6WQEwxSYpgfmeECQikdvbgwh7DJYZLWG-ENc6ra9SS3cz06tkydXTktTAky_8OwcoZ-Xo Jan 15 21:39:39 volumio-jh volumio[957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 15 21:39:39 volumio-jh volumio[957]: info: New Spotify access token = BQBPC0ZJk53rm9p35qsscLB5XjjPatzmrgcAP58LzYAB-XO8-4jjQMkYvU2aH2uEaTVex2q-HGoTiH5BRW-SGB0V_sJ1VlwGTt-NYBV90Yxal9OHn8gmajRXGXctAkzrMQC-iQg5BY8zk6K0GiC1FWu20DJVOxLxUAtN5loBDahxrIr8z6d3qohCMU6WQEwxSYpgfmeECQikdvbgwh7DJYZLWG-ENc6ra9SS3cz06tkydXTktTAky_8OwcoZ-Xo Jan 15 21:39:39 volumio-jh volumio[957]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 15 21:39:39 volumio-jh sudo[1214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 21:39:39 volumio-jh sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh sudo[1214]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:39 volumio-jh sudo[1216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 21:39:39 volumio-jh sudo[1216]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh volumio[957]: 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 15 21:39:39 volumio-jh volumio[957]: info: Spotify Successfully logged in Jan 15 21:39:39 volumio-jh sudo[1216]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:39 volumio-jh volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 21:39:39 volumio-jh volumio[957]: info: [1736973579341] CoreMusicLibrary::Adding element Spotify Jan 15 21:39:39 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:39 volumio-jh volumio[957]: Cannot find translation for source Spotify Jan 15 21:39:39 volumio-jh sudo[1220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 15 21:39:39 volumio-jh sudo[1220]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 21:39:39 volumio-jh systemd[1]: Started UPnP Renderer front-end to MPD. Jan 15 21:39:39 volumio-jh sudo[1220]: pam_unix(sudo:session): session closed for user root Jan 15 21:39:39 volumio-jh volumio[957]: info: Upmpdcli Daemon Started Jan 15 21:39:39 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:39+01:00" level=info msg="generated new device id: 66a116c6e83c482d902c72ed281dfd6df2d2a5db" Jan 15 21:39:39 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:39+01:00" level=debug msg="stored credentials found for jochen.heinze" Jan 15 21:39:40 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 15 21:39:40 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 15 21:39:40 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 15 21:39:40 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:40+01:00" level=debug msg="zeroconf server listening on port 34159" Jan 15 21:39:40 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:40+01:00" level=debug msg="obtained new client token: AABNCLqQI9OlDnTXY37iU036hmaZNDJKObo8u1m+QNY3dMz3BgTfGO7WSHCKdNZLsogU/vEc2kNctyIK+va2eHPD7N8kdx9CQh/HsuuyKtakS02zadGD+euxRX4bZXSRNGdWbwbpHWDnSYhTI9pInUwBsfC0B09UzL20Ev6qRkTk28gBI+0FQMyKDsOGWEmlqYnHhIFbqIHSEzV5qap0isF4Uev34aeNpHmD4BbjaHF+1vHQM1skuKcJsbem" Jan 15 21:39:41 volumio-jh volumio[957]: info: go-librespot daemon successfully initialized Jan 15 21:39:42 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:42] [connect] Successful connection Jan 15 21:39:42 volumio-jh volumio-remote-updater[584]: [2025-01-15 21:39:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736973582 101 Jan 15 21:39:42 volumio-jh volumio[957]: 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: 5 Jan 15 21:39:42 volumio-jh volumio[957]: 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: 6 Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 15 21:39:42 volumio-jh volumio[957]: info: Received Get System Info Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 15 21:39:42 volumio-jh volumio[957]: info: Discovery: Getting this device information Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetVisibleSources Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 15 21:39:42 volumio-jh volumio[957]: info: Received Get System Info Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 15 21:39:42 volumio-jh volumio[957]: info: Discovery: Getting this device information Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:42 volumio-jh volumio[957]: info: Listing playlists Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetQueue Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreStateMachine::getQueue Jan 15 21:39:42 volumio-jh volumio[957]: info: CorePlayQueue::getQueue Jan 15 21:39:42 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 15 21:39:44 volumio-jh volumio[957]: info: Initializing connection to go-librespot Websocket Jan 15 21:39:44 volumio-jh go-librespot[1201]: time="2025-01-15T21:39:44+01:00" level=debug msg="new websocket client" Jan 15 21:39:44 volumio-jh volumio[957]: info: Connection to go-librespot Websocket established Jan 15 21:39:45 volumio-jh systemd[1]: systemd-timedated.service: Succeeded. Jan 15 21:39:47 volumio-jh volumio[957]: info: Getting Spotify volume Jan 15 21:39:47 volumio-jh volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 15 21:39:48 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:48 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:48 volumio-jh volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 15 21:39:48 volumio-jh volumio[957]: SPOTIFY: SPOTIFY VOLUME undefined Jan 15 21:39:48 volumio-jh volumio[957]: SPOTIFY: VOLUMIO VOLUME 100 Jan 15 21:39:48 volumio-jh volumio[957]: info: Aligning Spotify Volume to Volumio Volume Jan 15 21:39:48 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetState Jan 15 21:39:48 volumio-jh volumio[957]: info: CorePlayQueue::getTrack 0 Jan 15 21:39:48 volumio-jh volumio[957]: info: Setting Spotify Volume from Volumio: 100 Jan 15 21:39:49 volumio-jh volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 15 21:39:49 volumio-jh volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Jan 15 21:39:49 volumio-jh volumio[957]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Jan 15 21:39:59 volumio-jh systemd-udevd[360]: Spawned process '/bin/bash -c '/usr/local/bin/volumio usbattach'' [504] is taking longer than 59s to complete Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetBrowseSources Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetBrowseSources Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::volumioGetBrowseSources Jan 15 21:39:59 volumio-jh systemd-udevd[354]: pcmC5D0p: Worker [360] processing SEQNUM=1945 is taking a long time Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 15 21:39:59 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 15 21:40:02 volumio-jh volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Jan 15 21:40:02 volumio-jh volumio[957]: verbose: ControllerMpd::sendMpdCommand update Jan 15 21:40:02 volumio-jh volumio[957]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 21:40:02 volumio-jh volumio[957]: TypeError: Cannot read property 'then' of undefined Jan 15 21:40:02 volumio-jh volumio[957]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Jan 15 21:40:02 volumio-jh volumio[957]: at ControllerMpd.updateDb (/volumio/app/plugins/music_service/mpd/index.js:1899:15) Jan 15 21:40:02 volumio-jh volumio[957]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Jan 15 21:40:02 volumio-jh volumio[957]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1085:26) Jan 15 21:40:02 volumio-jh volumio[957]: at Socket.emit (events.js:315:20) Jan 15 21:40:02 volumio-jh volumio[957]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 15 21:40:02 volumio-jh volumio[957]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jan 15 21:40:02 volumio-jh volumio[957]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 21:40:03 volumio-jh sudo[1271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-15 21:39 Jan 15 21:40:03 volumio-jh sudo[1271]: 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"