-- Logs begin at Sat 2025-04-26 21:12:22 CEST, end at Sat 2025-05-17 18:43:21 CEST. -- May 17 18:42:00 jukebox go-librespot[1350]: time="2025-05-17T18:42:00+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 17 18:42:00 jukebox go-librespot[1350]: time="2025-05-17T18:42:00+02:00" level=trace msg="emitting websocket event: volume" May 17 18:42:00 jukebox volumio[991]: SPOTIFY: received: {"type":"volume","data":{"value":63,"max":100}} May 17 18:42:00 jukebox volumio[991]: SPOTIFY: RECEIVED SPOTIFY VOLUME 63 May 17 18:42:00 jukebox volumio[991]: info: Setting Volumio Volume from Spotify: 63 May 17 18:42:00 jukebox volumio[991]: info: VolumeController::SetAlsaVolume63 May 17 18:42:00 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:00 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:00 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:00 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 May 17 18:42:07 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 63 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 65 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true May 17 18:42:07 jukebox volumio[991]: info: Setting Spotify Volume from Volumio: 65 May 17 18:42:07 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 65 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 67 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true May 17 18:42:07 jukebox volumio[991]: info: Setting Spotify Volume from Volumio: 67 May 17 18:42:07 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 67 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 69 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true May 17 18:42:07 jukebox volumio[991]: info: Setting Spotify Volume from Volumio: 69 May 17 18:42:07 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:07 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:07 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:08 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:08 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:08 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:08 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:08 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:08 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:08 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:08 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:08 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:08 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:08 jukebox volumio[991]: SPOTIFY: SETTING SPOTIFY VOLUME 69 May 17 18:42:08 jukebox volumio[991]: info: Sending Spotify command with payload to local API: /player/volume May 17 18:42:08 jukebox go-librespot[1350]: time="2025-05-17T18:42:08+02:00" level=debug msg="update volume to 45219/65535" May 17 18:42:08 jukebox go-librespot[1350]: time="2025-05-17T18:42:08+02:00" level=debug msg="fetched chunk 6/14, size: 524288" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:09 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:09 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:09 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:09 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:09 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:09 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:09 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:09 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:09 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:09 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:09 jukebox go-librespot[1350]: time="2025-05-17T18:42:09+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 17 18:42:09 jukebox go-librespot[1350]: time="2025-05-17T18:42:09+02:00" level=trace msg="emitting websocket event: volume" May 17 18:42:09 jukebox volumio[991]: SPOTIFY: received: {"type":"volume","data":{"value":69,"max":100}} May 17 18:42:09 jukebox volumio[991]: SPOTIFY: RECEIVED SPOTIFY VOLUME 69 May 17 18:42:13 jukebox go-librespot[1350]: time="2025-05-17T18:42:13+02:00" level=trace msg="sent dealer ping" May 17 18:42:13 jukebox go-librespot[1350]: time="2025-05-17T18:42:13+02:00" level=trace msg="received dealer pong" May 17 18:42:16 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:16 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:16 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:16 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:16 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:16 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:16 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:16 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:16 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:16 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:16 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:16 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:16 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:16 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:16 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:16 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:16 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:18 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:18 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:18 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:18 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:18 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:18 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:18 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:18 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:18 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:18 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:18 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:18 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:18 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:18 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:19 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:19 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:19 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:19 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:19 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:19 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:19 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:19 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:19 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:19 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:19 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:19 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:19 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:19 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:19 jukebox go-librespot[1350]: time="2025-05-17T18:42:19+02:00" level=debug msg="fetched chunk 7/14, size: 524288" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:20 jukebox volumio[991]: info: VolumeController::SetAlsaVolume+ May 17 18:42:20 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:20 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:20 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 69 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:20 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: false May 17 18:42:25 jukebox go-librespot[1350]: time="2025-05-17T18:42:25+02:00" level=debug msg="update volume to 45874/65535" May 17 18:42:26 jukebox go-librespot[1350]: time="2025-05-17T18:42:26+02:00" level=debug msg="update volume to 46530/65535" May 17 18:42:26 jukebox go-librespot[1350]: time="2025-05-17T18:42:26+02:00" level=debug msg="update volume to 47185/65535" May 17 18:42:27 jukebox go-librespot[1350]: time="2025-05-17T18:42:27+02:00" level=debug msg="update volume to 47840/65535" May 17 18:42:27 jukebox go-librespot[1350]: time="2025-05-17T18:42:27+02:00" level=debug msg="update volume to 48496/65535" May 17 18:42:27 jukebox go-librespot[1350]: time="2025-05-17T18:42:27+02:00" level=debug msg="update volume to 49151/65535" May 17 18:42:27 jukebox go-librespot[1350]: time="2025-05-17T18:42:27+02:00" level=debug msg="update volume to 49806/65535" May 17 18:42:28 jukebox go-librespot[1350]: time="2025-05-17T18:42:28+02:00" level=debug msg="update volume to 50462/65535" May 17 18:42:28 jukebox go-librespot[1350]: time="2025-05-17T18:42:28+02:00" level=debug msg="update volume to 51117/65535" May 17 18:42:28 jukebox go-librespot[1350]: time="2025-05-17T18:42:28+02:00" level=debug msg="update volume to 51773/65535" May 17 18:42:29 jukebox go-librespot[1350]: time="2025-05-17T18:42:29+02:00" level=debug msg="update volume to 52428/65535" May 17 18:42:29 jukebox go-librespot[1350]: time="2025-05-17T18:42:29+02:00" level=debug msg="update volume to 53083/65535" May 17 18:42:29 jukebox go-librespot[1350]: time="2025-05-17T18:42:29+02:00" level=debug msg="fetched chunk 8/14, size: 524288" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:30 jukebox go-librespot[1350]: time="2025-05-17T18:42:30+02:00" level=debug msg="update volume to 53739/65535" May 17 18:42:31 jukebox go-librespot[1350]: time="2025-05-17T18:42:31+02:00" level=debug msg="update volume to 54394/65535" May 17 18:42:31 jukebox go-librespot[1350]: time="2025-05-17T18:42:31+02:00" level=debug msg="update volume to 55049/65535" May 17 18:42:32 jukebox go-librespot[1350]: time="2025-05-17T18:42:32+02:00" level=debug msg="update volume to 55705/65535" May 17 18:42:32 jukebox go-librespot[1350]: time="2025-05-17T18:42:32+02:00" level=debug msg="update volume to 56360/65535" May 17 18:42:32 jukebox go-librespot[1350]: time="2025-05-17T18:42:32+02:00" level=debug msg="update volume to 57015/65535" May 17 18:42:33 jukebox go-librespot[1350]: time="2025-05-17T18:42:33+02:00" level=debug msg="update volume to 57671/65535" May 17 18:42:33 jukebox go-librespot[1350]: time="2025-05-17T18:42:33+02:00" level=debug msg="update volume to 58326/65535" May 17 18:42:34 jukebox go-librespot[1350]: time="2025-05-17T18:42:34+02:00" level=debug msg="update volume to 58981/65535" May 17 18:42:34 jukebox go-librespot[1350]: time="2025-05-17T18:42:34+02:00" level=debug msg="update volume to 60292/65535" May 17 18:42:34 jukebox go-librespot[1350]: time="2025-05-17T18:42:34+02:00" level=debug msg="update volume to 60947/65535" May 17 18:42:34 jukebox go-librespot[1350]: time="2025-05-17T18:42:34+02:00" level=debug msg="update volume to 61603/65535" May 17 18:42:35 jukebox go-librespot[1350]: time="2025-05-17T18:42:35+02:00" level=debug msg="update volume to 65535/65535" May 17 18:42:36 jukebox go-librespot[1350]: time="2025-05-17T18:42:36+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 17 18:42:36 jukebox go-librespot[1350]: time="2025-05-17T18:42:36+02:00" level=trace msg="emitting websocket event: volume" May 17 18:42:36 jukebox volumio[991]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 17 18:42:36 jukebox volumio[991]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 17 18:42:36 jukebox volumio[991]: info: Setting Volumio Volume from Spotify: 100 May 17 18:42:36 jukebox volumio[991]: info: VolumeController::SetAlsaVolume100 May 17 18:42:36 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:36 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:36 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:36 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:42:36 jukebox volumio[991]: SPOTIFY: SPOTIFY VOLUME 100 May 17 18:42:36 jukebox volumio[991]: SPOTIFY: VOLUMIO VOLUME 70 May 17 18:42:36 jukebox volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true May 17 18:42:36 jukebox volumio[991]: info: Setting Spotify Volume from Volumio: 70 May 17 18:42:37 jukebox volumio[991]: SPOTIFY: SETTING SPOTIFY VOLUME 70 May 17 18:42:37 jukebox volumio[991]: info: Sending Spotify command with payload to local API: /player/volume May 17 18:42:37 jukebox volumio[991]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request May 17 18:42:40 jukebox go-librespot[1350]: time="2025-05-17T18:42:40+02:00" level=debug msg="fetched chunk 9/14, size: 524288" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:43 jukebox go-librespot[1350]: time="2025-05-17T18:42:43+02:00" level=trace msg="received accesspoint ping" May 17 18:42:43 jukebox go-librespot[1350]: time="2025-05-17T18:42:43+02:00" level=trace msg="received accesspoint pong ack" May 17 18:42:43 jukebox go-librespot[1350]: time="2025-05-17T18:42:43+02:00" level=trace msg="sent dealer ping" May 17 18:42:43 jukebox go-librespot[1350]: time="2025-05-17T18:42:43+02:00" level=trace msg="received dealer pong" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=debug msg="handling seek_to player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=debug msg="seek track to 1648ms" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=debug msg="vorbis: corrupt or missing data in bitstream" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=trace msg="seek to 1648ms (diff: 19ms, samples: 72676, bytes: 60823)" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=trace msg="scheduling prefetch in 151s" May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=trace msg="emitting websocket event: seek" May 17 18:42:52 jukebox volumio[991]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","position":1648,"duration":182343,"play_origin":"playlist"}} May 17 18:42:52 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:42:52 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":1648,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:42:52 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:42:52 jukebox go-librespot[1350]: time="2025-05-17T18:42:52+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:42:52 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:42:52 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:42:52 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:42:52 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=debug msg="handling pause player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=debug msg="pause track at 9091ms" May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:00 jukebox go-librespot[1350]: time="2025-05-17T18:43:00+02:00" level=trace msg="emitting websocket event: paused" May 17 18:43:00 jukebox volumio[991]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","play_origin":"playlist"}} May 17 18:43:00 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:00 jukebox volumio[991]: SPOTIFY: {"status":"pause","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":9648,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:00 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:00 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:00 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:43:00 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:00 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:04 jukebox go-librespot[1350]: time="2025-05-17T18:43:04+02:00" level=debug msg="handling resume player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:43:04 jukebox go-librespot[1350]: time="2025-05-17T18:43:04+02:00" level=trace msg="seek to 9091ms (diff: 87ms, samples: 400913, bytes: 318224)" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - crossfeed jameier May 17 18:43:04 jukebox go-librespot[1350]: time="2025-05-17T18:43:04+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 17 18:43:04 jukebox go-librespot[1350]: time="2025-05-17T18:43:04+02:00" level=debug msg="resume track at 9004ms" May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - crossfeed jameier May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 18:43:04 jukebox volumio[991]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 18:43:05 jukebox go-librespot[1350]: time="2025-05-17T18:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:05 jukebox go-librespot[1350]: time="2025-05-17T18:43:05+02:00" level=trace msg="scheduling prefetch in 143s" May 17 18:43:05 jukebox go-librespot[1350]: time="2025-05-17T18:43:05+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:43:05 jukebox go-librespot[1350]: time="2025-05-17T18:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:05 jukebox go-librespot[1350]: time="2025-05-17T18:43:05+02:00" level=trace msg="emitting websocket event: playing" May 17 18:43:05 jukebox volumio[991]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","play_origin":"playlist"}} May 17 18:43:05 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:05 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":9648,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:05 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:05 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:05 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:43:05 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:05 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:05 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:05 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":9648,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:05 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:05 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:05 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:05 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=debug msg="handling seek_to player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=debug msg="seek track to 0ms" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=trace msg="seek to 0ms (diff: -213ms, samples: 0, bytes: 8893)" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=trace msg="scheduling prefetch in 152s" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=trace msg="emitting websocket event: seek" May 17 18:43:07 jukebox go-librespot[1350]: time="2025-05-17T18:43:07+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:43:07 jukebox volumio[991]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","position":0,"duration":182343,"play_origin":"playlist"}} May 17 18:43:07 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:07 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:07 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:07 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:07 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:43:07 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:07 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=debug msg="handling pause player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=debug msg="pause track at 1138ms" May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:08 jukebox go-librespot[1350]: time="2025-05-17T18:43:08+02:00" level=trace msg="emitting websocket event: paused" May 17 18:43:08 jukebox volumio[991]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","play_origin":"playlist"}} May 17 18:43:08 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:08 jukebox volumio[991]: SPOTIFY: {"status":"pause","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":1000,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:08 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:08 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:08 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:43:08 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:08 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="handling resume player command from d5ada6564a978a7c59fc3ed39672a024455f067d" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=trace msg="seek to 1138ms (diff: -27ms, samples: 50185, bytes: 44752)" uri="spotify:track:21bk4m2BIbuHZ6GKiPqFsG" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="resume track at 1165ms" May 17 18:43:09 jukebox volumio[991]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 18:43:09 jukebox volumio[991]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 18:43:09 jukebox volumio[991]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 18:43:09 jukebox volumio[991]: info: FusionDsp - crossfeed jameier May 17 18:43:09 jukebox volumio[991]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=trace msg="scheduling prefetch in 150s" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="sending successful reply for dealer request" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 17 18:43:09 jukebox go-librespot[1350]: time="2025-05-17T18:43:09+02:00" level=trace msg="emitting websocket event: playing" May 17 18:43:09 jukebox volumio[991]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","play_origin":"playlist"}} May 17 18:43:09 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:09 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":1000,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:09 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:09 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:09 jukebox volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 18:43:09 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:09 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:10 jukebox volumio[991]: SPOTIFY: PUSH STATE SPOTIFY May 17 18:43:10 jukebox volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"The Final Countdown 2025","artist":"David Guetta, Hypaton, Europe","album":"The Final Countdown 2025","albumart":"https://i.scdn.co/image/ab67616d00001e02fa291d8557adb1e61d2dfcc4","uri":"spotify:track:21bk4m2BIbuHZ6GKiPqFsG","trackType":"spotify","seek":1000,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":false,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 17 18:43:10 jukebox volumio[991]: info: CoreCommandRouter::servicePushState May 17 18:43:10 jukebox volumio[991]: info: CoreStateMachine::pushState May 17 18:43:10 jukebox volumio[991]: info: CoreCommandRouter::volumioPushState May 17 18:43:10 jukebox volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 17 18:43:13 jukebox go-librespot[1350]: time="2025-05-17T18:43:13+02:00" level=trace msg="sent dealer ping" May 17 18:43:13 jukebox go-librespot[1350]: time="2025-05-17T18:43:13+02:00" level=trace msg="received dealer pong" May 17 18:43:20 jukebox volumio[991]: info: [1747500200890] [80s80s] Pushing the next song state Tic Tac Toe - Ich find dich scheisse and getting next track. May 17 18:43:20 jukebox volumio[991]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 18:43:20 jukebox volumio[991]: TypeError: Cannot set property 'name' of undefined May 17 18:43:20 jukebox volumio[991]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) May 17 18:43:20 jukebox volumio[991]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) May 17 18:43:20 jukebox volumio[991]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) May 17 18:43:20 jukebox volumio[991]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) May 17 18:43:20 jukebox volumio[991]: at processImmediate (internal/timers.js:461:21) May 17 18:43:20 jukebox volumio[991]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 18:43:21 jukebox sudo[17550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-17 18:42 May 17 18:43:21 jukebox sudo[17550]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"