-- Logs begin at Tue 2025-07-15 00:46:04 UTC, end at Wed 2025-07-16 12:56:00 UTC. -- Jul 16 12:55:04 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:04Z" level=trace msg="sent dealer ping" Jul 16 12:55:04 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:04Z" level=trace msg="received dealer pong" Jul 16 12:55:08 hermanprimo volumio[3107]: info: Preload queue cleared Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::ClearQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::stop Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::clearPlayQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::saveQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPushQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::addQueueItems Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::addQueueItems Jul 16 12:55:08 hermanprimo volumio[3107]: info: Preload queue cleared Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/folder/http://192.168.188.30:50001/ContentDirectory/control@22$2776 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/folder/http://192.168.188.30:50001/ContentDirectory/control@22$2776 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3647 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3647 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3648 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3648 Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPushQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::saveQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::updateTrackBlock Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::getTrackBlock Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPlay Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::play index 2 Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::addQueueItems Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::addQueueItems Jul 16 12:55:08 hermanprimo volumio[3107]: info: Preload queue cleared Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3649 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3649 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3650 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3650 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3651 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3651 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3652 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3652 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3653 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3653 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3654 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3654 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3655 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3655 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3656 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3656 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3657 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3657 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3658 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3658 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3659 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3659 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3660 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3660 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Adding Item to queue: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3661 Jul 16 12:55:08 hermanprimo volumio[3107]: info: Using cached record of: upnp/http://192.168.188.30:50001/ContentDirectory/control@22$@3661 Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::stop Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPushQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::saveQueue Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::play index undefined Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:08 hermanprimo volumio[3107]: info: CoreStateMachine::updateTrackBlock Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::getTrackBlock Jul 16 12:55:08 hermanprimo volumio[3107]: info: CorePlayQueue::getTrack 2 Jul 16 12:55:11 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPlay Jul 16 12:55:11 hermanprimo volumio[3107]: info: CoreStateMachine::play index undefined Jul 16 12:55:11 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:11 hermanprimo volumio[3107]: info: CorePlayQueue::getTrack 0 Jul 16 12:55:22 hermanprimo volumio[3107]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Jul 16 12:55:22 hermanprimo volumio[3107]: info: MRS: Starting browser stream Jul 16 12:55:22 hermanprimo volumio[3107]: info: MRS: Setting this device as Streaming Server Jul 16 12:55:22 hermanprimo volumio[3107]: info: Jul 16 12:55:22 hermanprimo volumio[3107]: [1752670522902] ---------------------------- MRS: Setting Streaming Server Jul 16 12:55:22 hermanprimo volumio[3107]: info: Enabled audio output: browserPlayback Jul 16 12:55:22 hermanprimo volumio[3107]: info: MRS: enable multiroom server output Jul 16 12:55:22 hermanprimo volumio[3107]: info: MRS: Set multiroom target PCM to volumioMultiRoom Jul 16 12:55:22 hermanprimo volumio[3107]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Jul 16 12:55:22 hermanprimo volumio[3107]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Jul 16 12:55:22 hermanprimo volumio[3107]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Jul 16 12:55:23 hermanprimo volumio[3107]: info: MRS: STARTING volumioStreaming Jul 16 12:55:23 hermanprimo sudo[367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 16 12:55:23 hermanprimo sudo[367]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 12:55:23 hermanprimo sudo[367]: pam_unix(sudo:session): session closed for user root Jul 16 12:55:23 hermanprimo sudo[370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Jul 16 12:55:23 hermanprimo sudo[370]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 12:55:23 hermanprimo systemd[1]: Started VolumioStreamingService. Jul 16 12:55:23 hermanprimo sudo[370]: pam_unix(sudo:session): session closed for user root Jul 16 12:55:23 hermanprimo volumio[3107]: info: MRS: volumioStreaming STARTED Jul 16 12:55:23 hermanprimo sudo[375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 16 12:55:23 hermanprimo sudo[375]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 12:55:23 hermanprimo sudo[375]: pam_unix(sudo:session): session closed for user root Jul 16 12:55:29 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioGetState Jul 16 12:55:29 hermanprimo volumio[3107]: info: CorePlayQueue::getTrack 0 Jul 16 12:55:31 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioPlay Jul 16 12:55:31 hermanprimo volumio[3107]: info: CoreStateMachine::play index undefined Jul 16 12:55:31 hermanprimo volumio[3107]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 12:55:31 hermanprimo volumio[3107]: info: CorePlayQueue::getTrack 0 Jul 16 12:55:34 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:34Z" level=trace msg="sent dealer ping" Jul 16 12:55:34 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:34Z" level=trace msg="received dealer pong" Jul 16 12:55:37 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:37Z" level=trace msg="received accesspoint ping" Jul 16 12:55:37 hermanprimo go-librespot[3598]: time="2025-07-16T12:55:37Z" level=trace msg="received accesspoint pong ack" Jul 16 12:55:40 hermanprimo volumio[3107]: info: CoreCommandRouter::volumioGetState Jul 16 12:55:40 hermanprimo volumio[3107]: info: CorePlayQueue::getTrack 0 Jul 16 12:55:59 hermanprimo volumio[3107]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 16 12:55:59 hermanprimo volumio[3107]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 12:55:59 hermanprimo volumio[3107]: TypeError: Cannot read property 'length' of undefined Jul 16 12:55:59 hermanprimo volumio[3107]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 16 12:55:59 hermanprimo volumio[3107]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 16 12:55:59 hermanprimo volumio[3107]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 16 12:55:59 hermanprimo volumio[3107]: at Parser.emit (events.js:400:28) Jul 16 12:55:59 hermanprimo volumio[3107]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 16 12:55:59 hermanprimo volumio[3107]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 16 12:55:59 hermanprimo volumio[3107]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 16 12:55:59 hermanprimo volumio[3107]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 16 12:55:59 hermanprimo volumio[3107]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 16 12:55:59 hermanprimo volumio[3107]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 16 12:55:59 hermanprimo volumio[3107]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 16 12:55:59 hermanprimo volumio[3107]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 16 12:55:59 hermanprimo volumio[3107]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 16 12:55:59 hermanprimo volumio[3107]: at IncomingMessage.emit (events.js:412:35) Jul 16 12:55:59 hermanprimo volumio[3107]: at endReadableNT (internal/streams/readable.js:1333:12) Jul 16 12:55:59 hermanprimo volumio[3107]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jul 16 12:55:59 hermanprimo volumio[3107]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 12:56:00 hermanprimo sudo[569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-16 12:55 Jul 16 12:56:00 hermanprimo sudo[569]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 05:35:39 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="edafce61cd208ac365b59b7b2fb693e3"