-- Logs begin at Thu 2019-02-14 17:11:58 +07, end at Sun 2025-10-26 16:36:32 +07. -- Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::pause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::servicePause Oct 26 16:35:06 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::servicePause Oct 26 16:35:06 volumio3 volumio[1104]: info: [1761471306294] ControllerQobuz::pause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::pause Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand pause Oct 26 16:35:06 volumio3 volumio[1104]: info: Oct 26 16:35:06 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand pause took 2 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:06 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":29766,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"797 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:06 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService pause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:06 volumio3 volumio[1104]: info: ------------------------------ 10ms Oct 26 16:35:06 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:06 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:35:06 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:06 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:06 volumio3 volumio[1104]: info: [1761471306574] ControllerQobuz::resume Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::resume Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:35:06 volumio3 volumio[1104]: info: Oct 26 16:35:06 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand play took 118 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:06 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:35:06 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:06 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:06 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":30590,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"830 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:06 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:06 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:06 volumio3 volumio[1104]: info: ------------------------------ 5ms Oct 26 16:35:06 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:06 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:35:07 volumio3 volumio[1104]: info: peppy_screensaver: Start PeppyMeter Oct 26 16:35:12 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 16:35:12 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:14 volumio3 go-librespot[14096]: time="2025-10-26T16:35:14+07:00" level=trace msg="sent dealer ping" Oct 26 16:35:14 volumio3 go-librespot[14096]: time="2025-10-26T16:35:14+07:00" level=trace msg="received dealer pong" Oct 26 16:35:15 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:35:15 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioSeek Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::seek Oct 26 16:35:19 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:19 volumio3 volumio[1104]: info: TRACKBLOCK {"album":"หอมดินกลิ่นทุ่ง","albumUri":"qobuz://album/e4al0yaap366a","albumart":"https://static.qobuz.com/images/covers/6a/36/e4al0yaap366a_600.jpg","artist":"เทียรี่","artistUri":"qobuz://artist/22945920","audioQuality":"","duration":258,"explicit":false,"name":"ร้องไห้กับเดือน","service":"qobuz","title":"ร้องไห้กับเดือน","tracknumber":10,"type":"track","uri":"qobuz://song/276569726","volumeNumber":1,"tagImage":""} Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:19 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:19 volumio3 volumio[1104]: info: [1761471319179] ControllerQobuz::seek Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:19 volumio3 volumio[1104]: info: ControllerMpd::seek Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:19 volumio3 volumio[1104]: error: null Oct 26 16:35:19 volumio3 volumio[1104]: info: Oct 26 16:35:19 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:19 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:19 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:19 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:19 volumio3 volumio[1104]: info: sendMpdCommand status took 5 milliseconds Oct 26 16:35:19 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:19 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:19 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:35:19 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:19 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:19 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":228709,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"856 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:19 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:35:19 volumio3 volumio[1104]: info: Received an update from plugin. extracting info from payload Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:19 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:19 volumio3 volumio[1104]: info: ------------------------------ 13ms Oct 26 16:35:19 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:19 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPause Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::pause Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::servicePause Oct 26 16:35:22 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::servicePause Oct 26 16:35:22 volumio3 volumio[1104]: info: [1761471322702] ControllerQobuz::pause Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:22 volumio3 volumio[1104]: info: ControllerMpd::pause Oct 26 16:35:22 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand pause Oct 26 16:35:22 volumio3 volumio[1104]: info: Oct 26 16:35:22 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:22 volumio3 volumio[1104]: info: sendMpdCommand pause took 1 milliseconds Oct 26 16:35:22 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:22 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:22 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:22 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:22 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:22 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:22 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:22 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:22 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:22 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":232141,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"869 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:22 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService pause Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:22 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:22 volumio3 volumio[1104]: info: ------------------------------ 5ms Oct 26 16:35:22 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:22 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:35:23 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:23 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:23 volumio3 volumio[1104]: info: [1761471323006] ControllerQobuz::resume Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:23 volumio3 volumio[1104]: info: ControllerMpd::resume Oct 26 16:35:23 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:35:23 volumio3 volumio[1104]: info: Oct 26 16:35:23 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:23 volumio3 volumio[1104]: info: sendMpdCommand play took 134 milliseconds Oct 26 16:35:23 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:23 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:23 volumio3 volumio[1104]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:35:23 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:23 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:23 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:23 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:23 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:23 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:23 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":232964,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"888 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:23 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:23 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:23 volumio3 volumio[1104]: info: ------------------------------ 10ms Oct 26 16:35:23 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:23 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:35:23 volumio3 volumio[1104]: info: peppy_screensaver: Start PeppyMeter Oct 26 16:35:28 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 16:35:28 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:31 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:35:31 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::pause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::servicePause Oct 26 16:35:34 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::servicePause Oct 26 16:35:34 volumio3 volumio[1104]: info: [1761471334463] ControllerQobuz::pause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::pause Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand pause Oct 26 16:35:34 volumio3 volumio[1104]: info: Oct 26 16:35:34 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand pause took 0 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:34 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":244290,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"993 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:34 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService pause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:34 volumio3 volumio[1104]: info: ------------------------------ 5ms Oct 26 16:35:34 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:34 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:35:34 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:34 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:34 volumio3 volumio[1104]: info: [1761471334783] ControllerQobuz::resume Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::resume Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:35:34 volumio3 volumio[1104]: info: Oct 26 16:35:34 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand play took 134 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:34 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:34 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:34 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:34 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":245114,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"921 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:34 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:34 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:34 volumio3 volumio[1104]: info: ------------------------------ 6ms Oct 26 16:35:34 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:34 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:35:35 volumio3 volumio[1104]: info: peppy_screensaver: Start PeppyMeter Oct 26 16:35:40 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 16:35:40 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:43 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:35:43 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:44 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:44 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:44 volumio3 volumio[1104]: info: Prefetching next song Oct 26 16:35:44 volumio3 volumio[1104]: info: [1761471344545] ControllerQobuz::prefetch Oct 26 16:35:44 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/35505205" Oct 26 16:35:44 volumio3 volumio[1104]: STREAMING PROXY: Handling url /?data=qobuz://song/35505205 Oct 26 16:35:44 volumio3 volumio[1104]: info: Executing endpoint getStreamUrlqobuz Oct 26 16:35:44 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 26 16:35:44 volumio3 go-librespot[14096]: time="2025-10-26T16:35:44+07:00" level=trace msg="sent dealer ping" Oct 26 16:35:44 volumio3 go-librespot[14096]: time="2025-10-26T16:35:44+07:00" level=trace msg="received dealer pong" Oct 26 16:35:44 volumio3 volumio[1104]: info: getStreamUrl took 423 milliseconds Oct 26 16:35:44 volumio3 volumio[1104]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7738624&eid=35505205&fmt=6&profile=raw&app_id=539451548&cid=3184879&etsp=1761474944&hmac=82e_qDc-MMEYDenJrIpYGw8fyps Oct 26 16:35:46 volumio3 volumio[1104]: STREAMING PROXY: Response: 200, length: 11233049 Oct 26 16:35:46 volumio3 volumio[1104]: STREAMING PROXY: Client dropped request, destroying Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/35505205" Oct 26 16:35:46 volumio3 volumio[1104]: info: Oct 26 16:35:46 volumio3 volumio[1104]: ---------------------------- MPD announces system playlist update Oct 26 16:35:46 volumio3 volumio[1104]: info: Ignoring MPD Status Update Oct 26 16:35:46 volumio3 volumio[1104]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/35505205" took 0 milliseconds Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 26 16:35:46 volumio3 volumio[1104]: STREAMING PROXY: Handling url /?data=qobuz://song/35505205 Oct 26 16:35:46 volumio3 volumio[1104]: info: Oct 26 16:35:46 volumio3 volumio[1104]: ---------------------------- MPD announces state update: options Oct 26 16:35:46 volumio3 volumio[1104]: info: ------------------------------ 1ms Oct 26 16:35:46 volumio3 volumio[1104]: info: sendMpdCommand consume 1 took 0 milliseconds Oct 26 16:35:46 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:46 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:46 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:46 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:46 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:46 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":256828,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:35:46 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:35:46 volumio3 volumio[1104]: info: Received an update from plugin. extracting info from payload Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:46 volumio3 volumio[1104]: info: ------------------------------ 10ms Oct 26 16:35:46 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:46 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:46 volumio3 volumio[1104]: info: Executing endpoint getStreamUrlqobuz Oct 26 16:35:46 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 26 16:35:47 volumio3 volumio[1104]: info: getStreamUrl took 472 milliseconds Oct 26 16:35:47 volumio3 volumio[1104]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7738624&eid=35505205&fmt=6&profile=raw&app_id=539451548&cid=3184879&etsp=1761474946&hmac=Il3CrxLahGj6KrSgX_4qTdmOtiU Oct 26 16:35:47 volumio3 volumio[1104]: STREAMING PROXY: Response: 200, length: 11233049 Oct 26 16:35:48 volumio3 volumio[1104]: STREAMING PROXY: Client dropped request, destroying Oct 26 16:35:48 volumio3 volumio[1104]: info: Oct 26 16:35:48 volumio3 volumio[1104]: ---------------------------- MPD announces system playlist update Oct 26 16:35:48 volumio3 volumio[1104]: info: Ignoring MPD Status Update Oct 26 16:35:48 volumio3 volumio[1104]: info: Oct 26 16:35:48 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:48 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:48 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:48 volumio3 volumio[1104]: info: ------------------------------ 1ms Oct 26 16:35:48 volumio3 volumio[1104]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:35:48 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:48 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:48 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:48 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:48 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:35:48 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":128,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"330 Kbps","isStreaming":false,"title":"35505205","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/35505205","trackType":"qobuz"} Oct 26 16:35:48 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:35:48 volumio3 volumio[1104]: info: Received an update from plugin. extracting info from payload Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:48 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:48 volumio3 volumio[1104]: info: ------------------------------ 7ms Oct 26 16:35:48 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:48 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:49 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPrevious Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::previous Oct 26 16:35:49 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:49 volumio3 volumio[1104]: info: [1761471349199] ControllerQobuz::seek Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:49 volumio3 volumio[1104]: info: ControllerMpd::seek Oct 26 16:35:49 volumio3 volumio[1104]: error: null Oct 26 16:35:49 volumio3 volumio[1104]: info: Oct 26 16:35:49 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:49 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:49 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:49 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:49 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:49 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:49 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:49 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:49 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:49 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":128,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"330 Kbps","isStreaming":false,"title":"35505205","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/35505205","trackType":"qobuz"} Oct 26 16:35:49 volumio3 volumio[1104]: verbose: CURRENT POSITION 2 Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:35:49 volumio3 volumio[1104]: info: Received an update from plugin. extracting info from payload Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:49 volumio3 volumio[1104]: info: ------------------------------ 8ms Oct 26 16:35:49 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:49 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:49 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:49 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:51 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:35:51 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:35:51 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:35:51 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:35:51 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:35:51 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:35:51 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:35:51 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPause Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::pause Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::servicePause Oct 26 16:35:55 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::servicePause Oct 26 16:35:55 volumio3 volumio[1104]: info: [1761471355883] ControllerQobuz::pause Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:55 volumio3 volumio[1104]: info: ControllerMpd::pause Oct 26 16:35:55 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand pause Oct 26 16:35:55 volumio3 volumio[1104]: info: Oct 26 16:35:55 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:55 volumio3 volumio[1104]: info: sendMpdCommand pause took 1 milliseconds Oct 26 16:35:55 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:55 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:55 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:35:55 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:55 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:55 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:35:55 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:55 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:55 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:55 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":7298,"duration":128,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"705 Kbps","isStreaming":false,"title":"35505205","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/35505205","trackType":"qobuz"} Oct 26 16:35:55 volumio3 volumio[1104]: verbose: CURRENT POSITION 2 Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService pause Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:55 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:35:55 volumio3 volumio[1104]: info: ------------------------------ 4ms Oct 26 16:35:55 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:55 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:35:56 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:35:56 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:56 volumio3 volumio[1104]: info: [1761471356176] ControllerQobuz::resume Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:35:56 volumio3 volumio[1104]: info: ControllerMpd::resume Oct 26 16:35:56 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:35:56 volumio3 volumio[1104]: info: Oct 26 16:35:56 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:35:56 volumio3 volumio[1104]: info: sendMpdCommand play took 118 milliseconds Oct 26 16:35:56 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:35:56 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:35:56 volumio3 volumio[1104]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:35:56 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:35:56 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:35:56 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:35:56 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:35:56 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:35:56 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:35:56 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":8122,"duration":128,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"669 Kbps","isStreaming":false,"title":"35505205","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/35505205","trackType":"qobuz"} Oct 26 16:35:56 volumio3 volumio[1104]: verbose: CURRENT POSITION 2 Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:35:56 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:35:56 volumio3 volumio[1104]: info: ------------------------------ 7ms Oct 26 16:35:56 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:35:56 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:35:57 volumio3 volumio[1104]: info: peppy_screensaver: Start PeppyMeter Oct 26 16:36:00 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:01 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 16:36:01 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:02 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::play index 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::stop Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::updateTrackBlock Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrackBlock Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::serviceStop Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 2 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::serviceStop Oct 26 16:36:02 volumio3 volumio[1104]: info: [1761471362278] ControllerQobuz::stop Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:36:02 volumio3 volumio[1104]: info: ControllerMpd::stop Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand stop Oct 26 16:36:02 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:02 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:36:02 volumio3 volumio[1104]: info: Oct 26 16:36:02 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand stop took 129 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: [1761471362408] ControllerQobuz::clearAddPlayTrack Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand stop Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand stop took 0 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand clear Oct 26 16:36:02 volumio3 volumio[1104]: info: Oct 26 16:36:02 volumio3 volumio[1104]: ---------------------------- MPD announces system playlist update Oct 26 16:36:02 volumio3 volumio[1104]: info: Ignoring MPD Status Update Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand clear took 1 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/276569726" Oct 26 16:36:02 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:02 volumio3 volumio[1104]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 26 16:36:02 volumio3 volumio[1104]: STREAMING PROXY: Handling url /?data=qobuz://song/276569726 Oct 26 16:36:02 volumio3 volumio[1104]: info: ------------------------------ 10ms Oct 26 16:36:02 volumio3 volumio[1104]: error: updateQueue error: null Oct 26 16:36:02 volumio3 volumio[1104]: info: ------------------------------ 9ms Oct 26 16:36:02 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:02 volumio3 volumio[1104]: info: Executing endpoint getStreamUrlqobuz Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 26 16:36:02 volumio3 volumio[1104]: info: getStreamUrl took 370 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7738624&eid=276569726&fmt=6&profile=raw&app_id=539451548&cid=3184879&etsp=1761474962&hmac=HD8H2eAnFIbPjaq9x8QbaZhMJRY Oct 26 16:36:02 volumio3 volumio[1104]: STREAMING PROXY: Response: 200, length: 28189917 Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/276569726" Oct 26 16:36:02 volumio3 volumio[1104]: info: Oct 26 16:36:02 volumio3 volumio[1104]: ---------------------------- MPD announces system playlist update Oct 26 16:36:02 volumio3 volumio[1104]: info: Ignoring MPD Status Update Oct 26 16:36:02 volumio3 volumio[1104]: STREAMING PROXY: Client dropped request, destroying Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/276569726" took 1 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:36:02 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:36:02 volumio3 volumio[1104]: info: ------------------------------ 4ms Oct 26 16:36:02 volumio3 volumio[1104]: info: sendMpdCommand play took 3 milliseconds Oct 26 16:36:02 volumio3 volumio[1104]: STREAMING PROXY: Handling url /?data=qobuz://song/276569726 Oct 26 16:36:02 volumio3 volumio[1104]: info: Executing endpoint getStreamUrlqobuz Oct 26 16:36:02 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 26 16:36:03 volumio3 volumio[1104]: info: getStreamUrl took 367 milliseconds Oct 26 16:36:03 volumio3 volumio[1104]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7738624&eid=276569726&fmt=6&profile=raw&app_id=539451548&cid=3184879&etsp=1761474963&hmac=Xq4NCGT0yYi3_p5xuaj5erLFjnY Oct 26 16:36:03 volumio3 volumio[1104]: STREAMING PROXY: Response: 200, length: 28189917 Oct 26 16:36:03 volumio3 volumio[1104]: info: Oct 26 16:36:03 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:36:03 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:36:03 volumio3 volumio[1104]: info: Oct 26 16:36:03 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:36:03 volumio3 volumio[1104]: info: sendMpdCommand status took 116 milliseconds Oct 26 16:36:03 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:36:03 volumio3 volumio[1104]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:36:03 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:36:03 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:03 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:36:03 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus stop Oct 26 16:36:03 volumio3 volumio[1104]: info: ------------------------------ 119ms Oct 26 16:36:03 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 26 16:36:03 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:36:03 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:03 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":709,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"690 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:36:03 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:36:03 volumio3 volumio[1104]: info: Received an update from plugin. extracting info from payload Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:03 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:03 volumio3 volumio[1104]: info: ------------------------------ 9ms Oct 26 16:36:03 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:03 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:03 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:36:03 volumio3 volumio[1104]: STREAMING PROXY: Client dropped request, destroying Oct 26 16:36:04 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:04 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:04 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:04 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:04 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:04 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:04 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:36:04 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:05 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 12 Oct 26 16:36:05 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::pause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::servicePause Oct 26 16:36:08 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::servicePause Oct 26 16:36:08 volumio3 volumio[1104]: info: [1761471368235] ControllerQobuz::pause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::pause Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand pause Oct 26 16:36:08 volumio3 volumio[1104]: info: Oct 26 16:36:08 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand pause took 2 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:08 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5536,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"722 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:36:08 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService pause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:36:08 volumio3 volumio[1104]: info: ------------------------------ 6ms Oct 26 16:36:08 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:08 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 5 seconds. Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPlay Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::play index undefined Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:36:08 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:36:08 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:08 volumio3 volumio[1104]: info: [1761471368613] ControllerQobuz::resume Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::resume Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:36:08 volumio3 volumio[1104]: info: Oct 26 16:36:08 volumio3 volumio[1104]: ---------------------------- MPD announces state update: player Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand play took 129 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::getState Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand status took 0 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::parseState Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:36:08 volumio3 volumio[1104]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 26 16:36:08 volumio3 volumio[1104]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:36:08 volumio3 volumio[1104]: info: ControllerMpd::pushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::servicePushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CorePlayQueue::getTrack 1 Oct 26 16:36:08 volumio3 volumio[1104]: verbose: STATE SERVICE {"status":"play","position":0,"seek":6360,"duration":259,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"930 Kbps","isStreaming":false,"title":"276569726","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/276569726","trackType":"qobuz"} Oct 26 16:36:08 volumio3 volumio[1104]: verbose: CURRENT POSITION 1 Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::syncState stateService play Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::syncState currentStatus pause Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreStateMachine::pushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioPushState Oct 26 16:36:08 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:08 volumio3 volumio[1104]: info: ------------------------------ 7ms Oct 26 16:36:08 volumio3 volumio[1104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 26 16:36:08 volumio3 volumio[1104]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 26 16:36:09 volumio3 volumio[1104]: info: peppy_screensaver: Start PeppyMeter Oct 26 16:36:14 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 16:36:14 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:14 volumio3 go-librespot[14096]: time="2025-10-26T16:36:14+07:00" level=trace msg="received accesspoint ping" Oct 26 16:36:14 volumio3 go-librespot[14096]: time="2025-10-26T16:36:14+07:00" level=trace msg="received accesspoint pong ack" Oct 26 16:36:14 volumio3 go-librespot[14096]: time="2025-10-26T16:36:14+07:00" level=trace msg="sent dealer ping" Oct 26 16:36:14 volumio3 go-librespot[14096]: time="2025-10-26T16:36:14+07:00" level=trace msg="received dealer pong" Oct 26 16:36:17 volumio3 volumio[1104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 26 16:36:17 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:26 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetState Oct 26 16:36:28 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:28 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:28 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:28 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:28 volumio3 volumio[1104]: info: Executing endpoint metavolumio Oct 26 16:36:28 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: Retrieving Cloud Streaming UI Oct 26 16:36:30 volumio3 volumio[1104]: info: Getting Tidal Cloud Configuration Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: Getting Qobuz Cloud Configuration Oct 26 16:36:30 volumio3 volumio[1104]: info: Asking plugin for UI Config Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: Getting Spotify Cloud Configuration Oct 26 16:36:30 volumio3 volumio[1104]: info: Asking plugin for UI Config Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: Saving Spotify Acccount Oct 26 16:36:30 volumio3 volumio[1104]: info: Got it Oct 26 16:36:30 volumio3 volumio[1104]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 26 16:36:30 volumio3 volumio[1104]: info: Got Tidal Cloud Configuration Oct 26 16:36:30 volumio3 volumio[1104]: info: Got it Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 16:36:30 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 26 16:36:32 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Oct 26 16:36:32 volumio3 volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Oct 26 16:36:32 volumio3 volumio[1104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 16:36:32 volumio3 volumio[1104]: Error: getaddrinfo -3007 Oct 26 16:36:32 volumio3 volumio[1104]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Oct 26 16:36:32 volumio3 volumio[1104]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Oct 26 16:36:32 volumio3 volumio[1104]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Oct 26 16:36:32 volumio3 volumio[1104]: code: -3007, Oct 26 16:36:32 volumio3 volumio[1104]: errno: -3007, Oct 26 16:36:32 volumio3 volumio[1104]: syscall: 'getaddrinfo' Oct 26 16:36:32 volumio3 volumio[1104]: } Oct 26 16:36:32 volumio3 volumio[1104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 16:36:32 volumio3 sudo[15126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-26 16:35 Oct 26 16:36:32 volumio3 sudo[15126]: 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="5d50cd80bebce60dddccd7f5e813d656e28ca4cd" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7840f283c310c38bfe939a4c485727a6ff6a0ce1" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 21 Oct 2025 03:46:47 PM CEST" VOLUMIO_VERSION="3.866" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e2f3a8aca3147ba51b5da8167dd6ff8"