-- Logs begin at Thu 2024-09-05 23:11:44 UTC, end at Mon 2024-10-28 01:00:57 UTC. -- Oct 28 00:59:59 volumio systemd[1]: Starting Daily apt download activities... Oct 28 01:00:03 volumio volumio[823]: Starting albumart workers Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::initPlayerControls Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:04 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:05 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 28 01:00:05 volumio volumio[823]: Express server listening on port 3000 Oct 28 01:00:05 volumio volumio[823]: [Metrics] WebUI: 46s 201.31ms Oct 28 01:00:05 volumio volumio[823]: info: CoreStateMachine::resetVolumioState Oct 28 01:00:05 volumio volumio[823]: info: CoreStateMachine::getcurrentVolume Oct 28 01:00:05 volumio volumio[823]: info: CoreCommandRouter::volumioRetrievevolume Oct 28 01:00:06 volumio sudo[971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 28 01:00:06 volumio sudo[971]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:06 volumio sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 01:00:07 volumio sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:07 volumio sudo[973]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:07 volumio sudo[971]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:07 volumio volumio[823]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Oct 28 01:00:09 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.4.38 from 192.168.4.102 UA: Mozilla/5.0 (Linux; Android 13; SM-A127F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.58 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 28 01:00:09 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.4.38 from 192.168.4.102 UA: Mozilla/5.0 (Linux; Android 13; SM-A127F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.58 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 28 01:00:10 volumio volumio[823]: info: VolumeController:: Volume=undefined Mute =false Oct 28 01:00:10 volumio volumio[823]: info: CoreStateMachine::pushState Oct 28 01:00:11 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::volumioPushState Oct 28 01:00:11 volumio volumio[823]: info: CoreStateMachine::updateTrackBlock Oct 28 01:00:11 volumio volumio[823]: info: CorePlayQueue::getTrackBlock Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::volumioRetrievevolume Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 01:00:11 volumio volumio[823]: info: Discovery: Getting this device information Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:11 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:11 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 01:00:12 volumio systemd[1]: apt-daily.service: Succeeded. Oct 28 01:00:12 volumio systemd[1]: Started Daily apt download activities. Oct 28 01:00:12 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Oct 28 01:00:12 volumio volumio[823]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Oct 28 01:00:12 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:13 volumio volumio[823]: info: CoreStateMachine::setRepeat false single undefined Oct 28 01:00:13 volumio volumio[823]: info: CoreStateMachine::pushState Oct 28 01:00:13 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:13 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 01:00:13 volumio volumio[823]: info: CoreCommandRouter::volumioPushState Oct 28 01:00:13 volumio volumio[823]: info: CoreStateMachine::setRandom null Oct 28 01:00:13 volumio volumio[823]: info: CoreStateMachine::pushState Oct 28 01:00:13 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:13 volumio volumio[823]: info: CoreCommandRouter::volumioPushState Oct 28 01:00:13 volumio volumio[823]: info: Setting Device type: Raspberry PI Oct 28 01:00:13 volumio volumio[823]: info: Completed loading Core Plugins Oct 28 01:00:13 volumio volumio-remote-updater[545]: [2024-10-28 01:00:13] [connect] Successful connection Oct 28 01:00:13 volumio volumio[823]: info: Preparing to generate the ALSA configuration file Oct 28 01:00:13 volumio volumio[823]: info: VolumeController:: Volume=undefined Mute =false Oct 28 01:00:13 volumio volumio[823]: info: CoreStateMachine::pushState Oct 28 01:00:13 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:13 volumio volumio[823]: info: CoreCommandRouter::volumioPushState Oct 28 01:00:13 volumio volumio[823]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 28 01:00:13 volumio volumio[823]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 28 01:00:13 volumio volumio[823]: info: Reading ALSA contributions from plugins. Oct 28 01:00:13 volumio volumio[823]: info: Discovery: A device disappeared from network Oct 28 01:00:13 volumio volumio[823]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Oct 28 01:00:14 volumio volumio-remote-updater[545]: [2024-10-28 01:00:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1730077213 101 Oct 28 01:00:14 volumio volumio[823]: 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 Oct 28 01:00:14 volumio sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 28 01:00:14 volumio sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:14 volumio volumio[823]: info: Discovery: adding 9f933bb6-9a5b-410c-a963-756e7ffa1d2e Oct 28 01:00:14 volumio volumio[823]: info: Discovery: Found device Volumio Oct 28 01:00:14 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:14 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:14 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 28 01:00:14 volumio volumio[823]: info: Discovery: this is already registered, 9f933bb6-9a5b-410c-a963-756e7ffa1d2e Oct 28 01:00:14 volumio volumio[823]: info: Discovery: Found device Volumio Oct 28 01:00:14 volumio sudo[1044]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:14 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:14 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:14 volumio volumio[823]: info: Upmpdcli Daemon Started Oct 28 01:00:14 volumio volumio[823]: info: Asound.conf file unchanged, so no further update is needed Oct 28 01:00:14 volumio volumio[823]: info: Output device has changed, restarting MPD Oct 28 01:00:15 volumio volumio[823]: info: Output device has changed, restarting Shairport Sync Oct 28 01:00:15 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:15 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:15 volumio sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 01:00:15 volumio sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:15 volumio sudo[1049]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:15 volumio sudo[1051]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 01:00:15 volumio sudo[1051]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:15 volumio volumio[823]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 01:00:15 volumio systemd[1]: Listening on mpd.socket. Oct 28 01:00:15 volumio volumio[823]: info: ___________ START PLUGINS ___________ Oct 28 01:00:16 volumio systemd[1]: Starting Music Player Daemon... Oct 28 01:00:16 volumio volumio[823]: info: ControllerMpd::onStart: Initializing MPD Oct 28 01:00:16 volumio volumio[823]: info: Creating MPD Configuration file Oct 28 01:00:16 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 28 01:00:16 volumio volumio[823]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 28 01:00:16 volumio volumio[823]: info: [1730077216541] CoreMusicLibrary::Adding element Media Servers Oct 28 01:00:16 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 01:00:16 volumio sudo[1060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 01:00:16 volumio sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:16 volumio sudo[1060]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:16 volumio sudo[1062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 01:00:16 volumio sudo[1058]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 01:00:16 volumio sudo[1062]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:16 volumio sudo[1058]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:17 volumio sudo[1058]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 28 01:00:17 volumio sudo[1058]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:17 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:17 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:17 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 28 01:00:17 volumio systemd[1]: mpd.service: Succeeded. Oct 28 01:00:17 volumio systemd[1]: Stopped Music Player Daemon. Oct 28 01:00:17 volumio systemd[1]: Starting Music Player Daemon... Oct 28 01:00:17 volumio volumio[823]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 01:00:17 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:17 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:18 volumio volumio[823]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 28 01:00:18 volumio sudo[1068]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 01:00:18 volumio volumio[823]: info: [1730077218337] CoreMusicLibrary::Adding element Last_100 Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 01:00:18 volumio sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 28 01:00:18 volumio volumio[823]: info: [1730077218385] CoreMusicLibrary::Adding element Webradio Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 28 01:00:18 volumio sudo[1068]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 28 01:00:18 volumio sudo[1068]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:18 volumio volumio[823]: info: Initializing BBC Radios Oct 28 01:00:18 volumio volumio[823]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Oct 28 01:00:18 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:19 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 28 01:00:19 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:19 volumio volumio[823]: info: Creating Spotify config file Oct 28 01:00:19 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:20 volumio volumio[823]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 28 01:00:20 volumio volumio[823]: info: [1730077220593] CoreMusicLibrary::Adding element YouTube Music Oct 28 01:00:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 01:00:20 volumio volumio[823]: Cannot find translation for source YouTube Music Oct 28 01:00:20 volumio volumio[823]: info: Loading i18n strings for locale en Oct 28 01:00:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 28 01:00:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:20 volumio volumio[823]: info: FusionDsp - mixtype--------------------- undefined Oct 28 01:00:20 volumio volumio[823]: info: Loading i18n strings for locale en Oct 28 01:00:21 volumio volumio[823]: info: Volumio Calling Home Oct 28 01:00:22 volumio volumio[823]: info: Preparing to generate the ALSA configuration file Oct 28 01:00:24 volumio volumio[823]: info: camilladsp spawned new process with pid 1108, instance 1, run: true Oct 28 01:00:24 volumio volumio[823]: info: camilladsp service started and running in background, instance 1 Oct 28 01:00:24 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:25 volumio volumio[823]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 28 01:00:25 volumio volumio[823]: cannot open device 'volumioHw': No such device Oct 28 01:00:25 volumio volumio[823]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Oct 28 01:00:25 volumio volumio[823]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 28 01:00:25 volumio volumio[823]: cannot open device 'volumioHw': No such device Oct 28 01:00:25 volumio volumio[823]: info: FusionDsp loaded Oct 28 01:00:25 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 01:00:25 volumio volumio[823]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 28 01:00:25 volumio sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 28 01:00:25 volumio sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:25 volumio volumio[823]: info: Adding Signal Path Element [object Object] Oct 28 01:00:25 volumio volumio[823]: info: Adding fusiondspeq DSP Signal Path Element Oct 28 01:00:26 volumio volumio[823]: info: FusionDsp - ---- installed callbackRead Oct 28 01:00:26 volumio volumio[823]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 28 01:00:26 volumio systemd[1]: Started FusionDsp Daemon. Oct 28 01:00:26 volumio sudo[1127]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:26 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 28 01:00:26 volumio systemd[1]: Started Daily apt upgrade and clean activities. Oct 28 01:00:26 volumio volumio[823]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 28 01:00:26 volumio volumio[823]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 28 01:00:26 volumio volumio[823]: info: Reading ALSA contributions from plugins. Oct 28 01:00:26 volumio volumio[823]: info: MPD Permissions set Oct 28 01:00:26 volumio volumio[823]: info: MPD Permissions set Oct 28 01:00:27 volumio volumio[823]: info: Volumio called home Oct 28 01:00:27 volumio volumio[823]: info: Spotify config file written Oct 28 01:00:27 volumio sudo[1139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 28 01:00:27 volumio sudo[1139]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:28 volumio systemd[1]: Started go-librespot Daemon. Oct 28 01:00:28 volumio go-librespot[1141]: Librespot-go daemon starting... Oct 28 01:00:28 volumio sudo[1139]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:28 volumio volumio[823]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 28 01:00:28 volumio volumio[823]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 28 01:00:28 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio go-librespot[1141]: time="2024-10-28T01:00:29Z" level=info msg="generated new device id: 3ad9bc4dd5040872d570d1a4e24e97d6f52fe861" Oct 28 01:00:29 volumio go-librespot[1141]: time="2024-10-28T01:00:29Z" level=debug msg="stored credentials found for 11162989308" Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:29 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:30 volumio volumio[823]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 28 01:00:33 volumio go-librespot[1141]: time="2024-10-28T01:00:33Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 28 01:00:33 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.4.38 from 192.168.4.102 UA: Mozilla/5.0 (Linux; Android 13; SM-A127F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.58 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 28 01:00:33 volumio go-librespot[1141]: time="2024-10-28T01:00:33Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 28 01:00:33 volumio go-librespot[1141]: time="2024-10-28T01:00:33Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 28 01:00:33 volumio go-librespot[1141]: time="2024-10-28T01:00:33Z" level=debug msg="zeroconf server listening on port 41083" Oct 28 01:00:33 volumio volumio[823]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 28 01:00:33 volumio volumio[823]: SPOTIFY: BQCrEmThH_w7WvlLaY9dEt5j2S62ZHONefCUxtB2IelTmcBaCMFHBo6rXrprUD7Q7ooj0Sovacm8zT-Cr1DjO1qDrwwzjd4P80uDyBF-SJbtrBwu-amn8NRfsqWBJEo7QCMZeUr9li3HNJSdA_mJV84BDzkhSRZNhlCV8-dkNwhQxg60QH6YaxJ3BIUpUM-8RLnf8lbYlO3JyXvYUcql6A0rdf9T3XIJ5ZIfNG98-CUzTV95WkA_BtEA-NtS Oct 28 01:00:33 volumio volumio[823]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 28 01:00:33 volumio volumio[823]: info: New Spotify access token = BQCrEmThH_w7WvlLaY9dEt5j2S62ZHONefCUxtB2IelTmcBaCMFHBo6rXrprUD7Q7ooj0Sovacm8zT-Cr1DjO1qDrwwzjd4P80uDyBF-SJbtrBwu-amn8NRfsqWBJEo7QCMZeUr9li3HNJSdA_mJV84BDzkhSRZNhlCV8-dkNwhQxg60QH6YaxJ3BIUpUM-8RLnf8lbYlO3JyXvYUcql6A0rdf9T3XIJ5ZIfNG98-CUzTV95WkA_BtEA-NtS Oct 28 01:00:33 volumio volumio[823]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 28 01:00:34 volumio go-librespot[1141]: time="2024-10-28T01:00:34Z" level=debug msg="obtained new client token: AADx6JryOoMGOBOk0uqNmePnGAeoKKhdiLarEP702IxVz0gtLfKX4c9MkhU2AK4M4UD5c7ZyqD8FsOu8ymYaUxGIcNGnMHu6r+4wpARd0iwaC0mrDn2ptCE/5Pxr3TDmMxdaxpiTNxAtiZRkA2GorvhqCiV7JdbwTlbNM5t7UKsGJbE4K1RUA9mipnfKi44fTHo/eTiAQuBp4RaX2iEijZftgqXCtsYG7GE5tsK6KsS0dH3qLf66CqI=" Oct 28 01:00:34 volumio volumio[823]: info: Starting Shairport Sync Oct 28 01:00:34 volumio volumio[823]: info: Starting Shairport Sync Oct 28 01:00:34 volumio go-librespot[1141]: time="2024-10-28T01:00:34Z" level=debug msg="completed keyexchange" Oct 28 01:00:34 volumio volumio[823]: info: Starting Shairport Sync Oct 28 01:00:34 volumio sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 01:00:35 volumio go-librespot[1141]: time="2024-10-28T01:00:35Z" level=debug msg="completed challenge" Oct 28 01:00:35 volumio go-librespot[1141]: time="2024-10-28T01:00:35Z" level=debug msg="authenticated as 11162989308" Oct 28 01:00:35 volumio sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:35 volumio sudo[1173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 01:00:35 volumio sudo[1173]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:35 volumio go-librespot[1141]: time="2024-10-28T01:00:35Z" level=debug msg="authenticated as 11162989308" Oct 28 01:00:35 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 28 01:00:35 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 28 01:00:36 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="dealer connection opened" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="initializing zeroconf session, username: 11162989308" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 28 01:00:36 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="autoplay enabled: false" Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="received connection id: ZDU3YjY0OTEtN2QxMC00MDYwLWFiYzAtZjI2ZGY5NjAwNTJlK2RlYWxlcit0Y3A6Ly8wYWNhNDFmZS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNzc3RUZGREU5QUIwOEM1MDQ1NTYwQTc4M0U4MDJDOTU1RTY4MzFGMERBMDY0QjlBNjBFNTBEQjRCRjBFODk5MA==" Oct 28 01:00:36 volumio sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 01:00:36 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:36 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:36 volumio sudo[1171]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:36 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 28 01:00:36 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 28 01:00:36 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 28 01:00:36 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:36 volumio go-librespot[1141]: time="2024-10-28T01:00:36Z" level=debug msg="put connect state because NEW_DEVICE" Oct 28 01:00:36 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:36 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:37 volumio sudo[1173]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:37 volumio volumio[823]: info: go-librespot daemon successfully initialized Oct 28 01:00:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 28 01:00:37 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 28 01:00:37 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 28 01:00:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::volumioGetVisibleSources Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:37 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::volumioGetQueue Oct 28 01:00:37 volumio volumio[823]: info: CoreStateMachine::getQueue Oct 28 01:00:37 volumio volumio[823]: info: CorePlayQueue::getQueue Oct 28 01:00:37 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:37 volumio volumio[823]: info: Listing playlists Oct 28 01:00:37 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 28 01:00:38 volumio volumio[823]: info: Received Get System Info Oct 28 01:00:38 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 01:00:38 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 01:00:38 volumio volumio[823]: info: Discovery: Getting this device information Oct 28 01:00:38 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:38 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:38 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 01:00:38 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:38 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="handling transfer player command from 2403caffadbf63b00a84215f74e5c05ad09731de" Oct 28 01:00:39 volumio volumio[823]: info: Shairport-Sync Started Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="resolved context of track" uri="spotify:album:72mfhbEsMtXR6s7v9UhKe3" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=trace msg="fetched new page 0 with 11 items (list: 11)" uri="spotify:album:72mfhbEsMtXR6s7v9UhKe3" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="loading track (paused: false, position: 24934ms)" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:39 volumio volumio[823]: Error adding Membership: Error: addMembership EINVAL Oct 28 01:00:39 volumio volumio[823]: info: Shairport-Sync Started Oct 28 01:00:39 volumio volumio[823]: info: Asound.conf file unchanged, so no further update is needed Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=trace msg="emitting websocket event: will_play" Oct 28 01:00:39 volumio volumio[823]: info: Output device has changed, restarting MPD Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2808" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="selected format OGG_VORBIS_320 (ab142bf408cc928dd78b36e7d2d547e9c24283c1)" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="requested aes key for file ab142bf408cc928dd78b36e7d2d547e9c24283c1, gid: 7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:39 volumio go-librespot[1141]: time="2024-10-28T01:00:39Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1858" Oct 28 01:00:39 volumio volumio[823]: info: Output device has changed, restarting Shairport Sync Oct 28 01:00:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:40 volumio sudo[1220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 01:00:40 volumio sudo[1220]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:40 volumio sudo[1220]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:40 volumio sudo[1222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 01:00:40 volumio sudo[1222]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:40 volumio go-librespot[1141]: time="2024-10-28T01:00:40Z" level=debug msg="fetched first chunk of 33, total size is 17073316 bytes" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:41 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 28 01:00:41 volumio systemd[1]: mpd.service: Succeeded. Oct 28 01:00:41 volumio systemd[1]: Stopped Music Player Daemon. Oct 28 01:00:41 volumio systemd[1]: Starting Music Player Daemon... Oct 28 01:00:41 volumio volumio[823]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 01:00:41 volumio volumio[823]: info: Shairport-Sync Started Oct 28 01:00:41 volumio volumio[823]: info: Initializing connection to go-librespot Websocket Oct 28 01:00:42 volumio volumio[823]: info: MPD Permissions set Oct 28 01:00:42 volumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 28 01:00:42 volumio sudo[1230]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 01:00:42 volumio sudo[1230]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:42 volumio sudo[1230]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 28 01:00:42 volumio sudo[1230]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:43 volumio go-librespot[1141]: time="2024-10-28T01:00:43Z" level=debug msg="new websocket client" Oct 28 01:00:43 volumio volumio[823]: info: Connection to go-librespot Websocket established Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 01:00:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 01:00:45 volumio go-librespot[1141]: time="2024-10-28T01:00:45Z" level=debug msg="fetched chunk 3/32, size: 524288" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:46 volumio go-librespot[1141]: time="2024-10-28T01:00:46Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Oct 28 01:00:46 volumio go-librespot[1141]: time="2024-10-28T01:00:46Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2871" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=debug msg="fetched chunk 5/32, size: 524288" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=debug msg="fetched chunk 1/32, size: 524288" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=debug msg="fetched chunk 2/32, size: 524288" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=debug msg="fetched chunk 4/32, size: 524288" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:47 volumio go-librespot[1141]: time="2024-10-28T01:00:47Z" level=trace msg="seek to 24934ms (diff: 169ms, samples: 1099589, bytes: 1333424)" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="created new output device" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=info msg="loaded track \"Diamond Dogs - 2016 Remaster\" (paused: false, position: 24934ms, duration: 364240ms, prefetched: false)" uri="spotify:track:7Lk0PQDl3jtOr0UoZmQPhs" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2808" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=trace msg="scheduling prefetch in 309s" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=trace msg="emitting websocket event: metadata" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=trace msg="emitting websocket event: active" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="sending successful reply for dealer request" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 01:00:48 volumio go-librespot[1141]: time="2024-10-28T01:00:48Z" level=trace msg="emitting websocket event: playing" Oct 28 01:00:49 volumio go-librespot[1141]: time="2024-10-28T01:00:49Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1858" Oct 28 01:00:49 volumio volumio[823]: info: Getting Spotify volume Oct 28 01:00:49 volumio volumio[823]: info: Starting Shairport Sync Oct 28 01:00:49 volumio volumio[823]: info: FusionDsp - >>>>>>>>>>>>> armv6l Oct 28 01:00:49 volumio volumio[823]: info: FusionDsp - Convolution not available for cpu armv6l ! Oct 28 01:00:49 volumio sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 01:00:50 volumio sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 28 01:00:50 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 28 01:00:50 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 28 01:00:50 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:50 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 28 01:00:50 volumio sudo[1239]: pam_unix(sudo:session): session closed for user root Oct 28 01:00:51 volumio volumio[823]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 28 01:00:51 volumio volumio[823]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 28 01:00:51 volumio volumio[823]: info: camilladsp stopping service pid 1108... Oct 28 01:00:51 volumio volumio[823]: info: camilladsp service terminated, instance 1 Oct 28 01:00:52 volumio volumio[823]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 28 01:00:52 volumio volumio[823]: info: camilladsp service started and running in background, instance 1 Oct 28 01:00:52 volumio volumio[823]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7Lk0PQDl3jtOr0UoZmQPhs","name":"Diamond Dogs - 2016 Remaster","artist_names":["David Bowie"],"album_name":"Diamond Dogs (2016 Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ad22c83a6e1567f8453c32b3","position":24934,"duration":364240,"release_date":"year:1974 month:5 day:24","track_number":2,"disc_number":1}} Oct 28 01:00:52 volumio volumio[823]: SPOTIFY: received: {"type":"active","data":null} Oct 28 01:00:52 volumio volumio[823]: info: Aligning Spotify Volume to Volumio Volume Oct 28 01:00:52 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Oct 28 01:00:52 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Oct 28 01:00:52 volumio volumio[823]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7Lk0PQDl3jtOr0UoZmQPhs","play_origin":"playlist"}} Oct 28 01:00:52 volumio volumio[823]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 01:00:52 volumio volumio[823]: TypeError: Cannot read property 'service' of undefined Oct 28 01:00:52 volumio volumio[823]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Oct 28 01:00:52 volumio volumio[823]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Oct 28 01:00:52 volumio volumio[823]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Oct 28 01:00:52 volumio volumio[823]: at WebSocket.emit (events.js:315:20) Oct 28 01:00:52 volumio volumio[823]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 28 01:00:52 volumio volumio[823]: at Receiver.emit (events.js:315:20) Oct 28 01:00:52 volumio volumio[823]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 28 01:00:52 volumio volumio[823]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 28 01:00:52 volumio volumio[823]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 28 01:00:52 volumio volumio[823]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 28 01:00:52 volumio volumio[823]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 28 01:00:52 volumio volumio[823]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 28 01:00:52 volumio volumio[823]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Oct 28 01:00:52 volumio volumio[823]: at Socket.emit (events.js:315:20) Oct 28 01:00:52 volumio volumio[823]: at addChunk (internal/streams/readable.js:309:12) Oct 28 01:00:52 volumio volumio[823]: at readableAddChunk (internal/streams/readable.js:284:9) Oct 28 01:00:52 volumio volumio[823]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 01:00:57 volumio sudo[1255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-28 00:59 Oct 28 01:00:57 volumio sudo[1255]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"