-- Logs begin at Tue 2024-11-12 23:16:44 CET, end at Mon 2025-04-14 20:57:52 CEST. -- Apr 14 20:56:00 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:00 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:00 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:00 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:01 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:01 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:01 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:01 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:02 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:02 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:02 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:02 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:02 volumio go-librespot[1192]: time="2025-04-14T20:56:02+02:00" level=debug msg="fetched chunk 11/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:03 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:03 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:03 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:03 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:04 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:04 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:04 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:04 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:05 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:05 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:05 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:05 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:06 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:06 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:06 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:06 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:07 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:07 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:07 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:07 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:08 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:08 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:08 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:08 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:09 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:09 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:09 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:09 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:10 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:10 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:10 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:10 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:11 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:11 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:11 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:11 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:12 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:12 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:12 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:12 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:13 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:13 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:13 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:13 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:14 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:14 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:14 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:14 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:15 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:15 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:15 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:15 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:16 volumio go-librespot[1192]: time="2025-04-14T20:56:16+02:00" level=debug msg="fetched chunk 12/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:16 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:16 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:16 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:16 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:17 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:17 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:17 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:17 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:18 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:18 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:18 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:18 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:19 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:19 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:19 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:19 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:20 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:20 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:20 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:20 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:21 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:21 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:21 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:21 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:22 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:22 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:22 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:22 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:23 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:23 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:23 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:23 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:24 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:24 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:24 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:24 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:25 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:25 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:25 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:25 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:26 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:26 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:26 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:26 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:27 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:27 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:27 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:27 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:28 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:28 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:28 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:28 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:29 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:29 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:29 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:29 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:29 volumio go-librespot[1192]: time="2025-04-14T20:56:29+02:00" level=debug msg="fetched chunk 13/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:30 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:30 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:30 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:30 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:31 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:31 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:31 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:31 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:32 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:32 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:32 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:32 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:33 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:33 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:33 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:33 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:34 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:34 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:34 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:34 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:35 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:35 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:35 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:35 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:36 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:36 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:36 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:36 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:37 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:37 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:37 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:37 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:38 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:38 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:38 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:38 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:39 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:39 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:39 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:39 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:40 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:40 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:40 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:40 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:41 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:41 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:41 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:41 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:42 volumio go-librespot[1192]: time="2025-04-14T20:56:42+02:00" level=debug msg="fetched chunk 14/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:42 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:42 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:42 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:42 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:43 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:43 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:43 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:43 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:44 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:44 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:44 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:44 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:45 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:45 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:45 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:45 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:46 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:46 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:47 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:47 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:47 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:47 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:48 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:48 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:48 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:48 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:49 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:49 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:49 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:49 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:50 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:50 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:50 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:50 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:51 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:51 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:51 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:51 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:52 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:52 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:52 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:52 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:53 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:53 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:53 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:53 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="fetched chunk 15/15, size: 280308" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="handling pause player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="pause track at 168410ms" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:56:54 volumio go-librespot[1192]: time="2025-04-14T20:56:54+02:00" level=trace msg="emitting websocket event: paused" Apr 14 20:56:54 volumio volumio[800]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","play_origin":"playlist/ondemand"}} Apr 14 20:56:54 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:56:54 volumio volumio[800]: SPOTIFY: {"status":"pause","service":"spop","title":"Sky Is On Fire - Two&One Edit","artist":"Sneijder, Jess Morgan, Two&One","album":"Vocal Trance","albumart":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","trackType":"spotify","seek":169000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:56:54 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:56:54 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:56:54 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:56:54 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:56:54 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="handling resume player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=trace msg="seek to 168410ms (diff: 111ms, samples: 7426881, bytes: 6275794)" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="resume track at 168299ms" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=trace msg="scheduling prefetch in 15s" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:56:55 volumio go-librespot[1192]: time="2025-04-14T20:56:55+02:00" level=trace msg="emitting websocket event: playing" Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","play_origin":"playlist/ondemand"}} Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Sky Is On Fire - Two&One Edit","artist":"Sneijder, Jess Morgan, Two&One","album":"Vocal Trance","albumart":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","trackType":"spotify","seek":169000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:56:55 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:55 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:55 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Sky Is On Fire - Two&One Edit","artist":"Sneijder, Jess Morgan, Two&One","album":"Vocal Trance","albumart":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","trackType":"spotify","seek":169000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:56:55 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:56:55 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:56:55 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 14 20:56:56 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:56 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:56 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:56 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:57 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:57 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:57 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:57 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:58 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:58 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:58 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:58 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=debug msg="update volume to 29303/65535" Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:56:59 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} Apr 14 20:56:59 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=debug msg="update volume to 37998/65535" Apr 14 20:56:59 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:56:59 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:56:59 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:56:59 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:56:59 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":58,"max":100}} Apr 14 20:56:59 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 58 Apr 14 20:56:59 volumio volumio[800]: info: Setting Volumio Volume from Spotify: 58 Apr 14 20:56:59 volumio volumio[800]: info: VolumeController::SetAlsaVolume58 Apr 14 20:56:59 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:56:59 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:56:59 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:56:59 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Apr 14 20:56:59 volumio go-librespot[1192]: time="2025-04-14T20:56:59+02:00" level=debug msg="update volume to 39837/65535" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":61,"max":100}} Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 61 Apr 14 20:57:00 volumio volumio[800]: info: Setting Volumio Volume from Spotify: 61 Apr 14 20:57:00 volumio volumio[800]: info: VolumeController::SetAlsaVolume61 Apr 14 20:57:00 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 61 Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=debug msg="update volume to 39766/65535" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":61,"max":100}} Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 61 Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:00 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:00 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=debug msg="update volume to 36090/65535" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:57:00 volumio go-librespot[1192]: time="2025-04-14T20:57:00+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":56,"max":100}} Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 56 Apr 14 20:57:00 volumio volumio[800]: info: Setting Volumio Volume from Spotify: 56 Apr 14 20:57:00 volumio volumio[800]: info: VolumeController::SetAlsaVolume56 Apr 14 20:57:00 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:00 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:00 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Apr 14 20:57:01 volumio go-librespot[1192]: time="2025-04-14T20:57:01+02:00" level=debug msg="update volume to 35171/65535" Apr 14 20:57:01 volumio go-librespot[1192]: time="2025-04-14T20:57:01+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:57:01 volumio go-librespot[1192]: time="2025-04-14T20:57:01+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:57:01 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Apr 14 20:57:01 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Apr 14 20:57:01 volumio volumio[800]: info: Setting Volumio Volume from Spotify: 54 Apr 14 20:57:01 volumio volumio[800]: info: VolumeController::SetAlsaVolume54 Apr 14 20:57:01 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:01 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:01 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:01 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:01 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:01 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:01 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:01 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:02 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:02 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:02 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:02 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:03 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:03 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:03 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:03 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:04 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:04 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:04 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:04 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:05 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:05 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:05 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:05 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=trace msg="closed output device because of stop command" Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=debug msg="put connect state inactive" Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=trace msg="emitting websocket event: inactive" Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 14 20:57:06 volumio volumio[800]: SPOTIFY: received: {"type":"inactive","data":null} Apr 14 20:57:06 volumio volumio[800]: error: Failed to decode event: inactive Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1313" Apr 14 20:57:06 volumio go-librespot[1192]: time="2025-04-14T20:57:06+02:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.178.171:39930->34.158.1.133:4070: use of closed network connection" Apr 14 20:57:06 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:06 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:06 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:06 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:07 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:07 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:07 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:07 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:08 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:08 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:08 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:08 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:08 volumio go-librespot[1192]: time="2025-04-14T20:57:08+02:00" level=debug msg="obtained new client token: AABNJpeiZwKi+EHSE0k/1A/qjkZWPcWKhL6RBECKmo8yAoDN+RIx/FxMfIpCt4yJ7XU5id7etOhSLWycKFATYpRVLwNn8sEB6vEQETrGyrPX5FbJTvVxw5SttI6cAU1Xx4at2MN6Uv7ibnMjuxZ6v8jNspME1awappeR/Wq59bHaG965WG+BCNphn42txGRRthcY1gcO31et6iY7B5pwIu0RPb4jDZE+YgawV7WrfqSUpEF+J8C2ZcE1Fvcd85Y=" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="completed keyexchange" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="completed challenge" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="authenticated as mmhendriks" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="authenticated as mmhendriks" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="dealer connection opened" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=info msg="accepted zeroconf user mmhendriks from iPhone" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="autoplay enabled: false" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="received connection id: MmEyNTMwMGUtZmViYy00MjU0LWE2M2UtYjg5MDIzMjA2ZmM5K2RlYWxlcit0Y3A6Ly8wYWNhNTg0ZC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMzAwMTUwNDA5NUEzREM4ODZFRDk1QjdDNjY2NTNEMDEwNTlFRUM4RDA3OTlFMDAwQkMxMjc3MzhFQjYwQTA3Nw==" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 14 20:57:09 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:09 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:09 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:09 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="handling transfer player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:0gwCNEhe2dAIggBuxQRDAr" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=trace msg="fetched new page 0 with 1085 items (list: 1085)" uri="spotify:playlist:0gwCNEhe2dAIggBuxQRDAr" Apr 14 20:57:09 volumio go-librespot[1192]: time="2025-04-14T20:57:09+02:00" level=debug msg="loading track (paused: false, position: 172435ms)" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="emitting websocket event: will_play" Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","play_origin":"playlist/ondemand"}} Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="selected format OGG_VORBIS_320 (06233a469d8296fcebf62aad398a316aeafe33a2)" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="requested aes key for file 06233a469d8296fcebf62aad398a316aeafe33a2, gid: 5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1340" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched first chunk of 16, total size is 8144628 bytes" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 14/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 13/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 12/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 15/15, size: 280308" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="seek to 172435ms (diff: 122ms, samples: 7604383, bytes: 6448790)" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="created new output device" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=info msg="loaded track \"Sky Is On Fire - Two&One Edit\" (paused: false, position: 172435ms, duration: 213636ms, prefetched: false)" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:5YkxxyGrVfiq8BYrQzfZS9" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="scheduling prefetch in 11s" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="emitting websocket event: metadata" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="emitting websocket event: active" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","name":"Sky Is On Fire - Two\u0026One Edit","artist_names":["Sneijder","Jess Morgan","Two\u0026One"],"album_name":"Vocal Trance","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","position":172435,"duration":213636,"release_date":"year:2020 month:3 day:20","track_number":20,"disc_number":1}} Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: received: {"type":"active","data":null} Apr 14 20:57:10 volumio volumio[800]: info: Aligning Spotify Volume to Volumio Volume Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:10 volumio volumio[800]: info: Setting Spotify Volume from Volumio: 54 Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1114" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:10 volumio go-librespot[1192]: time="2025-04-14T20:57:10+02:00" level=trace msg="emitting websocket event: playing" Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","play_origin":"playlist/ondemand"}} Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Sky Is On Fire - Two&One Edit","artist":"Sneijder, Jess Morgan, Two&One","album":"Vocal Trance","albumart":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","trackType":"spotify","seek":172435,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:10 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Sky Is On Fire - Two&One Edit","artist":"Sneijder, Jess Morgan, Two&One","album":"Vocal Trance","albumart":"https://i.scdn.co/image/ab67616d00001e02e83a03830cf19005c5d80a13","uri":"spotify:track:5YkxxyGrVfiq8BYrQzfZS9","trackType":"spotify","seek":173435,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:10 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:10 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:10 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:10 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:10 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:10 volumio ntpd[760]: 185.51.192.63 local addr 192.168.178.171 -> Apr 14 20:57:11 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:11 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:11 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:11 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:11 volumio volumio[800]: SPOTIFY: SETTING SPOTIFY VOLUME 54 Apr 14 20:57:11 volumio volumio[800]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 20:57:11 volumio go-librespot[1192]: time="2025-04-14T20:57:11+02:00" level=debug msg="update volume to 35388/65535" Apr 14 20:57:11 volumio go-librespot[1192]: time="2025-04-14T20:57:11+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 14 20:57:11 volumio go-librespot[1192]: time="2025-04-14T20:57:11+02:00" level=trace msg="emitting websocket event: volume" Apr 14 20:57:11 volumio volumio[800]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Apr 14 20:57:11 volumio volumio[800]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Apr 14 20:57:12 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:12 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:12 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:12 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="handling skip_next player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=trace msg="emitting websocket event: will_play" Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","play_origin":"playlist/ondemand"}} Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="selected format OGG_VORBIS_320 (a5bd184f699fad6ec2c5c2e899ec3942730bcf60)" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="requested aes key for file a5bd184f699fad6ec2c5c2e899ec3942730bcf60, gid: 0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="fetched first chunk of 29, total size is 14823932 bytes" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=info msg="loaded track \"All Around You [Cosmic Gate with Myon & Shane 54 and Aruna] - Album Mix\" (paused: false, position: 0ms, duration: 331998ms, prefetched: false)" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="fetched chunk 1/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=trace msg="scheduling prefetch in 302s" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=trace msg="emitting websocket event: metadata" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","name":"All Around You [Cosmic Gate with Myon \u0026 Shane 54 and Aruna] - Album Mix","artist_names":["Cosmic Gate","Myon \u0026 Shane 54","Aruna"],"album_name":"Trance 75 - 2012, Vol. 1","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027355df5c3c85d27b6f45ff34","position":0,"duration":331998,"release_date":"year:2012 month:1 day:13","track_number":21,"disc_number":1}} Apr 14 20:57:13 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="fetched chunk 3/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:13 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:13 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:13 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=trace msg="emitting websocket event: playing" Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","play_origin":"playlist/ondemand"}} Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"All Around You [Cosmic Gate with Myon & Shane 54 and Aruna] - Album Mix","artist":"Cosmic Gate, Myon & Shane 54, Aruna","album":"Trance 75 - 2012, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e027355df5c3c85d27b6f45ff34","uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","trackType":"spotify","seek":0,"duration":331,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:13 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:13 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:13 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:13 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:13 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:13 volumio go-librespot[1192]: time="2025-04-14T20:57:13+02:00" level=debug msg="fetched chunk 2/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:14 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:14 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"All Around You [Cosmic Gate with Myon & Shane 54 and Aruna] - Album Mix","artist":"Cosmic Gate, Myon & Shane 54, Aruna","album":"Trance 75 - 2012, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e027355df5c3c85d27b6f45ff34","uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","trackType":"spotify","seek":0,"duration":331,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:14 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:14 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:14 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:14 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:14 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:14 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:14 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:14 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:15 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:15 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:15 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:15 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:16 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:16 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:16 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:16 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:17 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:17 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:17 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:17 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="handling seek_to player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="seek track to 67783ms" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="fetched chunk 8/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="fetched chunk 9/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="fetched chunk 7/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:18 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:18 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:18 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:18 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="fetched chunk 6/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=trace msg="seek to 67783ms (diff: 208ms, samples: 2989230, bytes: 3474240)" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=trace msg="scheduling prefetch in 234s" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=trace msg="emitting websocket event: seek" Apr 14 20:57:18 volumio go-librespot[1192]: time="2025-04-14T20:57:18+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:57:18 volumio volumio[800]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","position":67783,"duration":331998,"play_origin":"playlist/ondemand"}} Apr 14 20:57:18 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:18 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"All Around You [Cosmic Gate with Myon & Shane 54 and Aruna] - Album Mix","artist":"Cosmic Gate, Myon & Shane 54, Aruna","album":"Trance 75 - 2012, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e027355df5c3c85d27b6f45ff34","uri":"spotify:track:0eTuEIKaDFaqOjHNAPMTBf","trackType":"spotify","seek":67783,"duration":331,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:18 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:18 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:18 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:18 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:18 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:19 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:19 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:19 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:19 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:20 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:20 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:20 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:20 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:21 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:21 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:21 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:21 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:22 volumio go-librespot[1192]: time="2025-04-14T20:57:22+02:00" level=debug msg="fetched chunk 10/28, size: 524288" uri="spotify:track:0eTuEIKaDFaqOjHNAPMTBf" Apr 14 20:57:22 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:22 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:22 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:22 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:23 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:23 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:23 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:23 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:24 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:24 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:24 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:24 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:25 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:25 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:25 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:25 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:26 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:26 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:26 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:26 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="handling play player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="resolved context of track" uri="spotify:user:mmhendriks:collection" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="fetched new page 0 with 354 items (list: 354)" uri="spotify:user:mmhendriks:collection" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="emitting websocket event: will_play" Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","play_origin":"collection/songs"}} Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="selected format OGG_VORBIS_320 (d8adc3917d14ed093381b4da5fa2cb3b2aad28b0)" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="requested aes key for file d8adc3917d14ed093381b4da5fa2cb3b2aad28b0, gid: 6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="fetched first chunk of 29, total size is 14855216 bytes" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=info msg="loaded track \"Burned With Desire\" (paused: false, position: 0ms, duration: 353026ms, prefetched: false)" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="scheduling prefetch in 323s" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="emitting websocket event: metadata" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","name":"Burned With Desire","artist_names":["Armin van Buuren","Justine Suissa"],"album_name":"76","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028f301e7e7a75ec19aaf4e7ad","position":0,"duration":353026,"release_date":"year:2003 month:6 day:16","track_number":4,"disc_number":1}} Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=trace msg="emitting websocket event: playing" Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","play_origin":"collection/songs"}} Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Burned With Desire","artist":"Armin van Buuren, Justine Suissa","album":"76","albumart":"https://i.scdn.co/image/ab67616d00001e028f301e7e7a75ec19aaf4e7ad","uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","trackType":"spotify","seek":0,"duration":353,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:27 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="fetched chunk 1/28, size: 524288" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="fetched chunk 3/28, size: 524288" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio go-librespot[1192]: time="2025-04-14T20:57:27+02:00" level=debug msg="fetched chunk 2/28, size: 524288" uri="spotify:track:6NGxzYn3GgHjVw17aQjuoW" Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: {"status":"play","service":"spop","title":"Burned With Desire","artist":"Armin van Buuren, Justine Suissa","album":"76","albumart":"https://i.scdn.co/image/ab67616d00001e028f301e7e7a75ec19aaf4e7ad","uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","trackType":"spotify","seek":1000,"duration":353,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:27 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:27 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:27 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:27 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:27 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:28 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:28 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:28 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:28 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:29 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:29 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:29 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:29 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:30 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:30 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:30 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:30 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:31 volumio ntpd[760]: 185.224.145.68 local addr 192.168.178.171 -> Apr 14 20:57:31 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:31 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:31 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:31 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:32 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:32 volumio volumio[800]: info: CoreCommandRouter::volumioGetQueue Apr 14 20:57:32 volumio volumio[800]: info: CoreStateMachine::getQueue Apr 14 20:57:32 volumio volumio[800]: info: CorePlayQueue::getQueue Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=debug msg="handling pause player command from f0cb75f4971891d5089240c199e31ed3eea21498" Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=debug msg="pause track at 6318ms" Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=debug msg="sending successful reply for dealer request" Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 20:57:33 volumio go-librespot[1192]: time="2025-04-14T20:57:33+02:00" level=trace msg="emitting websocket event: paused" Apr 14 20:57:33 volumio volumio[800]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","play_origin":"collection/songs"}} Apr 14 20:57:33 volumio volumio[800]: SPOTIFY: PUSH STATE SPOTIFY Apr 14 20:57:33 volumio volumio[800]: SPOTIFY: {"status":"pause","service":"spop","title":"Burned With Desire","artist":"Armin van Buuren, Justine Suissa","album":"76","albumart":"https://i.scdn.co/image/ab67616d00001e028f301e7e7a75ec19aaf4e7ad","uri":"spotify:track:6NGxzYn3GgHjVw17aQjuoW","trackType":"spotify","seek":7000,"duration":353,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 14 20:57:33 volumio volumio[800]: info: CoreCommandRouter::servicePushState Apr 14 20:57:33 volumio volumio[800]: info: CoreStateMachine::pushState Apr 14 20:57:33 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 20:57:33 volumio volumio[800]: info: CoreCommandRouter::volumioPushState Apr 14 20:57:33 volumio volumio[800]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:44 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:44 volumio volumio[800]: verbose: New Socket.io Connection to 192.168.178.171:3000 from 192.168.178.204 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:44 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:44 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:45 volumio sudo[8242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 20:57:45 volumio sudo[8242]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 20:57:45 volumio sudo[8242]: pam_unix(sudo:session): session closed for user root Apr 14 20:57:45 volumio sudo[8244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 20:57:45 volumio sudo[8244]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 20:57:45 volumio sudo[8244]: pam_unix(sudo:session): session closed for user root Apr 14 20:57:46 volumio volumio[800]: verbose: New Socket.io Connection to 192.168.178.171 from 192.168.178.204 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 20:57:46 volumio volumio[800]: info: Received Get System Info Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:46 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: Listing playlists Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 14 20:57:46 volumio sudo[8248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 20:57:46 volumio sudo[8248]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 20:57:46 volumio sudo[8248]: pam_unix(sudo:session): session closed for user root Apr 14 20:57:46 volumio sudo[8250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 20:57:46 volumio sudo[8250]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 20:57:46 volumio sudo[8250]: pam_unix(sudo:session): session closed for user root Apr 14 20:57:46 volumio volumio[800]: verbose: New Socket.io Connection to 192.168.178.171 from 192.168.178.204 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 20:57:46 volumio volumio[800]: info: Received Get System Info Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:46 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:46 volumio volumio[800]: info: Listing playlists Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 20:57:46 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 14 20:57:47 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 14 20:57:48 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 20:57:48 volumio volumio[800]: info: Received Get System Info Apr 14 20:57:48 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:48 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:48 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:48 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:48 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:49 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 20:57:49 volumio volumio[800]: info: Received Get System Info Apr 14 20:57:49 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 20:57:49 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 20:57:49 volumio volumio[800]: info: Discovery: Getting this device information Apr 14 20:57:49 volumio volumio[800]: info: CoreCommandRouter::volumioGetState Apr 14 20:57:49 volumio volumio[800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 20:57:51 volumio volumio[800]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Apr 14 20:57:51 volumio volumio[800]: info: PLUGIN onReboot : networkfs Apr 14 20:57:51 volumio volumio[800]: info: PLUGIN onReboot : audiophonicsonoff Apr 14 20:57:51 volumio volumio[800]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 20:57:51 volumio volumio[800]: TypeError: Cannot read property 'writeSync' of undefined Apr 14 20:57:51 volumio volumio[800]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Apr 14 20:57:51 volumio volumio[800]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Apr 14 20:57:51 volumio volumio[800]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Apr 14 20:57:51 volumio volumio[800]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 14 20:57:51 volumio volumio[800]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 14 20:57:51 volumio volumio[800]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Apr 14 20:57:51 volumio volumio[800]: at CoreCommandRouter.reboot (/volumio/app/index.js:1344:22) Apr 14 20:57:51 volumio volumio[800]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:864:33) Apr 14 20:57:51 volumio volumio[800]: at Socket.emit (events.js:315:20) Apr 14 20:57:51 volumio volumio[800]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 14 20:57:51 volumio volumio[800]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 14 20:57:51 volumio volumio[800]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 20:57:52 volumio sudo[8263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-14 20:56 Apr 14 20:57:52 volumio sudo[8263]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"