-- Logs begin at Thu 2019-02-14 19:11:59 JST, end at Wed 2025-07-02 23:52:59 JST. -- Jul 02 23:51:00 volumio volumio[1054]: info: MYVOLUMIO: Adding device Jul 02 23:51:00 volumio volumio[1054]: info: MYVOLUMIO: Evaluating Server Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 02 23:51:00 volumio volumio[1054]: info: Received Get System Info Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 02 23:51:00 volumio volumio[1054]: info: Discovery: Getting this device information Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Jul 02 23:51:00 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 02 23:51:00 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 02 23:51:01 volumio volumio[1054]: info: Setting Geolocation for MyVolumio to as1 Jul 02 23:51:01 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:01 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:01 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:01 volumio volumio[1054]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jul 02 23:51:02 volumio volumio[1054]: info: Updating MyVolumio device info Jul 02 23:51:02 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:02 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:02 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 02 23:51:02 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 02 23:51:02 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Jul 02 23:51:02 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Jul 02 23:51:02 volumio volumio[1054]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jul 02 23:51:03 volumio volumio[1331]: ....................................................................................++++ Jul 02 23:51:03 volumio volumio[1331]: e is 65537 (0x010001) Jul 02 23:51:03 volumio volumio[1331]: writing RSA key Jul 02 23:51:03 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 02 23:51:03 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:03 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jul 02 23:51:04 volumio volumio-remote-updater[585]: No test mode Jul 02 23:51:04 volumio volumio-remote-updater[585]: No alpha test mode Jul 02 23:51:04 volumio volumio[1054]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES



 

","title":"Update v3.816","updateavailable":true} Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 02 23:51:04 volumio volumio[1054]: info: Received Get System Info Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 02 23:51:04 volumio volumio[1054]: info: Discovery: Getting this device information Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Jul 02 23:51:04 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Jul 02 23:51:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 02 23:51:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 02 23:51:05 volumio volumio[1054]: info: Received Get System Info Jul 02 23:51:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 02 23:51:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 02 23:51:05 volumio volumio[1054]: info: Discovery: Getting this device information Jul 02 23:51:05 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Jul 02 23:51:05 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Jul 02 23:51:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 02 23:51:07 volumio ntpd[854]: Soliciting pool server 202.181.103.212 Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Jul 02 23:51:07 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 02 23:51:07 volumio ntpd[854]: Soliciting pool server 133.130.121.141 Jul 02 23:51:07 volumio ntpd[854]: Soliciting pool server 138.3.216.120 Jul 02 23:51:08 volumio ntpd[854]: Soliciting pool server 129.250.35.250 Jul 02 23:51:08 volumio ntpd[854]: Soliciting pool server 64.176.59.83 Jul 02 23:51:09 volumio volumio[1054]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jul 02 23:51:09 volumio volumio[1054]: info: Completed starting MyVolumio Plugin Jul 02 23:51:09 volumio volumio[1054]: [Metrics] CommandRouter: 55s 187.04ms Jul 02 23:51:09 volumio volumio[1054]: info: CoreCommandRouter::volumiosetStartupVolume Jul 02 23:51:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 02 23:51:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 02 23:51:09 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Jul 02 23:51:09 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Jul 02 23:51:09 volumio ntpd[854]: Soliciting pool server 103.131.151.20 Jul 02 23:51:09 volumio ntpd[854]: Soliciting pool server 108.160.132.224 Jul 02 23:51:09 volumio volumio[1054]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 02 23:51:09 volumio volumio[1054]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 02 23:51:09 volumio volumio[1054]: info: camilladsp stopping service pid 1455... Jul 02 23:51:09 volumio volumio[1054]: info: camilladsp service terminated, instance 1 Jul 02 23:51:09 volumio volumio[1054]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 02 23:51:09 volumio volumio[1054]: info: camilladsp service started and running in background, instance 1 Jul 02 23:51:09 volumio volumio[1054]: info: camilladsp spawned new process with pid 2101, instance 1, run: true Jul 02 23:51:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 02 23:51:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 02 23:51:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 02 23:51:10 volumio ntpd[854]: Soliciting pool server 162.159.200.1 Jul 02 23:51:11 volumio ntpd[854]: Soliciting pool server 129.250.35.251 Jul 02 23:51:12 volumio ntpd[854]: Soliciting pool server 45.77.20.103 Jul 02 23:51:13 volumio ntpd[854]: Soliciting pool server 45.76.221.157 Jul 02 23:51:15 volumio volumio[1054]: info: camilladsp spawned new process with pid 2109, instance 1, run: true Jul 02 23:51:15 volumio volumio[1054]: info: CoreCommandRouter::volumioGetVisibleSources Jul 02 23:51:15 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 02 23:51:15 volumio volumio[1054]: info: CoreCommandRouter::volumioGetQueue Jul 02 23:51:15 volumio volumio[1054]: info: CoreStateMachine::getQueue Jul 02 23:51:15 volumio volumio[1054]: info: CorePlayQueue::getQueue Jul 02 23:51:16 volumio ntpd[854]: receive: Unexpected origin timestamp 0xec0fc5e3.af468786 does not match aorg 0000000000.00000000 from server@133.130.121.141 xmt 0xec0fc5e4.3d1bb750 Jul 02 23:51:16 volumio ntpd[854]: receive: Unexpected origin timestamp 0xec0fc5e3.af34473c does not match aorg 0000000000.00000000 from server@45.77.20.103 xmt 0xec0fc5e4.3cff4f46 Jul 02 23:51:16 volumio ntpd[854]: receive: Unexpected origin timestamp 0xec0fc5e3.af410923 does not match aorg 0000000000.00000000 from server@108.160.132.224 xmt 0xec0fc5e4.3cdde250 Jul 02 23:51:17 volumio volumio[1054]: info: BOOT COMPLETED Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 02 23:51:17 volumio volumio[1054]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 02 23:51:17 volumio volumio[1054]: info: Received Get System Version Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 02 23:51:17 volumio volumio[1054]: info: Received Get System Info Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 02 23:51:17 volumio volumio[1054]: info: Discovery: Getting this device information Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Jul 02 23:51:17 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Jul 02 23:51:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 02 23:51:18 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:18 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:20 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:20 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:22 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:22 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:24 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:24 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:28 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:28 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:38 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:38 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:39 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:40 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:47 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:47 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:53 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:53 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:51:53 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:51:54 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:02 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:02 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:04 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:04 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:14 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:14 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:16 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:16 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:18 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:18 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:23 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:23 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:30 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:30 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:31 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:31 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:39 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:39 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:41 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:42 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:44 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:45 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:55 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:55 volumio volumio[1054]: info: Preload queue cleared Jul 02 23:52:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 02 23:52:57 volumio volumio[1054]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 02 23:52:57 volumio volumio[1054]: TypeError: Cannot read property 'length' of undefined Jul 02 23:52:57 volumio volumio[1054]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 02 23:52:57 volumio volumio[1054]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 02 23:52:57 volumio volumio[1054]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 02 23:52:57 volumio volumio[1054]: at Parser.emit (events.js:315:20) Jul 02 23:52:57 volumio volumio[1054]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 02 23:52:57 volumio volumio[1054]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 02 23:52:57 volumio volumio[1054]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 02 23:52:57 volumio volumio[1054]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 02 23:52:57 volumio volumio[1054]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 02 23:52:57 volumio volumio[1054]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 02 23:52:57 volumio volumio[1054]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 02 23:52:57 volumio volumio[1054]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 02 23:52:57 volumio volumio[1054]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 02 23:52:57 volumio volumio[1054]: at IncomingMessage.emit (events.js:327:22) Jul 02 23:52:57 volumio volumio[1054]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 02 23:52:57 volumio volumio[1054]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 02 23:52:57 volumio volumio[1054]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 02 23:52:59 volumio sudo[2329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-02 23:51 Jul 02 23:52:59 volumio sudo[2329]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"