-- Logs begin at Thu 2025-04-17 00:25:41 CEST, end at Fri 2025-04-18 17:32:21 CEST. --
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="handling play player command from 8c2bba9032d020aaba1a431993d5db3020a8b02c"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="resolved context of track" uri="spotify:artist:1EJWNhiYbOyeUHbsS7Kp1P"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:artist:1EJWNhiYbOyeUHbsS7Kp1P"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=error msg="failed fetching next tracks" error="failed moving to next index 10 (page 1): failed fetching page: invalid status code from page at artistplaycontext/v1/page/spotify/artist-top-tracks-extensions/1EJWNhiYbOyeUHbsS7Kp1P?exclude_uri=spotify:track:5SJ7mZ4HZWbhFcHpBvHU55,spotify:track:3CP1LfoQjiixrTM1m6V0Ke,spotify:track:26GaafCq5fOfFnGEk2wT2k,spotify:track:6QpiBpYwFtR4M6QEG7XLXn,spotify:track:4sLqcpvMrIJUyOs7x6fl5m,spotify:track:3zUMbNzbCix8BiBoIhTjM4,spotify:track:3yUJ9gOvw1bGFiVhAyta1P,spotify:track:7A40nExk5Zq6wFgpcjvp6l,spotify:track:47aYiXnnWeECtWCFbyJEoX,spotify:track:6Xs5RQhdHaSPGOB5wkUohn: 404" uri="spotify:artist:1EJWNhiYbOyeUHbsS7Kp1P"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="loading track (paused: false, position: 102ms)" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=trace msg="emitting websocket event: will_play"
Apr 18 17:31:07 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","play_origin":"free-tier-artist"}}
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="selected format OGG_VORBIS_320 (36c4522ce8d87167e4f4c99fff6baaca0523308b)" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="requested aes key for file 36c4522ce8d87167e4f4c99fff6baaca0523308b, gid: 26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="fetched first chunk of 20, total size is 10407932 bytes" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=trace msg="seek to 102ms (diff: 102ms, samples: 4498, bytes: 0)" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=info msg="loaded track \"Low Place Like Home\" (paused: false, position: 102ms, duration: 277826ms, prefetched: false)" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=trace msg="scheduling prefetch in 248s"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=trace msg="emitting websocket event: metadata"
Apr 18 17:31:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:07+02:00" level=debug msg="sending successful reply for dealer request"
Apr 18 17:31:07 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","name":"Low Place Like Home","artist_names":["Sneaker Pimps"],"album_name":"Becoming X","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bd5b848b692f571fe69541ca","position":102,"duration":277826,"release_date":"year:1996 month:8 day:18","track_number":1,"disc_number":1}}
Apr 18 17:31:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:08+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:31:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:08+02:00" level=trace msg="emitting websocket event: playing"
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","play_origin":"free-tier-artist"}}
Apr 18 17:31:08 volumiobetel volumio[1176]: info: Spotify is playing in volatile mode
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: UNSET VOLATILE
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"pause","title":"Falco - Vienna Calling","artist":"80s80s Digital Web","album":null,"albumart":"/albumart","uri":"http://streams.80s80s.de/web/mp3-192/volumio","trackType":"","codec":"","seek":1304736,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"repeat":false,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true}
Apr 18 17:31:08 volumiobetel volumio[1176]: info: Setting Spotify stop after unset volatile call
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Low Place Like Home","artist":"Sneaker Pimps","album":"Becoming X","albumart":"https://i.scdn.co/image/ab67616d00001e02bd5b848b692f571fe69541ca","uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","trackType":"spotify","seek":102,"duration":277,"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 18 17:31:08 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:31:08 volumiobetel volumio[1176]: info: touch_display: Setting screensaver timeout to 0 seconds.
Apr 18 17:31:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:08+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Low Place Like Home","artist":"Sneaker Pimps","album":"Becoming X","albumart":"https://i.scdn.co/image/ab67616d00001e02bd5b848b692f571fe69541ca","uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","trackType":"spotify","seek":102,"duration":277,"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 18 17:31:08 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:31:08 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:31:08 volumiobetel volumio[1176]: info: Spotify Stop
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: SPOTIFY STOP
Apr 18 17:31:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","title":"Low Place Like Home","artist":"Sneaker Pimps","album":"Becoming X","albumart":"https://i.scdn.co/image/ab67616d00001e02bd5b848b692f571fe69541ca","uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","trackType":"spotify","codec":"ogg","seek":102,"duration":277,"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"}
Apr 18 17:31:12 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:12+02:00" level=debug msg="handling seek_to player command from 8c2bba9032d020aaba1a431993d5db3020a8b02c"
Apr 18 17:31:12 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:12+02:00" level=debug msg="seek track to 40026ms"
Apr 18 17:31:12 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:12+02:00" level=trace msg="seek to 40026ms (diff: 123ms, samples: 1765146, bytes: 1363316)" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=trace msg="scheduling prefetch in 208s"
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=trace msg="emitting websocket event: seek"
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=debug msg="sending successful reply for dealer request"
Apr 18 17:31:13 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","position":40026,"duration":277826,"play_origin":"free-tier-artist"}}
Apr 18 17:31:13 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:31:13 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Low Place Like Home","artist":"Sneaker Pimps","album":"Becoming X","albumart":"https://i.scdn.co/image/ab67616d00001e02bd5b848b692f571fe69541ca","uri":"spotify:track:26GaafCq5fOfFnGEk2wT2k","trackType":"spotify","seek":40026,"duration":277,"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 18 17:31:13 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:31:13 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:31:13 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 18 17:31:13 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:31:13 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:31:13 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:13+02:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 18 17:31:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 18 17:31:17 volumiobetel volumio[1176]: info: Discovery: Getting this device information
Apr 18 17:31:17 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioGetState
Apr 18 17:31:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 18 17:31:18 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:18+02:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:19 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:19+02:00" level=trace msg="sent dealer ping"
Apr 18 17:31:20 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:20+02:00" level=trace msg="received dealer pong"
Apr 18 17:31:32 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:32+02:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:46 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:46+02:00" level=debug msg="fetched chunk 8/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:31:47 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 18 17:31:47 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 18 17:31:47 volumiobetel volumio[1176]: info: Discovery: Getting this device information
Apr 18 17:31:47 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioGetState
Apr 18 17:31:47 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 18 17:31:49 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:49+02:00" level=trace msg="sent dealer ping"
Apr 18 17:31:50 volumiobetel go-librespot[1395]: time="2025-04-18T17:31:50+02:00" level=trace msg="received dealer pong"
Apr 18 17:32:01 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:01+02:00" level=debug msg="fetched chunk 9/19, size: 524288" uri="spotify:track:26GaafCq5fOfFnGEk2wT2k"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="handling play player command from 8c2bba9032d020aaba1a431993d5db3020a8b02c"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="resolved context of track" uri="spotify:album:1F8y2bg9V9nRoy8zuxo3Jt"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=trace msg="fetched new page 0 with 14 items (list: 14)" uri="spotify:album:1F8y2bg9V9nRoy8zuxo3Jt"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=trace msg="emitting websocket event: will_play"
Apr 18 17:32:07 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","play_origin":"playlist"}}
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="selected format OGG_VORBIS_320 (6e157ebba15ec333062836db2bc8120a22b02462)" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="requested aes key for file 6e157ebba15ec333062836db2bc8120a22b02462, gid: 2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=debug msg="fetched first chunk of 28, total size is 14277372 bytes" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:07 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:07+02:00" level=info msg="loaded track \"Pray For Rain\" (paused: false, position: 0ms, duration: 403533ms, prefetched: false)" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=trace msg="scheduling prefetch in 373s"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=trace msg="emitting websocket event: metadata"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="sending successful reply for dealer request"
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","name":"Pray For Rain","artist_names":["Massive Attack","Babatunde Adebimpe"],"album_name":"Heligoland","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","position":0,"duration":403533,"release_date":"year:2010 month:2 day:8","track_number":1,"disc_number":1}}
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=trace msg="emitting websocket event: playing"
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","play_origin":"playlist"}}
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Pray For Rain","artist":"Massive Attack, Babatunde Adebimpe","album":"Heligoland","albumart":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","trackType":"spotify","seek":0,"duration":403,"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 18 17:32:08 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:32:08 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:32:08 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 18 17:32:08 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="fetched chunk 1/27, size: 524288" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="fetched chunk 3/27, size: 524288" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:08 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:08+02:00" level=debug msg="fetched chunk 2/27, size: 524288" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Pray For Rain","artist":"Massive Attack, Babatunde Adebimpe","album":"Heligoland","albumart":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","trackType":"spotify","seek":0,"duration":403,"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 18 17:32:08 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:32:08 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:32:08 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:32:08 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=debug msg="handling pause player command from 8c2bba9032d020aaba1a431993d5db3020a8b02c"
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=debug msg="pause track at 6395ms"
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=debug msg="sending successful reply for dealer request"
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:14 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:14+02:00" level=trace msg="emitting websocket event: paused"
Apr 18 17:32:14 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","play_origin":"playlist"}}
Apr 18 17:32:14 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:32:14 volumiobetel volumio[1176]: SPOTIFY: {"status":"pause","service":"spop","title":"Pray For Rain","artist":"Massive Attack, Babatunde Adebimpe","album":"Heligoland","albumart":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","trackType":"spotify","seek":6000,"duration":403,"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 18 17:32:14 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:32:14 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:32:14 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 18 17:32:14 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:32:14 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:32:14 volumiobetel volumio[1176]: info: touch_display: Setting screensaver timeout to 1800 seconds.
Apr 18 17:32:16 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:16+02:00" level=debug msg="handling resume player command from 8c2bba9032d020aaba1a431993d5db3020a8b02c"
Apr 18 17:32:16 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:16+02:00" level=trace msg="seek to 6395ms (diff: 64ms, samples: 282019, bytes: 163997)" uri="spotify:track:2ttOFglLynQA0J1B7RhlgX"
Apr 18 17:32:16 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:16+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"
Apr 18 17:32:16 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:16+02:00" level=debug msg="resume track at 6331ms"
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 18 17:32:16 volumiobetel volumio[1176]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 18 17:32:17 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:17 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:17+02:00" level=trace msg="scheduling prefetch in 366s"
Apr 18 17:32:17 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:17+02:00" level=debug msg="sending successful reply for dealer request"
Apr 18 17:32:17 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 18 17:32:17 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:17+02:00" level=trace msg="emitting websocket event: playing"
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","play_origin":"playlist"}}
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Pray For Rain","artist":"Massive Attack, Babatunde Adebimpe","album":"Heligoland","albumart":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","trackType":"spotify","seek":6000,"duration":403,"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 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:32:17 volumiobetel volumio[1176]: info: touch_display: Setting screensaver timeout to 0 seconds.
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 18 17:32:17 volumiobetel volumio[1176]: info: Discovery: Getting this device information
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioGetState
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: PUSH STATE SPOTIFY
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: {"status":"play","service":"spop","title":"Pray For Rain","artist":"Massive Attack, Babatunde Adebimpe","album":"Heligoland","albumart":"https://i.scdn.co/image/ab67616d00001e02852aaa233e122f1dbfefcf00","uri":"spotify:track:2ttOFglLynQA0J1B7RhlgX","trackType":"spotify","seek":6000,"duration":403,"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 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::servicePushState
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreStateMachine::pushState
Apr 18 17:32:17 volumiobetel volumio[1176]: info: CoreCommandRouter::volumioPushState
Apr 18 17:32:17 volumiobetel volumio[1176]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 18 17:32:19 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:19+02:00" level=trace msg="received accesspoint ping"
Apr 18 17:32:19 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:19+02:00" level=trace msg="received accesspoint pong ack"
Apr 18 17:32:19 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:19+02:00" level=trace msg="sent dealer ping"
Apr 18 17:32:20 volumiobetel go-librespot[1395]: time="2025-04-18T17:32:20+02:00" level=trace msg="received dealer pong"
Apr 18 17:32:20 volumiobetel volumio[1176]: info: [1744990340894] [80s80s] Pushing the next song state Pet Shop Boys - West End Girls and getting next track.
Apr 18 17:32:20 volumiobetel volumio[1176]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 18 17:32:20 volumiobetel volumio[1176]: TypeError: Cannot set property 'name' of undefined
Apr 18 17:32:20 volumiobetel volumio[1176]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20)
Apr 18 17:32:20 volumiobetel volumio[1176]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34)
Apr 18 17:32:20 volumiobetel volumio[1176]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9)
Apr 18 17:32:20 volumiobetel volumio[1176]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66)
Apr 18 17:32:20 volumiobetel volumio[1176]: at processImmediate (internal/timers.js:461:21)
Apr 18 17:32:20 volumiobetel volumio[1176]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 18 17:32:21 volumiobetel sudo[8150]: volumio : unable to resolve host volumiobetel
Apr 18 17:32:21 volumiobetel sudo[8150]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 18 17:32:21 volumiobetel sudo[8150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-18 17:31
Apr 18 17:32:21 volumiobetel sudo[8150]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST"
VOLUMIO_VERSION="3.799"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"