-- Logs begin at Thu 2019-02-14 19:11:59 JST, end at Mon 2025-09-08 12:24:55 JST. -- Sep 08 12:23:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:02+09:00" level=trace msg="sent dealer ping" Sep 08 12:23:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:02+09:00" level=trace msg="received dealer pong" Sep 08 12:23:12 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:12+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 356" Sep 08 12:23:12 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:12+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 08 12:23:12 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:12+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 08 12:23:12 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:12+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1411" Sep 08 12:23:21 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:21+09:00" level=debug msg="handling transfer player command from 315fa158b8757cac47e33f92e2d9c6389c59739e" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E35hXYawMVFek" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E35hXYawMVFek" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="loading track (paused: false, position: 10000ms)" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="emitting websocket event: will_play" Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6VSTqcafshhlbCmly23TDc","play_origin":"playlist"}} Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6VSTqcafshhlbCmly23TDc","play_origin":"playlist"}} Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1329" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="selected format OGG_VORBIS_320 (6cf286c2843bb6284a8c37bf04c919ff4271a466)" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="requested aes key for file 6cf286c2843bb6284a8c37bf04c919ff4271a466, gid: 6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="fetched first chunk of 15, total size is 7750960 bytes" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="seek to 10000ms (diff: 212ms, samples: 441000, bytes: 388449)" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="created new output device" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1111" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=info msg="loaded track \"蜃気楼\" (paused: false, position: 10000ms, duration: 194906ms, prefetched: false)" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="scheduling prefetch in 155s" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="emitting websocket event: metadata" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="emitting websocket event: active" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="sending successful reply for dealer request" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E35hXYawMVFek" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6VSTqcafshhlbCmly23TDc","name":"蜃気楼","artist_names":["Blu-Swing"],"album_name":"BLU-SWING 10th ANNIVERSARY BEST","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02438c2e8921907ec978e5354e","position":10000,"duration":194906,"release_date":"year:2019 month:5 day:8","track_number":11,"disc_number":1}} Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"active","data":null} Sep 08 12:23:22 volumio-miku volumio[873]: info: Aligning Spotify Volume to Volumio Volume Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::volumioGetState Sep 08 12:23:22 volumio-miku volumio[873]: info: Setting Spotify Volume from Volumio: 38 Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"active","data":null} Sep 08 12:23:22 volumio-miku volumio[873]: info: Aligning Spotify Volume to Volumio Volume Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::volumioGetState Sep 08 12:23:22 volumio-miku volumio[873]: info: Setting Spotify Volume from Volumio: 38 Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 08 12:23:22 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:22+09:00" level=trace msg="emitting websocket event: playing" Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6VSTqcafshhlbCmly23TDc","resume":false,"play_origin":"playlist"}} Sep 08 12:23:22 volumio-miku volumio[873]: info: Spotify is playing in volatile mode Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: UNSET VOLATILE Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: {"status":"stop","position":0,"title":"foobar2000 audio stream","artist":null,"album":null,"albumart":"/albumart","uri":"http://192.168.10.80:49470/7/stream.wav","trackType":"wav","seek":null,"duration":16232,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"bitrate":null,"random":null,"repeat":null,"repeatSingle":false,"consume":true,"volume":38,"dbVolume":null,"mute":false,"disableVolumeControl":false,"disableUiControls":true,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: PUSH STATE SPOTIFY Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: {"status":"play","service":"spop","title":"蜃気楼","artist":"Blu-Swing","album":"BLU-SWING 10th ANNIVERSARY BEST","albumart":"https://i.scdn.co/image/ab67616d00001e02438c2e8921907ec978e5354e","uri":"spotify:track:6VSTqcafshhlbCmly23TDc","trackType":"spotify","seek":10000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::servicePushState Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6VSTqcafshhlbCmly23TDc","resume":false,"play_origin":"playlist"}} Sep 08 12:23:22 volumio-miku volumio[873]: info: Spotify is playing in volatile mode Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: UNSET VOLATILE Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: {"status":"stop","position":0,"title":"foobar2000 audio stream","artist":null,"album":null,"albumart":"/albumart","uri":"http://192.168.10.80:49470/7/stream.wav","trackType":"wav","seek":null,"duration":16232,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"bitrate":null,"random":null,"repeat":null,"repeatSingle":false,"consume":true,"volume":38,"dbVolume":null,"mute":false,"disableVolumeControl":false,"disableUiControls":true,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: PUSH STATE SPOTIFY Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: {"status":"play","service":"spop","title":"蜃気楼","artist":"Blu-Swing","album":"BLU-SWING 10th ANNIVERSARY BEST","albumart":"https://i.scdn.co/image/ab67616d00001e02438c2e8921907ec978e5354e","uri":"spotify:track:6VSTqcafshhlbCmly23TDc","trackType":"spotify","seek":10000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::servicePushState Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:22 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Sep 08 12:23:22 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: PUSH STATE SPOTIFY Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: {"status":"play","service":"spop","title":"蜃気楼","artist":"Blu-Swing","album":"BLU-SWING 10th ANNIVERSARY BEST","albumart":"https://i.scdn.co/image/ab67616d00001e02438c2e8921907ec978e5354e","uri":"spotify:track:6VSTqcafshhlbCmly23TDc","trackType":"spotify","seek":10000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreCommandRouter::servicePushState Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: PUSH STATE SPOTIFY Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: {"status":"play","service":"spop","title":"蜃気楼","artist":"Blu-Swing","album":"BLU-SWING 10th ANNIVERSARY BEST","albumart":"https://i.scdn.co/image/ab67616d00001e02438c2e8921907ec978e5354e","uri":"spotify:track:6VSTqcafshhlbCmly23TDc","trackType":"spotify","seek":10000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreCommandRouter::servicePushState Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:23 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:23 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Sep 08 12:23:23 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:23+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Sep 08 12:23:23 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:23+09:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E35hXYawMVFek" Sep 08 12:23:23 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:23+09:00" level=debug msg="handling update_context player command from 315fa158b8757cac47e33f92e2d9c6389c59739e" Sep 08 12:23:23 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:23+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 08 12:23:23 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:23+09:00" level=debug msg="sending successful reply for dealer request" Sep 08 12:23:24 volumio-miku volumio[873]: SPOTIFY: SETTING SPOTIFY VOLUME 38 Sep 08 12:23:24 volumio-miku volumio[873]: info: Sending Spotify command with payload to local API: /player/volume Sep 08 12:23:24 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:24+09:00" level=debug msg="update volume requested to 24903/65535" Sep 08 12:23:24 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:24+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:24 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:24+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:24 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":38,"max":100}} Sep 08 12:23:24 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 38 Sep 08 12:23:24 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":38,"max":100}} Sep 08 12:23:24 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 38 Sep 08 12:23:25 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:25+09:00" level=debug msg="fetched chunk 4/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:32 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:32+09:00" level=trace msg="sent dealer ping" Sep 08 12:23:32 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:32+09:00" level=trace msg="received dealer pong" Sep 08 12:23:39 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:39+09:00" level=debug msg="fetched chunk 5/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:40 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:40+09:00" level=debug msg="update volume requested to 25379/65535" Sep 08 12:23:40 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:40+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:40 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:40+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:40 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":39,"max":100}} Sep 08 12:23:40 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 39 Sep 08 12:23:40 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 39 Sep 08 12:23:40 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume39 Sep 08 12:23:40 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:40 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:40 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:40 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":39,"max":100}} Sep 08 12:23:40 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 39 Sep 08 12:23:40 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:40+09:00" level=debug msg="update volume requested to 30312/65535" Sep 08 12:23:40 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Sep 08 12:23:41 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:41+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:41 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:41+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:41 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:41 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:41 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 46 Sep 08 12:23:41 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume46 Sep 08 12:23:41 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:41 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:41 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:41 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:41 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:41 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 08 12:23:43 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:43+09:00" level=debug msg="update volume requested to 31016/65535" Sep 08 12:23:43 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:43+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:43 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:43+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:43 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":47,"max":100}} Sep 08 12:23:43 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 47 Sep 08 12:23:43 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 47 Sep 08 12:23:43 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume47 Sep 08 12:23:43 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:43 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:43 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:43 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":47,"max":100}} Sep 08 12:23:43 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 47 Sep 08 12:23:43 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Sep 08 12:23:43 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:43+09:00" level=debug msg="update volume requested to 36654/65535" Sep 08 12:23:44 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:44+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:44 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:44+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:44 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":56,"max":100}} Sep 08 12:23:44 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 56 Sep 08 12:23:44 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 56 Sep 08 12:23:44 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume56 Sep 08 12:23:44 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:44 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:44 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:44 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":56,"max":100}} Sep 08 12:23:44 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 56 Sep 08 12:23:44 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Sep 08 12:23:45 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:45+09:00" level=debug msg="update volume requested to 35949/65535" Sep 08 12:23:45 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:45+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:45 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:45+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:45 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":55,"max":100}} Sep 08 12:23:45 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 55 Sep 08 12:23:45 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 55 Sep 08 12:23:45 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume55 Sep 08 12:23:45 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:45 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:45 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:45 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":55,"max":100}} Sep 08 12:23:45 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 55 Sep 08 12:23:45 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Sep 08 12:23:45 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:45+09:00" level=debug msg="update volume requested to 31016/65535" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="update volume requested to 30312/65535" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:46 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 46 Sep 08 12:23:46 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume46 Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="update volume requested to 26788/65535" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Sep 08 12:23:46 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 41 Sep 08 12:23:46 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume41 Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:46 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="update volume requested to 23265/65535" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:46 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:46+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:46 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:46 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 36 Sep 08 12:23:46 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume36 Sep 08 12:23:47 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:47 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:47 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:47 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:47 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:47 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Sep 08 12:23:52 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:52+09:00" level=debug msg="fetched chunk 6/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:23:53 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:53+09:00" level=debug msg="update volume requested to 23265/65535" Sep 08 12:23:53 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:53+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:53 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:53+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:53 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:53 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:53 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:53 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:54 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:54+09:00" level=debug msg="update volume requested to 26788/65535" Sep 08 12:23:54 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:54+09:00" level=debug msg="update volume requested to 27493/65535" Sep 08 12:23:54 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:54+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:54 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:54+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:54 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":42,"max":100}} Sep 08 12:23:54 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 42 Sep 08 12:23:54 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 42 Sep 08 12:23:54 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume42 Sep 08 12:23:54 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:54 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:54 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:54 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":42,"max":100}} Sep 08 12:23:54 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 42 Sep 08 12:23:54 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 08 12:23:54 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:54+09:00" level=debug msg="update volume requested to 29607/65535" Sep 08 12:23:55 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:55+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:55 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:55+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 Sep 08 12:23:55 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 45 Sep 08 12:23:55 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume45 Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 08 12:23:55 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:55+09:00" level=debug msg="update volume requested to 33835/65535" Sep 08 12:23:55 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:55+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:55 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:55+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Sep 08 12:23:55 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 52 Sep 08 12:23:55 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume52 Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:55 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Sep 08 12:23:55 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Sep 08 12:23:56 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:56+09:00" level=debug msg="update volume requested to 32426/65535" Sep 08 12:23:56 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:56+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:56 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:56+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:56 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Sep 08 12:23:56 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Sep 08 12:23:56 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 49 Sep 08 12:23:56 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume49 Sep 08 12:23:56 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:56 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:56 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:56 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Sep 08 12:23:56 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Sep 08 12:23:56 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Sep 08 12:23:56 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:56+09:00" level=debug msg="update volume requested to 31016/65535" Sep 08 12:23:56 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:56+09:00" level=debug msg="update volume requested to 30312/65535" Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:57 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 46 Sep 08 12:23:57 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume46 Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=debug msg="update volume requested to 23970/65535" Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=debug msg="update volume requested to 23265/65535" Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:57 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:57+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:57 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 36 Sep 08 12:23:57 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume36 Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:57 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":36,"max":100}} Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 36 Sep 08 12:23:57 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Sep 08 12:23:58 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:58+09:00" level=debug msg="update volume requested to 21151/65535" Sep 08 12:23:58 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:58+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 08 12:23:58 volumio-miku go-librespot[3121]: time="2025-09-08T12:23:58+09:00" level=trace msg="emitting websocket event: volume" Sep 08 12:23:58 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":32,"max":100}} Sep 08 12:23:58 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 32 Sep 08 12:23:58 volumio-miku volumio[873]: info: Setting Volumio Volume from Spotify: 32 Sep 08 12:23:58 volumio-miku volumio[873]: info: VolumeController::SetAlsaVolume32 Sep 08 12:23:58 volumio-miku volumio[873]: info: CoreStateMachine::pushState Sep 08 12:23:58 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 12:23:58 volumio-miku volumio[873]: info: CoreCommandRouter::volumioPushState Sep 08 12:23:58 volumio-miku volumio[873]: SPOTIFY: received: {"type":"volume","data":{"value":32,"max":100}} Sep 08 12:23:58 volumio-miku volumio[873]: SPOTIFY: RECEIVED SPOTIFY VOLUME 32 Sep 08 12:23:58 volumio-miku volumio[873]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Sep 08 12:24:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:02+09:00" level=trace msg="received accesspoint ping" Sep 08 12:24:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:02+09:00" level=trace msg="received accesspoint pong ack" Sep 08 12:24:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:02+09:00" level=trace msg="sent dealer ping" Sep 08 12:24:02 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:02+09:00" level=trace msg="received dealer pong" Sep 08 12:24:06 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:06+09:00" level=debug msg="fetched chunk 7/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:24:19 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:19+09:00" level=debug msg="fetched chunk 8/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:24:32 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:32+09:00" level=trace msg="sent dealer ping" Sep 08 12:24:32 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:32+09:00" level=trace msg="received dealer pong" Sep 08 12:24:33 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:33+09:00" level=debug msg="fetched chunk 9/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:24:47 volumio-miku go-librespot[3121]: time="2025-09-08T12:24:47+09:00" level=debug msg="fetched chunk 10/14, size: 524288" uri="spotify:track:6VSTqcafshhlbCmly23TDc" Sep 08 12:24:48 volumio-miku volumio[873]: info: CoreCommandRouter::volumioGetQueue Sep 08 12:24:48 volumio-miku volumio[873]: info: CoreStateMachine::getQueue Sep 08 12:24:48 volumio-miku volumio[873]: info: CorePlayQueue::getQueue Sep 08 12:24:51 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 08 12:24:52 volumio-miku volumio[873]: info: Preload queue cleared Sep 08 12:24:55 volumio-miku volumio[873]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 08 12:24:55 volumio-miku volumio[873]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 12:24:55 volumio-miku volumio[873]: TypeError: Cannot read property 'length' of undefined Sep 08 12:24:55 volumio-miku volumio[873]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 08 12:24:55 volumio-miku volumio[873]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 08 12:24:55 volumio-miku volumio[873]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 08 12:24:55 volumio-miku volumio[873]: at Parser.emit (events.js:315:20) Sep 08 12:24:55 volumio-miku volumio[873]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 08 12:24:55 volumio-miku volumio[873]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 08 12:24:55 volumio-miku volumio[873]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 08 12:24:55 volumio-miku volumio[873]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 08 12:24:55 volumio-miku volumio[873]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 08 12:24:55 volumio-miku volumio[873]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 08 12:24:55 volumio-miku volumio[873]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 08 12:24:55 volumio-miku volumio[873]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 08 12:24:55 volumio-miku volumio[873]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 08 12:24:55 volumio-miku volumio[873]: at IncomingMessage.emit (events.js:327:22) Sep 08 12:24:55 volumio-miku volumio[873]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 08 12:24:55 volumio-miku volumio[873]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 08 12:24:55 volumio-miku volumio[873]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 12:24:55 volumio-miku sudo[3689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-08 12:23 Sep 08 12:24:55 volumio-miku sudo[3689]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"