-- Logs begin at Sat 2024-05-11 21:28:19 EDT, end at Sat 2024-05-11 21:31:33 EDT. -- May 11 21:30:27 volumio volumio[598]: verbose: New Socket.io Connection to volumio.loc from 10.1.113.101 UA: Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0 Total Clients: 6 May 11 21:30:27 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:27 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:27 volumio volumio[598]: info: CoreCommandRouter::volumioGetQueue May 11 21:30:27 volumio volumio[598]: info: CoreStateMachine::getQueue May 11 21:30:27 volumio volumio[598]: info: CorePlayQueue::getQueue May 11 21:30:27 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid May 11 21:30:27 volumio volumio[598]: info: CALLMETHOD: music_service inputs serialMonitorAction [object Object] May 11 21:30:27 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: inputs , serialMonitorAction May 11 21:30:27 volumio volumio[598]: info: Error : CoreCommandRouter::executeOnPlugin: No method [serialMonitorAction] in plugin inputs May 11 21:30:27 volumio volumio[598]: info: CALLMETHOD: system_controller motivocontrol displaySelection [object Object] May 11 21:30:27 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: motivocontrol , displaySelection May 11 21:30:28 volumio volumio[598]: info: CALLMETHOD: system_controller system enableSSH true May 11 21:30:28 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , enableSSH May 11 21:30:28 volumio sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start ssh.service May 11 21:30:29 volumio sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 21:30:29 volumio systemd[1]: Starting OpenBSD Secure Shell server... May 11 21:30:29 volumio sshd[967]: Server listening on 0.0.0.0 port 22. May 11 21:30:29 volumio sshd[967]: Server listening on :: port 22. May 11 21:30:29 volumio systemd[1]: Started OpenBSD Secure Shell server. May 11 21:30:29 volumio sudo[964]: pam_unix(sudo:session): session closed for user root May 11 21:30:29 volumio sudo[968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable ssh.service May 11 21:30:29 volumio sudo[968]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 21:30:30 volumio systemd[1]: Reloading. May 11 21:30:30 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 11 21:30:31 volumio systemd[1]: serial-getty@ttyAMA0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 11 21:30:31 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 11 21:30:31 volumio sudo[968]: pam_unix(sudo:session): session closed for user root May 11 21:30:31 volumio volumio[598]: error: Cannot enable SSH service: Error: Command failed: /usr/bin/sudo /bin/systemctl start ssh.service && /usr/bin/sudo /bin/systemctl enable ssh.service May 11 21:30:31 volumio volumio[598]: Synchronizing state of ssh.service with SysV service script with /lib/systemd/systemd-sysv-install. May 11 21:30:31 volumio volumio[598]: Executing: /lib/systemd/systemd-sysv-install enable ssh May 11 21:30:31 volumio volumio[598]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). May 11 21:30:31 volumio volumio[598]: insserv: warning: current stop runlevel(s) (2 3 4 5) of script `ssh' overrides LSB defaults (empty). May 11 21:30:31 volumio volumio[598]: update-rc.d: error: No space left on device May 11 21:30:33 volumio sshd[988]: Accepted password for volumio from 10.1.113.101 port 42904 ssh2 May 11 21:30:33 volumio sshd[988]: pam_unix(sshd:session): session opened for user volumio by (uid=0) May 11 21:30:33 volumio systemd[1]: Created slice User Slice of UID 1000. May 11 21:30:33 volumio systemd[1]: Starting User Runtime Directory /run/user/1000... May 11 21:30:33 volumio systemd-logind[379]: New session 1 of user volumio. May 11 21:30:33 volumio systemd[1]: Started User Runtime Directory /run/user/1000. May 11 21:30:33 volumio systemd[1]: Starting User Manager for UID 1000... May 11 21:30:33 volumio systemd[992]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) May 11 21:30:33 volumio systemd[992]: gpgconf: running /usr/bin/gpg-agent failed (exitcode=2): General error May 11 21:30:33 volumio systemd[992]: gpgconf: fatal error (exit status 1) May 11 21:30:33 volumio systemd[992]: Reached target Timers. May 11 21:30:33 volumio systemd[992]: Listening on GnuPG network certificate management daemon. May 11 21:30:33 volumio systemd[992]: Starting D-Bus User Message Bus Socket. May 11 21:30:33 volumio systemd[992]: Listening on GnuPG cryptographic agent (ssh-agent emulation). May 11 21:30:33 volumio systemd[992]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). May 11 21:30:33 volumio systemd[992]: Reached target Paths. May 11 21:30:33 volumio systemd[992]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). May 11 21:30:33 volumio systemd[992]: Listening on GnuPG cryptographic agent and passphrase cache. May 11 21:30:33 volumio systemd[992]: Listening on Sound System. May 11 21:30:34 volumio systemd[992]: Listening on D-Bus User Message Bus Socket. May 11 21:30:34 volumio systemd[992]: Reached target Sockets. May 11 21:30:34 volumio systemd[992]: Reached target Basic System. May 11 21:30:34 volumio systemd[1]: Started User Manager for UID 1000. May 11 21:30:34 volumio systemd[992]: Starting Music Player Daemon... May 11 21:30:34 volumio systemd[1]: Started Session 1 of user volumio. May 11 21:30:36 volumio mpd[1003]: exception: Default TCP listener setup failed, but this is okay because we have a $XDG_RUNTIME_DIR listener: Failed to bind to '[::]:6600'; Failed to bind socket: Address already in use May 11 21:30:36 volumio mpd[1003]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 21:30:36 volumio mpd[1003]: output: No 'audio_output' defined in config file May 11 21:30:36 volumio mpd[1003]: output: Successfully detected a sndio audio device May 11 21:30:36 volumio systemd[992]: Starting Sound Service... May 11 21:30:36 volumio systemd[992]: Started Music Player Daemon. May 11 21:30:36 volumio systemd[992]: Reached target Default. May 11 21:30:36 volumio dbus-daemon[395]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.14' (uid=1000 pid=1015 comm="/usr/bin/pulseaudio --daemonize=no ") May 11 21:30:36 volumio systemd[1]: rtkit-daemon.service: Failed to run 'start' task: No space left on device May 11 21:30:36 volumio systemd[1]: rtkit-daemon.service: Failed with result 'resources'. May 11 21:30:36 volumio systemd[1]: Failed to start RealtimeKit Scheduling Policy Service. May 11 21:30:43 volumio sudo[1020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 11 21:30:43 volumio sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 21:30:43 volumio sudo[1020]: pam_unix(sudo:session): session closed for user root May 11 21:30:43 volumio sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 11 21:30:43 volumio sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 21:30:43 volumio sudo[1022]: pam_unix(sudo:session): session closed for user root May 11 21:30:43 volumio volumio[598]: verbose: New Socket.io Connection to 10.1.151.210 from 10.1.113.101 UA: Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0 Total Clients: 6 May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::volumioGetVisibleSources May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:43 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 11 21:30:43 volumio volumio[598]: info: Received Get System Info May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 11 21:30:43 volumio volumio[598]: info: Discovery: Getting this device information May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:43 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:43 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:43 volumio volumio[598]: info: Listing playlists May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 11 21:30:43 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 11 21:30:44 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:44 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 11 21:30:45 volumio volumio[598]: info: Received Get System Info May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 11 21:30:45 volumio volumio[598]: info: Discovery: Getting this device information May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:45 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 11 21:30:45 volumio volumio[598]: info: Received Get System Info May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 11 21:30:45 volumio volumio[598]: info: Discovery: Getting this device information May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:30:45 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:30:45 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 11 21:30:47 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 11 21:30:47 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 11 21:30:51 volumio volumio[598]: info: Enabling plugin spop May 11 21:30:51 volumio volumio[598]: info: Loading plugin "spop"... May 11 21:30:54 volumio volumio[598]: info: PLUGIN START: spop May 11 21:30:54 volumio volumio[598]: info: Creating Spotify config file May 11 21:30:54 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 21:30:54 volumio volumio[598]: info: Done. May 11 21:30:54 volumio volumio[598]: Configuration write error: Error: ENOSPC: no space left on device, write May 11 21:30:54 volumio volumio[598]: info: Spotify config file written May 11 21:30:54 volumio volumio[598]: info: Enabling plugin fusiondsp May 11 21:30:54 volumio volumio[598]: info: Loading plugin "fusiondsp"... May 11 21:30:54 volumio sudo[1028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 11 21:30:54 volumio sudo[1028]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 21:30:54 volumio systemd[1]: Started go-librespot Daemon. May 11 21:30:54 volumio go-librespot[1030]: Librespot-go daemon starting... May 11 21:30:54 volumio sudo[1028]: pam_unix(sudo:session): session closed for user root May 11 21:30:55 volumio go-librespot[1030]: time="2024-05-11T21:30:55-04:00" level=info msg="generated new device id: 014cd7e79a69a5280a83618be5683d2be1c39244" May 11 21:30:55 volumio volumio[598]: error: Could not copy default configuration to /data/configuration/audio_interface/fusiondsp/config.json May 11 21:30:55 volumio go-librespot[1030]: time="2024-05-11T21:30:55-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 11 21:30:55 volumio go-librespot[1030]: time="2024-05-11T21:30:55-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 11 21:30:55 volumio go-librespot[1030]: time="2024-05-11T21:30:55-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 11 21:30:55 volumio go-librespot[1030]: time="2024-05-11T21:30:55-04:00" level=debug msg="zeroconf server listening on port 38939" May 11 21:30:55 volumio volumio[598]: info: Preparing to generate the ALSA configuration file May 11 21:30:55 volumio volumio[598]: info: Error: SyntaxError: /data/configuration/plugins.json: Unexpected end of JSON input May 11 21:30:55 volumio volumio[598]: Configuration write error: Error: ENOSPC: no space left on device, write May 11 21:30:58 volumio volumio[598]: info: go-librespot daemon successfully initialized May 11 21:31:01 volumio dbus-daemon[395]: [system] Failed to activate service 'org.freedesktop.RealtimeKit1': timed out (service_start_timeout=25000ms) May 11 21:31:01 volumio dbus-daemon[395]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.15' (uid=1000 pid=1015 comm="/usr/bin/pulseaudio --daemonize=no ") May 11 21:31:01 volumio systemd[1]: rtkit-daemon.service: Failed to run 'start' task: No space left on device May 11 21:31:01 volumio systemd[1]: rtkit-daemon.service: Failed with result 'resources'. May 11 21:31:01 volumio systemd[1]: Failed to start RealtimeKit Scheduling Policy Service. May 11 21:31:01 volumio volumio[598]: info: Initializing connection to go-librespot Websocket May 11 21:31:01 volumio go-librespot[1030]: time="2024-05-11T21:31:01-04:00" level=debug msg="new websocket client" May 11 21:31:01 volumio volumio[598]: info: Connection to go-librespot Websocket established May 11 21:31:03 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 11 21:31:05 volumio volumio[598]: info: Getting Spotify volume May 11 21:31:05 volumio volumio[598]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 11 21:31:05 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:31:05 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:31:05 volumio volumio[598]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 11 21:31:05 volumio volumio[598]: SPOTIFY: SPOTIFY VOLUME undefined May 11 21:31:05 volumio volumio[598]: SPOTIFY: VOLUMIO VOLUME 100 May 11 21:31:05 volumio volumio[598]: info: Aligning Spotify Volume to Volumio Volume May 11 21:31:05 volumio volumio[598]: info: CoreCommandRouter::volumioGetState May 11 21:31:05 volumio volumio[598]: info: CorePlayQueue::getTrack 0 May 11 21:31:05 volumio volumio[598]: info: Setting Spotify Volume from Volumio: 100 May 11 21:31:06 volumio volumio[598]: SPOTIFY: SETTING SPOTIFY VOLUME 100 May 11 21:31:06 volumio volumio[598]: info: Sending Spotify command with payload to local API: /player/volume May 11 21:31:15 volumio volumio[598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 11 21:31:19 volumio ntpd[565]: Soliciting pool server 216.232.132.102 May 11 21:31:22 volumio ntpd[565]: Soliciting pool server 216.232.132.95 May 11 21:31:24 volumio ntpd[565]: Soliciting pool server 208.81.1.244 May 11 21:31:25 volumio ntpd[565]: Soliciting pool server 162.159.200.1 May 11 21:31:26 volumio dbus-daemon[395]: [system] Failed to activate service 'org.freedesktop.RealtimeKit1': timed out (service_start_timeout=25000ms) May 11 21:31:26 volumio dbus-daemon[395]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.16' (uid=1000 pid=1015 comm="/usr/bin/pulseaudio --daemonize=no ") May 11 21:31:26 volumio systemd[1]: rtkit-daemon.service: Failed to run 'start' task: No space left on device May 11 21:31:26 volumio systemd[1]: rtkit-daemon.service: Failed with result 'resources'. May 11 21:31:26 volumio systemd[1]: Failed to start RealtimeKit Scheduling Policy Service. May 11 21:31:32 volumio volumio[598]: info: Starting Uninstall of plugin audio_interface - fusiondsp May 11 21:31:32 volumio volumio[598]: info: Uninstalling plugin fusiondsp May 11 21:31:32 volumio volumio[598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 21:31:32 volumio volumio[598]: TypeError: Cannot read property 'off' of undefined May 11 21:31:32 volumio volumio[598]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) May 11 21:31:32 volumio volumio[598]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) May 11 21:31:32 volumio volumio[598]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) May 11 21:31:32 volumio volumio[598]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1459:22) May 11 21:31:32 volumio volumio[598]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1218:45) May 11 21:31:32 volumio volumio[598]: at Socket.emit (events.js:315:20) May 11 21:31:32 volumio volumio[598]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 11 21:31:32 volumio volumio[598]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 11 21:31:32 volumio volumio[598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 21:31:33 volumio sudo[1083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-11 21:30 May 11 21:31:33 volumio sudo[1083]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"