Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:02 volumio go-librespot[1656]: time="2026-04-03T01:11:02+07:00" level=trace msg="received accesspoint ping" Apr 03 01:11:02 volumio go-librespot[1656]: time="2026-04-03T01:11:02+07:00" level=trace msg="received accesspoint pong ack" Apr 03 01:11:02 volumio go-librespot[1656]: time="2026-04-03T01:11:02+07:00" level=trace msg="sent dealer ping" Apr 03 01:11:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:02 volumio go-librespot[1656]: time="2026-04-03T01:11:02+07:00" level=trace msg="received dealer pong" Apr 03 01:11:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:02 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Apr 03 01:11:02 volumio volumio[1330]: info: In handleBrowseUri, curUri=spotify/playlists Apr 03 01:11:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:02 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: Searching plugin music_service/spop Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , search Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:08 volumio volumio[1330]: info: All search sources collected, pushing search results Apr 03 01:11:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:10 volumio volumio[1330]: Searching plugin music_service/spop Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , search Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:11 volumio volumio[1330]: info: All search sources collected, pushing search results Apr 03 01:11:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Apr 03 01:11:13 volumio volumio[1330]: info: In handleBrowseUri, curUri=spotify:artist:6jz7YuFH9wdID30tgjPbqn Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:2WGyA3UIA2w7s3s6hGfuzW Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:75i48xBIlj5W7cRBva5TOk Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:4b2DmyKGtzsUVg9VBeT69d Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:1r4RFDMk4kpvQeCGgaKzeF Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:7Cq6L1qcbCuCcEuoCwP7qb Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:5Bn2YvNO3x1CypEaxT3HGB Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:5pSfa2ewWsMhb9e1N6vZpr Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:465ZlK8FsLXsSZQBIWZn7o Apr 03 01:11:15 volumio volumio[1330]: info: Preloading song: spotify:track:1e4OLJONl0a3zaVw6Zap8Q Apr 03 01:11:15 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:15 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: No valid Plugin REST Endpoint Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:19 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 03 01:11:19 volumio volumio[1330]: info: CoreStateMachine::ClearQueue Apr 03 01:11:19 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:19 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::clearPlayQueue Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:19 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:19 volumio volumio[1330]: info: CoreStateMachine::addQueueItems Apr 03 01:11:19 volumio volumio[1330]: info: CorePlayQueue::addQueueItems Apr 03 01:11:19 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:19 volumio volumio[1330]: info: Adding Item to queue: spotify:track:2WGyA3UIA2w7s3s6hGfuzW Apr 03 01:11:19 volumio volumio[1330]: info: Exploding uri spotify:track:2WGyA3UIA2w7s3s6hGfuzW in service spop Apr 03 01:11:19 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:2WGyA3UIA2w7s3s6hGfuzW Apr 03 01:11:19 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:19 volumio volumio[1330]: info: Exploding uri spotify:track:1oVB40CVxu6TBkEy9KpieQ in service spop Apr 03 01:11:19 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","service":"spop","name":"Cuộc đời vẫn đẹp sao","artist":"NSND Thanh Hoa","album":"Em vẫn đợi chờ","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b273a092f805845be313ac420fcd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2WGyA3UIA2w7s3s6hGfuzW","service":"spop","name":"Made In Vietnam","artist":"DTAP","album":"Made In Vietnam","type":"song","duration":281,"albumart":"https://i.scdn.co/image/ab67616d0000b273310d97601b4afa452e354c27","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::updateTrackBlock Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrackBlock Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::play index 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::addQueueItems Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::addQueueItems Apr 03 01:11:20 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:75i48xBIlj5W7cRBva5TOk Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:75i48xBIlj5W7cRBva5TOk in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:75i48xBIlj5W7cRBva5TOk Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:4b2DmyKGtzsUVg9VBeT69d Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:4b2DmyKGtzsUVg9VBeT69d in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:4b2DmyKGtzsUVg9VBeT69d Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1r4RFDMk4kpvQeCGgaKzeF Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:1r4RFDMk4kpvQeCGgaKzeF in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:1r4RFDMk4kpvQeCGgaKzeF Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:7Cq6L1qcbCuCcEuoCwP7qb Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:7Cq6L1qcbCuCcEuoCwP7qb in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:7Cq6L1qcbCuCcEuoCwP7qb Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:5Bn2YvNO3x1CypEaxT3HGB Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:5Bn2YvNO3x1CypEaxT3HGB in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:5Bn2YvNO3x1CypEaxT3HGB Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:5pSfa2ewWsMhb9e1N6vZpr Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:5pSfa2ewWsMhb9e1N6vZpr in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:5pSfa2ewWsMhb9e1N6vZpr Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:465ZlK8FsLXsSZQBIWZn7o Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:465ZlK8FsLXsSZQBIWZn7o in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:465ZlK8FsLXsSZQBIWZn7o Apr 03 01:11:20 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1e4OLJONl0a3zaVw6Zap8Q Apr 03 01:11:20 volumio volumio[1330]: info: Exploding uri spotify:track:1e4OLJONl0a3zaVw6Zap8Q in service spop Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: EXPLODING URI:spotify:track:1e4OLJONl0a3zaVw6Zap8Q Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: [1775153480120] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:20 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="resolved context of track" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4b2DmyKGtzsUVg9VBeT69d","service":"spop","name":"Tôi Đã Già","artist":"NSND Thanh Hoa","album":"Tôi Đã Già","type":"song","duration":316,"albumart":"https://i.scdn.co/image/ab67616d0000b2733923f2547f9762c91ebdf933","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","service":"spop","name":"Làng quan họ quê tôi","artist":"NSND Thanh Hoa","album":"Ước hẹn đồng quê","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b2738bfbb38f69c5e114afad6f1b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5pSfa2ewWsMhb9e1N6vZpr","service":"spop","name":"Tình yêu trên dòng sông quan họ","artist":"NSND Thanh Hoa","album":"Em vẫn đợi chờ","type":"song","duration":275,"albumart":"https://i.scdn.co/image/ab67616d0000b273a092f805845be313ac420fcd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","play_origin":"go-librespot"}} Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:75i48xBIlj5W7cRBva5TOk","service":"spop","name":"Tàu anh qua núi","artist":"NSND Thanh Hoa","album":"Em vẫn đợi chờ","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b273a092f805845be313ac420fcd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1e4OLJONl0a3zaVw6Zap8Q","service":"spop","name":"Tình yêu trên dòng sông quan họ","artist":"NSND Thanh Hoa","album":"Màu hoa đỏ","type":"song","duration":352,"albumart":"https://i.scdn.co/image/ab67616d0000b273a6ec1fbc051c12bc30425129","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7Cq6L1qcbCuCcEuoCwP7qb","service":"spop","name":"Mùa xuân làng lúa làng hoa","artist":"NSND Thanh Hoa","album":"Ước hẹn đồng quê","type":"song","duration":272,"albumart":"https://i.scdn.co/image/ab67616d0000b2738bfbb38f69c5e114afad6f1b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Bn2YvNO3x1CypEaxT3HGB","service":"spop","name":"Gửi em ở cuối sông Hồng","artist":"NSND Thanh Hoa","album":"Em vẫn đợi chờ","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273a092f805845be313ac420fcd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="selected format OGG_VORBIS_320 (b0a52f462a52138da5093efa84043580b65e2fe5)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="requested aes key for file b0a52f462a52138da5093efa84043580b65e2fe5, gid: 1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1oVB40CVxu6TBkEy9KpieQ: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:20 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:20 volumio volumio[1330]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1r4RFDMk4kpvQeCGgaKzeF","service":"spop","name":"Tình ca mùa xuân","artist":"NSND Thanh Hoa","album":"Em vẫn đợi chờ","type":"song","duration":280,"albumart":"https://i.scdn.co/image/ab67616d0000b273a092f805845be313ac420fcd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:20 volumio volumio[1330]: info: CoreStateMachine::updateTrackBlock Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrackBlock Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Apr 03 01:11:20 volumio go-librespot[1656]: time="2026-04-03T01:11:20+07:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 1 Apr 03 01:11:21 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::ClearQueue Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::clearPlayQueue Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::addQueueItems Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::addQueueItems Apr 03 01:11:21 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:21 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:21 volumio volumio[1330]: info: Using cached record of: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::updateTrackBlock Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrackBlock Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::play index 0 Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:21 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:21 volumio volumio[1330]: info: [1775153481632] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:21 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=debug msg="resolved context of track" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:21 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","play_origin":"go-librespot"}} Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=debug msg="selected format OGG_VORBIS_320 (b0a52f462a52138da5093efa84043580b65e2fe5)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=debug msg="requested aes key for file b0a52f462a52138da5093efa84043580b65e2fe5, gid: 1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:21 volumio go-librespot[1656]: time="2026-04-03T01:11:21+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1oVB40CVxu6TBkEy9KpieQ: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:21 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:24 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:24 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: [1775153484123] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:24 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=debug msg="resolved context of track" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:24 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","uri":"spotify:track:1oVB40CVxu6TBkEy9KpieQ","play_origin":"go-librespot"}} Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=debug msg="selected format OGG_VORBIS_320 (b0a52f462a52138da5093efa84043580b65e2fe5)" uri="spotify:track:1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=debug msg="requested aes key for file b0a52f462a52138da5093efa84043580b65e2fe5, gid: 1oVB40CVxu6TBkEy9KpieQ" Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio go-librespot[1656]: time="2026-04-03T01:11:24+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1oVB40CVxu6TBkEy9KpieQ: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:24 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:25 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:25 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:26 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:26 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:27 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:27 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:28 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:28 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:29 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:29 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:30 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:30 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:31 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:31 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=trace msg="sent dealer ping" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=trace msg="received dealer pong" Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 0 Apr 03 01:11:32 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::ClearQueue Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::clearPlayQueue Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::addQueueItems Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::addQueueItems Apr 03 01:11:32 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:2WGyA3UIA2w7s3s6hGfuzW Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:2WGyA3UIA2w7s3s6hGfuzW Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:1oVB40CVxu6TBkEy9KpieQ Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:75i48xBIlj5W7cRBva5TOk Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:75i48xBIlj5W7cRBva5TOk Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:4b2DmyKGtzsUVg9VBeT69d Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:4b2DmyKGtzsUVg9VBeT69d Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1r4RFDMk4kpvQeCGgaKzeF Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:1r4RFDMk4kpvQeCGgaKzeF Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:7Cq6L1qcbCuCcEuoCwP7qb Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:7Cq6L1qcbCuCcEuoCwP7qb Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:5Bn2YvNO3x1CypEaxT3HGB Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:5Bn2YvNO3x1CypEaxT3HGB Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:5pSfa2ewWsMhb9e1N6vZpr Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:5pSfa2ewWsMhb9e1N6vZpr Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:465ZlK8FsLXsSZQBIWZn7o Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:465ZlK8FsLXsSZQBIWZn7o Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::updateTrackBlock Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrackBlock Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::play index 8 Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::addQueueItems Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::addQueueItems Apr 03 01:11:32 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:32 volumio volumio[1330]: info: Adding Item to queue: spotify:track:1e4OLJONl0a3zaVw6Zap8Q Apr 03 01:11:32 volumio volumio[1330]: info: Using cached record of: spotify:track:1e4OLJONl0a3zaVw6Zap8Q Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::stop Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioPushQueue Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::saveQueue Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::updateTrackBlock Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrackBlock Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:32 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:32 volumio volumio[1330]: info: [1775153492433] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:32 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=debug msg="resolved context of track" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:32 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","play_origin":"go-librespot"}} Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=debug msg="selected format OGG_VORBIS_320 (ae85cd96ce3c64cf1df791614deb9c6ef7c380a1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=debug msg="requested aes key for file ae85cd96ce3c64cf1df791614deb9c6ef7c380a1, gid: 465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:32 volumio go-librespot[1656]: time="2026-04-03T01:11:32+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:465ZlK8FsLXsSZQBIWZn7o: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:32 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:32 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:32 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio go-librespot[1656]: time="2026-04-03T01:11:33+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Apr 03 01:11:33 volumio go-librespot[1656]: time="2026-04-03T01:11:33+07:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:33 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:33 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:34 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:34 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Apr 03 01:11:35 volumio volumio[1330]: info: In handleBrowseUri, curUri=spotify:artist:6jz7YuFH9wdID30tgjPbqn Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:35 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:35 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:36 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:36 volumio volumio[1330]: info: Preload queue cleared Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:36 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:36 volumio volumio[1330]: info: No valid Plugin REST Endpoint Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:37 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:37 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:38 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:38 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:38 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:38 volumio volumio[1330]: info: [1775153498959] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:38 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=debug msg="resolved context of track" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:39 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","play_origin":"go-librespot"}} Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=debug msg="selected format OGG_VORBIS_320 (ae85cd96ce3c64cf1df791614deb9c6ef7c380a1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=debug msg="requested aes key for file ae85cd96ce3c64cf1df791614deb9c6ef7c380a1, gid: 465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:39 volumio go-librespot[1656]: time="2026-04-03T01:11:39+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:465ZlK8FsLXsSZQBIWZn7o: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:39 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:39 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:39 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: [1775153500069] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:40 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="resolved context of track" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:40 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","play_origin":"go-librespot"}} Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="selected format OGG_VORBIS_320 (ae85cd96ce3c64cf1df791614deb9c6ef7c380a1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="requested aes key for file ae85cd96ce3c64cf1df791614deb9c6ef7c380a1, gid: 465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:465ZlK8FsLXsSZQBIWZn7o: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:40 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioPlay Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::play index undefined Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: CoreStateMachine::startPlaybackTimer Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: info: [1775153500631] ControllerSpotify::clearAddPlayTrack Apr 03 01:11:40 volumio volumio[1330]: info: Sending Spotify command with payload to local API: /player/play Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="resolved context of track" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=trace msg="emitting websocket event: will_play" Apr 03 01:11:40 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:40 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:40 volumio volumio[1330]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","uri":"spotify:track:465ZlK8FsLXsSZQBIWZn7o","play_origin":"go-librespot"}} Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="selected format OGG_VORBIS_320 (ae85cd96ce3c64cf1df791614deb9c6ef7c380a1)" uri="spotify:track:465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=debug msg="requested aes key for file ae85cd96ce3c64cf1df791614deb9c6ef7c380a1, gid: 465ZlK8FsLXsSZQBIWZn7o" Apr 03 01:11:40 volumio go-librespot[1656]: time="2026-04-03T01:11:40+07:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:465ZlK8FsLXsSZQBIWZn7o: failed retrieving audio key: failed retrieving aes key with code 1" Apr 03 01:11:40 volumio volumio[1330]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:41 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:41 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:42 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:42 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:43 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:43 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:44 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:44 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:45 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:45 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:46 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:46 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:47 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:47 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:48 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:48 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:49 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:49 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:50 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:50 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:51 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:51 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:52 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:52 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:53 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:53 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:54 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:54 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:55 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:55 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:56 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:56 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:57 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:57 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:58 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:58 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:11:59 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:11:59 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:00 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:00 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:01 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:01 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio go-librespot[1656]: time="2026-04-03T01:12:02+07:00" level=trace msg="sent dealer ping" Apr 03 01:12:02 volumio go-librespot[1656]: time="2026-04-03T01:12:02+07:00" level=trace msg="received dealer pong" Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:02 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:02 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:03 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:03 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:04 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:04 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:05 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:05 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:06 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:06 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:07 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:07 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:08 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:08 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:09 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:09 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:10 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:10 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:11 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:11 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio volumio[1330]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Apr 03 01:12:12 volumio volumio[1330]: info: Creating Spotify config file Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 01:12:12 volumio volumio[1330]: info: Spotify config file written Apr 03 01:12:12 volumio sudo[2369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 01:12:12 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 03 01:12:12 volumio systemd[1]: go-librespot-daemon.service: Killing process 1659 (go-librespot) with signal SIGKILL. Apr 03 01:12:12 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 03 01:12:12 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:12 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:12 volumio go-librespot[2371]: go-librespot daemon starting... Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=info msg="running go-librespot 0.7.1" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=debug msg="app state loaded" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:12 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=info msg="zeroconf server listening on port 36019" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 01:12:12 volumio go-librespot[2372]: time="2026-04-03T01:12:12+07:00" level=debug msg="obtained new client token: AADJ4iRg9hFBRQjaMmdkyLhHiuPNd2UPH7S0061UwB/XRzOSAvYkp04wBYTaiCnzD+0G4EmDqnYxSbU+np1fkwIeFRNbtn9xziEwNTZPeyTvF7jG8rovmCOXOXt5ehpaAV2itZMDk3Nc4xUBiA4jgv33NPVOhEzDCxIBaL4VmjaREUtZLfqQbByofk8jpEGCTzYdXCNoT+Zsv1eKTMgghouUgecbPFjvPvnznqJDFVTEE1ae/OeY9svMog==" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="completed keyexchange" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="completed challenge" Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=info msg="authenticated AP" username="31************************du" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=info msg="authenticated Login5" username="31************************du" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="initializing zeroconf session" username="31************************du" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="dealer connection opened" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=trace msg="starting accesspoint recv loop" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=trace msg="starting dealer recv loop" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=trace msg="received accesspoint ping" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="received connection id: ZmRhMzNlNDEtN2Nh...NzI3NzVCQkVCMw==" Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=trace msg="received accesspoint pong ack" Apr 03 01:12:13 volumio go-librespot[2372]: time="2026-04-03T01:12:13+07:00" level=debug msg="put connect state because NEW_DEVICE" Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:13 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:13 volumio volumio[1330]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Apr 03 01:12:13 volumio volumio[1330]: info: Creating Spotify config file Apr 03 01:12:13 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 01:12:13 volumio volumio[1330]: info: Spotify config file written Apr 03 01:12:13 volumio sudo[2382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 01:12:13 volumio sudo[2382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:13 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 03 01:12:13 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 03 01:12:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:13 volumio go-librespot[2384]: go-librespot daemon starting... Apr 03 01:12:13 volumio sudo[2382]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:13 volumio go-librespot[2385]: time="2026-04-03T01:12:13+07:00" level=info msg="running go-librespot 0.7.1" Apr 03 01:12:13 volumio go-librespot[2385]: time="2026-04-03T01:12:13+07:00" level=debug msg="app state loaded" Apr 03 01:12:13 volumio go-librespot[2385]: time="2026-04-03T01:12:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=info msg="zeroconf server listening on port 33317" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="obtained new client token: AAChOraUzccHkeCyxGcUQKNGMKysYxUKiByNvgo4erl+nnoaDUfj933aD/T/uYHzvo2MtZFSu/Sl5/32ez/yM4chaKcqTLboMe/uKCbGmzQHrYuXfItDB6314WltdIp4dl5NfL2umjix00z9SJISgJsLBrQjpbiYNVlj/SDaMaXRdTzOSnhlRdcObyXzH9cPmL4bNzjJtCa0wAmy4rDzAxNMUY3RpC6wpUxkhYylR7VgLHtjY2KZEoc=" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="completed keyexchange" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="completed challenge" Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=info msg="authenticated AP" username="31************************du" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=info msg="authenticated Login5" username="31************************du" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="initializing zeroconf session" username="31************************du" Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="dealer connection opened" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=trace msg="starting accesspoint recv loop" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=trace msg="starting dealer recv loop" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=trace msg="received accesspoint ping" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="received connection id: MzNhMWQ2NjYtYTM2...MDUxMjMwNzFFQQ==" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=trace msg="received accesspoint pong ack" Apr 03 01:12:14 volumio go-librespot[2385]: time="2026-04-03T01:12:14+07:00" level=debug msg="put connect state because NEW_DEVICE" Apr 03 01:12:14 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:14 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:15 volumio go-librespot[2385]: time="2026-04-03T01:12:15+07:00" level=debug msg="new websocket client" Apr 03 01:12:15 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:15 volumio volumio[1330]: info: go-librespot daemon successfully initialized Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Apr 03 01:12:15 volumio volumio[1330]: info: Creating Spotify config file Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 01:12:15 volumio volumio[1330]: info: Spotify config file written Apr 03 01:12:15 volumio sudo[2409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 01:12:15 volumio sudo[2409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 03 01:12:15 volumio systemd[1]: go-librespot-daemon.service: Killing process 2393 (go-librespot) with signal SIGKILL. Apr 03 01:12:15 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 03 01:12:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:15 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:15 volumio go-librespot[2411]: go-librespot daemon starting... Apr 03 01:12:15 volumio sudo[2409]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:15 volumio go-librespot[2412]: time="2026-04-03T01:12:15+07:00" level=info msg="running go-librespot 0.7.1" Apr 03 01:12:15 volumio go-librespot[2412]: time="2026-04-03T01:12:15+07:00" level=debug msg="app state loaded" Apr 03 01:12:15 volumio go-librespot[2412]: time="2026-04-03T01:12:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 01:12:16 volumio volumio[1330]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Apr 03 01:12:16 volumio volumio[1330]: info: Creating Spotify config file Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 01:12:16 volumio volumio[1330]: info: Spotify config file written Apr 03 01:12:16 volumio sudo[2422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 01:12:16 volumio sudo[2422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 03 01:12:16 volumio systemd[1]: go-librespot-daemon.service: Killing process 2415 (go-librespot) with signal SIGKILL. Apr 03 01:12:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 03 01:12:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:16 volumio go-librespot[2425]: go-librespot daemon starting... Apr 03 01:12:16 volumio sudo[2422]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="running go-librespot 0.7.1" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="app state loaded" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="zeroconf server listening on port 35127" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="obtained new client token: AAABnOXyqXGphtEjNHBB++NEROBkfqNLYQmVzy1dT/aUJkqNR5K9GoEBdVTX6o4ZtDrZlNhFWQvIecWY02S5DN/j37FfbtzzbOn5gsSt085e2cJXI4tvcNHdzVAFXlDPN3Ahf4kSkCzvy6NohPM9OvoGXZARpY3HWZrW/g99/Md/pqA02AngcWNI3J/3mGn6I+7lG1xE8spyr/AgcG43QfKcPGaPHoGC6mHhTU+m95jJe16LTyLHmpr+EQ==" Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="completed keyexchange" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="completed challenge" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="authenticated AP" username="31************************du" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=info msg="authenticated Login5" username="31************************du" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="initializing zeroconf session" username="31************************du" Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:16 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:16 volumio volumio[1330]: info: go-librespot daemon successfully initialized Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="dealer connection opened" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=trace msg="starting accesspoint recv loop" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=trace msg="starting dealer recv loop" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=trace msg="received accesspoint ping" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=debug msg="received connection id: MDRmYzJlYTMtN2Zm...QjAzQzM2NERGOA==" Apr 03 01:12:16 volumio go-librespot[2426]: time="2026-04-03T01:12:16+07:00" level=trace msg="received accesspoint pong ack" Apr 03 01:12:17 volumio go-librespot[2426]: time="2026-04-03T01:12:17+07:00" level=debug msg="put connect state because NEW_DEVICE" Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:17 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:17 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: Getting Spotify volume Apr 03 01:12:18 volumio volumio[1330]: info: Spotify volume: 100 Apr 03 01:12:18 volumio volumio[1330]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:18 volumio volumio[1330]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 03 01:12:18 volumio go-librespot[2426]: time="2026-04-03T01:12:18+07:00" level=debug msg="new websocket client" Apr 03 01:12:18 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:18 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:18 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:18 volumio go-librespot[2426]: time="2026-04-03T01:12:18+07:00" level=debug msg="new websocket client" Apr 03 01:12:18 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:18 volumio volumio[1330]: info: go-librespot daemon successfully initialized Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: go-librespot daemon successfully initialized Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:19 volumio go-librespot[2426]: time="2026-04-03T01:12:19+07:00" level=debug msg="new websocket client" Apr 03 01:12:19 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:19 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:19 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:20 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:20 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: Getting Spotify volume Apr 03 01:12:21 volumio volumio[1330]: info: Spotify volume: 100 Apr 03 01:12:21 volumio volumio[1330]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: info: Getting Spotify volume Apr 03 01:12:21 volumio volumio[1330]: info: Spotify volume: 100 Apr 03 01:12:21 volumio volumio[1330]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 03 01:12:21 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:21 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:21 volumio volumio[1330]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 03 01:12:21 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:21 volumio go-librespot[2426]: time="2026-04-03T01:12:21+07:00" level=debug msg="new websocket client" Apr 03 01:12:21 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: Initializing connection to go-librespot Websocket Apr 03 01:12:22 volumio go-librespot[2426]: time="2026-04-03T01:12:22+07:00" level=debug msg="new websocket client" Apr 03 01:12:22 volumio volumio[1330]: info: Connection to go-librespot Websocket established Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: info: Getting Spotify volume Apr 03 01:12:22 volumio volumio[1330]: info: Spotify volume: 100 Apr 03 01:12:22 volumio volumio[1330]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 03 01:12:22 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:22 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:22 volumio volumio[1330]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio go-librespot[2426]: time="2026-04-03T01:12:23+07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 01:12:23 volumio volumio[1330]: Cannot find translation for source SoundCloud Apr 03 01:12:23 volumio volumio[1330]: Cannot find translation for source YouTube2 Apr 03 01:12:23 volumio volumio[1330]: Cannot find translation for source YouTube Music Apr 03 01:12:23 volumio volumio[1330]: info: Disabling plugin spop Apr 03 01:12:23 volumio volumio[1330]: info: Done. Apr 03 01:12:23 volumio sudo[2437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Apr 03 01:12:23 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:23 volumio sudo[2437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 03 01:12:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 2429 (go-librespot) with signal SIGKILL. Apr 03 01:12:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 03 01:12:23 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:23 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:23 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:23 volumio volumio[1330]: info: Connection to go-librespot Websocket closed Apr 03 01:12:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:23 volumio sudo[2437]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:23 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:23 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::volumioGetState Apr 03 01:12:24 volumio volumio[1330]: info: CorePlayQueue::getTrack 8 Apr 03 01:12:24 volumio volumio[1330]: info: Enabling plugin spop Apr 03 01:12:24 volumio volumio[1330]: info: Loading plugin "spop"... Apr 03 01:12:24 volumio volumio[1330]: info: PLUGIN START: spop Apr 03 01:12:24 volumio volumio[1330]: info: Creating Spotify config file Apr 03 01:12:24 volumio volumio[1330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 01:12:24 volumio volumio[1330]: info: Done. Apr 03 01:12:24 volumio volumio[1330]: info: Spotify config file written Apr 03 01:12:24 volumio volumio[1330]: info: No need to fix Spotify hosts Apr 03 01:12:24 volumio volumio[1330]: info: Getting Spotify volume Apr 03 01:12:24 volumio sudo[2440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 01:12:24 volumio volumio[1330]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 01:12:24 volumio sudo[2440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:24 volumio volumio[1330]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 03 01:12:24 volumio volumio[1330]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 03 01:12:24 volumio volumio[1330]: errno: -111, Apr 03 01:12:24 volumio volumio[1330]: code: 'ECONNREFUSED', Apr 03 01:12:24 volumio volumio[1330]: syscall: 'connect', Apr 03 01:12:24 volumio volumio[1330]: address: '127.0.0.1', Apr 03 01:12:24 volumio volumio[1330]: port: 9879, Apr 03 01:12:24 volumio volumio[1330]: response: undefined Apr 03 01:12:24 volumio volumio[1330]: } Apr 03 01:12:24 volumio volumio[1330]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 01:12:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 03 01:12:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 01:12:25 volumio go-librespot[2445]: go-librespot daemon starting... Apr 03 01:12:25 volumio sudo[2440]: pam_unix(sudo:session): session closed for user root Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=info msg="running go-librespot 0.7.1" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=debug msg="app state loaded" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=info msg="zeroconf server listening on port 34577" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 01:12:25 volumio sudo[2466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-03 01:11' Apr 03 01:12:25 volumio sudo[2466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=debug msg="obtained new client token: AABqK7WZtDTrrk+a4G1NXu2N+ao9kqbHwJDBN3oRuUBkONkTGUhcjbLauTjScjEiTwNwkywv6mlrpistbI0ZVUYjM2/u+qpNcbII03qHwqjuJmyLDvkeb0iN3itauoGnxM7p57/mBTMhngk5gwPfFI7d1w2Pz6trI+o1pSjXCLwLApsRZ81MAWgutgnZnBAu5Eop+qvEPltZzjldUYpVV4lrDe8zTeY8Dhd0ATbEv14+K/y7IOJD33fKDA==" Apr 03 01:12:25 volumio go-librespot[2455]: time="2026-04-03T01:12:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"