Apr 12 19:49:08 dac go-librespot[17711]: time="2026-04-12T19:49:08+05:30" level=trace msg="sent dealer ping" Apr 12 19:49:09 dac go-librespot[17711]: time="2026-04-12T19:49:09+05:30" level=trace msg="received dealer pong" Apr 12 19:49:09 dac go-librespot[17711]: time="2026-04-12T19:49:09+05:30" level=debug msg="fetched chunk 11/23, size: 524288" uri="spotify:track:7roNDDmU52OYgYwCN9SI8E" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="handling play player command from ca7f795144ac718384138a333b45361b9f8d2c8c" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="resolved context of track" uri="spotify:album:3OBhnTLrvkoEEETjFA3Qfk" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=trace msg="fetched new page 0 with 30 items (list: 30)" uri="spotify:album:3OBhnTLrvkoEEETjFA3Qfk" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=trace msg="emitting websocket event: will_play" Apr 12 19:49:13 dac volumio[17452]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:3OBhnTLrvkoEEETjFA3Qfk","uri":"spotify:track:2VCSO1mqWPALcPbEQwgSd3","play_origin":"album"}} Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="selected format OGG_VORBIS_320 (7f3b0fda189c0f2153d62552157cd60993c8817e)" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=debug msg="requested aes key for file 7f3b0fda189c0f2153d62552157cd60993c8817e, gid: 2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:13 dac go-librespot[17711]: time="2026-04-12T19:49:13+05:30" level=trace msg="found 2 cdn urls" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="fetched first chunk of 25, total size is 12866470 bytes" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=info msg="loaded track \"Money\" (paused: false, position: 0ms, duration: 282019ms, prefetched: false)" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=trace msg="scheduling prefetch in 252s" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=trace msg="emitting websocket event: metadata" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="sending successful reply for dealer request" Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2VCSO1mqWPALcPbEQwgSd3","name":"Money","artist_names":["Michael Jackson"],"album_name":"HIStory - PAST, PRESENT AND FUTURE - BOOK I","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b4a878f008a0eda552446701","position":0,"duration":282019,"release_date":"year:1995 month:6 day:16","track_number":7,"disc_number":2}} Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 19:49:14 dac go-librespot[17711]: time="2026-04-12T19:49:14+05:30" level=trace msg="emitting websocket event: playing" Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:3OBhnTLrvkoEEETjFA3Qfk","uri":"spotify:track:2VCSO1mqWPALcPbEQwgSd3","resume":false,"play_origin":"album"}} Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: {"status":"play","service":"spop","title":"Money","artist":"Michael Jackson","album":"HIStory - PAST, PRESENT AND FUTURE - BOOK I","albumart":"https://i.scdn.co/image/ab67616d00001e02b4a878f008a0eda552446701","uri":"spotify:track:2VCSO1mqWPALcPbEQwgSd3","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 12 19:49:14 dac volumio[17452]: info: CoreCommandRouter::servicePushState Apr 12 19:49:14 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:14 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:14 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:14 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:14.341+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=0 volume=63 Apr 12 19:49:14 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:14.341+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: {"status":"play","service":"spop","title":"Money","artist":"Michael Jackson","album":"HIStory - PAST, PRESENT AND FUTURE - BOOK I","albumart":"https://i.scdn.co/image/ab67616d00001e02b4a878f008a0eda552446701","uri":"spotify:track:2VCSO1mqWPALcPbEQwgSd3","trackType":"spotify","seek":0,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 12 19:49:14 dac volumio[17452]: info: CoreCommandRouter::servicePushState Apr 12 19:49:14 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:14 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:14 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:14.642+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=0 volume=63 Apr 12 19:49:14 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:14.643+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:14 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:25 dac go-librespot[17711]: time="2026-04-12T19:49:25+05:30" level=debug msg="fetched chunk 4/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:26 dac go-librespot[17711]: time="2026-04-12T19:49:26+05:30" level=debug msg="update volume requested to 43908/65535" Apr 12 19:49:26 dac go-librespot[17711]: time="2026-04-12T19:49:26+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:26 dac go-librespot[17711]: time="2026-04-12T19:49:26+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Apr 12 19:49:26 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 67 Apr 12 19:49:26 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:26 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 67 Apr 12 19:49:26 dac sudo[19356]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:26 dac sudo[19356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:26 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:26 dac sudo[19356]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:26 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:26 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:26 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:26 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:26 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:26.329+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=12000 volume=63 Apr 12 19:49:26 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:26.329+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 67 Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:26 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:26 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:26 dac go-librespot[17711]: time="2026-04-12T19:49:26+05:30" level=debug msg="update volume requested to 46530/65535" Apr 12 19:49:27 dac go-librespot[17711]: time="2026-04-12T19:49:27+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:27 dac go-librespot[17711]: time="2026-04-12T19:49:27+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:27 dac go-librespot[17711]: time="2026-04-12T19:49:27+05:30" level=debug msg="update volume requested to 49151/65535" Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":71,"max":100}} Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 71 Apr 12 19:49:27 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 71 Apr 12 19:49:27 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:27 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 71 Apr 12 19:49:27 dac sudo[19360]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:27 dac sudo[19360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:27 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:27 dac sudo[19360]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:27 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:27 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:27 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:27 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:27 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:27.197+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=13000 volume=63 Apr 12 19:49:27 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:27.197+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 71 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:27 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:27 dac go-librespot[17711]: time="2026-04-12T19:49:27+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:27 dac go-librespot[17711]: time="2026-04-12T19:49:27+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":75,"max":100}} Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 75 Apr 12 19:49:27 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 75 Apr 12 19:49:27 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:27 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 75 Apr 12 19:49:27 dac sudo[19363]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:27 dac sudo[19363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:27 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:27 dac sudo[19363]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:27 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:27 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:27 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:27 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:27.451+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=13000 volume=63 Apr 12 19:49:27 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:27.452+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 75 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:27 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:27 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:28 dac volumio[17452]: SPOTIFY: SETTING SPOTIFY VOLUME 63 Apr 12 19:49:28 dac volumio[17452]: info: Sending Spotify command with payload to local API: /player/volume Apr 12 19:49:28 dac go-librespot[17711]: time="2026-04-12T19:49:28+05:30" level=debug msg="update volume requested to 41287/65535" Apr 12 19:49:29 dac go-librespot[17711]: time="2026-04-12T19:49:29+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:29 dac go-librespot[17711]: time="2026-04-12T19:49:29+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:29 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":63,"max":100}} Apr 12 19:49:29 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 63 Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="update volume requested to 43908/65535" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="update volume requested to 46530/65535" Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Apr 12 19:49:33 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 67 Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 67 Apr 12 19:49:33 dac sudo[19366]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:33 dac sudo[19366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:33 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:33 dac sudo[19366]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:33 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.454+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=19000 volume=63 Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.456+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 67 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:33 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="update volume requested to 51773/65535" Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":71,"max":100}} Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 71 Apr 12 19:49:33 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 71 Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 71 Apr 12 19:49:33 dac sudo[19369]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:33 dac sudo[19369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:33 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:33 dac sudo[19369]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:33 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.705+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=19000 volume=63 Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.705+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 71 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:33 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:33 dac go-librespot[17711]: time="2026-04-12T19:49:33+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Apr 12 19:49:33 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 79 Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 79 Apr 12 19:49:33 dac sudo[19372]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:33 dac sudo[19372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:33 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:33 dac sudo[19372]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:33 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:33 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:33 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 79 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:33 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:33 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.954+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=19000 volume=63 Apr 12 19:49:33 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:33.955+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:34 dac go-librespot[17711]: time="2026-04-12T19:49:34+05:30" level=debug msg="update volume requested to 54394/65535" Apr 12 19:49:34 dac go-librespot[17711]: time="2026-04-12T19:49:34+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:34 dac go-librespot[17711]: time="2026-04-12T19:49:34+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:34 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":83,"max":100}} Apr 12 19:49:34 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 83 Apr 12 19:49:34 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 83 Apr 12 19:49:34 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:34 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 83 Apr 12 19:49:34 dac sudo[19375]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:35 dac sudo[19375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:35 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:35 dac sudo[19375]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:35 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:35 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:35 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:35 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:35 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:35.013+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=20000 volume=63 Apr 12 19:49:35 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:35.014+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 83 Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:35 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:35 dac go-librespot[17711]: time="2026-04-12T19:49:35+05:30" level=debug msg="update volume requested to 57015/65535" Apr 12 19:49:35 dac go-librespot[17711]: time="2026-04-12T19:49:35+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:35 dac go-librespot[17711]: time="2026-04-12T19:49:35+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":87,"max":100}} Apr 12 19:49:35 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 87 Apr 12 19:49:35 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 87 Apr 12 19:49:35 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:35 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 87 Apr 12 19:49:36 dac sudo[19392]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:36 dac sudo[19392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:36 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:36 dac sudo[19392]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:36 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:36 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:36 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:36 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:36 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:36.031+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=21000 volume=63 Apr 12 19:49:36 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:36.031+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:36 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:36 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 87 Apr 12 19:49:36 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:36 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:36 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=debug msg="update volume requested to 59637/65535" Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: SETTING SPOTIFY VOLUME 63 Apr 12 19:49:37 dac volumio[17452]: info: Sending Spotify command with payload to local API: /player/volume Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=debug msg="update volume requested to 41287/65535" Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":91,"max":100}} Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 91 Apr 12 19:49:37 dac volumio[17452]: info: Setting Volumio Volume from Spotify: 91 Apr 12 19:49:37 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:37 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 91 Apr 12 19:49:37 dac sudo[19395]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:37 dac sudo[19395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:37 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:37 dac sudo[19395]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:37 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:37 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:37 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:37 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:37 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:37.603+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=23000 volume=63 Apr 12 19:49:37 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:37.603+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: SPOTIFY VOLUME 91 Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: VOLUMIO VOLUME 63 Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 19:49:37 dac volumio[17452]: info: Setting Spotify Volume from Volumio: 63 Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=debug msg="fetched chunk 5/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:37 dac go-librespot[17711]: time="2026-04-12T19:49:37+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":63,"max":100}} Apr 12 19:49:37 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 63 Apr 12 19:49:38 dac go-librespot[17711]: time="2026-04-12T19:49:38+05:30" level=trace msg="sent dealer ping" Apr 12 19:49:39 dac volumio[17452]: SPOTIFY: SETTING SPOTIFY VOLUME 63 Apr 12 19:49:39 dac volumio[17452]: info: Sending Spotify command with payload to local API: /player/volume Apr 12 19:49:39 dac go-librespot[17711]: time="2026-04-12T19:49:39+05:30" level=trace msg="received dealer pong" Apr 12 19:49:39 dac go-librespot[17711]: time="2026-04-12T19:49:39+05:30" level=debug msg="update volume requested to 41287/65535" Apr 12 19:49:39 dac go-librespot[17711]: time="2026-04-12T19:49:39+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 19:49:39 dac go-librespot[17711]: time="2026-04-12T19:49:39+05:30" level=trace msg="emitting websocket event: volume" Apr 12 19:49:39 dac volumio[17452]: SPOTIFY: received: {"type":"volume","data":{"value":63,"max":100}} Apr 12 19:49:39 dac volumio[17452]: SPOTIFY: RECEIVED SPOTIFY VOLUME 63 Apr 12 19:49:43 dac volumio[17452]: verbose: New Socket.io Connection to 192.168.0.11 from 192.168.0.19 UA: Mozilla/5.0 (Linux; Android 16; A142 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: Listing playlists Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: Listing playlists Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: Listing playlists Apr 12 19:49:43 dac volumio[17452]: info: Received Get System Info Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:49:43 dac volumio[17452]: info: Discovery: Getting this device information Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::volumioGetState Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 19:49:43 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 19:49:45 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:45 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 66 Apr 12 19:49:45 dac sudo[19414]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:45 dac sudo[19414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:45 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:45 dac sudo[19414]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:45 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:45 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:45 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:45 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:45 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:45.531+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=31000 volume=63 Apr 12 19:49:45 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:45.531+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:45 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:46 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:46 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 87 Apr 12 19:49:46 dac sudo[19433]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:46 dac sudo[19433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:46 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:46 dac sudo[19433]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:46 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:46 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:46 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:46 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:46 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:46.215+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=32000 volume=63 Apr 12 19:49:46 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:46.216+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:46 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:48 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:48 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 84 Apr 12 19:49:48 dac sudo[19437]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:48 dac sudo[19437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:48 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:48 dac sudo[19437]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:48 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:48 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:48 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:48 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:48 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:48.243+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=34000 volume=63 Apr 12 19:49:48 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:48.243+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:48 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:49 dac go-librespot[17711]: time="2026-04-12T19:49:49+05:30" level=debug msg="fetched chunk 6/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:49:50 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:50 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 100 Apr 12 19:49:50 dac sudo[19440]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:50 dac sudo[19440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:50 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:50 dac sudo[19440]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:50 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:50 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:50 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:50 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:50 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:50.501+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=36000 volume=63 Apr 12 19:49:50 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:50.502+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:50 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:53 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:53 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 100 Apr 12 19:49:53 dac sudo[19443]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:53 dac sudo[19443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:53 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:53 dac sudo[19443]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:53 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:53 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:53 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:53 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:53 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:53.086+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=39000 volume=63 Apr 12 19:49:53 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:53.087+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:53 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:49:56 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:49:56 dac volumio[17452]: info: Allo Relay Attenuator: alsavolume called with 100 Apr 12 19:49:56 dac sudo[19460]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 19:49:56 dac sudo[19460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:49:56 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 19:49:56 dac sudo[19460]: pam_unix(sudo:session): session closed for user root Apr 12 19:49:56 dac volumio[17452]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 19:49:56 dac volumio[17452]: info: CoreStateMachine::pushState Apr 12 19:49:56 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:49:56 dac volumio[17452]: info: CoreCommandRouter::volumioPushState Apr 12 19:49:56 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:56.072+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=42000 volume=63 Apr 12 19:49:56 dac volumio5-onboarding[1586]: time=2026-04-12T19:49:56.073+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:2VCSO1mqWPALcPbEQwgSd3 title=Money Apr 12 19:49:56 dac volumio[17452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 19:50:00 dac go-librespot[17711]: time="2026-04-12T19:50:00+05:30" level=debug msg="fetched chunk 7/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:50:08 dac go-librespot[17711]: time="2026-04-12T19:50:08+05:30" level=trace msg="sent dealer ping" Apr 12 19:50:09 dac go-librespot[17711]: time="2026-04-12T19:50:09+05:30" level=trace msg="received dealer pong" Apr 12 19:50:11 dac go-librespot[17711]: time="2026-04-12T19:50:11+05:30" level=debug msg="fetched chunk 8/24, size: 524288" uri="spotify:track:2VCSO1mqWPALcPbEQwgSd3" Apr 12 19:50:12 dac volumio[17452]: info: Allo Relay Attenuator: Stopping plugin Apr 12 19:50:12 dac sudo[19479]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c GET_VOLUME Apr 12 19:50:12 dac sudo[19479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:50:12 dac sudo[19479]: pam_unix(sudo:session): session closed for user root Apr 12 19:50:12 dac volumio[17452]: info: Allo Relay Attenuator: Saved volume 63 for Remember Last Apr 12 19:50:12 dac volumio[17452]: info: Allo Relay Attenuator: Unregistering volume override Apr 12 19:50:12 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Apr 12 19:50:12 dac volumio[17452]: info: Setting Device Volume Override Apr 12 19:50:12 dac volumio[17452]: error: Failed to set Device Volume Override: missing parameters Apr 12 19:50:12 dac volumio[17452]: info: Allo Relay Attenuator: Volume override unregistered Apr 12 19:50:12 dac sudo[19482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fn-rattenu.service Apr 12 19:50:12 dac sudo[19482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 19:50:12 dac systemd[1]: Stopping fn-rattenu.service - Allo Relay Attenuator Daemon... Apr 12 19:50:12 dac lircd[1057]: lircd-0.10.1[1057]: Info: removed client Apr 12 19:50:12 dac lircd-0.10.1[1057]: Info: removed client Apr 12 19:50:12 dac systemd[1]: fn-rattenu.service: Deactivated successfully. Apr 12 19:50:12 dac systemd[1]: Stopped fn-rattenu.service - Allo Relay Attenuator Daemon. Apr 12 19:50:12 dac systemd[1]: fn-rattenu.service: Consumed 3.585s CPU time. Apr 12 19:50:12 dac sudo[19482]: pam_unix(sudo:session): session closed for user root Apr 12 19:50:12 dac volumio[17452]: info: Allo Relay Attenuator: Daemon stopped Apr 12 19:50:12 dac volumio[17452]: info: Disabling plugin allo_relay_attenuator Apr 12 19:50:12 dac volumio[17452]: info: Done. Apr 12 19:50:15 dac volumio[17452]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 19:50:15 dac volumio[17452]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 19:50:15 dac volumio[17452]: TypeError: Cannot read properties of undefined (reading 'then') Apr 12 19:50:15 dac volumio[17452]: at CoreCommandRouter.volumiosetvolume (/volumio/app/index.js:136:10) Apr 12 19:50:15 dac volumio[17452]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:304:33) Apr 12 19:50:15 dac volumio[17452]: at Socket.emit (node:events:514:28) Apr 12 19:50:15 dac volumio[17452]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 12 19:50:15 dac volumio[17452]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 19:50:15 dac volumio[17452]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 19:50:16 dac sudo[19512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 19:49' Apr 12 19:50:16 dac sudo[19512]: 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"