May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:00 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:00 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.140Z level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.153:37766 May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 15:41:02 volumio volumio[1113]: info: Discovery: Getting this device information May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.601Z level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.153:37766 @ 0x21286f0" latency=262.418806ms timeout=10s May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.601Z level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.601Z level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.153:37766 @ 0x21286f0" latency=263.703597ms platform=PLATFORM_ANDROID version=5.260413.0 May 30 15:41:02 volumio volumio[1113]: info: Received Get System Info May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 15:41:02 volumio volumio[1113]: info: Discovery: Getting this device information May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.605Z level=INFO msg="emitting device name changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" name=Volumio May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.616Z level=INFO msg="emitting device language changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" language=fr May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.619Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" timezone=Europe/Paris May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.620Z level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" available=true connected=true macAddress=b8:27:eb:ea:cb:80 ip4Address=192.168.1.157/24 ip6Address= May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.620Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" available=false connected=false macAddress= ip4Address= ip6Address= ssid= May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.621Z level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" setupComplete=true May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 15:41:02 volumio volumio[1113]: amixer -c 1 info | grep "bcm2835 Headphones" May 30 15:41:02 volumio volumio[1113]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' May 30 15:41:02 volumio volumio[1113]: amixer -c 0 info | grep "bcm2835 ALSA" May 30 15:41:02 volumio volumio[1113]: amixer -c 1 info | grep "bcm2835 Headphones" May 30 15:41:02 volumio volumio[1113]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' May 30 15:41:02 volumio volumio[1113]: verbose: New Socket.io Connection to 192.168.1.157:3000 from 192.168.1.153 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 May 30 15:41:02 volumio volumio[1113]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 May 30 15:41:02 volumio volumio[1113]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 30 15:41:02 volumio volumio[1113]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 30 15:41:02 volumio volumio[1113]: amixer -c 2 info | grep "vc4-hdmi" May 30 15:41:02 volumio volumio[1113]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.816Z level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" selectedOutputId=1 May 30 15:41:02 volumio volumio[1113]: info: Received Get System Info May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 15:41:02 volumio volumio[1113]: info: Discovery: Getting this device information May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.826Z level=INFO msg="emitting software info changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" currentVersion=4.119 latestVersion=4.119 May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.827Z level=INFO msg="emitting software update progress event" component=server peer="192.168.1.153:37766 @ 0x21286f0" status=UPDATE_STATUS_NONE progress=0 May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.828Z level=INFO msg="emitting user changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" userId= May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.829Z level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" providers=3 May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.830Z level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" plugins=67 May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.834Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:02 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:02.835Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 30 15:41:02 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=debug msg="pause track at 70742ms" May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:03 volumio go-librespot[3826]: time="2026-05-30T15:41:03+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:03 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:03 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:03 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:03 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:03 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:03.177Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:03 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:03.177Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:03 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:03 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:03 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:03 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:03 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:03.184Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:03 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:03.185Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:03 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:03 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:03 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:03 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:03 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:03 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:03 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:03.448Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=79.812076ms timeout=10s May 30 15:41:03 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:03 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:05 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:05.953Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.153:37766 @ 0x21286f0" latency=11.829235ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE May 30 15:41:08 volumio sudo[8469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 15:41:08 volumio sudo[8469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:41:08 volumio sudo[8469]: pam_unix(sudo:session): session closed for user root May 30 15:41:08 volumio sudo[8471]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 15:41:08 volumio sudo[8471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:41:08 volumio sudo[8471]: pam_unix(sudo:session): session closed for user root May 30 15:41:08 volumio volumio[1113]: verbose: New Socket.io Connection to 192.168.1.157 from 192.168.1.153 UA: Mozilla/5.0 (Linux; Android 15; 2310FPCA4G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/148.0.7778.178 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::volumioGetVisibleSources May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 30 15:41:08 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 15:41:09 volumio sudo[8477]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 15:41:09 volumio sudo[8477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:41:09 volumio sudo[8477]: pam_unix(sudo:session): session closed for user root May 30 15:41:09 volumio sudo[8479]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 15:41:09 volumio sudo[8479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:41:09 volumio sudo[8479]: pam_unix(sudo:session): session closed for user root May 30 15:41:09 volumio volumio[1113]: verbose: New Socket.io Connection to 192.168.1.157 from 192.168.1.153 UA: Mozilla/5.0 (Linux; Android 15; 2310FPCA4G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/148.0.7778.178 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 30 15:41:09 volumio volumio[1113]: info: Listing playlists May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 30 15:41:09 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 15:41:11 volumio go-librespot[3826]: time="2026-05-30T15:41:11+02:00" level=trace msg="sent dealer ping" May 30 15:41:11 volumio go-librespot[3826]: time="2026-05-30T15:41:11+02:00" level=trace msg="received dealer pong" May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:12 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:12 volumio volumio[1113]: info: Spotify Play May 30 15:41:12 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=trace msg="seek to 70742ms (diff: 45ms, samples: 3119722, bytes: 1362528)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="resume track at 70697ms" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=trace msg="scheduling prefetch in 101s" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:12 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:12 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:12 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:12 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.539Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.539Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:12 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:12 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:12 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:12 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.545Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.546Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:12 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:12 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:12 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:12 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:12 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:12 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:12 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:12 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.838Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.839Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:12 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:12 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:12 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:12 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:12 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.850Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:12 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:12.851Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:12 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:12 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:12 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:12 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="pause track at 71307ms" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:12 volumio go-librespot[3826]: time="2026-05-30T15:41:12+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:13 volumio go-librespot[3826]: time="2026-05-30T15:41:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:13 volumio go-librespot[3826]: time="2026-05-30T15:41:13+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:13 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:13 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:13 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:13 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:13 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:13.061Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:13 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:13.062Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:13 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:13 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:13 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:13 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:13 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:13.068Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:13 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:13.068Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:13 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:13 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:13 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:13 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:13 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:13 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:13 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:13.228Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=6.375502ms timeout=10s May 30 15:41:13 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:13 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:21 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:21 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:21 volumio volumio[1113]: info: Spotify Play May 30 15:41:21 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:21 volumio go-librespot[3826]: time="2026-05-30T15:41:21+02:00" level=trace msg="seek to 71307ms (diff: 186ms, samples: 3144638, bytes: 1373320)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:21 volumio go-librespot[3826]: time="2026-05-30T15:41:21+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:21 volumio go-librespot[3826]: time="2026-05-30T15:41:21+02:00" level=debug msg="resume track at 71121ms" May 30 15:41:21 volumio go-librespot[3826]: time="2026-05-30T15:41:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:21 volumio go-librespot[3826]: time="2026-05-30T15:41:21+02:00" level=trace msg="scheduling prefetch in 101s" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.057Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.057Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.064Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.064Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:22 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:22 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:22 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="pause track at 71114ms" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:22 volumio go-librespot[3826]: time="2026-05-30T15:41:22+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.263Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:22 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.265Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.270Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.271Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.357Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.357Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:22 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:22 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:22 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:22 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:22 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.371Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:22 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:22.372Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:22 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:23 volumio volumio[1113]: info: Spotify Play May 30 15:41:23 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=trace msg="seek to 71114ms (diff: 225ms, samples: 3136127, bytes: 1369635)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="resume track at 70889ms" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=trace msg="scheduling prefetch in 101s" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.253Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.254Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.260Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.261Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:23 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:23 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:23 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.510Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=7.270592ms timeout=10s May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:23 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:23 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:23 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="pause track at 71168ms" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.553Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.554Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.572Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.572Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:23 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:23 volumio go-librespot[3826]: time="2026-05-30T15:41:23+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.651Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.652Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:23 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:23 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:23 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:23 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.658Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:23 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:23.659Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:23 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:24 volumio volumio[1113]: info: Spotify Play May 30 15:41:24 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=trace msg="seek to 71168ms (diff: 279ms, samples: 3138508, bytes: 1370666)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="resume track at 70515ms" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=trace msg="scheduling prefetch in 101s" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.373Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.374Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.380Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.381Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:24 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:24 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:24 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.667Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.668Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:24 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.682Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.683Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:24 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.693Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=17.690001ms timeout=10s May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:24 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:24 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:24 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="pause track at 71356ms" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.849Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.850Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:24 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:24 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:24 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:24 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.855Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:24 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:24.856Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:24 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="pause track at 71771ms" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:24 volumio go-librespot[3826]: time="2026-05-30T15:41:24+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:25 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:25 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:25 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.060Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.061Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:25 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:25 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:25 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.067Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.067Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:25 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:25 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:25 volumio volumio[1113]: info: Spotify Play May 30 15:41:25 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=trace msg="seek to 71771ms (diff: 209ms, samples: 3165101, bytes: 1382180)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=debug msg="resume track at 71188ms" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=trace msg="scheduling prefetch in 101s" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:25 volumio go-librespot[3826]: time="2026-05-30T15:41:25+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:25 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:25 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:25 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.956Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.956Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:25 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:25 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:25 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:25 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.965Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:25 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:25.966Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:25 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:25 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:25 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:25 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:25 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:25 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="pause track at 71780ms" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.252Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=9.214452ms timeout=10s May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.256Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.256Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:26 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:26 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:26 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.273Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.273Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="pause track at 72221ms" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.290Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.290Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.296Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.297Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:26 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:26 volumio go-librespot[3826]: time="2026-05-30T15:41:26+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.417Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.418Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:26 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:26 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:26 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:26 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.424Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=70001 volume=100 May 30 15:41:26 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:26.425Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:26 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 15:41:27 volumio volumio[1113]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 30 15:41:27 volumio volumio[1113]: info: Received Get System Version May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:41:27 volumio volumio[1113]: info: Received Get System Info May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 15:41:27 volumio volumio[1113]: info: Discovery: Getting this device information May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::volumioGetState May 30 15:41:27 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1818" May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 415" May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1814" May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1411" May 30 15:41:29 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:29 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:29 volumio volumio[1113]: info: Spotify Play May 30 15:41:29 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=trace msg="seek to 72221ms (diff: 232ms, samples: 3184946, bytes: 1390772)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:29 volumio go-librespot[3826]: time="2026-05-30T15:41:29+02:00" level=debug msg="resume track at 71989ms" May 30 15:41:30 volumio go-librespot[3826]: time="2026-05-30T15:41:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:30 volumio go-librespot[3826]: time="2026-05-30T15:41:30+02:00" level=trace msg="scheduling prefetch in 100s" May 30 15:41:30 volumio go-librespot[3826]: time="2026-05-30T15:41:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:30 volumio go-librespot[3826]: time="2026-05-30T15:41:30+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:30 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:30 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:30 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:30 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.251Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.251Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:30 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:30 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:30 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:30 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.257Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.258Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:30 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:30 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:30 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:30 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:30 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.547Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.548Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:30 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:30 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:30 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:30 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:30 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.562Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=70001 volume=100 May 30 15:41:30 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:30.562Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:30 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:30 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:30 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:38 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:38.701Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=13.322352ms timeout=10s May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:38 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:38 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:38 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:38 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:38 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:38 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":70001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:38 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:38 volumio go-librespot[3826]: time="2026-05-30T15:41:38+02:00" level=debug msg="pause track at 80692ms" May 30 15:41:38 volumio go-librespot[3826]: time="2026-05-30T15:41:38+02:00" level=debug msg="fetched chunk 6/7, size: 524288" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:38 volumio go-librespot[3826]: time="2026-05-30T15:41:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:38 volumio go-librespot[3826]: time="2026-05-30T15:41:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:38 volumio go-librespot[3826]: time="2026-05-30T15:41:38+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:38 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:38 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:38 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:38 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:38 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:38.842Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:38 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:38.842Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:38 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:38 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:38 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:38 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:38 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:38 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:38.848Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:38 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:38.849Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:38 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:38 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:38 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:38 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:38 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:38 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:40 volumio volumio[1113]: info: Spotify Play May 30 15:41:40 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=trace msg="seek to 80692ms (diff: 222ms, samples: 3558517, bytes: 1556735)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=debug msg="resume track at 80470ms" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=trace msg="scheduling prefetch in 92s" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:40 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:40 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:40 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:40 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:40 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:40 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.492Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.493Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.494Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.494Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:40 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:40 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:40 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:40 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:40 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:40 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:40 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.784Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.785Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:40 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:40 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:40 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.795Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.796Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:40 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:40 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:40 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:40 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:40 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:40.958Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=8.690475ms timeout=10s May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:40 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:40 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:40 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:40 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:40 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:40 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:40 volumio go-librespot[3826]: time="2026-05-30T15:41:40+02:00" level=debug msg="pause track at 80935ms" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:41 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:41 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:41 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.130Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.131Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:41 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:41 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:41 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.136Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.137Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:41 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="pause track at 81343ms" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:41 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:41 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:41 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.608Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.609Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:41 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:41 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:41 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.614Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:41 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:41.615Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:41 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:41 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:41 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="sent dealer ping" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="received dealer pong" May 30 15:41:41 volumio volumio[1113]: info: CoreCommandRouter::volumioVolatilePlay May 30 15:41:41 volumio volumio[1113]: info: CoreStateMachine::volatilePlay May 30 15:41:41 volumio volumio[1113]: info: Spotify Play May 30 15:41:41 volumio volumio[1113]: info: Sending Spotify command to local API: /player/resume May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="seek to 81343ms (diff: 232ms, samples: 3587226, bytes: 1569387)" uri="spotify:track:1ewYoK8HL3Rflxyrjo1CAY" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="resume track at 81111ms" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:41 volumio go-librespot[3826]: time="2026-05-30T15:41:41+02:00" level=trace msg="scheduling prefetch in 91s" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=trace msg="emitting websocket event: playing" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.014Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.015Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","resume":true,"play_origin":"go-librespot"}} May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.020Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.021Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:42 volumio volumio[1113]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:42 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:42 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.225Z level=INFO msg="player pause request" component=server type=REQUEST_TYPE_PLAYER_PAUSE peer="192.168.1.153:37766 @ 0x21286f0" latency=8.580132ms timeout=10s May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPause May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pause May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::stPlaybackTimer May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::servicePause May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePause May 30 15:41:42 volumio volumio[1113]: info: Spotify Received pause May 30 15:41:42 volumio volumio[1113]: SPOTIFY: SPOTIFY PAUSE May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"play","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","codec":"ogg","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 30 15:41:42 volumio volumio[1113]: info: Sending Spotify command to local API: /player/pause May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="pause track at 81402ms" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.315Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.315Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"play","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.325Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PLAYING positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.326Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is playing May 30 15:41:42 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:42 volumio volumio[1113]: error: FusionDsp - Monitor WebSocket error: [object Object] May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.377Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.378Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.383Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.384Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:42 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="handling pause player command from 59a55243bed3f36ab4e1636e7390997f00d5136a" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="pause track at 81828ms" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="sending successful reply for dealer request" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 30 15:41:42 volumio go-librespot[3826]: time="2026-05-30T15:41:42+02:00" level=trace msg="emitting websocket event: paused" May 30 15:41:42 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:42 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:42 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:42 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:42 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:42 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.999Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:43 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:42.999Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:43 volumio volumio[1113]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","uri":"spotify:track:1ewYoK8HL3Rflxyrjo1CAY","play_origin":"go-librespot"}} May 30 15:41:43 volumio volumio[1113]: SPOTIFY: PUSH STATE SPOTIFY May 30 15:41:43 volumio volumio[1113]: SPOTIFY: {"status":"pause","service":"spop","title":"An Irish Pub Song","artist":"The Rumjacks","album":"Gangs Of New Holland","albumart":"https://i.scdn.co/image/ab67616d00001e022ece398b5a61d8b508abc075","uri":"spotify:track:5UGJICh0UfvXTansc82A1k","trackType":"spotify","seek":78001,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 30 15:41:43 volumio volumio[1113]: info: CoreCommandRouter::servicePushState May 30 15:41:43 volumio volumio[1113]: info: CoreStateMachine::pushState May 30 15:41:43 volumio volumio[1113]: info: CoreCommandRouter::volumioPushState May 30 15:41:43 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:43.005Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" state=STATUS_PAUSED positionMs=78001 volume=100 May 30 15:41:43 volumio volumio5-onboarding[1635]: time=2026-05-30T13:41:43.005Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.153:37766 @ 0x21286f0" id=spotify:track:5UGJICh0UfvXTansc82A1k title="An Irish Pub Song" May 30 15:41:43 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:43 volumio volumio[1113]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 15:41:43 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:43 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:43 volumio volumio[1113]: info: FusionDsp - Volumio is not playing May 30 15:41:43 volumio volumio[1113]: info: FusionDsp - Clipped samples monitor stopped May 30 15:41:44 volumio volumio[1113]: info: CoreCommandRouter::volumioGetQueue May 30 15:41:44 volumio volumio[1113]: info: CoreStateMachine::getQueue May 30 15:41:44 volumio volumio[1113]: info: CorePlayQueue::getQueue May 30 15:41:50 volumio volumio[1113]: info: CoreCommandRouter::volumioGetVisibleSources May 30 15:41:50 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:41:54 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 30 15:41:54 volumio volumio[1113]: info: In handleBrowseUri, curUri=spotify May 30 15:41:54 volumio volumio[1113]: info: Preload queue cleared May 30 15:41:54 volumio volumio[1113]: info: Preload queue cleared May 30 15:41:54 volumio volumio[1113]: info: Preload queue cleared May 30 15:41:54 volumio volumio[1113]: info: Preload queue cleared May 30 15:42:00 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 30 15:42:00 volumio volumio[1113]: info: In handleBrowseUri, curUri=spotify/playlists May 30 15:42:00 volumio volumio[1113]: info: Preload queue cleared May 30 15:42:11 volumio go-librespot[3826]: time="2026-05-30T15:42:11+02:00" level=trace msg="sent dealer ping" May 30 15:42:11 volumio go-librespot[3826]: time="2026-05-30T15:42:11+02:00" level=trace msg="received dealer pong" May 30 15:42:14 volumio volumio[1113]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 30 15:42:14 volumio volumio[1113]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:3I0MzPoqkag1Y3yoiIcz8Y May 30 15:42:15 volumio volumio[1113]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:42:15 volumio volumio[1113]: TypeError: Cannot read properties of null (reading '0') May 30 15:42:15 volumio volumio[1113]: at /data/plugins/music_service/spop/index.js:2504:56 May 30 15:42:15 volumio volumio[1113]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) May 30 15:42:15 volumio volumio[1113]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:42:16 volumio sudo[8605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-30 15:41' May 30 15:42:16 volumio sudo[8605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"