-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Sun 2024-11-24 18:20:52 EST. -- Nov 24 18:19:03 pi2aes volumio[1058]: info: Preload queue cleared Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::ClearQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::stop Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::updateTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::stPlaybackTimer Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:19:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:19:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::serviceStop Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::serviceStop Nov 24 18:19:03 pi2aes volumio[1058]: info: ControllerMpd::stop Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand stop Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::clearPlayQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::saveQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::addQueueItems Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::addQueueItems Nov 24 18:19:03 pi2aes volumio[1058]: info: Preload queue cleared Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009477 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009477 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::saveQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::updateTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPlay Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::play index 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::addQueueItems Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::addQueueItems Nov 24 18:19:03 pi2aes volumio[1058]: info: Preload queue cleared Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009478 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009478 Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009479 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009479 Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009480 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009480 Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009481 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009481 Nov 24 18:19:03 pi2aes volumio[1058]: info: Adding Item to queue: qobuz://song/145009482 Nov 24 18:19:03 pi2aes volumio[1058]: info: Using cached record of: qobuz://song/145009482 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::stop Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::saveQueue Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::play index undefined Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::updateTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrackBlock Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::startPlaybackTimer Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: [1732490343324] ControllerQobuz::clearAddPlayTrack Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand stop Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand stop took 36 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand stop took 12 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand clear Nov 24 18:19:03 pi2aes volumio[1058]: info: Nov 24 18:19:03 pi2aes volumio[1058]: ---------------------------- MPD announces system playlist update Nov 24 18:19:03 pi2aes volumio[1058]: info: Ignoring MPD Status Update Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand clear took 2 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/145009477" Nov 24 18:19:03 pi2aes volumio[1058]: error: updateQueue error: null Nov 24 18:19:03 pi2aes volumio[1058]: info: ------------------------------ 2ms Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Handling url /?data=qobuz://song/145009477 Nov 24 18:19:03 pi2aes volumio[1058]: info: Executing endpoint getStreamUrlqobuz Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 24 18:19:03 pi2aes volumio[1058]: info: getStreamUrl took 274 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2750920&eid=145009477&fmt=7&profile=raw&app_id=539451548&cid=1935808&etsp=1732493943&hmac=IVRtoi7ucX143bBNOvcTkoOty1M Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Response: 200, length: 38114271 Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/145009477" Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Client dropped request, destroying Nov 24 18:19:03 pi2aes volumio[1058]: info: Nov 24 18:19:03 pi2aes volumio[1058]: ---------------------------- MPD announces system playlist update Nov 24 18:19:03 pi2aes volumio[1058]: info: Ignoring MPD Status Update Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/145009477" took 3 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand play Nov 24 18:19:03 pi2aes volumio[1058]: info: ------------------------------ 5ms Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand play took 2 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Handling url /?data=qobuz://song/145009477 Nov 24 18:19:03 pi2aes volumio[1058]: info: Executing endpoint getStreamUrlqobuz Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 24 18:19:03 pi2aes volumio[1058]: info: getStreamUrl took 207 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2750920&eid=145009477&fmt=7&profile=raw&app_id=539451548&cid=1935808&etsp=1732493943&hmac=IVRtoi7ucX143bBNOvcTkoOty1M Nov 24 18:19:03 pi2aes volumio[1058]: STREAMING PROXY: Response: 200, length: 38114271 Nov 24 18:19:03 pi2aes volumio[1058]: info: Nov 24 18:19:03 pi2aes volumio[1058]: ---------------------------- MPD announces state update: player Nov 24 18:19:03 pi2aes volumio[1058]: info: ControllerMpd::getState Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:19:03 pi2aes volumio[1058]: info: Nov 24 18:19:03 pi2aes volumio[1058]: ---------------------------- MPD announces state update: player Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand status took 5 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: info: ControllerMpd::getState Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand status took 3 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 18:19:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseTrackInfo Nov 24 18:19:03 pi2aes volumio[1058]: info: ControllerMpd::pushState Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreCommandRouter::servicePushState Nov 24 18:19:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:03 pi2aes volumio[1058]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"145009477","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/145009477","trackType":"qobuz"} Nov 24 18:19:03 pi2aes volumio[1058]: verbose: CURRENT POSITION 0 Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState stateService play Nov 24 18:19:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState currentStatus stop Nov 24 18:19:04 pi2aes volumio[1058]: info: ------------------------------ 15ms Nov 24 18:19:04 pi2aes volumio[1058]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 24 18:19:04 pi2aes volumio[1058]: verbose: ControllerMpd::parseTrackInfo Nov 24 18:19:04 pi2aes volumio[1058]: info: ControllerMpd::pushState Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreCommandRouter::servicePushState Nov 24 18:19:04 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:04 pi2aes volumio[1058]: verbose: STATE SERVICE {"status":"play","position":0,"seek":304,"duration":202,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1021 Kbps","isStreaming":false,"title":"145009477","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/145009477","trackType":"qobuz"} Nov 24 18:19:04 pi2aes volumio[1058]: verbose: CURRENT POSITION 0 Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreStateMachine::syncState stateService play Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreStateMachine::syncState currentStatus play Nov 24 18:19:04 pi2aes volumio[1058]: info: Received an update from plugin. extracting info from payload Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:19:04 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:19:04 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:19:04 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:19:04 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:19:04 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:19:04 pi2aes volumio[1058]: info: ------------------------------ 79ms Nov 24 18:19:04 pi2aes volumio[1058]: STREAMING PROXY: Client dropped request, destroying Nov 24 18:19:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 18:19:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 18:19:17 pi2aes volumio[1058]: info: Discovery: Getting this device information Nov 24 18:19:17 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetState Nov 24 18:19:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: Retrieving Cloud Streaming UI Nov 24 18:19:20 pi2aes volumio[1058]: info: Getting Tidal Cloud Configuration Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: Getting Qobuz Cloud Configuration Nov 24 18:19:20 pi2aes volumio[1058]: info: Asking plugin for UI Config Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: Getting Spotify Cloud Configuration Nov 24 18:19:20 pi2aes volumio[1058]: info: Asking plugin for UI Config Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: Saving Spotify Acccount Nov 24 18:19:20 pi2aes volumio[1058]: info: Got it Nov 24 18:19:20 pi2aes volumio[1058]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 24 18:19:20 pi2aes volumio[1058]: info: Got Tidal Cloud Configuration Nov 24 18:19:20 pi2aes volumio[1058]: info: Got it Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:19:20 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:19:21 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:21 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 24 18:19:25 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:28 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Nov 24 18:19:28 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand update Nov 24 18:19:28 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:19:28 pi2aes volumio[1058]: info: Nov 24 18:19:28 pi2aes volumio[1058]: ---------------------------- MPD announces state update: update Nov 24 18:19:28 pi2aes volumio[1058]: info: sendMpdCommand update took 2 milliseconds Nov 24 18:19:28 pi2aes volumio[1058]: info: ControllerMpd::getState Nov 24 18:19:28 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:19:28 pi2aes volumio[1058]: info: sendMpdCommand status took 2 milliseconds Nov 24 18:19:28 pi2aes volumio[1058]: info: sendMpdCommand status took 2 milliseconds Nov 24 18:19:28 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:19:29 pi2aes volumio[1058]: info: Command Router : Notfying DB Updatetrue Nov 24 18:19:29 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:19:29 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 18:19:29 pi2aes volumio[1058]: info: sendMpdCommand playlistinfo took 4 milliseconds Nov 24 18:19:29 pi2aes volumio[1058]: verbose: ControllerMpd::parseTrackInfo Nov 24 18:19:29 pi2aes volumio[1058]: info: ControllerMpd::pushState Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreCommandRouter::servicePushState Nov 24 18:19:29 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:19:29 pi2aes volumio[1058]: verbose: STATE SERVICE {"status":"play","position":0,"seek":26113,"duration":202,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1442 Kbps","isStreaming":false,"title":"145009477","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/145009477","trackType":"qobuz"} Nov 24 18:19:29 pi2aes volumio[1058]: verbose: CURRENT POSITION 0 Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreStateMachine::syncState stateService play Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreStateMachine::syncState currentStatus play Nov 24 18:19:29 pi2aes volumio[1058]: info: Received an update from plugin. extracting info from payload Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:19:29 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:19:29 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:19:29 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:19:29 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:19:29 pi2aes volumio[1058]: info: ------------------------------ 364ms Nov 24 18:19:29 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:31 pi2aes volumio[1058]: info: CoreCommandRouter::Close All Modals sent Nov 24 18:19:33 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:37 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:39 pi2aes volumio[1058]: info: Tunnel connection is inactive, restarting it Nov 24 18:19:39 pi2aes volumio[1058]: info: Starting Tunnel 1 Nov 24 18:19:39 pi2aes volumio[1058]: info: Starting Tunnel Connection Checker Nov 24 18:19:39 pi2aes sudo[3298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Nov 24 18:19:39 pi2aes sudo[3298]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 18:19:39 pi2aes autossh[1545]: received signal to exit (15) Nov 24 18:19:39 pi2aes systemd[1]: Stopping MyVolumio SSH Tunnel... Nov 24 18:19:39 pi2aes systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Nov 24 18:19:39 pi2aes systemd[1]: sshtunnel.service: Succeeded. Nov 24 18:19:39 pi2aes systemd[1]: Stopped MyVolumio SSH Tunnel. Nov 24 18:19:40 pi2aes volumio[1058]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 18:19:40 pi2aes volumio[1058]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 18:19:40 pi2aes systemd[1]: Started MyVolumio SSH Tunnel. Nov 24 18:19:40 pi2aes sudo[3298]: pam_unix(sudo:session): session closed for user root Nov 24 18:19:40 pi2aes volumio[1058]: info: Remote SSH Started Nov 24 18:19:40 pi2aes autossh[3302]: port set to 0, monitoring disabled Nov 24 18:19:40 pi2aes autossh[3302]: starting ssh (count 1) Nov 24 18:19:40 pi2aes autossh[3302]: ssh child pid is 3305 Nov 24 18:19:40 pi2aes volumio[1058]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 24 18:19:40 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetState Nov 24 18:19:40 pi2aes volumiossh-tunnel[3300]: Warning: Permanently added '[us3.myvolumio.org]:2222,[159.203.57.91]:2222' (RSA) to the list of known hosts. Nov 24 18:19:40 pi2aes volumiossh-tunnel[3300]: Warning: remote port forwarding failed for listen port 8091 Nov 24 18:19:41 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:45 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 18:19:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 18:19:47 pi2aes volumio[1058]: info: Discovery: Getting this device information Nov 24 18:19:47 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetState Nov 24 18:19:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 18:19:49 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:53 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:19:57 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:20:01 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:20:03 pi2aes volumio[1058]: info: MPD Database updated - AlbumList cache refreshed Nov 24 18:20:03 pi2aes volumio[1058]: info: Nov 24 18:20:03 pi2aes volumio[1058]: ---------------------------- MPD announces state update: database Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:20:03 pi2aes volumio[1058]: info: Nov 24 18:20:03 pi2aes volumio[1058]: ---------------------------- MPD announces state update: update Nov 24 18:20:03 pi2aes volumio[1058]: info: ControllerMpd::getState Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:20:03 pi2aes volumio[1058]: info: ControllerMpd::getState Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand status Nov 24 18:20:03 pi2aes volumio[1058]: info: sendMpdCommand status took 203 milliseconds Nov 24 18:20:03 pi2aes volumio[1058]: info: sendMpdCommand status took 202 milliseconds Nov 24 18:20:03 pi2aes volumio[1058]: info: sendMpdCommand status took 202 milliseconds Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:20:03 pi2aes volumio[1058]: info: Command Router : Notfying DB Updatefalse Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::Close All Modals sent Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseState Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 18:20:03 pi2aes volumio[1058]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 24 18:20:03 pi2aes volumio[1058]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseTrackInfo Nov 24 18:20:03 pi2aes volumio[1058]: verbose: ControllerMpd::parseTrackInfo Nov 24 18:20:03 pi2aes volumio[1058]: info: ControllerMpd::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::servicePushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:20:03 pi2aes volumio[1058]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61110,"duration":202,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1574 Kbps","isStreaming":false,"title":"145009477","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/145009477","trackType":"qobuz"} Nov 24 18:20:03 pi2aes volumio[1058]: verbose: CURRENT POSITION 0 Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState stateService play Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState currentStatus play Nov 24 18:20:03 pi2aes volumio[1058]: info: Received an update from plugin. extracting info from payload Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:20:03 pi2aes volumio[1058]: info: ControllerMpd::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::servicePushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CorePlayQueue::getTrack 0 Nov 24 18:20:03 pi2aes volumio[1058]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61110,"duration":202,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1574 Kbps","isStreaming":false,"title":"145009477","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/145009477","trackType":"qobuz"} Nov 24 18:20:03 pi2aes volumio[1058]: verbose: CURRENT POSITION 0 Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState stateService play Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::syncState currentStatus play Nov 24 18:20:03 pi2aes volumio[1058]: info: Received an update from plugin. extracting info from payload Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreStateMachine::pushState Nov 24 18:20:03 pi2aes volumio[1058]: info: CoreCommandRouter::volumioPushState Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output update for this device Nov 24 18:20:03 pi2aes volumio[1058]: info: MRS: Pushing multiroomSync output Nov 24 18:20:03 pi2aes volumio[1058]: info: ------------------------------ 287ms Nov 24 18:20:03 pi2aes volumio[1058]: info: ------------------------------ 288ms Nov 24 18:20:05 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:11 pi2aes volumio[1058]: xcb_connection_has_error() returned true Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 24 18:20:11 pi2aes volumio[1058]: xcb_connection_has_error() returned true Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 24 18:20:11 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 18:20:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 18:20:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 18:20:17 pi2aes volumio[1058]: info: Discovery: Getting this device information Nov 24 18:20:17 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetState Nov 24 18:20:17 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: Retrieving Cloud Streaming UI Nov 24 18:20:46 pi2aes volumio[1058]: info: Getting Tidal Cloud Configuration Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: Getting Qobuz Cloud Configuration Nov 24 18:20:46 pi2aes volumio[1058]: info: Asking plugin for UI Config Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: Getting Spotify Cloud Configuration Nov 24 18:20:46 pi2aes volumio[1058]: info: Asking plugin for UI Config Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: Saving Spotify Acccount Nov 24 18:20:46 pi2aes volumio[1058]: info: Got it Nov 24 18:20:46 pi2aes volumio[1058]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 24 18:20:46 pi2aes volumio[1058]: info: Got Tidal Cloud Configuration Nov 24 18:20:46 pi2aes volumio[1058]: info: Got it Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetBrowseSources Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:20:46 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 24 18:20:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 18:20:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 18:20:47 pi2aes volumio[1058]: info: Discovery: Getting this device information Nov 24 18:20:47 pi2aes volumio[1058]: info: CoreCommandRouter::volumioGetState Nov 24 18:20:47 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 18:20:50 pi2aes volumio[1058]: info: Disabling MyMusic plugin upnp Nov 24 18:20:50 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 24 18:20:50 pi2aes sudo[3474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Nov 24 18:20:50 pi2aes sudo[3474]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 18:20:50 pi2aes systemd[1]: Stopping UPnP Renderer front-end to MPD... Nov 24 18:20:50 pi2aes volumio[1058]: error: Upnp client error: Error: This socket has been ended by the other party Nov 24 18:20:50 pi2aes volumio[1058]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 18:20:52 pi2aes volumio[1058]: info: Enabling MyMusic plugin upnp Nov 24 18:20:52 pi2aes volumio[1058]: info: Enabling plugin upnp Nov 24 18:20:52 pi2aes volumio[1058]: info: Loading plugin "upnp"... Nov 24 18:20:52 pi2aes volumio[1058]: info: [1732490452095] Starting Upmpd Daemon Nov 24 18:20:52 pi2aes volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 24 18:20:52 pi2aes volumio[1058]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 18:20:52 pi2aes volumio[1058]: Error: listen EADDRINUSE: address already in use :::6599 Nov 24 18:20:52 pi2aes volumio[1058]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Nov 24 18:20:52 pi2aes volumio[1058]: at listenInCluster (net.js:1366:12) Nov 24 18:20:52 pi2aes volumio[1058]: at Server.listen (net.js:1452:7) Nov 24 18:20:52 pi2aes volumio[1058]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Nov 24 18:20:52 pi2aes volumio[1058]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Nov 24 18:20:52 pi2aes volumio[1058]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 24 18:20:52 pi2aes volumio[1058]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 24 18:20:52 pi2aes volumio[1058]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 24 18:20:52 pi2aes volumio[1058]: code: 'EADDRINUSE', Nov 24 18:20:52 pi2aes volumio[1058]: errno: -98, Nov 24 18:20:52 pi2aes volumio[1058]: syscall: 'listen', Nov 24 18:20:52 pi2aes volumio[1058]: address: '::', Nov 24 18:20:52 pi2aes volumio[1058]: port: 6599 Nov 24 18:20:52 pi2aes volumio[1058]: } Nov 24 18:20:52 pi2aes volumio[1058]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 18:20:52 pi2aes sudo[3523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-24 18:19 Nov 24 18:20:52 pi2aes sudo[3523]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"