-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2024-07-18 12:28:19 CEST. -- Jul 18 12:27:00 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:01 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:02 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:03 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:04 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:05 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:06 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:07 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:08 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:08+02:00" level=debug msg="fetched chunk 4/22, size: 524288" Jul 18 12:27:08 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:09 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:10 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:12 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:13 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:14 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:14 ysfirenze volumio[824]: info: Jul 18 12:27:14 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:14 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:14 ysfirenze volumio[824]: info: Jul 18 12:27:14 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:14 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:14 ysfirenze volumio[824]: info: Jul 18 12:27:14 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:14 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:14 ysfirenze volumio[824]: info: Jul 18 12:27:14 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:14 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:14 ysfirenze volumio[824]: info: ------------------------------ 2ms Jul 18 12:27:14 ysfirenze volumio[824]: info: sendMpdCommand status took 1 milliseconds Jul 18 12:27:14 ysfirenze volumio[824]: info: ------------------------------ 1ms Jul 18 12:27:14 ysfirenze volumio[824]: info: sendMpdCommand status took 1 milliseconds Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:14 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:14 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:14 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:14 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:14 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:14 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:27:14 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:15 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:15 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:15 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:15 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:15 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:15 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:15 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:15 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:15 ysfirenze volumio[824]: info: ------------------------------ 25ms Jul 18 12:27:15 ysfirenze volumio[824]: info: ------------------------------ 25ms Jul 18 12:27:15 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:15 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:15 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:16 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:17 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:18 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:19 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:20 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:20 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:20+02:00" level=debug msg="fetched chunk 5/22, size: 524288" Jul 18 12:27:21 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:22 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:23 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:24 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:25 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:26 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:27 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:28 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:28 ysfirenze volumio[824]: info: Jul 18 12:27:28 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:28 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:28 ysfirenze volumio[824]: info: Jul 18 12:27:28 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:28 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:28 ysfirenze volumio[824]: info: Jul 18 12:27:28 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:28 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:28 ysfirenze volumio[824]: info: Jul 18 12:27:28 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:28 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:28 ysfirenze volumio[824]: info: ------------------------------ 3ms Jul 18 12:27:28 ysfirenze volumio[824]: info: sendMpdCommand status took 2 milliseconds Jul 18 12:27:28 ysfirenze volumio[824]: info: ------------------------------ 2ms Jul 18 12:27:28 ysfirenze volumio[824]: info: sendMpdCommand status took 1 milliseconds Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:28 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:28 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:28 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:28 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:28 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:28 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:28 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:28 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:28 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:28 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:29 ysfirenze volumio[824]: info: ------------------------------ 14ms Jul 18 12:27:29 ysfirenze volumio[824]: info: ------------------------------ 17ms Jul 18 12:27:29 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:29 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:29 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:30 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:31 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:32 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:33 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:33+02:00" level=debug msg="fetched chunk 6/22, size: 524288" Jul 18 12:27:33 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:34 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:35 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:36 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:37 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:38 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:39 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:40 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:41 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:42 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:44 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:44 ysfirenze volumio[824]: info: Jul 18 12:27:44 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:44 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:44 ysfirenze volumio[824]: info: Jul 18 12:27:44 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:44 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:44 ysfirenze volumio[824]: info: Jul 18 12:27:44 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:44 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:44 ysfirenze volumio[824]: info: Jul 18 12:27:44 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:44 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:44 ysfirenze volumio[824]: info: ------------------------------ 3ms Jul 18 12:27:44 ysfirenze volumio[824]: info: sendMpdCommand status took 2 milliseconds Jul 18 12:27:44 ysfirenze volumio[824]: info: ------------------------------ 3ms Jul 18 12:27:44 ysfirenze volumio[824]: info: sendMpdCommand status took 2 milliseconds Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:44 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:44 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:44 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:44 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:44 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:44 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:44 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:44 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:44 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:44 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:44 ysfirenze volumio[824]: info: ------------------------------ 22ms Jul 18 12:27:44 ysfirenze volumio[824]: info: ------------------------------ 20ms Jul 18 12:27:44 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:44 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:45 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:45 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:45+02:00" level=debug msg="handling play_as_next_in_queue player command from a2ee9257d09c5850173f0f5d7dfa143d07863d3c" Jul 18 12:27:45 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:45+02:00" level=warning msg="failed handling dealer request" error="unsupported player command: play_as_next_in_queue" Jul 18 12:27:46 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:46 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:46+02:00" level=debug msg="fetched chunk 7/22, size: 524288" Jul 18 12:27:47 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:48 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:49 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:50 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:51 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:52 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:53 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:54 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:55 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=debug msg="handling play player command from a2ee9257d09c5850173f0f5d7dfa143d07863d3c" Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=trace msg="fetched new page 0 with 25 items (list: 25)" Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=debug msg="loading track spotify:track:4LJqP6p2Q9orOaqwyjSupj (paused: false, position: 213ms)" Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=trace msg="emitting websocket event: will_play" Jul 18 12:27:55 ysfirenze volumio[824]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","play_origin":"playlist"}} Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4LJqP6p2Q9orOaqwyjSupj" Jul 18 12:27:55 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:55+02:00" level=debug msg="requested aes key for file 37b1aaeaff6997d0d81205853ab7b0671eb2d473, gid: 4LJqP6p2Q9orOaqwyjSupj" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="fetched first chunk of 18, total size is 8920600 bytes" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=trace msg="seek to 213ms (diff: 213ms, samples: 9393, bytes: 0)" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=info msg="loaded track \"Lontano dagli occhi\" (uri: spotify:track:4LJqP6p2Q9orOaqwyjSupj, paused: false, position: 213ms, duration: 225813ms)" Jul 18 12:27:56 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="fetched chunk 3/17, size: 524288" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="fetched chunk 2/17, size: 524288" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=trace msg="emitting websocket event: metadata" Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","name":"Lontano dagli occhi","artist_names":["Sergio Endrigo"],"album_name":"I Grandi Successi: Sergio Endrigo","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02de3953e7e72234b5d276bed4","position":213,"duration":225813,"release_date":"year:2008 month:9 day:5","track_number":1,"disc_number":1}} Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="sending successful reply for delaer request" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="fetched chunk 1/17, size: 524288" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 18 12:27:56 ysfirenze go-librespot[1411]: time="2024-07-18T12:27:56+02:00" level=trace msg="emitting websocket event: playing" Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","play_origin":"playlist"}} Jul 18 12:27:56 ysfirenze volumio[824]: info: Spotify is playing in volatile mode Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: UNSET VOLATILE Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: {"status":"play","title":"All about Dance before 2000!","artist":null,"album":null,"albumart":"/albumart","uri":"https://retro.dancewave.online:443/retrodance.mp3","trackType":"mp3","codec":"","seek":84226,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"repeat":false,"consume":false,"volume":55,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true} Jul 18 12:27:56 ysfirenze volumio[824]: info: Setting Spotify stop after unset volatile call Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: PUSH STATE SPOTIFY Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: {"status":"play","service":"spop","title":"Lontano dagli occhi","artist":"Sergio Endrigo","album":"I Grandi Successi: Sergio Endrigo","albumart":"https://i.scdn.co/image/ab67616d00001e02de3953e7e72234b5d276bed4","uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","trackType":"spotify","seek":1213,"duration":225,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:56 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:56 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: PUSH STATE SPOTIFY Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: {"status":"play","service":"spop","title":"Lontano dagli occhi","artist":"Sergio Endrigo","album":"I Grandi Successi: Sergio Endrigo","albumart":"https://i.scdn.co/image/ab67616d00001e02de3953e7e72234b5d276bed4","uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","trackType":"spotify","seek":1213,"duration":225,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:56 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:56 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:56 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:56 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:57 ysfirenze volumio[824]: info: Spotify Stop Jul 18 12:27:57 ysfirenze volumio[824]: SPOTIFY: SPOTIFY STOP Jul 18 12:27:57 ysfirenze volumio[824]: SPOTIFY: {"status":"play","title":"Lontano dagli occhi","artist":"Sergio Endrigo","album":"I Grandi Successi: Sergio Endrigo","albumart":"https://i.scdn.co/image/ab67616d00001e02de3953e7e72234b5d276bed4","uri":"spotify:track:4LJqP6p2Q9orOaqwyjSupj","trackType":"spotify","codec":"ogg","seek":1213,"duration":225,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":55,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jul 18 12:27:57 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:58 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:27:59 ysfirenze volumio[824]: info: Jul 18 12:27:59 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:59 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:59 ysfirenze volumio[824]: info: Jul 18 12:27:59 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:59 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:59 ysfirenze volumio[824]: info: Jul 18 12:27:59 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:27:59 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:27:59 ysfirenze volumio[824]: info: Jul 18 12:27:59 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:27:59 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:27:59 ysfirenze volumio[824]: info: ------------------------------ 2ms Jul 18 12:27:59 ysfirenze volumio[824]: info: sendMpdCommand status took 2 milliseconds Jul 18 12:27:59 ysfirenze volumio[824]: info: ------------------------------ 2ms Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:59 ysfirenze volumio[824]: info: sendMpdCommand status took 1 milliseconds Jul 18 12:27:59 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:59 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:59 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:59 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:59 ysfirenze volumio[824]: info: ------------------------------ 23ms Jul 18 12:27:59 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 20 milliseconds Jul 18 12:27:59 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:27:59 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:27:59 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:27:59 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:27:59 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:27:59 ysfirenze volumio[824]: info: ------------------------------ 33ms Jul 18 12:27:59 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:59 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:27:59 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:00 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:01 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:02 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:03 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:04 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:05 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:06 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:07 ysfirenze go-librespot[1411]: time="2024-07-18T12:28:07+02:00" level=debug msg="fetched chunk 4/17, size: 524288" Jul 18 12:28:07 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:08 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:09 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:10 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:11 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:12 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:14 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:14 ysfirenze volumio[824]: info: Jul 18 12:28:14 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:28:14 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:28:14 ysfirenze volumio[824]: info: Jul 18 12:28:14 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:28:14 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:28:14 ysfirenze volumio[824]: info: Jul 18 12:28:14 ysfirenze volumio[824]: ---------------------------- MPD announces system playlist update Jul 18 12:28:14 ysfirenze volumio[824]: info: Ignoring MPD Status Update Jul 18 12:28:14 ysfirenze volumio[824]: info: Jul 18 12:28:14 ysfirenze volumio[824]: ---------------------------- MPD announces state update: player Jul 18 12:28:14 ysfirenze volumio[824]: info: ControllerMpd::getState Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand status Jul 18 12:28:14 ysfirenze volumio[824]: info: ------------------------------ 3ms Jul 18 12:28:14 ysfirenze volumio[824]: info: sendMpdCommand status took 2 milliseconds Jul 18 12:28:14 ysfirenze volumio[824]: info: ------------------------------ 1ms Jul 18 12:28:14 ysfirenze volumio[824]: info: sendMpdCommand status took 1 milliseconds Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseState Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 12:28:14 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 12:28:14 ysfirenze volumio[824]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:28:14 ysfirenze volumio[824]: verbose: ControllerMpd::parseTrackInfo Jul 18 12:28:14 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:28:14 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:28:14 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:28:14 ysfirenze volumio[824]: info: ControllerMpd::pushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreCommandRouter::servicePushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreStateMachine::pushState Jul 18 12:28:14 ysfirenze volumio[824]: info: CoreCommandRouter::volumioPushState Jul 18 12:28:14 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output update for this device Jul 18 12:28:14 ysfirenze volumio[824]: info: MRS: Pushing multiroomSync output Jul 18 12:28:14 ysfirenze volumio[824]: info: ------------------------------ 16ms Jul 18 12:28:14 ysfirenze volumio[824]: info: ------------------------------ 20ms Jul 18 12:28:14 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:28:14 ysfirenze volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Jul 18 12:28:15 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:16 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:17 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:18 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:18 ysfirenze go-librespot[1411]: time="2024-07-18T12:28:18+02:00" level=debug msg="fetched chunk 5/17, size: 524288" Jul 18 12:28:19 ysfirenze volumio[824]: error: MyVolumio MQTT error: Error: Cannot parse topic Jul 18 12:28:19 ysfirenze volumio[824]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Jul 18 12:28:19 ysfirenze volumio[824]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Jul 18 12:28:19 ysfirenze volumio[824]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 12:28:19 ysfirenze volumio[824]: TypeError: Cannot read property 'then' of undefined Jul 18 12:28:19 ysfirenze volumio[824]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Jul 18 12:28:19 ysfirenze volumio[824]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30) Jul 18 12:28:19 ysfirenze volumio[824]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1435:26) Jul 18 12:28:19 ysfirenze volumio[824]: at Socket.emit (events.js:400:28) Jul 18 12:28:19 ysfirenze volumio[824]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 18 12:28:19 ysfirenze volumio[824]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jul 18 12:28:19 ysfirenze volumio[824]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 12:28:19 ysfirenze sudo[5165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-18 12:27 Jul 18 12:28:19 ysfirenze sudo[5165]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:59:47 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="5afa2cba9d125c5d0103869143516973"