Apr 12 18:50:01 dac go-librespot[10712]: time="2026-04-12T18:50:01+05:30" level=debug msg="fetched chunk 18/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:50:08 dac go-librespot[10712]: time="2026-04-12T18:50:08+05:30" level=trace msg="sent dealer ping" Apr 12 18:50:08 dac go-librespot[10712]: time="2026-04-12T18:50:08+05:30" level=trace msg="received dealer pong" Apr 12 18:50:14 dac go-librespot[10712]: time="2026-04-12T18:50:14+05:30" level=debug msg="fetched chunk 19/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:50:27 dac go-librespot[10712]: time="2026-04-12T18:50:27+05:30" level=debug msg="fetched chunk 20/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:50:38 dac go-librespot[10712]: time="2026-04-12T18:50:38+05:30" level=trace msg="sent dealer ping" Apr 12 18:50:38 dac go-librespot[10712]: time="2026-04-12T18:50:38+05:30" level=trace msg="received dealer pong" Apr 12 18:50:41 dac go-librespot[10712]: time="2026-04-12T18:50:41+05:30" level=debug msg="fetched chunk 21/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:50:54 dac go-librespot[10712]: time="2026-04-12T18:50:54+05:30" level=debug msg="fetched chunk 22/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:51:08 dac go-librespot[10712]: time="2026-04-12T18:51:08+05:30" level=trace msg="sent dealer ping" Apr 12 18:51:08 dac go-librespot[10712]: time="2026-04-12T18:51:08+05:30" level=trace msg="received dealer pong" Apr 12 18:51:09 dac go-librespot[10712]: time="2026-04-12T18:51:09+05:30" level=debug msg="fetched chunk 23/46, size: 524288" uri="spotify:track:4eyl6CaFdDW0jWAQiYyP6E" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="handling play player command from ca7f795144ac718384138a333b45361b9f8d2c8c" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="resolved context of track" uri="spotify:album:3LG1c3DYgaEtCxea2z7ZSa" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=trace msg="fetched new page 0 with 5 items (list: 5)" uri="spotify:album:3LG1c3DYgaEtCxea2z7ZSa" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=trace msg="emitting websocket event: will_play" Apr 12 18:51:16 dac volumio[10455]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:3LG1c3DYgaEtCxea2z7ZSa","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","play_origin":"album"}} Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="selected format OGG_VORBIS_320 (cf0666a20ffcc7b3b79122edc4e27a3a5fe3ad63)" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:16 dac go-librespot[10712]: time="2026-04-12T18:51:16+05:30" level=debug msg="requested aes key for file cf0666a20ffcc7b3b79122edc4e27a3a5fe3ad63, gid: 5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=trace msg="found 2 cdn urls" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="fetched first chunk of 39, total size is 20356768 bytes" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=info msg="loaded track \"Elijah\" (paused: false, position: 1ms, duration: 561200ms, prefetched: false)" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="fetched chunk 1/38, size: 524288" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="fetched chunk 2/38, size: 524288" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=trace msg="scheduling prefetch in 531s" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=trace msg="emitting websocket event: metadata" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="sending successful reply for dealer request" Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","name":"Elijah","artist_names":["Donald Byrd"],"album_name":"A New Perspective (Remastered / Rudy Van Gelder Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02efa9a21bf03198d78c4f1233","position":1,"duration":561200,"release_date":"year:1963","track_number":1,"disc_number":1}} Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="fetched chunk 3/38, size: 524288" uri="spotify:track:5Kfn5waksBVFhELQHSCJzN" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:17 dac go-librespot[10712]: time="2026-04-12T18:51:17+05:30" level=trace msg="emitting websocket event: playing" Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:3LG1c3DYgaEtCxea2z7ZSa","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","resume":false,"play_origin":"album"}} Apr 12 18:51:17 dac volumio[10455]: info: Spotify is playing in volatile mode Apr 12 18:51:17 dac volumio[10455]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: UNSET VOLATILE Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":63,"dbVolume":null,"mute":false,"random":null,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: {"status":"play","service":"spop","title":"Elijah","artist":"Donald Byrd","album":"A New Perspective (Remastered / Rudy Van Gelder Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e02efa9a21bf03198d78c4f1233","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","trackType":"spotify","seek":1,"duration":561,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 12 18:51:17 dac volumio[10455]: info: CoreCommandRouter::servicePushState Apr 12 18:51:17 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:17 dac volumio[10455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 18:51:17 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:17 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:17.706+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=1 volume=63 Apr 12 18:51:17 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:17.706+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:5Kfn5waksBVFhELQHSCJzN title=Elijah Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 18:51:17 dac volumio[10455]: SPOTIFY: {"status":"play","service":"spop","title":"Elijah","artist":"Donald Byrd","album":"A New Perspective (Remastered / Rudy Van Gelder Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e02efa9a21bf03198d78c4f1233","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","trackType":"spotify","seek":1,"duration":561,"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 18:51:17 dac volumio[10455]: info: CoreCommandRouter::servicePushState Apr 12 18:51:17 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:17 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:18 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:18.003+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=1 volume=63 Apr 12 18:51:18 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:18.003+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:5Kfn5waksBVFhELQHSCJzN title=Elijah Apr 12 18:51:18 dac volumio[10455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=debug msg="handling pause player command from ca7f795144ac718384138a333b45361b9f8d2c8c" Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=debug msg="pause track at 3849ms" Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=debug msg="sending successful reply for dealer request" Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:21 dac go-librespot[10712]: time="2026-04-12T18:51:21+05:30" level=trace msg="emitting websocket event: paused" Apr 12 18:51:21 dac volumio[10455]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:3LG1c3DYgaEtCxea2z7ZSa","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","play_origin":"album"}} Apr 12 18:51:21 dac volumio[10455]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 18:51:21 dac volumio[10455]: SPOTIFY: {"status":"pause","service":"spop","title":"Elijah","artist":"Donald Byrd","album":"A New Perspective (Remastered / Rudy Van Gelder Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e02efa9a21bf03198d78c4f1233","uri":"spotify:track:5Kfn5waksBVFhELQHSCJzN","trackType":"spotify","seek":3001,"duration":561,"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 18:51:21 dac volumio[10455]: info: CoreCommandRouter::servicePushState Apr 12 18:51:21 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:21 dac volumio[10455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 18:51:21 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:21 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:21.621+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PAUSED positionMs=3001 volume=63 Apr 12 18:51:21 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:21.621+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:5Kfn5waksBVFhELQHSCJzN title=Elijah Apr 12 18:51:21 dac volumio[10455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 18:51:37 dac go-librespot[10712]: time="2026-04-12T18:51:37+05:30" level=trace msg="received accesspoint ping" Apr 12 18:51:37 dac go-librespot[10712]: time="2026-04-12T18:51:37+05:30" level=trace msg="received accesspoint pong ack" Apr 12 18:51:38 dac go-librespot[10712]: time="2026-04-12T18:51:38+05:30" level=trace msg="sent dealer ping" Apr 12 18:51:38 dac go-librespot[10712]: time="2026-04-12T18:51:38+05:30" level=trace msg="received dealer pong" Apr 12 18:51:49 dac go-librespot[10712]: time="2026-04-12T18:51:49+05:30" level=debug msg="handling play player command from ca7f795144ac718384138a333b45361b9f8d2c8c" Apr 12 18:51:49 dac go-librespot[10712]: time="2026-04-12T18:51:49+05:30" level=debug msg="resolved context of track" uri="spotify:album:5Au3YEzlPKwqfo0UdHpecX" Apr 12 18:51:49 dac go-librespot[10712]: time="2026-04-12T18:51:49+05:30" level=trace msg="fetched new page 0 with 11 items (list: 11)" uri="spotify:album:5Au3YEzlPKwqfo0UdHpecX" Apr 12 18:51:49 dac go-librespot[10712]: time="2026-04-12T18:51:49+05:30" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:50 dac go-librespot[10712]: time="2026-04-12T18:51:50+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:50 dac go-librespot[10712]: time="2026-04-12T18:51:50+05:30" level=trace msg="emitting websocket event: will_play" Apr 12 18:51:50 dac volumio[10455]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:5Au3YEzlPKwqfo0UdHpecX","uri":"spotify:track:1lgoTe73Y4GH4S1mKasdVb","play_origin":"album"}} Apr 12 18:51:50 dac go-librespot[10712]: time="2026-04-12T18:51:50+05:30" level=debug msg="selected format OGG_VORBIS_320 (906db6f0efa3939e26c6dd2080dcf35f06341ea2)" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:50 dac go-librespot[10712]: time="2026-04-12T18:51:50+05:30" level=debug msg="requested aes key for file 906db6f0efa3939e26c6dd2080dcf35f06341ea2, gid: 1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:50 dac go-librespot[10712]: time="2026-04-12T18:51:50+05:30" level=trace msg="found 2 cdn urls" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="fetched first chunk of 36, total size is 18424088 bytes" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=info msg="loaded track \"Dafino, Vino Crveno\" (paused: false, position: 1ms, duration: 423053ms, prefetched: false)" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="fetched chunk 1/35, size: 524288" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="fetched chunk 2/35, size: 524288" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=trace msg="scheduling prefetch in 393s" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=trace msg="emitting websocket event: metadata" Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="sending successful reply for dealer request" Apr 12 18:51:51 dac volumio[10455]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1lgoTe73Y4GH4S1mKasdVb","name":"Dafino, Vino Crveno","artist_names":["Miroslav Tadic","Vlatko Stefanovski"],"album_name":"Live In Belgrade","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026165b61311fc22f5bc601064","position":1,"duration":423053,"release_date":"year:2014 month:2 day:25","track_number":1,"disc_number":1}} Apr 12 18:51:51 dac go-librespot[10712]: time="2026-04-12T18:51:51+05:30" level=debug msg="fetched chunk 3/35, size: 524288" uri="spotify:track:1lgoTe73Y4GH4S1mKasdVb" Apr 12 18:51:52 dac go-librespot[10712]: time="2026-04-12T18:51:52+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 18:51:52 dac go-librespot[10712]: time="2026-04-12T18:51:52+05:30" level=trace msg="emitting websocket event: playing" Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:5Au3YEzlPKwqfo0UdHpecX","uri":"spotify:track:1lgoTe73Y4GH4S1mKasdVb","resume":false,"play_origin":"album"}} Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: {"status":"play","service":"spop","title":"Dafino, Vino Crveno","artist":"Miroslav Tadic, Vlatko Stefanovski","album":"Live In Belgrade","albumart":"https://i.scdn.co/image/ab67616d00001e026165b61311fc22f5bc601064","uri":"spotify:track:1lgoTe73Y4GH4S1mKasdVb","trackType":"spotify","seek":1,"duration":423,"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 18:51:52 dac volumio[10455]: info: CoreCommandRouter::servicePushState Apr 12 18:51:52 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:52 dac volumio[10455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 18:51:52 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:52 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:52.093+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=1 volume=63 Apr 12 18:51:52 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:52.093+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:1lgoTe73Y4GH4S1mKasdVb title="Dafino, Vino Crveno" Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: {"status":"play","service":"spop","title":"Dafino, Vino Crveno","artist":"Miroslav Tadic, Vlatko Stefanovski","album":"Live In Belgrade","albumart":"https://i.scdn.co/image/ab67616d00001e026165b61311fc22f5bc601064","uri":"spotify:track:1lgoTe73Y4GH4S1mKasdVb","trackType":"spotify","seek":1,"duration":423,"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 18:51:52 dac volumio[10455]: info: CoreCommandRouter::servicePushState Apr 12 18:51:52 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:52 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:52 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:52.392+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=1 volume=63 Apr 12 18:51:52 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:52.392+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:1lgoTe73Y4GH4S1mKasdVb title="Dafino, Vino Crveno" Apr 12 18:51:52 dac volumio[10455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Apr 12 18:51:56 dac go-librespot[10712]: time="2026-04-12T18:51:56+05:30" level=debug msg="update volume requested to 43908/65535" Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=trace msg="emitting websocket event: volume" Apr 12 18:51:57 dac volumio[10455]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Apr 12 18:51:57 dac volumio[10455]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Apr 12 18:51:57 dac volumio[10455]: info: Setting Volumio Volume from Spotify: 67 Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=debug msg="update volume requested to 46530/65535" Apr 12 18:51:57 dac volumio[10455]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Apr 12 18:51:57 dac volumio[10455]: info: Allo Relay Attenuator: alsavolume called with 67 Apr 12 18:51:57 dac sudo[11201]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=63 Apr 12 18:51:57 dac sudo[11201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 18:51:57 dac fn-rattenu[1701]: Error: Writing to I2C Apr 12 18:51:57 dac sudo[11201]: pam_unix(sudo:session): session closed for user root Apr 12 18:51:57 dac volumio[10455]: info: Allo Relay Attenuator: Hardware volume set to 63 Apr 12 18:51:57 dac volumio[10455]: info: CoreCommandRouter::volumioGetState Apr 12 18:51:57 dac volumio[10455]: info: CoreStateMachine::pushState Apr 12 18:51:57 dac volumio[10455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 18:51:57 dac volumio[10455]: info: CoreCommandRouter::volumioPushState Apr 12 18:51:57 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:57.069+05:30 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" state=STATUS_PLAYING positionMs=4001 volume=63 Apr 12 18:51:57 dac volumio5-onboarding[1586]: time=2026-04-12T18:51:57.069+05:30 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.19:49630 @ 0x2401890" id=spotify:track:1lgoTe73Y4GH4S1mKasdVb title="Dafino, Vino Crveno" Apr 12 18:51:57 dac volumio[10455]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 18:51:57 dac volumio[10455]: TypeError: Cannot read properties of undefined (reading 'vol') Apr 12 18:51:57 dac volumio[10455]: at /data/plugins/music_service/ytcr/dist/index.js:300:35 Apr 12 18:51:57 dac volumio[10455]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) Apr 12 18:51:57 dac volumio[10455]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) Apr 12 18:51:57 dac volumio[10455]: at Promise._successFn (/volumio/app/index.js:137:16) Apr 12 18:51:57 dac volumio[10455]: at nextTickCallback (/data/plugins/system_hardware/allo_relay_attenuator/node_modules/kew/kew.js:47:28) Apr 12 18:51:57 dac volumio[10455]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 18:51:57 dac volumio[10455]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=trace msg="emitting websocket event: volume" Apr 12 18:51:57 dac go-librespot[10712]: time="2026-04-12T18:51:57+05:30" level=debug msg="update volume requested to 64880/65535" Apr 12 18:51:57 dac sudo[11217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 18:50' Apr 12 18:51:57 dac sudo[11217]: 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"