-- Logs begin at Tue 2024-11-19 18:29:28 CET, end at Sun 2024-11-24 14:58:48 CET. -- Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 14:57:40 rivo volumio[3117]: info: Discovery: Getting this device information Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:40 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 14:57:40 rivo volumio[3117]: info: Discovery: Getting this device information Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:40 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:40 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 14:57:41 rivo volumio[3117]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.99 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Nov 24 14:57:42 rivo volumio[3117]: verbose: New Socket.io Connection to 192.168.0.58 from 192.168.0.99 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 8 Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetVisibleSources Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:42 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:42 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 24 14:57:42 rivo volumio[3117]: info: Received Get System Info Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 14:57:42 rivo volumio[3117]: info: Discovery: Getting this device information Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:42 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:57:42 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:42 rivo volumio[3117]: info: Listing playlists Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::volumioGetQueue Nov 24 14:57:42 rivo volumio[3117]: info: CoreStateMachine::getQueue Nov 24 14:57:42 rivo volumio[3117]: info: CorePlayQueue::getQueue Nov 24 14:57:42 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 24 14:57:44 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:57:44 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:57:44 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:57:44 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:57:44 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:57:44 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:57:48 rivo volumio[3117]: info: CorePlayQueue::getTrack 6 Nov 24 14:57:48 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:48 rivo volumio[3117]: info: Prefetching next song Nov 24 14:57:48 rivo volumio[3117]: info: [1732456668310] ControllerQobuz::prefetch Nov 24 14:57:48 rivo volumio[3117]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/30516273" Nov 24 14:57:48 rivo volumio[3117]: STREAMING PROXY: Handling url /?data=qobuz://song/30516273 Nov 24 14:57:48 rivo volumio[3117]: info: Executing endpoint getStreamUrlqobuz Nov 24 14:57:48 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 24 14:57:49 rivo volumio[3117]: info: getStreamUrl took 804 milliseconds Nov 24 14:57:49 rivo volumio[3117]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1345637&eid=30516273&fmt=27&profile=raw&app_id=539451548&cid=1213534&etsp=1732460268&hmac=RR8HGciO7dzQdqV3za8pCyArGAA Nov 24 14:57:49 rivo volumio[3117]: STREAMING PROXY: Response: 200, length: 108716137 Nov 24 14:57:49 rivo volumio[3117]: STREAMING PROXY: Client dropped request, destroying Nov 24 14:57:49 rivo volumio[3117]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/30516273" Nov 24 14:57:49 rivo volumio[3117]: info: Nov 24 14:57:49 rivo volumio[3117]: ---------------------------- MPD announces system playlist update Nov 24 14:57:49 rivo volumio[3117]: info: Ignoring MPD Status Update Nov 24 14:57:49 rivo volumio[3117]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/30516273" took 2 milliseconds Nov 24 14:57:49 rivo volumio[3117]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 24 14:57:49 rivo volumio[3117]: verbose: ControllerMpd::sendMpdCommand consume 1 Nov 24 14:57:49 rivo volumio[3117]: info: ------------------------------ 4ms Nov 24 14:57:49 rivo volumio[3117]: info: sendMpdCommand consume 1 took 2 milliseconds Nov 24 14:57:49 rivo volumio[3117]: STREAMING PROXY: Handling url /?data=qobuz://song/30516273 Nov 24 14:57:49 rivo volumio[3117]: info: Executing endpoint getStreamUrlqobuz Nov 24 14:57:49 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 24 14:57:50 rivo volumio[3117]: info: getStreamUrl took 709 milliseconds Nov 24 14:57:50 rivo volumio[3117]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1345637&eid=30516273&fmt=27&profile=raw&app_id=539451548&cid=1213534&etsp=1732460270&hmac=ErZtpaOoi9I6efbO7u37_9KjrNA Nov 24 14:57:50 rivo volumio[3117]: STREAMING PROXY: Response: 200, length: 108716137 Nov 24 14:57:52 rivo volumio[3117]: STREAMING PROXY: Client dropped request, destroying Nov 24 14:57:52 rivo volumio[3117]: info: CoreStateMachine::startPlaybackTimer Nov 24 14:57:52 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:53 rivo volumio[3117]: info: CoreStateMachine::pushState Nov 24 14:57:53 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:53 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 14:57:53 rivo volumio[3117]: info: CoreCommandRouter::volumioPushState Nov 24 14:57:53 rivo volumio[3117]: info: Signalling Playback active due to playback status change Nov 24 14:57:53 rivo volumio[3117]: info: Updating RAAT Signal Path Nov 24 14:57:54 rivo volumio[3117]: info: Nov 24 14:57:54 rivo volumio[3117]: ---------------------------- MPD announces system playlist update Nov 24 14:57:54 rivo volumio[3117]: info: Ignoring MPD Status Update Nov 24 14:57:54 rivo volumio[3117]: info: Nov 24 14:57:54 rivo volumio[3117]: ---------------------------- MPD announces state update: player Nov 24 14:57:54 rivo volumio[3117]: info: ControllerMpd::getState Nov 24 14:57:54 rivo volumio[3117]: verbose: ControllerMpd::sendMpdCommand status Nov 24 14:57:54 rivo volumio[3117]: info: ------------------------------ 3ms Nov 24 14:57:54 rivo volumio[3117]: info: sendMpdCommand status took 3 milliseconds Nov 24 14:57:54 rivo volumio[3117]: verbose: ControllerMpd::parseState Nov 24 14:57:54 rivo volumio[3117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 14:57:54 rivo volumio[3117]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 24 14:57:54 rivo volumio[3117]: verbose: ControllerMpd::parseTrackInfo Nov 24 14:57:54 rivo volumio[3117]: info: ControllerMpd::pushState Nov 24 14:57:54 rivo volumio[3117]: info: CoreCommandRouter::servicePushState Nov 24 14:57:54 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:54 rivo volumio[3117]: verbose: STATE SERVICE {"status":"play","position":0,"seek":52,"duration":169,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5130 Kbps","isStreaming":false,"title":"30516273","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/30516273","trackType":"qobuz"} Nov 24 14:57:54 rivo volumio[3117]: verbose: CURRENT POSITION 7 Nov 24 14:57:54 rivo volumio[3117]: info: CoreStateMachine::syncState stateService play Nov 24 14:57:54 rivo volumio[3117]: info: CoreStateMachine::syncState currentStatus play Nov 24 14:57:54 rivo volumio[3117]: info: Received an update from plugin. extracting info from payload Nov 24 14:57:54 rivo volumio[3117]: info: CoreStateMachine::pushState Nov 24 14:57:54 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:54 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 14:57:54 rivo volumio[3117]: info: CoreCommandRouter::volumioPushState Nov 24 14:57:54 rivo volumio[3117]: info: CoreStateMachine::pushState Nov 24 14:57:54 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:57:54 rivo volumio[3117]: info: CoreCommandRouter::volumioPushState Nov 24 14:57:54 rivo volumio[3117]: info: ------------------------------ 32ms Nov 24 14:57:54 rivo volumio[3117]: info: Signalling Playback active due to playback status change Nov 24 14:57:54 rivo volumio[3117]: info: Signalling Playback active due to playback status change Nov 24 14:57:54 rivo volumio[3117]: info: Updating RAAT Signal Path Nov 24 14:57:54 rivo volumio[3117]: info: Updating RAAT Signal Path Nov 24 14:58:00 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:58:00 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:58:00 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:58:00 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:58:00 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:58:00 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:58:02 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:58:02 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:58:02 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:58:02 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:58:02 rivo volumio[3117]: info: Executing endpoint metavolumio Nov 24 14:58:02 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 24 14:58:02 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:02 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:07 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 14:58:07 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 14:58:07 rivo volumio[3117]: info: Discovery: Getting this device information Nov 24 14:58:07 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:58:07 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:58:07 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 14:58:11 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:16 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:16 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:20 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:21 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:22 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:25 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:25 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:37 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 14:58:37 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 14:58:37 rivo volumio[3117]: info: Discovery: Getting this device information Nov 24 14:58:37 rivo volumio[3117]: info: CoreCommandRouter::volumioGetState Nov 24 14:58:37 rivo volumio[3117]: info: CorePlayQueue::getTrack 7 Nov 24 14:58:37 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 14:58:44 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:44 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:45 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:46 rivo volumio[3117]: info: Preload queue cleared Nov 24 14:58:47 rivo volumio[3117]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 14:58:47 rivo volumio[3117]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 14:58:47 rivo volumio[3117]: TypeError: Cannot read property 'length' of undefined Nov 24 14:58:47 rivo volumio[3117]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 24 14:58:47 rivo volumio[3117]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 24 14:58:47 rivo volumio[3117]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 24 14:58:47 rivo volumio[3117]: at Parser.emit (events.js:400:28) Nov 24 14:58:47 rivo volumio[3117]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 24 14:58:47 rivo volumio[3117]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 24 14:58:47 rivo volumio[3117]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 24 14:58:47 rivo volumio[3117]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 24 14:58:47 rivo volumio[3117]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 24 14:58:47 rivo volumio[3117]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 24 14:58:47 rivo volumio[3117]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 24 14:58:47 rivo volumio[3117]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 24 14:58:47 rivo volumio[3117]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 24 14:58:47 rivo volumio[3117]: at IncomingMessage.emit (events.js:412:35) Nov 24 14:58:47 rivo volumio[3117]: at endReadableNT (internal/streams/readable.js:1333:12) Nov 24 14:58:47 rivo volumio[3117]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Nov 24 14:58:47 rivo volumio[3117]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 14:58:48 rivo sudo[8772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-24 14:57 Nov 24 14:58:48 rivo sudo[8772]: 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="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"