Sep 07 08:12:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 08:12:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 08:12:00 volumio volumio[1029]: info: Discovery: Getting this device information Sep 07 08:12:00 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Sep 07 08:12:00 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 08:12:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 08:12:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 08:12:03 volumio volumio[1029]: info: Discovery: Getting this device information Sep 07 08:12:03 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Sep 07 08:12:03 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 08:12:06 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 07 08:12:06 volumio volumio[1029]: info: In handleBrowseUri, curUri=spotify Sep 07 08:12:07 volumio volumio[1029]: info: New access token = BQAwOp6nxUoV6tyUNc7HB3Y5pTHyxmLGwbQz14UXhL5noc0x-VWXGDvqjJr7QG10jjwuy0VF6qpVh_-Z5y29EBHLnIX9vC4Hw6sUhLQm4DQVDtB30d8ciE10F1YZFzPLWTiwbU-mGbn1P1wU0rmVOPzDqnk1nrZxuzMzwg4ChLSwo0RtJzw6BqAbNC1AHFULvb-9PK1GfCr8xmWmGoP_ey8vyIQjuYqVtYFT5gljS5LNMoa2UrWTNlrz9O_eZRBphFxJVRGvebQWQJOObaruM-7SdbkjU31L-xPE6eMaZ2l4oPa8RcI Sep 07 08:12:07 volumio volumio[1029]: info: New access token = BQA-ERcI15yMhokgTXYgdtwXoZDTPKufEJwMullzXrRGigXAHxvZl7GsZDSlfZWFPb4IoeynjkMvzPqgacSNPE2IDa13eiRT1S9A9D4PqkAHgNCBeab1WVl3kFgZ4275wmQkEeHPAR6mU12m5-8Wp_2141yuzh0GxeE3kAUfqto_Chz70UkK8Y7p1il4qH6wfRn7C4_h9yP-7j70g_pOekefcpYIHQkaomA5joQef1lNCGq79EDY5VR3IVnBe7okrOVSrZxNQ0WySBtpAv3GXqlHYsmekEEz2VX27lMJIj8qmc9Jv5Q Sep 07 08:12:07 volumio volumio[1029]: info: New access token = BQA4w0gDkTWsPsXe1iS8J4J2HWpm0cam-VzDsamUWHDALzbi5uUqwXI70IoXL6DowU_xt0hldD3wlmJd2xiIRuY8ltidNZ7g8rGbS6U4OuZeG0SiDuwLjBCrW4HKY7olu0vtHFJWyKEMwADSNAtohbxTIefIBtrKzVXAcRvIT0NGa9JnyydF3FB8xx0KDgTw4WmoHzCtBPV4RtrNQrB8Z1hz-zVVajHSYxNiXoifnAwJt36BCsPnQkUiR54YmzVUtaHzadSgCnHjhA9sozo4WxBY33nf2rs_7imF037tbQAjVB3I4Nk Sep 07 08:12:07 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:07 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:07 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:07 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:12 volumio volumio[1029]: Searching plugin music_service/spop Sep 07 08:12:12 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 07 08:12:13 volumio volumio[1029]: info: All search sources collected, pushing search results Sep 07 08:12:15 volumio volumio[1029]: Searching plugin music_service/spop Sep 07 08:12:15 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 07 08:12:15 volumio go-librespot[1394]: time="2025-09-07T08:12:15+02:00" level=trace msg="sent dealer ping" Sep 07 08:12:15 volumio go-librespot[1394]: time="2025-09-07T08:12:15+02:00" level=trace msg="received dealer pong" Sep 07 08:12:16 volumio volumio[1029]: info: All search sources collected, pushing search results Sep 07 08:12:16 volumio volumio[1029]: Searching plugin music_service/spop Sep 07 08:12:16 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 07 08:12:17 volumio volumio[1029]: info: All search sources collected, pushing search results Sep 07 08:12:20 volumio volumio[1029]: Searching plugin music_service/spop Sep 07 08:12:20 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 07 08:12:21 volumio volumio[1029]: info: All search sources collected, pushing search results Sep 07 08:12:26 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 07 08:12:27 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 07 08:12:27 volumio volumio[1029]: info: In handleBrowseUri, curUri=spotify:album:1tPdeMpLKYYsaRbGnNjPgg Sep 07 08:12:28 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0DqqKYKk9QDBQKPjeLHUSH Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:5bDKSAVWcGGAINPfcFV96C Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2SxXAWo4gWwuRJl2iw5tL3 Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2Vacj2jBJT9PIf7R1gr3lJ Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2Nsov179mVonJogmJ4iggy Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0nEp9EbGItowGitiwhVi7I Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:4qFXaZgy4vu8WTJ3x4bYuo Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0mAJVhd3A72PiWK5GffFLv Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2hP2xUjL6xrVShBoGpswWp Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:7sA5ula3kKpv0pjD7e64Eg Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:66DssUKuFPWRcvMPoToHMt Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:725G8EcsoXJ6Fse5QLwYe5 Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0PmwKGX0rgyVEftRQp4Gxp Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:3dNmHYwQhnBOCfhC0PoezQ Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:1JIQSlWWhUcYNtAxrTgcXm Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:5A9uqvCz1mn4QQAfHNjgd5 Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:35TpK0iogYS3rtScga2hMS Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:30kTfWp4MDeSLf4IvkapIF Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:1T5JS3wx5egyaUIisMrp3P Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:7MLZOsxO4avkfpwHLHFTEN Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2CYyycckOIN4YPiJXhzQEH Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:4eVw2oWrCm0vrmRedYh1pB Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:4Ff5i7bUrqZ9SjlFOnIP9a Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0dV9ikR51E0A82uNvhLeQH Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:6NbkuWd8PF20tcovy73qiI Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:04Pzx0NIbUkL2dt2wBsbZC Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:0xb9JCFsX06mTQkx5YMv5L Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:6QLXuPjOrPNI2QJLOk18VX Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:4M4VTpcEjGfhU3rZkLRpCo Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2yiccSfAs8pjGqdVs62PZk Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:5rU9jeqgDDescVz2KlMiVE Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:4X9u34Vfk0SItjbErCVPfW Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:2ni7KPT89PsCCiuD4rsZfa Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:5j9vWzVPJGHlrMfUw63SvC Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:7Mrsk85MBwa23RhUihDQ0F Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:7L3qSpTKkIVIrQ6Gmo86Yp Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:74Jmts0L7699g4pJ1HpbIz Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:6azgG6vBybBOdL33mCzLYA Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:3S5BR4h8iFGgOIfovJxgbc Sep 07 08:12:28 volumio volumio[1029]: info: Preloading song: spotify:track:7mRqYbhrwYOdgKiUXTOSqR Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:0DqqKYKk9QDBQKPjeLHUSH in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0DqqKYKk9QDBQKPjeLHUSH Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:5bDKSAVWcGGAINPfcFV96C in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:5bDKSAVWcGGAINPfcFV96C Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:2SxXAWo4gWwuRJl2iw5tL3 in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2SxXAWo4gWwuRJl2iw5tL3 Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","service":"spop","name":"Happy Morning Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":179,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:2Vacj2jBJT9PIf7R1gr3lJ in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2Vacj2jBJT9PIf7R1gr3lJ Sep 07 08:12:28 volumio volumio[1029]: info: No valid Plugin REST Endpoint Sep 07 08:12:28 volumio volumio[1029]: info: No valid Plugin REST Endpoint Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:2Nsov179mVonJogmJ4iggy in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2Nsov179mVonJogmJ4iggy Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5bDKSAVWcGGAINPfcFV96C","service":"spop","name":"Morning Bossa Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":179,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2SxXAWo4gWwuRJl2iw5tL3","service":"spop","name":"Bossa Nova Life","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:0nEp9EbGItowGitiwhVi7I in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0nEp9EbGItowGitiwhVi7I Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Vacj2jBJT9PIf7R1gr3lJ","service":"spop","name":"Sunrise Bossa Music","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":206,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:4qFXaZgy4vu8WTJ3x4bYuo in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:4qFXaZgy4vu8WTJ3x4bYuo Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Nsov179mVonJogmJ4iggy","service":"spop","name":"Morning Radio","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:0mAJVhd3A72PiWK5GffFLv in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0mAJVhd3A72PiWK5GffFLv Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0nEp9EbGItowGitiwhVi7I","service":"spop","name":"Morning Jazz","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":199,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:28 volumio volumio[1029]: info: Exploding uri spotify:track:2hP2xUjL6xrVShBoGpswWp in service spop Sep 07 08:12:28 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2hP2xUjL6xrVShBoGpswWp Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4qFXaZgy4vu8WTJ3x4bYuo","service":"spop","name":"Morning Jazz Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:7sA5ula3kKpv0pjD7e64Eg in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:7sA5ula3kKpv0pjD7e64Eg Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:66DssUKuFPWRcvMPoToHMt in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:66DssUKuFPWRcvMPoToHMt Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0mAJVhd3A72PiWK5GffFLv","service":"spop","name":"Morning Wind","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2hP2xUjL6xrVShBoGpswWp","service":"spop","name":"Cafe Time","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":141,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:725G8EcsoXJ6Fse5QLwYe5 in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:725G8EcsoXJ6Fse5QLwYe5 Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sA5ula3kKpv0pjD7e64Eg","service":"spop","name":"Bossa Latte","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":146,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:0PmwKGX0rgyVEftRQp4Gxp in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0PmwKGX0rgyVEftRQp4Gxp Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:66DssUKuFPWRcvMPoToHMt","service":"spop","name":"Jazz Bossa Lounge","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":188,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:3dNmHYwQhnBOCfhC0PoezQ in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:3dNmHYwQhnBOCfhC0PoezQ Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:725G8EcsoXJ6Fse5QLwYe5","service":"spop","name":"Waltz terrace","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:1JIQSlWWhUcYNtAxrTgcXm in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:1JIQSlWWhUcYNtAxrTgcXm Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0PmwKGX0rgyVEftRQp4Gxp","service":"spop","name":"Happy Morning Shop","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":205,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:5A9uqvCz1mn4QQAfHNjgd5 in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:5A9uqvCz1mn4QQAfHNjgd5 Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3dNmHYwQhnBOCfhC0PoezQ","service":"spop","name":"Morning Rain","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":111,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:35TpK0iogYS3rtScga2hMS in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:35TpK0iogYS3rtScga2hMS Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:30kTfWp4MDeSLf4IvkapIF in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:30kTfWp4MDeSLf4IvkapIF Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:1T5JS3wx5egyaUIisMrp3P in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:1T5JS3wx5egyaUIisMrp3P Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1JIQSlWWhUcYNtAxrTgcXm","service":"spop","name":"TV JAZZ","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:35TpK0iogYS3rtScga2hMS","service":"spop","name":"Wood Garden Jazz","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:7MLZOsxO4avkfpwHLHFTEN in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:7MLZOsxO4avkfpwHLHFTEN Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5A9uqvCz1mn4QQAfHNjgd5","service":"spop","name":"Rainbow Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:2CYyycckOIN4YPiJXhzQEH in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2CYyycckOIN4YPiJXhzQEH Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:4eVw2oWrCm0vrmRedYh1pB in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:4eVw2oWrCm0vrmRedYh1pB Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:30kTfWp4MDeSLf4IvkapIF","service":"spop","name":"Jazz & Tea","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:4Ff5i7bUrqZ9SjlFOnIP9a in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:4Ff5i7bUrqZ9SjlFOnIP9a Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1T5JS3wx5egyaUIisMrp3P","service":"spop","name":"Green Bossa","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":147,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7MLZOsxO4avkfpwHLHFTEN","service":"spop","name":"Wind Garden","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":150,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:0dV9ikR51E0A82uNvhLeQH in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0dV9ikR51E0A82uNvhLeQH Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2CYyycckOIN4YPiJXhzQEH","service":"spop","name":"Waltz Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":188,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:6NbkuWd8PF20tcovy73qiI in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:6NbkuWd8PF20tcovy73qiI Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4eVw2oWrCm0vrmRedYh1pB","service":"spop","name":"Morning FM","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4Ff5i7bUrqZ9SjlFOnIP9a","service":"spop","name":"Bossa Bakery","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:04Pzx0NIbUkL2dt2wBsbZC in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:04Pzx0NIbUkL2dt2wBsbZC Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0dV9ikR51E0A82uNvhLeQH","service":"spop","name":"House key & Music","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:0xb9JCFsX06mTQkx5YMv5L in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:0xb9JCFsX06mTQkx5YMv5L Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:6QLXuPjOrPNI2QJLOk18VX in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:6QLXuPjOrPNI2QJLOk18VX Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6NbkuWd8PF20tcovy73qiI","service":"spop","name":"bicycle & wind","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:04Pzx0NIbUkL2dt2wBsbZC","service":"spop","name":"Fountain","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":220,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:29 volumio volumio[1029]: info: Exploding uri spotify:track:4M4VTpcEjGfhU3rZkLRpCo in service spop Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:4M4VTpcEjGfhU3rZkLRpCo Sep 07 08:12:29 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0xb9JCFsX06mTQkx5YMv5L","service":"spop","name":"Park chair","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:2yiccSfAs8pjGqdVs62PZk in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2yiccSfAs8pjGqdVs62PZk Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6QLXuPjOrPNI2QJLOk18VX","service":"spop","name":"Morning Park","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:5rU9jeqgDDescVz2KlMiVE in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:5rU9jeqgDDescVz2KlMiVE Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:4X9u34Vfk0SItjbErCVPfW in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:4X9u34Vfk0SItjbErCVPfW Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2yiccSfAs8pjGqdVs62PZk","service":"spop","name":"Soy Latte Bossa","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:2ni7KPT89PsCCiuD4rsZfa in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:2ni7KPT89PsCCiuD4rsZfa Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5rU9jeqgDDescVz2KlMiVE","service":"spop","name":"Coffee Stand","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:5j9vWzVPJGHlrMfUw63SvC in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:5j9vWzVPJGHlrMfUw63SvC Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4X9u34Vfk0SItjbErCVPfW","service":"spop","name":"Morning Working","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:7Mrsk85MBwa23RhUihDQ0F in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:7Mrsk85MBwa23RhUihDQ0F Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4M4VTpcEjGfhU3rZkLRpCo","service":"spop","name":"Banana Cake","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:7L3qSpTKkIVIrQ6Gmo86Yp in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:7L3qSpTKkIVIrQ6Gmo86Yp Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ni7KPT89PsCCiuD4rsZfa","service":"spop","name":"Lake Jazz","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":129,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5j9vWzVPJGHlrMfUw63SvC","service":"spop","name":"Piano Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":201,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:74Jmts0L7699g4pJ1HpbIz in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:74Jmts0L7699g4pJ1HpbIz Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7Mrsk85MBwa23RhUihDQ0F","service":"spop","name":"Jazzy Jazzy","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:6azgG6vBybBOdL33mCzLYA in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:6azgG6vBybBOdL33mCzLYA Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:3S5BR4h8iFGgOIfovJxgbc in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:3S5BR4h8iFGgOIfovJxgbc Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:74Jmts0L7699g4pJ1HpbIz","service":"spop","name":"Lounge Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: info: Exploding uri spotify:track:7mRqYbhrwYOdgKiUXTOSqR in service spop Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:track:7mRqYbhrwYOdgKiUXTOSqR Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6azgG6vBybBOdL33mCzLYA","service":"spop","name":"Jazz & Coffee","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7L3qSpTKkIVIrQ6Gmo86Yp","service":"spop","name":"TOKYO MORNING","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3S5BR4h8iFGgOIfovJxgbc","service":"spop","name":"Vibraphone Bossa","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":176,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:30 volumio volumio[1029]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7mRqYbhrwYOdgKiUXTOSqR","service":"spop","name":"HAPPY Bossa Nova","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","type":"song","duration":151,"albumart":"https://i.scdn.co/image/ab67616d0000b2738fa0bdc35e5b400d5be45d7e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 07 08:12:31 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::ClearQueue Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::stPlaybackTimer Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::updateTrackBlock Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrackBlock Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::serviceStop Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::serviceStop Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::stop Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand stop Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::clearPlayQueue Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::saveQueue Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushQueue Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::addQueueItems Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::addQueueItems Sep 07 08:12:31 volumio volumio[1029]: info: Preload queue cleared Sep 07 08:12:31 volumio volumio[1029]: info: Adding Item to queue: spotify:album:1tPdeMpLKYYsaRbGnNjPgg Sep 07 08:12:31 volumio volumio[1029]: info: Exploding uri spotify:album:1tPdeMpLKYYsaRbGnNjPgg in service spop Sep 07 08:12:31 volumio volumio[1029]: SPOTIFY: EXPLODING URI:spotify:album:1tPdeMpLKYYsaRbGnNjPgg Sep 07 08:12:31 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:31 volumio volumio[1029]: info: Sep 07 08:12:31 volumio volumio[1029]: ---------------------------- MPD announces state update: player Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand stop took 8 milliseconds Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::getState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Sep 07 08:12:31 volumio volumio[1029]: info: Sep 07 08:12:31 volumio volumio[1029]: ---------------------------- MPD announces state update: player Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::getState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Sep 07 08:12:31 volumio volumio[1029]: info: Sep 07 08:12:31 volumio volumio[1029]: ---------------------------- MPD announces state update: player Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::getState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand status took 2 milliseconds Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand status took 2 milliseconds Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand status took 1 milliseconds Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseState Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 07 08:12:31 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Sep 07 08:12:31 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","artist":null,"album":null,"uri":"USB/FCEF-C1DF/Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","trackType":"mp3"} Sep 07 08:12:31 volumio volumio[1029]: verbose: CURRENT POSITION 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState stateService stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: No code Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","artist":null,"album":null,"uri":"USB/FCEF-C1DF/Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","trackType":"mp3"} Sep 07 08:12:31 volumio volumio[1029]: verbose: CURRENT POSITION 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState stateService stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: No code Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: ControllerMpd::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","artist":null,"album":null,"uri":"USB/FCEF-C1DF/Vintage Remix Caf - Remixes of Popular Songs 5 Hours 192k.mp3","trackType":"mp3"} Sep 07 08:12:31 volumio volumio[1029]: verbose: CURRENT POSITION 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState stateService stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus stop Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:31 volumio volumio[1029]: info: No code Sep 07 08:12:31 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:31 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:31 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:32 volumio volumio[1029]: info: ------------------------------ 20ms Sep 07 08:12:32 volumio volumio[1029]: info: ------------------------------ 20ms Sep 07 08:12:32 volumio volumio[1029]: info: ------------------------------ 19ms Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:32 volumio volumio[1029]: info: CoreCommandRouter::volumioPushQueue Sep 07 08:12:32 volumio volumio[1029]: info: CorePlayQueue::saveQueue Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::updateTrackBlock Sep 07 08:12:32 volumio volumio[1029]: info: CorePlayQueue::getTrackBlock Sep 07 08:12:32 volumio volumio[1029]: info: CoreCommandRouter::volumioPlay Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::play index 0 Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::stop Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::play index undefined Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 08:12:32 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::startPlaybackTimer Sep 07 08:12:32 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:32 volumio volumio[1029]: info: [1757225552270] ControllerSpotify::clearAddPlayTrack Sep 07 08:12:32 volumio volumio[1029]: info: Sending Spotify command with payload to local API: /player/play Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="resolved context of track" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="emitting websocket event: will_play" Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","play_origin":"go-librespot"}} Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1370" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="selected format OGG_VORBIS_320 (10b789883dab9ee3e3f291c64a7abbad7053385b)" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="requested aes key for file 10b789883dab9ee3e3f291c64a7abbad7053385b, gid: 0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="fetched first chunk of 12, total size is 5892176 bytes" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="created new output device" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+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" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=info msg="loaded track \"Happy Morning Cafe\" (paused: false, position: 0ms, duration: 179246ms, prefetched: false)" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="scheduling prefetch in 149s" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="emitting websocket event: metadata" Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","name":"Happy Morning Cafe","artist_names":["Cafe Music BGM channel"],"album_name":"HAPPY MORNING ~Relaxing Cafe Music~","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028fa0bdc35e5b400d5be45d7e","position":0,"duration":179246,"release_date":"year:2018 month:9 day:29","track_number":1,"disc_number":1}} Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 08:12:32 volumio go-librespot[1394]: time="2025-09-07T08:12:32+02:00" level=trace msg="emitting websocket event: playing" Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","resume":false,"play_origin":"go-librespot"}} Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 08:12:32 volumio volumio[1029]: SPOTIFY: {"status":"play","service":"spop","title":"Happy Morning Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","albumart":"https://i.scdn.co/image/ab67616d00001e028fa0bdc35e5b400d5be45d7e","uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","trackType":"spotify","seek":0,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 08:12:32 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Sep 07 08:12:32 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:32 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Happy Morning Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","albumart":"https://i.scdn.co/image/ab67616d00001e028fa0bdc35e5b400d5be45d7e","uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","trackType":"spotify","seek":0,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 08:12:32 volumio volumio[1029]: verbose: CURRENT POSITION 0 Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Sep 07 08:12:32 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus stop Sep 07 08:12:33 volumio go-librespot[1394]: time="2025-09-07T08:12:33+02:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:33 volumio volumio[1029]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 08:12:33 volumio volumio[1029]: SPOTIFY: {"status":"play","service":"spop","title":"Happy Morning Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","albumart":"https://i.scdn.co/image/ab67616d00001e028fa0bdc35e5b400d5be45d7e","uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","trackType":"spotify","seek":0,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Sep 07 08:12:33 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:33 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Happy Morning Cafe","artist":"Cafe Music BGM channel","album":"HAPPY MORNING ~Relaxing Cafe Music~","albumart":"https://i.scdn.co/image/ab67616d00001e028fa0bdc35e5b400d5be45d7e","uri":"spotify:track:0DqqKYKk9QDBQKPjeLHUSH","trackType":"spotify","seek":0,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 08:12:33 volumio volumio[1029]: verbose: CURRENT POSITION 0 Sep 07 08:12:33 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Sep 07 08:12:33 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus play Sep 07 08:12:33 volumio volumio[1029]: info: Received an update from plugin. extracting info from payload Sep 07 08:12:33 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:33 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:33 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:12:33 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:12:33 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:33 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 08:12:33 volumio volumio[1029]: info: Discovery: Getting this device information Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Sep 07 08:12:33 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:12:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 08:12:45 volumio go-librespot[1394]: time="2025-09-07T08:12:45+02:00" level=trace msg="sent dealer ping" Sep 07 08:12:45 volumio go-librespot[1394]: time="2025-09-07T08:12:45+02:00" level=trace msg="received dealer pong" Sep 07 08:12:48 volumio go-librespot[1394]: time="2025-09-07T08:12:48+02:00" level=debug msg="fetched chunk 4/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:12:49 volumio nmbd[960]: [2025/09/07 08:12:49.263551, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Sep 07 08:12:49 volumio nmbd[960]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.100.51 for name WORKGROUP<1d>. Sep 07 08:12:49 volumio nmbd[960]: This response was from IP 192.168.100.250, reporting an IP address of 192.168.100.250. Sep 07 08:13:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 08:13:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 08:13:03 volumio volumio[1029]: info: Discovery: Getting this device information Sep 07 08:13:03 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Sep 07 08:13:03 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:03 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 08:13:04 volumio go-librespot[1394]: time="2025-09-07T08:13:04+02:00" level=debug msg="fetched chunk 5/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:13:15 volumio go-librespot[1394]: time="2025-09-07T08:13:15+02:00" level=trace msg="sent dealer ping" Sep 07 08:13:15 volumio go-librespot[1394]: time="2025-09-07T08:13:15+02:00" level=trace msg="received dealer pong" Sep 07 08:13:15 volumio go-librespot[1394]: time="2025-09-07T08:13:15+02:00" level=trace msg="received accesspoint ping" Sep 07 08:13:15 volumio go-librespot[1394]: time="2025-09-07T08:13:15+02:00" level=trace msg="received accesspoint pong ack" Sep 07 08:13:20 volumio go-librespot[1394]: time="2025-09-07T08:13:20+02:00" level=debug msg="fetched chunk 6/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:13:21 volumio volumio[1029]: info: VolumeController::SetAlsaVolume+ Sep 07 08:13:21 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:13:21 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 93 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: SPOTIFY VOLUME 92 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: VOLUMIO VOLUME 93 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 07 08:13:21 volumio volumio[1029]: info: VolumeController::SetAlsaVolume+ Sep 07 08:13:21 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:13:21 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 94 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: SPOTIFY VOLUME 92 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: VOLUMIO VOLUME 94 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 07 08:13:21 volumio volumio[1029]: info: Setting Spotify Volume from Volumio: 94 Sep 07 08:13:21 volumio volumio[1029]: info: VolumeController::SetAlsaVolume+ Sep 07 08:13:21 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:13:21 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: SPOTIFY VOLUME 94 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: VOLUMIO VOLUME 95 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 07 08:13:21 volumio volumio[1029]: info: VolumeController::SetAlsaVolume+ Sep 07 08:13:21 volumio volumio[1029]: info: CoreStateMachine::pushState Sep 07 08:13:21 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 08:13:21 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: SPOTIFY VOLUME 94 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: VOLUMIO VOLUME 96 Sep 07 08:13:21 volumio volumio[1029]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 07 08:13:21 volumio volumio[1029]: info: Setting Spotify Volume from Volumio: 96 Sep 07 08:13:23 volumio volumio[1029]: SPOTIFY: SETTING SPOTIFY VOLUME 96 Sep 07 08:13:23 volumio volumio[1029]: info: Sending Spotify command with payload to local API: /player/volume Sep 07 08:13:23 volumio go-librespot[1394]: time="2025-09-07T08:13:23+02:00" level=debug msg="update volume requested to 62913/65535" Sep 07 08:13:23 volumio go-librespot[1394]: time="2025-09-07T08:13:23+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 07 08:13:23 volumio go-librespot[1394]: time="2025-09-07T08:13:23+02:00" level=trace msg="emitting websocket event: volume" Sep 07 08:13:23 volumio volumio[1029]: SPOTIFY: received: {"type":"volume","data":{"value":96,"max":100}} Sep 07 08:13:23 volumio volumio[1029]: SPOTIFY: RECEIVED SPOTIFY VOLUME 96 Sep 07 08:13:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 08:13:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 08:13:33 volumio volumio[1029]: info: Discovery: Getting this device information Sep 07 08:13:33 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Sep 07 08:13:33 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Sep 07 08:13:33 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 08:13:36 volumio go-librespot[1394]: time="2025-09-07T08:13:36+02:00" level=debug msg="fetched chunk 7/11, size: 524288" uri="spotify:track:0DqqKYKk9QDBQKPjeLHUSH" Sep 07 08:13:44 volumio volumio[1029]: Searching all installed plugins Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: , search Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 07 08:13:44 volumio volumio[1029]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search Sep 07 08:13:44 volumio volumio[1029]: info: [youtube2] InnertubeLoader: creating Innertube instance... Sep 07 08:13:44 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 07 08:13:44 volumio dbus-daemon[619]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.3285' (uid=0 pid=32119 comm="timedatectl show --property=NTPSynchronized --valu") Sep 07 08:13:44 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 07 08:13:44 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 07 08:13:44 volumio dbus-daemon[619]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 07 08:13:44 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 07 08:13:44 volumio setdatetime-helper.sh[32118]: Time is already synchronized. Sep 07 08:13:44 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 07 08:13:44 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 07 08:13:44 volumio volumio[1029]: Use XMLElement.setAttribute instead Sep 07 08:13:44 volumio volumio[1029]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 08:13:44 volumio volumio[1029]: TypeError: children[i].attr(...).value is not a function Sep 07 08:13:44 volumio volumio[1029]: at /volumio/app/plugins/music_service/webradio/index.js:956:46 Sep 07 08:13:44 volumio volumio[1029]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Sep 07 08:13:44 volumio volumio[1029]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 08:13:45 volumio sudo[32138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-07 08:12' Sep 07 08:13:45 volumio sudo[32138]: 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="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:09:10 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f9bd4447a30d4b2c74b3880e7a50e48b"