-- Logs begin at Mon 2025-01-13 17:57:32 CET, end at Mon 2025-01-13 18:56:32 CET. -- Jan 13 18:55:32 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 0 Jan 13 18:55:32 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:32 gerdbg volumio[1418]: info: Prefetching next song Jan 13 18:55:32 gerdbg volumio[1418]: info: [1736790932618] ControllerQobuz::prefetch Jan 13 18:55:32 gerdbg volumio[1418]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/209082302" Jan 13 18:55:32 gerdbg volumio[1418]: STREAMING PROXY: Handling url /?data=qobuz://song/209082302 Jan 13 18:55:32 gerdbg volumio[1418]: info: Executing endpoint getStreamUrlqobuz Jan 13 18:55:32 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 13 18:55:35 gerdbg systemd[1]: Stopping Music Player Daemon... Jan 13 18:55:35 gerdbg volumio[1418]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 13 18:55:37 gerdbg volumio[1418]: info: CoreStateMachine::startPlaybackTimer Jan 13 18:55:37 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:37 gerdbg volumio[1418]: info: CoreStateMachine::pushState Jan 13 18:55:37 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:37 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 18:55:37 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPushState Jan 13 18:55:37 gerdbg volumio[1418]: info: MRS: Pushing multiroomSync output update for this device Jan 13 18:55:37 gerdbg volumio[1418]: info: MRS: Pushing multiroomSync output Jan 13 18:55:39 gerdbg volumio[1418]: info: Executing endpoint metavolumio Jan 13 18:55:39 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 13 18:55:39 gerdbg volumio[1418]: info: Executing endpoint metavolumio Jan 13 18:55:39 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 13 18:55:39 gerdbg volumio[1418]: info: Executing endpoint metavolumio Jan 13 18:55:39 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 18:55:45 gerdbg volumio[1418]: info: Discovery: Getting this device information Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:55:45 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 18:55:45 gerdbg volumio[1418]: info: Discovery: Getting this device information Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:55:45 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:45 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 18:55:45 gerdbg volumio[1418]: verbose: New Socket.io Connection to 192.168.0.92:3000 from 192.168.0.64 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 13 18:55:46 gerdbg volumio[1418]: verbose: New Socket.io Connection to 192.168.0.92 from 192.168.0.64 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:55:46 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 18:55:46 gerdbg volumio[1418]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 13 18:55:46 gerdbg volumio[1418]: info: Received Get System Info Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 18:55:46 gerdbg volumio[1418]: info: Discovery: Getting this device information Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:55:46 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:55:46 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:55:46 gerdbg volumio[1418]: info: Listing playlists Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetQueue Jan 13 18:55:46 gerdbg volumio[1418]: info: CoreStateMachine::getQueue Jan 13 18:55:46 gerdbg volumio[1418]: info: CorePlayQueue::getQueue Jan 13 18:55:46 gerdbg volumio[1418]: error: Failed request for metavolumio API Jan 13 18:55:46 gerdbg volumio[1418]: error: Failed request for metavolumio API Jan 13 18:55:47 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 13 18:55:53 gerdbg volumio[1418]: info: getStreamUrl took 20388 milliseconds Jan 13 18:55:53 gerdbg volumio[1418]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3051813&eid=209082302&fmt=7&profile=raw&app_id=539451548&cid=2172505&etsp=1736794552&hmac=Bqdw_28_NtQoKioRE2XnoMLwxNQ Jan 13 18:55:54 gerdbg volumio[1418]: STREAMING PROXY: Response: 200, length: 70840039 Jan 13 18:55:54 gerdbg volumio[1418]: STREAMING PROXY: Client dropped request, destroying Jan 13 18:55:54 gerdbg volumio[1418]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209082302" Jan 13 18:55:54 gerdbg systemd[1]: mpd.service: Succeeded. Jan 13 18:55:54 gerdbg systemd[1]: Stopped Music Player Daemon. Jan 13 18:55:54 gerdbg volumio[1418]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 13 18:55:54 gerdbg systemd[1]: Starting Music Player Daemon... Jan 13 18:55:54 gerdbg volumio[1418]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 13 18:55:54 gerdbg sudo[11073]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 18:55:54 gerdbg sudo[11073]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 18:55:54 gerdbg sudo[11073]: pam_unix(sudo:session): session closed for user root Jan 13 18:55:54 gerdbg mpd[11075]: Jan 13 18:55 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 18:55:54 gerdbg systemd[1]: Started Music Player Daemon. Jan 13 18:55:54 gerdbg mpd_monitor.sh[787]: MPD restarted due to no mpc output. Jan 13 18:55:55 gerdbg volumio[1418]: info: handleBrowseUri took 7413 milliseconds Jan 13 18:55:55 gerdbg volumio[1418]: info: Preload queue cleared Jan 13 18:55:55 gerdbg volumio[1418]: info: Executing endpoint getSimilarArtists Jan 13 18:55:55 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 13 18:55:55 gerdbg volumio[1418]: info: Executing endpoint metavolumio Jan 13 18:55:55 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 13 18:56:00 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 18:56:00 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 18:56:00 gerdbg volumio[1418]: info: Discovery: Getting this device information Jan 13 18:56:00 gerdbg volumio[1418]: info: CoreCommandRouter::volumioGetState Jan 13 18:56:00 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:56:00 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 18:56:01 gerdbg volumio[1418]: info: Preload queue cleared Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::ClearQueue Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::stop Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::stPlaybackTimer Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::updateTrackBlock Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::getTrackBlock Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::pushState Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPushState Jan 13 18:56:01 gerdbg volumio[1418]: info: MRS: Pushing multiroomSync output update for this device Jan 13 18:56:01 gerdbg volumio[1418]: info: MRS: Pushing multiroomSync output Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::serviceStop Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreCommandRouter::serviceStop Jan 13 18:56:01 gerdbg volumio[1418]: info: [1736790961916] ControllerQobuz::stop Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 13 18:56:01 gerdbg volumio[1418]: info: ControllerMpd::stop Jan 13 18:56:01 gerdbg volumio[1418]: verbose: ControllerMpd::sendMpdCommand stop Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::clearPlayQueue Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::saveQueue Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPushQueue Jan 13 18:56:01 gerdbg volumio[1418]: info: CoreStateMachine::addQueueItems Jan 13 18:56:01 gerdbg volumio[1418]: info: CorePlayQueue::addQueueItems Jan 13 18:56:01 gerdbg volumio[1418]: info: Preload queue cleared Jan 13 18:56:01 gerdbg volumio[1418]: info: Adding Item to queue: qobuz://album/jgy2ggdieunfb Jan 13 18:56:01 gerdbg volumio[1418]: info: Exploding uri qobuz://album/jgy2ggdieunfb in service qobuz Jan 13 18:56:01 gerdbg volumio[1418]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 13 18:56:01 gerdbg volumio[1418]: error: MPD error: Error: This socket has been ended by the other party Jan 13 18:56:01 gerdbg volumio[1418]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 13 18:56:01 gerdbg volumio[1418]: error: MPD error: Error: This socket has been ended by the other party Jan 13 18:56:01 gerdbg volumio[1418]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 13 18:56:01 gerdbg volumio[1418]: error: MPD error: Error: This socket has been ended by the other party Jan 13 18:56:01 gerdbg volumio[1418]: error: This socket has been ended by the other party {"code":"EPIPE"} Jan 13 18:56:10 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 13 18:56:12 gerdbg volumio[1418]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 13 18:56:15 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPlay Jan 13 18:56:15 gerdbg volumio[1418]: info: CoreStateMachine::play index undefined Jan 13 18:56:15 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:15 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 1 Jan 13 18:56:19 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPlay Jan 13 18:56:19 gerdbg volumio[1418]: info: CoreStateMachine::play index undefined Jan 13 18:56:19 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:19 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 0 Jan 13 18:56:21 gerdbg volumio[1418]: info: Tunnel connection is inactive, restarting it Jan 13 18:56:21 gerdbg volumio[1418]: info: Starting Tunnel 1 Jan 13 18:56:21 gerdbg volumio[1418]: info: Starting Tunnel Connection Checker Jan 13 18:56:21 gerdbg sudo[11121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 13 18:56:21 gerdbg sudo[11121]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 18:56:21 gerdbg autossh[2308]: received signal to exit (15) Jan 13 18:56:21 gerdbg systemd[1]: Stopping MyVolumio SSH Tunnel... Jan 13 18:56:21 gerdbg systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Jan 13 18:56:21 gerdbg systemd[1]: sshtunnel.service: Succeeded. Jan 13 18:56:21 gerdbg systemd[1]: Stopped MyVolumio SSH Tunnel. Jan 13 18:56:21 gerdbg volumio[1418]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 13 18:56:21 gerdbg volumio[1418]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 13 18:56:21 gerdbg systemd[1]: Started MyVolumio SSH Tunnel. Jan 13 18:56:21 gerdbg sudo[11121]: pam_unix(sudo:session): session closed for user root Jan 13 18:56:21 gerdbg autossh[11124]: port set to 0, monitoring disabled Jan 13 18:56:21 gerdbg autossh[11124]: starting ssh (count 1) Jan 13 18:56:21 gerdbg autossh[11124]: ssh child pid is 11127 Jan 13 18:56:21 gerdbg volumio[1418]: info: Remote SSH Started Jan 13 18:56:29 gerdbg volumio[1418]: info: explodeUri took 28039 milliseconds Jan 13 18:56:29 gerdbg volumio[1418]: error: QOBUZ Browse Error: No response received Jan 13 18:56:29 gerdbg volumio[1418]: error: Commandrouter: Cannot explode uri qobuz://album/jgy2ggdieunfb from service qobuz: No response received Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPushQueue Jan 13 18:56:29 gerdbg volumio[1418]: info: CorePlayQueue::saveQueue Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::updateTrackBlock Jan 13 18:56:29 gerdbg volumio[1418]: info: CorePlayQueue::getTrackBlock Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreCommandRouter::volumioPlay Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::play index 0 Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::stop Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::play index undefined Jan 13 18:56:29 gerdbg volumio[1418]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 18:56:29 gerdbg volumio[1418]: info: CorePlayQueue::getTrack 0 Jan 13 18:56:32 gerdbg volumio[1418]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 18:56:32 gerdbg volumio[1418]: Error: getaddrinfo ENOTFOUND lastfm.freetls.fastly.net Jan 13 18:56:32 gerdbg volumio[1418]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:71:26) { Jan 13 18:56:32 gerdbg volumio[1418]: errno: -3007, Jan 13 18:56:32 gerdbg volumio[1418]: code: 'ENOTFOUND', Jan 13 18:56:32 gerdbg volumio[1418]: syscall: 'getaddrinfo', Jan 13 18:56:32 gerdbg volumio[1418]: hostname: 'lastfm.freetls.fastly.net' Jan 13 18:56:32 gerdbg volumio[1418]: } Jan 13 18:56:32 gerdbg volumio[1418]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 18:56:32 gerdbg sudo[11157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-13 18:55 Jan 13 18:56:32 gerdbg sudo[11157]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"