-- Logs begin at Thu 2019-02-14 10:11:58 GMT, end at Thu 2025-06-05 20:28:16 BST. -- Jun 05 20:27:00 volumio volumio[1686]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 05 20:27:00 volumio volumio[1686]: info: Completed starting MyVolumio Plugin Jun 05 20:27:00 volumio volumio[1686]: [Metrics] CommandRouter: 39s 321.82ms Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::volumiosetStartupVolume Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 20:27:00 volumio volumio[1686]: info: VolumeController:: Setting startup Volume 20 Jun 05 20:27:00 volumio volumio[1686]: info: VolumeController::SetAlsaVolume20 Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::Close All Modals sent Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::Close All Modals sent Jun 05 20:27:00 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:00 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:00 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:00 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:00 volumio volumio[1686]: SPOTIFY: SPOTIFY VOLUME 41 Jun 05 20:27:00 volumio volumio[1686]: SPOTIFY: VOLUMIO VOLUME 20 Jun 05 20:27:00 volumio volumio[1686]: SPOTIFY: DELTA VOLUME ENOUGH: true Jun 05 20:27:00 volumio volumio[1686]: info: Setting Spotify Volume from Volumio: 20 Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 05 20:27:00 volumio volumio[1686]: info: camilladsp stopping service pid 2206... Jun 05 20:27:00 volumio volumio[1686]: info: camilladsp service terminated, instance 1 Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:00 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:00 volumio volumio[1686]: info: camilladsp service started and running in background, instance 1 Jun 05 20:27:00 volumio volumio[1686]: error: FusionDsp - WebSocket error: [object Object] Jun 05 20:27:00 volumio volumio[1686]: info: camilladsp spawned new process with pid 2242, instance 1, run: true Jun 05 20:27:01 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 05 20:27:01 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 20:27:01 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 05 20:27:01 volumio go-librespot[1884]: time="2025-06-05T20:27:01+01:00" level=debug msg="handling transfer player command from bf0bb2eb8890341d41b9f28ccf86fdb3b3892618" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:4wMDfEgsG8xRo82P7iY0q4" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=trace msg="fetched new page 0 with 29 items (list: 29)" uri="spotify:playlist:4wMDfEgsG8xRo82P7iY0q4" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="shuffled context with seed 7495033936734073010 (len: 29, keep: 8)" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="loading track (paused: false, position: 50160ms)" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:02 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 21. Jun 05 20:27:02 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=trace msg="emitting websocket event: will_play" Jun 05 20:27:02 volumio volumio[1686]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","play_origin":"playlist"}} Jun 05 20:27:02 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="selected format OGG_VORBIS_320 (db154e2a3bf61842c8746661eff640a9ec3a9ad6)" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="requested aes key for file db154e2a3bf61842c8746661eff640a9ec3a9ad6, gid: 60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio volumio[2249]: Traceback (most recent call last): Jun 05 20:27:02 volumio volumio[2249]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:02 volumio volumio[2249]: from aiohttp import web Jun 05 20:27:02 volumio volumio[2249]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:02 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:02 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:02 volumio volumio[1686]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Jun 05 20:27:02 volumio volumio[1686]: info: Sending Spotify command with payload to local API: /player/volume Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched first chunk of 16, total size is 8239324 bytes" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:27:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:27:02 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:27:02 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:02 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=trace msg="seek to 50160ms (diff: 152ms, samples: 2212056, bytes: 1268280)" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 05 20:27:02 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 05 20:27:02 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=debug msg="created new output device" Jun 05 20:27:02 volumio go-librespot[1884]: time="2025-06-05T20:27:02+01:00" level=info msg="loaded track \"Wendo Wa Cash Money\" (paused: false, position: 50160ms, duration: 326333ms, prefetched: false)" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:27:02 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=trace msg="scheduling prefetch in 246s" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=trace msg="emitting websocket event: metadata" Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","name":"Wendo Wa Cash Money","artist_names":["Peter Kigia Wa Esther"],"album_name":"Reke Tumanwo","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","position":50160,"duration":326333,"release_date":"year:2024 month:4 day:5","track_number":39,"disc_number":1}} Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=trace msg="emitting websocket event: active" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="sending successful reply for dealer request" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="update volume to 13107/65535" Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: received: {"type":"active","data":null} Jun 05 20:27:03 volumio volumio[1686]: info: Aligning Spotify Volume to Volumio Volume Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:03 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:03 volumio volumio[1686]: info: Setting Spotify Volume from Volumio: 20 Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=trace msg="emitting websocket event: volume" Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: received: {"type":"volume","data":{"value":20,"max":100}} Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: RECEIVED SPOTIFY VOLUME 20 Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=trace msg="emitting websocket event: playing" Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","play_origin":"playlist"}} Jun 05 20:27:03 volumio volumio[1686]: info: Spotify is playing in volatile mode Jun 05 20:27:03 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: UNSET VOLATILE Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: {"status":"play","position":0,"title":"Boyz II Men - 4 Seasons of Loneliness","artist":"90s90s Black & RnB","album":"","albumart":"https://is4-ssl.mzstatic.com/image/thumb/Music124/v4/c5/1f/f8/c51ff8be-95b5-87ac-e543-3c76d8d61a4b/source/600x600bb.jpg","uri":"http://streams.90s90s.de/rnb/mp3-192/volumio","trackType":"80s80s Radio","seek":8000,"duration":"283","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeatSingle":false,"consume":false,"volume":20,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Jun 05 20:27:03 volumio volumio[1686]: info: Setting Spotify stop after unset volatile call Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: {"status":"play","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":50160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:03 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2004" Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: {"status":"play","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":50160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:03 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:03 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:03 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 20:27:03 volumio go-librespot[1884]: time="2025-06-05T20:27:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1446" Jun 05 20:27:03 volumio sudo[2216]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:03 volumio volumio[1686]: info: Cannot mount NAS Tony-mac-mini at system boot, trial number 4 ,retrying in 5 seconds Jun 05 20:27:03 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 05 20:27:03 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Jun 05 20:27:03 volumio volumio[1686]: info: Spotify Stop Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: SPOTIFY STOP Jun 05 20:27:03 volumio volumio[1686]: SPOTIFY: {"status":"play","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","codec":"ogg","seek":50160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":20,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Jun 05 20:27:04 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:04 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 22. Jun 05 20:27:04 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:04 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:04 volumio volumio[2268]: Traceback (most recent call last): Jun 05 20:27:04 volumio volumio[2268]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:04 volumio volumio[2268]: from aiohttp import web Jun 05 20:27:04 volumio volumio[2268]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:04 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:04 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:04 volumio volumio[1686]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Jun 05 20:27:04 volumio volumio[1686]: info: Sending Spotify command with payload to local API: /player/volume Jun 05 20:27:05 volumio volumio[1686]: info: [jellyfin-poller] Polled http://192.168.1.124:8096: offline Jun 05 20:27:06 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:06 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 23. Jun 05 20:27:06 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:06 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:06 volumio volumio[2269]: Traceback (most recent call last): Jun 05 20:27:06 volumio volumio[2269]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:06 volumio volumio[2269]: from aiohttp import web Jun 05 20:27:06 volumio volumio[2269]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:06 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:06 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 05 20:27:07 volumio volumio[1686]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 05 20:27:07 volumio volumio[1686]: info: Received Get System Version Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 05 20:27:07 volumio volumio[1686]: info: Received Get System Info Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:27:07 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:07 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:27:07 volumio volumio[1686]: info: BOOT COMPLETED Jun 05 20:27:08 volumio volumio[1686]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Jun 05 20:27:08 volumio volumio[1686]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Jun 05 20:27:08 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:08 volumio volumio[1686]: info: CoreCommandRouter::volumioPause Jun 05 20:27:08 volumio volumio[1686]: info: CoreStateMachine::pause Jun 05 20:27:08 volumio volumio[1686]: info: CoreStateMachine::stPlaybackTimer Jun 05 20:27:08 volumio volumio[1686]: info: CoreStateMachine::servicePause Jun 05 20:27:08 volumio volumio[1686]: info: CoreCommandRouter::servicePause Jun 05 20:27:08 volumio volumio[1686]: info: Spotify Received pause Jun 05 20:27:08 volumio volumio[1686]: SPOTIFY: SPOTIFY PAUSE Jun 05 20:27:08 volumio volumio[1686]: SPOTIFY: {"status":"play","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","codec":"ogg","seek":50160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":20,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Jun 05 20:27:08 volumio volumio[1686]: info: Sending Spotify command to local API: /player/pause Jun 05 20:27:08 volumio volumio[1686]: info: mpdhttpout --- Volumio set on pause Jun 05 20:27:08 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:08 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 24. Jun 05 20:27:08 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:08 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:08 volumio volumio[2270]: Traceback (most recent call last): Jun 05 20:27:08 volumio volumio[2270]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:08 volumio volumio[2270]: from aiohttp import web Jun 05 20:27:08 volumio volumio[2270]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:08 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:08 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:08 volumio sudo[2272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.126/smb:/Tony’s Mac/tony/Music/Music /mnt/NAS/Tony-mac-mini Jun 05 20:27:08 volumio sudo[2272]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:27:08 volumio kernel: CIFS: Attempting to mount //192.168.1.126/smb:/Tony’s Mac/tony/Music/Music Jun 05 20:27:09 volumio sudo[2277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 05 20:27:09 volumio sudo[2277]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:27:09 volumio sudo[2277]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:09 volumio sudo[2279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 05 20:27:09 volumio sudo[2279]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:27:09 volumio sudo[2279]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:09 volumio volumio[1686]: verbose: New Socket.io Connection to 192.168.1.191 from 192.168.1.189 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jun 05 20:27:09 volumio go-librespot[1884]: time="2025-06-05T20:27:09+01:00" level=debug msg="pause track at 51510ms" Jun 05 20:27:09 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:09 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:09 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:09 volumio go-librespot[1884]: time="2025-06-05T20:27:09+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:09 volumio go-librespot[1884]: time="2025-06-05T20:27:09+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:09 volumio go-librespot[1884]: time="2025-06-05T20:27:09+01:00" level=trace msg="emitting websocket event: paused" Jun 05 20:27:09 volumio volumio[1686]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","play_origin":"playlist"}} Jun 05 20:27:09 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:27:09 volumio volumio[1686]: SPOTIFY: {"status":"pause","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:27:09 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:09 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:09 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:09 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:09 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:09 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:09 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:09 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:09 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Jun 05 20:27:10 volumio sudo[2295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 20:27:10 volumio sudo[2295]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:27:10 volumio systemd[1]: Stopping Music Player Daemon... Jun 05 20:27:10 volumio systemd[1]: mpd.service: Succeeded. Jun 05 20:27:10 volumio systemd[1]: Stopped Music Player Daemon. Jun 05 20:27:10 volumio systemd[1]: Starting Music Player Daemon... Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 05 20:27:10 volumio sudo[2297]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 05 20:27:10 volumio sudo[2297]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:27:10 volumio sudo[2297]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioGetVisibleSources Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioGetQueue Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::getQueue Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::getQueue Jun 05 20:27:10 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 05 20:27:10 volumio volumio[1686]: info: Received Get System Info Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:27:10 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 05 20:27:10 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::ClearQueue Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:10 volumio volumio[1686]: info: Spotify Stop Jun 05 20:27:10 volumio volumio[1686]: SPOTIFY: SPOTIFY STOP Jun 05 20:27:10 volumio volumio[1686]: SPOTIFY: {"status":"pause","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","codec":"ogg","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":20,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Jun 05 20:27:10 volumio volumio[1686]: info: Sending Spotify command to local API: /player/pause Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::clearPlayQueue Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::addQueueItems Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::addQueueItems Jun 05 20:27:10 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:10 volumio volumio[1686]: info: Adding Item to queue: webnineties/7 Jun 05 20:27:10 volumio volumio[1686]: info: Exploding uri webnineties/7 in service 80s80s Jun 05 20:27:10 volumio volumio[1686]: info: [1749151630953] [80s80s] explodeUri: webnineties/7 Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::play index 0 Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::stPlaybackTimer Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:10 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:10 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:10 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:10 volumio volumio[1686]: info: ControllerMpd::stop Jun 05 20:27:10 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:10 volumio volumio[1686]: error: MPD error: Error: This socket has been ended by the other party Jun 05 20:27:10 volumio volumio[1686]: error: This socket has been ended by the other party {"code":"EPIPE"} Jun 05 20:27:10 volumio volumio[1686]: error: MPD error: Error: This socket has been ended by the other party Jun 05 20:27:10 volumio volumio[1686]: error: This socket has been ended by the other party {"code":"EPIPE"} Jun 05 20:27:10 volumio volumio[1686]: error: MPD error: Error: This socket has been ended by the other party Jun 05 20:27:10 volumio volumio[1686]: error: This socket has been ended by the other party {"code":"EPIPE"} Jun 05 20:27:10 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:10 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:10 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:10 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:11 volumio go-librespot[1884]: time="2025-06-05T20:27:11+01:00" level=debug msg="pause track at 52127ms" Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:11 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:11 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 25. Jun 05 20:27:11 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:11 volumio go-librespot[1884]: time="2025-06-05T20:27:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:11 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:11 volumio go-librespot[1884]: time="2025-06-05T20:27:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:27:11 volumio go-librespot[1884]: time="2025-06-05T20:27:11+01:00" level=trace msg="emitting websocket event: paused" Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","play_origin":"playlist"}} Jun 05 20:27:11 volumio volumio[1686]: info: Spotify is playing in volatile mode Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: UNSET VOLATILE Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: {"status":"stop","position":0,"title":"90s90s HipHop & Rap","artist":"","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-rap-cover.png","uri":"http://streams.90s90s.de/hiphop/mp3-192/volumio","trackType":"80s80s Radio","seek":0,"duration":1000,"random":true,"repeatSingle":false,"consume":false,"volume":20,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: {"status":"pause","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:11 volumio volumio[2301]: Traceback (most recent call last): Jun 05 20:27:11 volumio volumio[2301]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:11 volumio volumio[2301]: from aiohttp import web Jun 05 20:27:11 volumio volumio[2301]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:11 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:11 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:11 volumio mpd[2299]: Jun 05 20:27 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 05 20:27:11 volumio systemd[1]: Started Music Player Daemon. Jun 05 20:27:11 volumio sudo[2295]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:11 volumio volumio[1686]: error: updateQueue error: null Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 20:27:11 volumio volumio[1686]: info: Received Get System Info Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:27:11 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 05 20:27:11 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::ClearQueue Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:11 volumio volumio[1686]: info: Spotify Stop Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: SPOTIFY STOP Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: {"status":"pause","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","codec":"ogg","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":20,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::clearPlayQueue Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::addQueueItems Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::addQueueItems Jun 05 20:27:11 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:11 volumio volumio[1686]: info: Adding Item to queue: webnineties/6 Jun 05 20:27:11 volumio volumio[1686]: info: Using cached record of: webnineties/6 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::play index 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::stPlaybackTimer Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:11 volumio volumio[1686]: info: ControllerMpd::stop Jun 05 20:27:11 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:11 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:11 volumio volumio[1686]: info: sendMpdCommand stop took 15 milliseconds Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is4-ssl.mzstatic.com/image/thumb/Music124/v4/c5/1f/f8/c51ff8be-95b5-87ac-e543-3c76d8d61a4b/source/600x600bb.jpg","name":"Boyz II Men - 4 Seasons of Loneliness","title":"4 Seasons of Loneliness","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"283","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:11 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::syncState stateService stop Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:11 volumio volumio[1686]: info: No code Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: CoreStateMachine::startPlaybackTimer Jun 05 20:27:11 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:11 volumio volumio[1686]: info: [1749151631913] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:11 volumio volumio[1686]: info: [1749151631913] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=266&count=2 Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:11 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632295] [80s80s] received new event containing 2 songs. Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand stop took 1 milliseconds Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand clear Jun 05 20:27:12 volumio volumio[1686]: info: Jun 05 20:27:12 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:12 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand clear took 1 milliseconds Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 05 20:27:12 volumio volumio[1686]: error: updateQueue error: null Jun 05 20:27:12 volumio volumio[1686]: info: Jun 05 20:27:12 volumio volumio[1686]: ---------------------------- MPD announces state update: options Jun 05 20:27:12 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand consume 1 took 1 milliseconds Jun 05 20:27:12 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632300] [80s80s] adding url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" Jun 05 20:27:12 volumio volumio[1686]: info: Jun 05 20:27:12 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:12 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand status took 2 milliseconds Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" took 1 milliseconds Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand play Jun 05 20:27:12 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:12 volumio volumio[1686]: info: ------------------------------ 17ms Jun 05 20:27:12 volumio volumio[1686]: info: ------------------------------ 17ms Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand play took 11 milliseconds Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632318] [80s80s] Pushing the next song state: USHER - My Way (Pat Antony Radio Mix) Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","name":"USHER - My Way (Pat Antony Radio Mix)","title":"My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"194","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:12 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::syncState stateService play Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632320] [80s80s] PlayNextTrack API delay: 3 Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632323] [80s80s] Setting timer to: 63680 milliseconds. Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 1 Jun 05 20:27:12 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::ClearQueue Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::stPlaybackTimer Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:12 volumio volumio[1686]: info: ControllerMpd::stop Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::clearPlayQueue Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::addQueueItems Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::addQueueItems Jun 05 20:27:12 volumio volumio[1686]: info: Preload queue cleared Jun 05 20:27:12 volumio volumio[1686]: info: Adding Item to queue: webnineties/6 Jun 05 20:27:12 volumio volumio[1686]: info: Using cached record of: webnineties/6 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushQueue Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::saveQueue Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::play index 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::startPlaybackTimer Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632563] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:12 volumio volumio[1686]: info: [1749151632563] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=266&count=2 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: info: Jun 05 20:27:12 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand stop took 94 milliseconds Jun 05 20:27:12 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","name":"USHER - My Way (Pat Antony Radio Mix)","title":"My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"194","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:12 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::syncState stateService stop Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: No code Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand status took 290 milliseconds Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:12 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 05 20:27:12 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:12 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:12 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:12 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:12 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:12 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:12 volumio volumio[1686]: info: ------------------------------ 310ms Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:12 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:13 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:13 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:13 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 26. Jun 05 20:27:13 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:13 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:13 volumio volumio[2335]: Traceback (most recent call last): Jun 05 20:27:13 volumio volumio[2335]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:13 volumio volumio[2335]: from aiohttp import web Jun 05 20:27:13 volumio volumio[2335]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:13 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:13 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:13 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 05 20:27:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:13 volumio volumio[1686]: info: [1749151633555] [80s80s] received new event containing 2 songs. Jun 05 20:27:13 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:13 volumio volumio[1686]: info: sendMpdCommand stop took 0 milliseconds Jun 05 20:27:13 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand clear Jun 05 20:27:13 volumio volumio[1686]: info: Jun 05 20:27:13 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:13 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:13 volumio volumio[1686]: info: sendMpdCommand clear took 1 milliseconds Jun 05 20:27:13 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 05 20:27:13 volumio volumio[1686]: error: updateQueue error: null Jun 05 20:27:13 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:27:13 volumio volumio[1686]: info: sendMpdCommand consume 1 took 1 milliseconds Jun 05 20:27:13 volumio volumio[1686]: info: [1749151633559] [80s80s] adding url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:13 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" Jun 05 20:27:13 volumio volumio[1686]: info: Jun 05 20:27:13 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:13 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:13 volumio volumio[1686]: info: sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" took 1 milliseconds Jun 05 20:27:13 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand play Jun 05 20:27:13 volumio volumio[1686]: info: ------------------------------ 6ms Jun 05 20:27:13 volumio volumio[1686]: info: sendMpdCommand play took 3 milliseconds Jun 05 20:27:13 volumio volumio[1686]: info: [1749151633568] [80s80s] Pushing the next song state: USHER - My Way (Pat Antony Radio Mix) Jun 05 20:27:13 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:13 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:13 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:13 volumio volumio[1686]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","name":"USHER - My Way (Pat Antony Radio Mix)","title":"My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"194","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:13 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:13 volumio volumio[1686]: info: CoreStateMachine::syncState stateService play Jun 05 20:27:13 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:13 volumio volumio[1686]: info: [1749151633569] [80s80s] PlayNextTrack API delay: 3 Jun 05 20:27:13 volumio volumio[1686]: info: [1749151633570] [80s80s] Setting timer to: 62431 milliseconds. Jun 05 20:27:13 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:13 volumio volumio[1686]: info: CorePlayQueue::getTrack 1 Jun 05 20:27:14 volumio volumio[1686]: info: camilladsp spawned new process with pid 2339, instance 1, run: true Jun 05 20:27:15 volumio sudo[2272]: pam_unix(sudo:session): session closed for user root Jun 05 20:27:15 volumio volumio[1686]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jun 05 20:27:15 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 05 20:27:15 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Jun 05 20:27:15 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:15 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 27. Jun 05 20:27:15 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:15 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:15 volumio volumio[2346]: Traceback (most recent call last): Jun 05 20:27:15 volumio volumio[2346]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:15 volumio volumio[2346]: from aiohttp import web Jun 05 20:27:15 volumio volumio[2346]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:15 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:15 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:15 volumio volumio[1686]: info: Jun 05 20:27:15 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:15 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:15 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 48000 Jun 05 20:27:15 volumio volumio[1686]: info: camilladsp stopping service pid 2339... Jun 05 20:27:15 volumio volumio[1686]: info: camilladsp service terminated, instance 1 Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:15 volumio volumio[1686]: info: camilladsp service started and running in background, instance 1 Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 48000 Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:15 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:16 volumio volumio[1686]: info: Jun 05 20:27:16 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand status took 267 milliseconds Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:16 volumio volumio[1686]: info: Jun 05 20:27:16 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:16 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:16 volumio volumio[1686]: info: Jun 05 20:27:16 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand status took 3 milliseconds Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:16 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:16 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:16 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 274ms Jun 05 20:27:16 volumio volumio[1686]: error: FusionDsp - WebSocket error: [object Object] Jun 05 20:27:16 volumio volumio[1686]: info: camilladsp spawned new process with pid 2351, instance 1, run: true Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 18ms Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand status took 17 milliseconds Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 16 milliseconds Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:16 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:16 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:16 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 24ms Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:16 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:16 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:16 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 23ms Jun 05 20:27:16 volumio volumio[1686]: info: Jun 05 20:27:16 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:16 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:16 volumio volumio[1686]: info: Jun 05 20:27:16 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand status took 1 milliseconds Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:16 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 20:27:16 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:16 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:16 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:16 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:16 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:16 volumio volumio[1686]: info: ------------------------------ 4ms Jun 05 20:27:17 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:17 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 28. Jun 05 20:27:17 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:17 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:17 volumio volumio[2358]: Traceback (most recent call last): Jun 05 20:27:17 volumio volumio[2358]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:17 volumio volumio[2358]: from aiohttp import web Jun 05 20:27:17 volumio volumio[2358]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:17 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:17 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:19 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:19 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:20 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:20 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 29. Jun 05 20:27:20 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:20 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:20 volumio volumio[2370]: Traceback (most recent call last): Jun 05 20:27:20 volumio volumio[2370]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:20 volumio volumio[2370]: from aiohttp import web Jun 05 20:27:20 volumio volumio[2370]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:20 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:20 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:22 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:22 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 30. Jun 05 20:27:22 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:22 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:22 volumio volumio[2371]: Traceback (most recent call last): Jun 05 20:27:22 volumio volumio[2371]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:22 volumio volumio[2371]: from aiohttp import web Jun 05 20:27:22 volumio volumio[2371]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:22 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:22 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:23 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:23 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:23 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:23 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:23 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:23 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:23 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:23 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:24 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:24 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 31. Jun 05 20:27:24 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:24 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:24 volumio volumio[2387]: Traceback (most recent call last): Jun 05 20:27:24 volumio volumio[2387]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:24 volumio volumio[2387]: from aiohttp import web Jun 05 20:27:24 volumio volumio[2387]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:24 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:24 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:26 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:26 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 32. Jun 05 20:27:26 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:26 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:26 volumio volumio[2388]: Traceback (most recent call last): Jun 05 20:27:26 volumio volumio[2388]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:26 volumio volumio[2388]: from aiohttp import web Jun 05 20:27:26 volumio volumio[2388]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:26 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:26 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioNext Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::next Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::stop Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::stPlaybackTimer Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::updateTrackBlock Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrackBlock Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::serviceStop Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::serviceStop Jun 05 20:27:28 volumio volumio[1686]: info: ControllerMpd::stop Jun 05 20:27:28 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:28 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:28 volumio volumio[1686]: info: Jun 05 20:27:28 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:28 volumio volumio[1686]: info: sendMpdCommand stop took 19 milliseconds Jun 05 20:27:28 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:28 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","name":"USHER - My Way (Pat Antony Radio Mix)","title":"My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"194","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:28 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::syncState stateService stop Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:28 volumio volumio[1686]: info: No code Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 1 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:28 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:28 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:28 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:28 volumio volumio[1686]: info: sendMpdCommand status took 217 milliseconds Jun 05 20:27:28 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:28 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:28 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 20:27:28 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:28 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:28 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:27:28 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:27:28 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:28 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:28 volumio volumio[1686]: info: ------------------------------ 230ms Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:28 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:28 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:29 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:29 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 33. Jun 05 20:27:29 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:29 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:29 volumio volumio[2394]: Traceback (most recent call last): Jun 05 20:27:29 volumio volumio[2394]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:29 volumio volumio[2394]: from aiohttp import web Jun 05 20:27:29 volumio volumio[2394]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:29 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:29 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:29 volumio volumio[1686]: info: camilladsp spawned new process with pid 2395, instance 1, run: true Jun 05 20:27:29 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:29 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:29 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:29 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:31 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:31 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 34. Jun 05 20:27:31 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:31 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:31 volumio volumio[2413]: Traceback (most recent call last): Jun 05 20:27:31 volumio volumio[2413]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:31 volumio volumio[2413]: from aiohttp import web Jun 05 20:27:31 volumio volumio[2413]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:31 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:31 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:32 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:32 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:32 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:32 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:32 volumio volumio[1686]: info: CoreStateMachine::startPlaybackTimer Jun 05 20:27:32 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:32 volumio volumio[1686]: info: [1749151652797] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:32 volumio volumio[1686]: info: [1749151652797] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=266&count=2 Jun 05 20:27:32 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:27:32 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:27:32 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:27:32 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:32 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:32 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:27:33 volumio volumio[1686]: info: [1749151653067] [80s80s] received new event containing 2 songs. Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 20:27:33 volumio volumio[1686]: info: sendMpdCommand stop took 1 milliseconds Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand clear Jun 05 20:27:33 volumio volumio[1686]: info: Jun 05 20:27:33 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:33 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:33 volumio volumio[1686]: info: sendMpdCommand clear took 1 milliseconds Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 05 20:27:33 volumio volumio[1686]: error: updateQueue error: null Jun 05 20:27:33 volumio volumio[1686]: info: ------------------------------ 1ms Jun 05 20:27:33 volumio volumio[1686]: info: sendMpdCommand consume 1 took 1 milliseconds Jun 05 20:27:33 volumio volumio[1686]: info: [1749151653072] [80s80s] adding url: http://streams.90s90s.de/rnb/mp3-192/volumio Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" Jun 05 20:27:33 volumio volumio[1686]: info: Jun 05 20:27:33 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:33 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:33 volumio volumio[1686]: info: sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" took 1 milliseconds Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand play Jun 05 20:27:33 volumio volumio[1686]: info: ------------------------------ 6ms Jun 05 20:27:33 volumio volumio[1686]: info: sendMpdCommand play took 3 milliseconds Jun 05 20:27:33 volumio volumio[1686]: info: [1749151653080] [80s80s] Pushing the next song state: USHER - My Way (Pat Antony Radio Mix) Jun 05 20:27:33 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:33 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:33 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:33 volumio volumio[1686]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","name":"USHER - My Way (Pat Antony Radio Mix)","title":"My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"194","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 05 20:27:33 volumio volumio[1686]: verbose: CURRENT POSITION 0 Jun 05 20:27:33 volumio volumio[1686]: info: CoreStateMachine::syncState stateService play Jun 05 20:27:33 volumio volumio[1686]: info: CoreStateMachine::syncState currentStatus stop Jun 05 20:27:33 volumio volumio[1686]: info: [1749151653082] [80s80s] PlayNextTrack API delay: 3 Jun 05 20:27:33 volumio volumio[1686]: info: [1749151653083] [80s80s] Setting timer to: 42918 milliseconds. Jun 05 20:27:33 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:33 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 35. Jun 05 20:27:33 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:33 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:33 volumio volumio[2431]: Traceback (most recent call last): Jun 05 20:27:33 volumio volumio[2431]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:33 volumio volumio[2431]: from aiohttp import web Jun 05 20:27:33 volumio volumio[2431]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:33 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:33 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:33 volumio volumio[1686]: info: Jun 05 20:27:33 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:33 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:33 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 48000 Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 48000 Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:27:33 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:27:34 volumio volumio[1686]: info: Jun 05 20:27:34 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand status took 254 milliseconds Jun 05 20:27:34 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:34 volumio volumio[1686]: info: Jun 05 20:27:34 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:34 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:34 volumio volumio[1686]: info: Jun 05 20:27:34 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:34 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand status took 3 milliseconds Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:34 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:34 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:34 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:34 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:34 volumio volumio[1686]: info: ------------------------------ 261ms Jun 05 20:27:34 volumio volumio[1686]: info: ------------------------------ 5ms Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand status took 3 milliseconds Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:34 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:34 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:34 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:34 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:34 volumio volumio[1686]: info: ------------------------------ 9ms Jun 05 20:27:34 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 05 20:27:34 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:34 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:34 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:34 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:34 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:34 volumio volumio[1686]: info: ------------------------------ 9ms Jun 05 20:27:34 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:34 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:27:35 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:35 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 36. Jun 05 20:27:35 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:35 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:35 volumio volumio[2435]: Traceback (most recent call last): Jun 05 20:27:35 volumio volumio[2435]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:35 volumio volumio[2435]: from aiohttp import web Jun 05 20:27:35 volumio volumio[2435]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:35 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:35 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:38 volumio volumio[1686]: info: Jun 05 20:27:38 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:27:38 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:27:38 volumio volumio[1686]: info: Jun 05 20:27:38 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:27:38 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:27:38 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:27:38 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:27:38 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:38 volumio volumio[1686]: info: sendMpdCommand status took 2 milliseconds Jun 05 20:27:38 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:27:38 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:27:38 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 37. Jun 05 20:27:38 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:38 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 20:27:38 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:27:38 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:27:38 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:27:38 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:38 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jun 05 20:27:38 volumio volumio[1686]: info: ------------------------------ 6ms Jun 05 20:27:38 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:38 volumio volumio[2436]: Traceback (most recent call last): Jun 05 20:27:38 volumio volumio[2436]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:38 volumio volumio[2436]: from aiohttp import web Jun 05 20:27:38 volumio volumio[2436]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:38 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:38 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:38 volumio volumio[1686]: info: [jellyfin-poller] Polled http://192.168.1.124:8096: offline Jun 05 20:27:39 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:39 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:40 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:40 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 38. Jun 05 20:27:40 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:40 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:40 volumio volumio[2448]: Traceback (most recent call last): Jun 05 20:27:40 volumio volumio[2448]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:40 volumio volumio[2448]: from aiohttp import web Jun 05 20:27:40 volumio volumio[2448]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:40 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:40 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:42 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:42 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 39. Jun 05 20:27:42 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:42 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:42 volumio volumio[2449]: Traceback (most recent call last): Jun 05 20:27:42 volumio volumio[2449]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:42 volumio volumio[2449]: from aiohttp import web Jun 05 20:27:42 volumio volumio[2449]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:42 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:42 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:44 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:44 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 40. Jun 05 20:27:44 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:44 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:44 volumio volumio[2464]: Traceback (most recent call last): Jun 05 20:27:44 volumio volumio[2464]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:44 volumio volumio[2464]: from aiohttp import web Jun 05 20:27:44 volumio volumio[2464]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:44 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:44 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:47 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:47 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 41. Jun 05 20:27:47 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:47 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:47 volumio volumio[2509]: Traceback (most recent call last): Jun 05 20:27:47 volumio volumio[2509]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:47 volumio volumio[2509]: from aiohttp import web Jun 05 20:27:47 volumio volumio[2509]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:47 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:47 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:49 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:49 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 42. Jun 05 20:27:49 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:49 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:49 volumio volumio[2510]: Traceback (most recent call last): Jun 05 20:27:49 volumio volumio[2510]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:49 volumio volumio[2510]: from aiohttp import web Jun 05 20:27:49 volumio volumio[2510]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:49 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:49 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:49 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:49 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:49 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:49 volumio volumio[1686]: info: Listing playlists Jun 05 20:27:51 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:51 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 43. Jun 05 20:27:51 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:51 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:51 volumio volumio[2522]: Traceback (most recent call last): Jun 05 20:27:51 volumio volumio[2522]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:51 volumio volumio[2522]: from aiohttp import web Jun 05 20:27:51 volumio volumio[2522]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:51 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:51 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:53 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:53 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 44. Jun 05 20:27:53 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:53 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:53 volumio volumio[2541]: Traceback (most recent call last): Jun 05 20:27:53 volumio volumio[2541]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:53 volumio volumio[2541]: from aiohttp import web Jun 05 20:27:53 volumio volumio[2541]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:53 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:53 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:54 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:27:54 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:27:54 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:27:54 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:27:56 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:56 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 45. Jun 05 20:27:56 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:56 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:56 volumio volumio[2542]: Traceback (most recent call last): Jun 05 20:27:56 volumio volumio[2542]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:56 volumio volumio[2542]: from aiohttp import web Jun 05 20:27:56 volumio volumio[2542]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:56 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:56 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:58 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:27:58 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 46. Jun 05 20:27:58 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:27:58 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:27:58 volumio volumio[2543]: Traceback (most recent call last): Jun 05 20:27:58 volumio volumio[2543]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:27:58 volumio volumio[2543]: from aiohttp import web Jun 05 20:27:58 volumio volumio[2543]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:27:58 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:27:58 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:27:59 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:27:59 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:28:00 volumio volumio[1686]: info: CoreCommandRouter::volumioPlay Jun 05 20:28:00 volumio volumio[1686]: info: CoreStateMachine::play index undefined Jun 05 20:28:00 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:28:00 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:28:00 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:00 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 47. Jun 05 20:28:00 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:00 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:00 volumio volumio[2555]: Traceback (most recent call last): Jun 05 20:28:00 volumio volumio[2555]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:00 volumio volumio[2555]: from aiohttp import web Jun 05 20:28:00 volumio volumio[2555]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:00 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:00 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:02 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:02 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 48. Jun 05 20:28:02 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 20:28:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 20:28:02 volumio volumio[1686]: info: Discovery: Getting this device information Jun 05 20:28:02 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:28:02 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:28:02 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 20:28:02 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:02 volumio volumio[2569]: Traceback (most recent call last): Jun 05 20:28:02 volumio volumio[2569]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:02 volumio volumio[2569]: from aiohttp import web Jun 05 20:28:02 volumio volumio[2569]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:02 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:02 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:05 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:05 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 49. Jun 05 20:28:05 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:05 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:05 volumio volumio[2571]: Traceback (most recent call last): Jun 05 20:28:05 volumio volumio[2571]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:05 volumio volumio[2571]: from aiohttp import web Jun 05 20:28:05 volumio volumio[2571]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:05 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:05 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=debug msg="handling resume player command from bf0bb2eb8890341d41b9f28ccf86fdb3b3892618" Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=trace msg="seek to 52127ms (diff: 157ms, samples: 2298800, bytes: 1320390)" uri="spotify:track:60bcqJ1484op57M1qhIJbC" Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 05 20:28:05 volumio volumio[1686]: info: camilladsp stopping service pid 2395... Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=debug msg="resume track at 51893ms" Jun 05 20:28:05 volumio volumio[1686]: info: camilladsp service terminated, instance 1 Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:05 volumio volumio[1686]: info: camilladsp service started and running in background, instance 1 Jun 05 20:28:05 volumio volumio[1686]: info: camilladsp spawned new process with pid 2575, instance 1, run: true Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=trace msg="scheduling prefetch in 244s" Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=debug msg="sending successful reply for dealer request" Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 20:28:05 volumio go-librespot[1884]: time="2025-06-05T20:28:05+01:00" level=trace msg="emitting websocket event: playing" Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:60bcqJ1484op57M1qhIJbC","play_origin":"playlist"}} Jun 05 20:28:05 volumio volumio[1686]: info: Spotify is playing in volatile mode Jun 05 20:28:05 volumio volumio[1686]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: UNSET VOLATILE Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: {"status":"stop","position":0,"title":"USHER - My Way (Pat Antony Radio Mix)","artist":"90s90s Black & RnB","album":"","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-black-cover.png","uri":"http://streams.90s90s.de/rnb/mp3-192/volumio","trackType":"80s80s Radio","seek":700,"duration":"194","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeatSingle":false,"consume":false,"volume":20,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: {"status":"play","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:28:05 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:28:05 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:28:05 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:28:05 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:05 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:28:05 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:28:06 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:28:06 volumio volumio[1686]: SPOTIFY: {"status":"play","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":56160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:28:06 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:28:06 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:28:06 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:28:06 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:28:06 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:06 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:06 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:28:06 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:28:07 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:07 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 50. Jun 05 20:28:07 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:07 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:07 volumio volumio[2584]: Traceback (most recent call last): Jun 05 20:28:07 volumio volumio[2584]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:07 volumio volumio[2584]: from aiohttp import web Jun 05 20:28:07 volumio volumio[2584]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:07 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:07 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:09 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:09 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 51. Jun 05 20:28:09 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:09 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:09 volumio volumio[2585]: Traceback (most recent call last): Jun 05 20:28:09 volumio volumio[2585]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:09 volumio volumio[2585]: from aiohttp import web Jun 05 20:28:09 volumio volumio[2585]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:09 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:09 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:09 volumio volumio[1686]: info: CoreCommandRouter::volumioGetState Jun 05 20:28:09 volumio volumio[1686]: info: Listing playlists Jun 05 20:28:09 volumio volumio[1686]: info: Listing playlists Jun 05 20:28:11 volumio volumio[1686]: info: Jun 05 20:28:11 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:28:11 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:28:11 volumio volumio[1686]: info: Jun 05 20:28:11 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:28:11 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:28:11 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:28:11 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:28:11 volumio volumio[1686]: info: sendMpdCommand status took 1 milliseconds Jun 05 20:28:11 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:28:11 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:28:11 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 20:28:11 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:28:11 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:28:11 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:28:11 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:28:11 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:28:11 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:28:11 volumio volumio[1686]: info: ------------------------------ 16ms Jun 05 20:28:11 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:28:11 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:11 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:11 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:28:11 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:28:11 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:11 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 52. Jun 05 20:28:11 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:11 volumio volumio[1686]: info: [jellyfin-poller] Polled http://192.168.1.124:8096: offline Jun 05 20:28:11 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:11 volumio volumio[2598]: Traceback (most recent call last): Jun 05 20:28:11 volumio volumio[2598]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:11 volumio volumio[2598]: from aiohttp import web Jun 05 20:28:11 volumio volumio[2598]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:11 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:11 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 337" Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1515" Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 20:28:12 volumio go-librespot[1884]: time="2025-06-05T20:28:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2065" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=trace msg="closed output device because of stop command" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=debug msg="put connect state inactive" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=trace msg="emitting websocket event: inactive" Jun 05 20:28:13 volumio volumio[1686]: SPOTIFY: received: {"type":"inactive","data":null} Jun 05 20:28:13 volumio volumio[1686]: error: Failed to decode event: inactive Jun 05 20:28:13 volumio volumio[1686]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=trace msg="emitting websocket event: stopped" Jun 05 20:28:13 volumio volumio[1686]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 20:28:13 volumio volumio[1686]: SPOTIFY: {"status":"stop","service":"spop","title":"Wendo Wa Cash Money","artist":"Peter Kigia Wa Esther","album":"Reke Tumanwo","albumart":"https://i.scdn.co/image/ab67616d00001e020ae7eb831cb93e62d2eeac25","uri":"spotify:track:60bcqJ1484op57M1qhIJbC","trackType":"spotify","seek":63160,"duration":326,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 20:28:13 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:28:13 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:28:13 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:28:13 volumio volumio[1686]: info: CorePlayQueue::getTrack 0 Jun 05 20:28:13 volumio volumio[1686]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received spop Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.191:57366->104.199.65.9:443: use of closed network connection" Jun 05 20:28:13 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:28:13 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:13 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:13 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:28:13 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=debug msg="obtained new client token: AAAghqeUYxeVXV2P/SuiVSJ6dRYE2pQ5Mf0FalUlTc+OCJxbxHlgbl66MwmdNo+eZdOTD9itUqNDGYepqaGbsUhrkrjBHmiAJH2VeqY960DluDGxYmWkNNtepg0QkfBH5LpaM0kTEiSzpZM2l8CD9oQeMQG6N7IBF8mkbbXoEOL4cO/ZKIrPZ15QK3+IAOoGZfoUchMmQ7MGDgxmkN21RJChB0OIoTlhsW9GD1k4NhB5MDoOuhgW77YpOoDLNA==" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=info msg="connected to ap-gew1.spotify.com:4070" Jun 05 20:28:13 volumio go-librespot[1884]: time="2025-06-05T20:28:13+01:00" level=debug msg="completed keyexchange" Jun 05 20:28:14 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:14 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 53. Jun 05 20:28:14 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="completed challenge" Jun 05 20:28:14 volumio systemd[1]: Started FusionDsp Daemon. Jun 05 20:28:14 volumio volumio[1686]: info: Jun 05 20:28:14 volumio volumio[1686]: ---------------------------- MPD announces system playlist update Jun 05 20:28:14 volumio volumio[1686]: info: Ignoring MPD Status Update Jun 05 20:28:14 volumio volumio[1686]: info: Jun 05 20:28:14 volumio volumio[1686]: ---------------------------- MPD announces state update: player Jun 05 20:28:14 volumio volumio[1686]: info: ControllerMpd::getState Jun 05 20:28:14 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand status Jun 05 20:28:14 volumio volumio[1686]: info: ------------------------------ 2ms Jun 05 20:28:14 volumio volumio[1686]: info: sendMpdCommand status took 1 milliseconds Jun 05 20:28:14 volumio volumio[1686]: verbose: ControllerMpd::parseState Jun 05 20:28:14 volumio volumio[1686]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 20:28:14 volumio volumio[1686]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 20:28:14 volumio volumio[1686]: verbose: ControllerMpd::parseTrackInfo Jun 05 20:28:14 volumio volumio[1686]: info: ControllerMpd::pushState Jun 05 20:28:14 volumio volumio[1686]: info: CoreCommandRouter::servicePushState Jun 05 20:28:14 volumio volumio[1686]: info: CoreStateMachine::pushState Jun 05 20:28:14 volumio volumio[1686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 20:28:14 volumio volumio[1686]: info: CoreCommandRouter::volumioPushState Jun 05 20:28:14 volumio volumio[1686]: info: ------------------------------ 15ms Jun 05 20:28:14 volumio volumio[1686]: info: FusionDsp - volume level for loudness 20 gain applied 15.33 Jun 05 20:28:14 volumio volumio[1686]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 05 20:28:14 volumio volumio[1686]: info: FusionDsp - Loudness is ON true Jun 05 20:28:14 volumio volumio[1686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="authenticated as fish-e1" Jun 05 20:28:14 volumio volumio[1686]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 05 20:28:14 volumio volumio[2617]: Traceback (most recent call last): Jun 05 20:28:14 volumio volumio[2617]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jun 05 20:28:14 volumio volumio[2617]: from aiohttp import web Jun 05 20:28:14 volumio volumio[2617]: ModuleNotFoundError: No module named 'aiohttp' Jun 05 20:28:14 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jun 05 20:28:14 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="authenticated as fish-e1" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="dealer connection opened" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="restored session after logout, username: fish-e1" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 337" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="autoplay enabled: false" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="received connection id: YjE5M2M4OTItOWVhNS00ZDI3LThmYTYtOTMxZjA0MjA2YjJlK2RlYWxlcit0Y3A6Ly8wYWNhNDBjNi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMTA2M0VBMTBCMTgxMUI5RTg5NjREMURCREE5QUY2NjkwRDdFQzBEMjM5OTM0QTY4MzU4QzExRDRBMDY1ODlFRg==" Jun 05 20:28:14 volumio go-librespot[1884]: time="2025-06-05T20:28:14+01:00" level=debug msg="put connect state because NEW_DEVICE" Jun 05 20:28:16 volumio volumio[1686]: info: [1749151696001] [80s80s] Pushing the next song state USHER - My Way (Pat Antony Radio Mix) and getting next track. Jun 05 20:28:16 volumio volumio[1686]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 20:28:16 volumio volumio[1686]: TypeError: Cannot set property 'name' of undefined Jun 05 20:28:16 volumio volumio[1686]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Jun 05 20:28:16 volumio volumio[1686]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Jun 05 20:28:16 volumio volumio[1686]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Jun 05 20:28:16 volumio volumio[1686]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Jun 05 20:28:16 volumio volumio[1686]: at processImmediate (internal/timers.js:461:21) Jun 05 20:28:16 volumio volumio[1686]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 20:28:16 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jun 05 20:28:16 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 54. Jun 05 20:28:16 volumio sudo[2629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-05 20:27 Jun 05 20:28:16 volumio systemd[1]: Stopped FusionDsp Daemon. Jun 05 20:28:16 volumio sudo[2629]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 20:28:16 volumio systemd[1]: Started FusionDsp Daemon. 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"