-- Logs begin at Thu 2019-02-14 14:11:59 +04, end at Fri 2025-10-17 19:50:05 +04. -- Oct 17 19:49:00 sw1x-vdtii volumio[663]: info: getStreamUrl took 754 milliseconds Oct 17 19:49:00 sw1x-vdtii volumio[663]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7352552&eid=348512517&fmt=7&profile=raw&app_id=539451548&cid=3107506&etsp=1760719740&hmac=-tAvO8su24p_3KSEEYXdiBkjiik Oct 17 19:49:00 sw1x-vdtii ntpd[631]: Soliciting pool server 89.36.162.11 Oct 17 19:49:00 sw1x-vdtii ntpd[631]: Soliciting pool server 47.91.111.180 Oct 17 19:49:00 sw1x-vdtii ntpd[631]: Soliciting pool server 47.91.111.180 Oct 17 19:49:01 sw1x-vdtii volumio[663]: STREAMING PROXY: Response: 200, length: 12812988 Oct 17 19:49:01 sw1x-vdtii volumio[663]: STREAMING PROXY: Client dropped request, destroying Oct 17 19:49:01 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/348512517" Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: Oct 17 19:49:01 sw1x-vdtii volumio[663]: ---------------------------- MPD announces system playlist update Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: Ignoring MPD Status Update Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/348512517" took 4 milliseconds Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 17 19:49:01 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand play Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: ------------------------------ 7ms Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: sendMpdCommand play took 5 milliseconds Oct 17 19:49:01 sw1x-vdtii volumio[663]: STREAMING PROXY: Handling url /?data=qobuz://song/348512517 Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: Executing endpoint getStreamUrlqobuz Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 17 19:49:01 sw1x-vdtii ntpd[631]: Soliciting pool server 2001:ac8:81:65:0:2:0:3 Oct 17 19:49:01 sw1x-vdtii volumio[663]: info: getStreamUrl took 690 milliseconds Oct 17 19:49:01 sw1x-vdtii volumio[663]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=7352552&eid=348512517&fmt=7&profile=raw&app_id=539451548&cid=3107506&etsp=1760719742&hmac=YB4ubQ8y_5kIVaq42uTlLJOvl0U Oct 17 19:49:02 sw1x-vdtii volumio[663]: STREAMING PROXY: Response: 200, length: 12812988 Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: Oct 17 19:49:02 sw1x-vdtii volumio[663]: ---------------------------- MPD announces state update: player Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ControllerMpd::getState Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand status Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: Oct 17 19:49:02 sw1x-vdtii volumio[663]: ---------------------------- MPD announces state update: player Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: sendMpdCommand status took 29 milliseconds Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ControllerMpd::getState Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand status Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::parseState Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: sendMpdCommand status took 21 milliseconds Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: sendMpdCommand playlistinfo took 19 milliseconds Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::parseState Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::parseTrackInfo Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ControllerMpd::pushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::servicePushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CorePlayQueue::getTrack 0 Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":215,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348512517","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348512517","trackType":"qobuz"} Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: CURRENT POSITION 0 Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::syncState stateService play Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::syncState currentStatus stop Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ------------------------------ 85ms Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: ControllerMpd::parseTrackInfo Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ControllerMpd::pushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::servicePushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CorePlayQueue::getTrack 0 Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":147,"duration":215,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"264 Kbps","isStreaming":false,"title":"348512517","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348512517","trackType":"qobuz"} Oct 17 19:49:02 sw1x-vdtii volumio[663]: verbose: CURRENT POSITION 0 Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::syncState stateService play Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::syncState currentStatus play Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: Received an update from plugin. extracting info from payload Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::pushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioPushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: MRS: Pushing multiroomSync output update for this device Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: MRS: Pushing multiroomSync output Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioGetState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreStateMachine::pushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioPushState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: MRS: Pushing multiroomSync output update for this device Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: MRS: Pushing multiroomSync output Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioGetState Oct 17 19:49:02 sw1x-vdtii volumio[663]: info: ------------------------------ 180ms Oct 17 19:49:04 sw1x-vdtii volumio[663]: STREAMING PROXY: Client dropped request, destroying Oct 17 19:49:08 sw1x-vdtii ntpd[631]: receive: Unexpected origin timestamp 0xec9ce3f3.828c6f76 does not match aorg 0000000000.00000000 from server@47.91.111.180 xmt 0xec9ce3f4.5fc5458d Oct 17 19:49:22 sw1x-vdtii systemd[1]: systemd-hostnamed.service: Succeeded. Oct 17 19:49:23 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioGetState Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:25 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:27 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 17 19:49:27 sw1x-vdtii volumio[663]: info: handleBrowseUri took 373 milliseconds Oct 17 19:49:27 sw1x-vdtii volumio[663]: info: Preload queue cleared Oct 17 19:49:27 sw1x-vdtii volumio[663]: info: Preload queue cleared Oct 17 19:49:28 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 19:49:28 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 19:49:28 sw1x-vdtii volumio[663]: info: Discovery: Getting this device information Oct 17 19:49:28 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioGetState Oct 17 19:49:28 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 19:49:35 sw1x-vdtii volumio[663]: Searching plugin music_service/qobuz Oct 17 19:49:35 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 17 19:49:36 sw1x-vdtii volumio[663]: info: searchQOBUZUri took 1395 milliseconds Oct 17 19:49:36 sw1x-vdtii volumio[663]: info: All search sources collected, pushing search results Oct 17 19:49:45 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: handleBrowseUri took 1111 milliseconds Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: Preload queue cleared Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: Executing endpoint getSimilarArtists Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:46 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:49 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 17 19:49:49 sw1x-vdtii volumio[663]: info: handleBrowseUri took 626 milliseconds Oct 17 19:49:49 sw1x-vdtii volumio[663]: info: Preload queue cleared Oct 17 19:49:49 sw1x-vdtii volumio[663]: info: Preloading song: qobuz://song/111593852 Oct 17 19:49:49 sw1x-vdtii volumio[663]: info: Exploding uri qobuz://song/111593852 in service qobuz Oct 17 19:49:49 sw1x-vdtii volumio[663]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: Executing endpoint getSimilarAlbums Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:49:50 sw1x-vdtii volumio[663]: info: explodeUri took 683 milliseconds Oct 17 19:49:52 sw1x-vdtii volumiologrotate[462]: ls: cannot access '/var/log/samba/log.wb-SW1X': No such file or directory Oct 17 19:49:52 sw1x-vdtii volumiologrotate[462]: ls: cannot access '_VDT_II': No such file or directory Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: Discovery: Getting this device information Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: CoreCommandRouter::volumioGetState Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 19:49:58 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: handleBrowseUri took 1974 milliseconds Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: Preload queue cleared Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: Executing endpoint getSimilarArtists Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: Executing endpoint metavolumio Oct 17 19:50:00 sw1x-vdtii volumio[663]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 17 19:50:04 sw1x-vdtii volumio[663]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 19:50:04 sw1x-vdtii volumio[663]: TypeError: Cannot read property 'slice' of null Oct 17 19:50:04 sw1x-vdtii volumio[663]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at Object.onceWrapper (events.js:422:26) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at ClientRequest.emit (events.js:315:20) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at TLSSocket.socketOnData (_http_client.js:509:22) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at TLSSocket.emit (events.js:315:20) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at addChunk (internal/streams/readable.js:309:12) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at readableAddChunk (internal/streams/readable.js:284:9) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at TLSSocket.Readable.push (internal/streams/readable.js:223:10) Oct 17 19:50:04 sw1x-vdtii volumio[663]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Oct 17 19:50:04 sw1x-vdtii volumio[663]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 19:50:05 sw1x-vdtii sudo[1486]: volumio : unable to resolve host sw1x-vdtii Oct 17 19:50:05 sw1x-vdtii sudo[1486]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Oct 17 19:50:05 sw1x-vdtii sudo[1486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-17 19:49 Oct 17 19:50:05 sw1x-vdtii sudo[1486]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"