-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2025-06-11 14:25:56 CEST. -- Jun 11 14:25:39 akai-aa-1010 systemd-timedated[1057]: Changed local time to Wed Jun 11 14:25:39 2025 Jun 11 14:25:39 akai-aa-1010 sudo[1055]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:39 akai-aa-1010 systemd[1]: Starting Daily apt download activities... Jun 11 14:25:39 akai-aa-1010 volumio-time-update[635]: volumio-time-update-util: System time updated successfully. Jun 11 14:25:39 akai-aa-1010 systemd[1]: Started Volumio Time Update Utility. Jun 11 14:25:39 akai-aa-1010 systemd[1]: Reached target Multi-User System. Jun 11 14:25:39 akai-aa-1010 systemd[1]: Reached target Graphical Interface. Jun 11 14:25:39 akai-aa-1010 systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 11 14:25:39 akai-aa-1010 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 11 14:25:39 akai-aa-1010 systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "network"... Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Refreshing Cached IP Addresses Jun 11 14:25:39 akai-aa-1010 sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "services"... Jun 11 14:25:39 akai-aa-1010 sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:39 akai-aa-1010 sudo[1068]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:39 akai-aa-1010 sudo[1070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 11 14:25:39 akai-aa-1010 sudo[1070]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:39 akai-aa-1010 sudo[1070]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "alsa_controller"... Jun 11 14:25:39 akai-aa-1010 sudo[1079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 11 14:25:39 akai-aa-1010 sudo[1079]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "wizard"... Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "networkfs"... Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Starting Udev Watcher for removable devices Jun 11 14:25:39 akai-aa-1010 sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=root,password=Bilbo418,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.200/Media\\media\\music /mnt/NAS/File_Server Jun 11 14:25:39 akai-aa-1010 sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Ignoring mount for partition: boot Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Ignoring mount for partition: volumio Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Ignoring mount for partition: volumio_data Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "volumio_command_line_client"... Jun 11 14:25:39 akai-aa-1010 volumio[1007]: info: Loading plugin "upnp"... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: [1749644740009] Starting Upmpd Daemon Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "my_music"... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "mpd"... Jun 11 14:25:40 akai-aa-1010 kernel: Key type cifs.spnego registered Jun 11 14:25:40 akai-aa-1010 kernel: Key type cifs.idmap registered Jun 11 14:25:40 akai-aa-1010 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. Jun 11 14:25:40 akai-aa-1010 kernel: CIFS: Attempting to mount //192.168.1.200/Media/media/music Jun 11 14:25:40 akai-aa-1010 systemd[1]: apt-daily.service: Succeeded. Jun 11 14:25:40 akai-aa-1010 systemd[1]: Started Daily apt download activities. Jun 11 14:25:40 akai-aa-1010 sudo[1109]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:40 akai-aa-1010 systemd[1]: Starting Daily apt upgrade and clean activities... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "upnp_browser"... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "alarm-clock"... Jun 11 14:25:40 akai-aa-1010 systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 11 14:25:40 akai-aa-1010 systemd[1]: Started Daily apt upgrade and clean activities. Jun 11 14:25:40 akai-aa-1010 systemd[1]: Startup finished in 14.851s (kernel) + 40.492s (userspace) = 55.343s. Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "airplay_emulation"... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Starting Shairport Sync Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "last_100"... Jun 11 14:25:40 akai-aa-1010 volumio[1007]: info: Loading plugin "webradio"... Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: Loading plugin "i2s_dacs"... Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: Loading plugin "volumiodiscovery"... Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** For more information see Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 11 14:25:41 akai-aa-1010 volumio[1007]: *** WARNING *** For more information see Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** For more information see Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 11 14:25:41 akai-aa-1010 node[1007]: *** WARNING *** For more information see Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: Discovery: Started advertising with name: Akai AA-1010 Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 11 14:25:41 akai-aa-1010 volumio[1007]: info: Loading plugin "spop"... Jun 11 14:25:42 akai-aa-1010 sh[536]: timed out Jun 11 14:25:42 akai-aa-1010 dhcpcd[588]: timed out Jun 11 14:25:42 akai-aa-1010 sh[536]: dhcpcd exited Jun 11 14:25:42 akai-aa-1010 dhcpcd[588]: dhcpcd exited Jun 11 14:25:42 akai-aa-1010 sh[536]: ifup: failed to bring up eth0 Jun 11 14:25:42 akai-aa-1010 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 11 14:25:42 akai-aa-1010 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 11 14:25:42 akai-aa-1010 volumio[1007]: info: Loading plugin "ytcr"... Jun 11 14:25:42 akai-aa-1010 sudo[1079]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:45 akai-aa-1010 volumio-remote-updater[636]: [2025-06-11 14:25:45] [connect] Successful connection Jun 11 14:25:46 akai-aa-1010 systemd[1]: systemd-hostnamed.service: Succeeded. Jun 11 14:25:46 akai-aa-1010 volumio[1007]: info: Loading plugin "outputs"... Jun 11 14:25:46 akai-aa-1010 volumio[1007]: info: Loading plugin "albumart"... Jun 11 14:25:46 akai-aa-1010 volumio[1007]: info: Plugin example_plugin is not enabled Jun 11 14:25:46 akai-aa-1010 volumio[1007]: info: Loading plugin "inputs"... Jun 11 14:25:46 akai-aa-1010 volumio[1007]: info: Loading plugin "updater_comm"... Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Plugin mpdemulation is not enabled Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Loading plugin "rest_api"... Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Loading plugin "websocket"... Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Forking 3 albumart workers Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Starting Socket.io Server version 2.3.0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Loading i18n strings for locale en Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Updating browse sources language Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::initPlayerControls Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Express server listening on port 3000 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: [Metrics] WebUI: 11s 727.42ms Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::resetVolumioState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::getcurrentVolume Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Volumio Network Manager: Network status updated: 2 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: verbose: New Socket.io Connection to 192.168.1.42:3000 from 192.168.1.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: verbose: New Socket.io Connection to 192.168.1.42:3000 from 192.168.1.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 11 14:25:47 akai-aa-1010 volumio-remote-updater[636]: [2025-06-11 14:25:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1749644745 101 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Starting albumart workers Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Starting albumart workers Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Executing start script for DAC IQaudIO Pi-DigiAMP+ Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Reloading queue from file Jun 11 14:25:47 akai-aa-1010 volumio[1007]: Starting albumart workers Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: VolumeController:: Volume=74 Mute =false Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::pushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::updateTrackBlock Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrackBlock Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::setRepeat null single undefined Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::pushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::setRandom null Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreStateMachine::pushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Setting Device type: Raspberry PI Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: DAC script executed Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Completed loading Core Plugins Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Preparing to generate the ALSA configuration file Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Listing playlists Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Listing playlists Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Discovery: adding 2da7189b-305a-4cd9-8076-4d7bbb0878bf Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Discovery: Found device Akai AA-1010 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Asound.conf file unchanged, so no further update is needed Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Output device has changed, restarting MPD Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: Output device has changed, restarting Shairport Sync Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:47 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:47 akai-aa-1010 sudo[1269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 11 14:25:47 akai-aa-1010 sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:47 akai-aa-1010 sudo[1269]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:47 akai-aa-1010 sudo[1272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 11 14:25:47 akai-aa-1010 sudo[1272]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 systemd[1]: Stopping Music Player Daemon... Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: ___________ START PLUGINS ___________ Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: ControllerMpd::onStart: Initializing MPD Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Creating MPD Configuration file Jun 11 14:25:48 akai-aa-1010 sudo[1283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 11 14:25:48 akai-aa-1010 sudo[1283]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: [1749644748122] CoreMusicLibrary::Adding element Media Servers Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 11 14:25:48 akai-aa-1010 sudo[1283]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:48 akai-aa-1010 sudo[1289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 sudo[1289]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: [1749644748289] CoreMusicLibrary::Adding element Last_100 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: [1749644748291] CoreMusicLibrary::Adding element Webradio Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Initializing BBC Radios Jun 11 14:25:48 akai-aa-1010 systemd[1]: mpd.service: Succeeded. Jun 11 14:25:48 akai-aa-1010 systemd[1]: Stopped Music Player Daemon. Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Creating Spotify config file Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 systemd[1]: Starting Music Player Daemon... Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Volumio Calling Home Jun 11 14:25:48 akai-aa-1010 sudo[1320]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 11 14:25:48 akai-aa-1010 sudo[1320]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 sudo[1320]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: MPD Permissions set Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: MPD Permissions set Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: VolumeController:: Volume=74 Mute =false Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreStateMachine::pushState Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 11 14:25:48 akai-aa-1010 volumio[1007]: verbose: New Socket.io Connection to 192.168.1.42:3000 from 192.168.1.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Volumio called home Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Spotify config file written Jun 11 14:25:48 akai-aa-1010 volumio[1007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 11 14:25:48 akai-aa-1010 sudo[1330]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 11 14:25:48 akai-aa-1010 sudo[1330]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: No need to fix Spotify hosts Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Discovery: adding 94f269ef-2e68-487e-a0c2-f1d748f9b401 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Discovery: Found device Pioneer SX-950 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Discovery: Connecting to remote: 192.168.1.23 Jun 11 14:25:48 akai-aa-1010 systemd[1]: Started go-librespot Daemon. Jun 11 14:25:48 akai-aa-1010 go-librespot[1336]: Librespot-go daemon starting... Jun 11 14:25:48 akai-aa-1010 sudo[1330]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Discovery: Connected to remote: 192.168.1.23 Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Starting Shairport Sync Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Starting Shairport Sync Jun 11 14:25:48 akai-aa-1010 sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: Starting Shairport Sync Jun 11 14:25:48 akai-aa-1010 sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 sudo[1345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 11 14:25:48 akai-aa-1010 sudo[1345]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:48 akai-aa-1010 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 11 14:25:48 akai-aa-1010 systemd[1]: shairport-sync.service: Succeeded. Jun 11 14:25:48 akai-aa-1010 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 11 14:25:48 akai-aa-1010 sudo[1349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 11 14:25:48 akai-aa-1010 sudo[1349]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:48 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:48 akai-aa-1010 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 11 14:25:49 akai-aa-1010 sudo[1343]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:49 akai-aa-1010 sudo[1345]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:49 akai-aa-1010 volumio[1007]: info: Shairport-Sync Started Jun 11 14:25:49 akai-aa-1010 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 11 14:25:49 akai-aa-1010 volumio[1007]: Error adding Membership: Error: addMembership EINVAL Jun 11 14:25:49 akai-aa-1010 systemd[1]: shairport-sync.service: Succeeded. Jun 11 14:25:49 akai-aa-1010 volumio[1007]: info: Shairport-Sync Started Jun 11 14:25:49 akai-aa-1010 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 11 14:25:49 akai-aa-1010 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 11 14:25:49 akai-aa-1010 sudo[1349]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:49 akai-aa-1010 volumio[1007]: info: Shairport-Sync Started Jun 11 14:25:49 akai-aa-1010 mpd[1328]: Jun 11 14:25 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 11 14:25:49 akai-aa-1010 systemd[1]: Started Music Player Daemon. Jun 11 14:25:49 akai-aa-1010 sudo[1289]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:49 akai-aa-1010 sudo[1272]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:49 akai-aa-1010 volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jun 11 14:25:49 akai-aa-1010 volumio[1007]: assert.ok(self.idling) Jun 11 14:25:49 akai-aa-1010 volumio[1007]: error: The expression evaluated to a falsy value: Jun 11 14:25:49 akai-aa-1010 volumio[1007]: assert.ok(self.idling) Jun 11 14:25:49 akai-aa-1010 volumio[1007]: error: updateQueue error: null Jun 11 14:25:49 akai-aa-1010 volumio[1007]: info: MPD running with PID1328 Jun 11 14:25:49 akai-aa-1010 volumio[1007]: ,establishing connection Jun 11 14:25:49 akai-aa-1010 volumio[1007]: error: updateQueue error: null Jun 11 14:25:50 akai-aa-1010 sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 11 14:25:50 akai-aa-1010 sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:50 akai-aa-1010 sudo[1380]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:50 akai-aa-1010 sudo[1383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 11 14:25:50 akai-aa-1010 sudo[1383]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:50 akai-aa-1010 sudo[1383]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:50 akai-aa-1010 sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 11 14:25:50 akai-aa-1010 sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 14:25:50 akai-aa-1010 systemd[1]: Started UPnP Renderer front-end to MPD. Jun 11 14:25:50 akai-aa-1010 sudo[1386]: pam_unix(sudo:session): session closed for user root Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: Upmpdcli Daemon Started Jun 11 14:25:50 akai-aa-1010 volumio[1388]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jun 11 14:25:50 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:50+02:00" level=info msg="generated new device id: c75179f008821d981468b67c162aac64fdd1c3df" Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: Completed starting Core Plugins Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: ------------------------------------------- Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: ----- MyVolumio plugins startup ---- Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: ------------------------------------------- Jun 11 14:25:50 akai-aa-1010 volumio[1007]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 11 14:25:51 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:51+02: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]" Jun 11 14:25:51 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:51+02: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]" Jun 11 14:25:51 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:51+02: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]" Jun 11 14:25:51 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:51+02:00" level=debug msg="zeroconf server listening on port 38629" Jun 11 14:25:51 akai-aa-1010 volumio[1007]: info: go-librespot daemon successfully initialized Jun 11 14:25:53 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:53+02:00" level=debug msg="obtained new client token: AADgsPo5RTpqBcdmyOPKT0oH2BPl+9m/3/h56gySuJaL4CZNNYgvMKnehRS+osMVhO1HMNbFkB1rUaqBX8opMC5bBPe3TswYOXA2eTvK0IaK1NCJhKsejTyMMqA63UJ91cALCxJt+macFXhwN9ocJdgTT8qPZP2LcSegbBhFQR5X4B3ycW00hC3pN5Dpjan09SSI51ZWhkCVFImHfoLcYTubb7glZHNG1CctQJ5pHRUcMTGJhdKk+WRK+vFdxV8=" Jun 11 14:25:53 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:53+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Jun 11 14:25:53 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:53+02:00" level=debug msg="completed keyexchange" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="completed challenge" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="authenticated as ohjay93" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="authenticated as ohjay93" Jun 11 14:25:54 akai-aa-1010 volumio[1007]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="dealer connection opened" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=info msg="accepted zeroconf user ohjay93 from Joachim’s MacBook Air" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="autoplay enabled: false" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="received connection id: ZWIzYWJmOTYtNGFiYi00NmIzLWE0ZjktZWQyOTk0YjZkZTNkK2RlYWxlcit0Y3A6Ly8wYWNhNTk1YS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNzY2RkRFQzg3Mzk0RDYyNUNBOEI0MDhDRTJFQjIwOURERUZFMTMzRkE2NTZENEVBMUM4OEU1N0NFQjhBNzFFNg==" Jun 11 14:25:54 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:54 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="handling transfer player command from 37364cf56342693c50e5a4dc590c226a60ca5103" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="resolved context of track" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="loading track (paused: true, position: 107020ms)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:54 akai-aa-1010 volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="new websocket client" Jun 11 14:25:54 akai-aa-1010 volumio[1007]: info: Connection to go-librespot Websocket established Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=trace msg="emitting websocket event: will_play" Jun 11 14:25:54 akai-aa-1010 volumio[1007]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4XHtgJqXoegZNXjj1qKdTZ","play_origin":"search"}} Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="selected format OGG_VORBIS_320 (71aa30e01adc99d9e8dc536280ea80d71c77aaeb)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="requested aes key for file 71aa30e01adc99d9e8dc536280ea80d71c77aaeb, gid: 4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:54 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3185" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched first chunk of 22, total size is 11304544 bytes" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2039" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 12/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 10/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 11/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="fetched chunk 9/21, size: 524288" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=trace msg="seek to 107020ms (diff: 101ms, samples: 4719582, bytes: 4725425)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="created new output device" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=info msg="loaded track \"Sveve over byen\" (paused: true, position: 107020ms, duration: 262906ms, prefetched: false)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=trace msg="emitting websocket event: metadata" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=trace msg="emitting websocket event: active" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="sending successful reply for dealer request" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 11 14:25:55 akai-aa-1010 volumio[1007]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4XHtgJqXoegZNXjj1qKdTZ","name":"Sveve over byen","artist_names":["deLillos"],"album_name":"Festen er ikke over, det er kake igjen (1985-2005)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020c3ad0649e34e8ceb67cc40f","position":107020,"duration":262906,"release_date":"year:2005 month:4 day:1","track_number":26,"disc_number":1}} Jun 11 14:25:55 akai-aa-1010 volumio[1007]: SPOTIFY: received: {"type":"active","data":null} Jun 11 14:25:55 akai-aa-1010 volumio[1007]: info: Aligning Spotify Volume to Volumio Volume Jun 11 14:25:55 akai-aa-1010 volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 11 14:25:55 akai-aa-1010 volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 11 14:25:55 akai-aa-1010 volumio[1007]: info: Setting Spotify Volume from Volumio: 74 Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 11 14:25:55 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:55+02:00" level=trace msg="emitting websocket event: paused" Jun 11 14:25:55 akai-aa-1010 volumio[1007]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4XHtgJqXoegZNXjj1qKdTZ","play_origin":"search"}} Jun 11 14:25:55 akai-aa-1010 volumio[1007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 14:25:55 akai-aa-1010 volumio[1007]: TypeError: Cannot read property 'service' of undefined Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at WebSocket.emit (events.js:315:20) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.emit (events.js:315:20) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at Socket.emit (events.js:315:20) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at addChunk (internal/streams/readable.js:309:12) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 11 14:25:55 akai-aa-1010 volumio[1007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=debug msg="handling resume player command from 37364cf56342693c50e5a4dc590c226a60ca5103" Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=trace msg="seek to 107020ms (diff: 101ms, samples: 4719582, bytes: 4725425)" uri="spotify:track:4XHtgJqXoegZNXjj1qKdTZ" Jun 11 14:25:56 akai-aa-1010 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=debug msg="resume track at 106919ms" Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=trace msg="scheduling prefetch in 126s" Jun 11 14:25:56 akai-aa-1010 go-librespot[1336]: time="2025-06-11T14:25:56+02:00" level=debug msg="sending successful reply for dealer request" Jun 11 14:25:56 akai-aa-1010 sudo[1421]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-11 14:24 Jun 11 14:25:56 akai-aa-1010 sudo[1421]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"