-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sat 2024-11-23 10:55:26 CET. -- Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin bluetooth to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin multiroom to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin metavolumio to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin cd_controller to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 23 10:54:00 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 23 10:54:02 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 23 10:54:02 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 23 10:54:02 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 10:54:02 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 10:54:02 volumiojw2 volumio[687]: info: Starting MyVolumio Remote Streaming Endpoints Nov 23 10:54:02 volumiojw2 volumio[687]: info: MyVolumio not started Nov 23 10:54:02 volumiojw2 volumio[687]: info: Initializing device activation check Nov 23 10:54:02 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 23 10:54:03 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 23 10:54:05 volumiojw2 volumio[687]: info: Starting Streaming Service Transparent Proxy Nov 23 10:54:05 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 23 10:54:05 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 23 10:54:05 volumiojw2 volumio[687]: info: Streaming services startup Nov 23 10:54:05 volumiojw2 volumio[687]: info: Starting Streaming Daemon Nov 23 10:54:05 volumiojw2 sudo[1004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 23 10:54:05 volumiojw2 sudo[1004]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 10:54:05 volumiojw2 volumio[687]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 23 10:54:05 volumiojw2 sudo[1004]: pam_unix(sudo:session): session closed for user root Nov 23 10:54:06 volumiojw2 systemd[1]: systemd-timedated.service: Succeeded. Nov 23 10:54:06 volumiojw2 volumio[687]: error: Cannot start Volumio Streaming Daemon Nov 23 10:54:06 volumiojw2 volumio[687]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 23 10:54:06 volumiojw2 volumio[687]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 23 10:54:08 volumiojw2 volumio[687]: STREAMING PROXY: Starting server on port 3245 Nov 23 10:54:08 volumiojw2 volumio[687]: Node JS runtime: 14 Nov 23 10:54:11 volumiojw2 volumio[961]: ...................................................................++++ Nov 23 10:54:11 volumiojw2 volumio[961]: e is 65537 (0x010001) Nov 23 10:54:11 volumiojw2 volumio[961]: writing RSA key Nov 23 10:54:12 volumiojw2 volumio[687]: verbose: New Socket.io Connection to 192.168.188.219 from 192.168.188.197 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetVisibleSources Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetState Nov 23 10:54:12 volumiojw2 volumio[687]: info: CorePlayQueue::getTrack 0 Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetState Nov 23 10:54:12 volumiojw2 volumio[687]: info: CorePlayQueue::getTrack 0 Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 10:54:12 volumiojw2 volumio[687]: info: Received Get System Info Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 23 10:54:12 volumiojw2 volumio[687]: info: Discovery: Getting this device information Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetState Nov 23 10:54:12 volumiojw2 volumio[687]: info: CorePlayQueue::getTrack 0 Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetState Nov 23 10:54:12 volumiojw2 volumio[687]: info: CorePlayQueue::getTrack 0 Nov 23 10:54:12 volumiojw2 volumio[687]: info: Listing playlists Nov 23 10:54:12 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 23 10:54:17 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 10:54:17 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 10:54:17 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 23 10:54:17 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 23 10:54:18 volumiojw2 volumio[687]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 23 10:54:18 volumiojw2 volumio-remote-updater[461]: No test mode Nov 23 10:54:18 volumiojw2 volumio-remote-updater[461]: No alpha test mode Nov 23 10:54:18 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 23 10:54:18 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetState Nov 23 10:54:18 volumiojw2 volumio[687]: info: CorePlayQueue::getTrack 0 Nov 23 10:54:18 volumiojw2 volumio[687]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 23 10:54:18 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetBrowseSources Nov 23 10:54:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 10:54:25 volumiojw2 volumio[687]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 23 10:54:25 volumiojw2 volumio[687]: info: Completed starting MyVolumio Plugin Nov 23 10:54:25 volumiojw2 volumio[687]: [Metrics] CommandRouter: 50s 621.82ms Nov 23 10:54:25 volumiojw2 volumio[687]: info: CoreCommandRouter::volumiosetStartupVolume Nov 23 10:54:25 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 10:54:25 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 10:54:25 volumiojw2 volumio[687]: info: CoreCommandRouter::Close All Modals sent Nov 23 10:54:25 volumiojw2 volumio[687]: info: CoreCommandRouter::Close All Modals sent Nov 23 10:54:26 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 23 10:54:26 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 23 10:54:26 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 23 10:54:31 volumiojw2 ntpd[642]: Soliciting pool server 185.244.195.159 Nov 23 10:54:32 volumiojw2 ntpd[642]: Soliciting pool server 159.69.64.189 Nov 23 10:54:32 volumiojw2 ntpd[642]: Soliciting pool server 176.9.157.155 Nov 23 10:54:32 volumiojw2 volumio[687]: info: BOOT COMPLETED Nov 23 10:54:33 volumiojw2 ntpd[642]: Soliciting pool server 159.69.245.253 Nov 23 10:54:33 volumiojw2 ntpd[642]: Soliciting pool server 85.214.83.151 Nov 23 10:54:33 volumiojw2 ntpd[642]: Soliciting pool server 185.207.105.38 Nov 23 10:54:34 volumiojw2 ntpd[642]: Soliciting pool server 162.159.200.1 Nov 23 10:54:34 volumiojw2 ntpd[642]: Soliciting pool server 78.46.162.102 Nov 23 10:54:34 volumiojw2 ntpd[642]: Soliciting pool server 78.46.60.40 Nov 23 10:54:34 volumiojw2 ntpd[642]: Soliciting pool server 194.25.134.196 Nov 23 10:54:35 volumiojw2 ntpd[642]: Soliciting pool server 131.188.3.220 Nov 23 10:54:35 volumiojw2 ntpd[642]: Soliciting pool server 80.153.195.191 Nov 23 10:54:35 volumiojw2 ntpd[642]: Soliciting pool server 78.47.56.71 Nov 23 10:54:36 volumiojw2 ntpd[642]: Soliciting pool server 144.76.66.157 Nov 23 10:54:36 volumiojw2 ntpd[642]: Soliciting pool server 49.12.125.53 Nov 23 10:54:37 volumiojw2 ntpd[642]: Soliciting pool server 88.198.200.96 Nov 23 10:54:37 volumiojw2 ntpd[642]: Soliciting pool server 2a13:7840:c0de::2 Nov 23 10:54:40 volumiojw2 ntpd[642]: receive: Unexpected origin timestamp 0xeaec24df.3c0721cf does not match aorg 0000000000.00000000 from server@159.69.64.189 xmt 0xeaec24e0.0a2d7913 Nov 23 10:54:40 volumiojw2 ntpd[642]: receive: Unexpected origin timestamp 0xeaec24df.3becf2c1 does not match aorg 0000000000.00000000 from server@194.25.134.196 xmt 0xeaec24e0.0b3310a2 Nov 23 10:54:40 volumiojw2 ntpd[642]: receive: Unexpected origin timestamp 0xeaec24df.3c012ac5 does not match aorg 0000000000.00000000 from server@85.214.83.151 xmt 0xeaec24e0.0b169da0 Nov 23 10:55:09 volumiojw2 volumio[687]: info: CoreCommandRouter::volumioGetQueue Nov 23 10:55:09 volumiojw2 volumio[687]: info: CoreStateMachine::getQueue Nov 23 10:55:09 volumiojw2 volumio[687]: info: CorePlayQueue::getQueue Nov 23 10:55:16 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 23 10:55:16 volumiojw2 volumio[687]: info: Preload queue cleared Nov 23 10:55:19 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 23 10:55:19 volumiojw2 volumio[687]: info: Preload queue cleared Nov 23 10:55:22 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 23 10:55:22 volumiojw2 volumio[687]: info: Preload queue cleared Nov 23 10:55:25 volumiojw2 volumio[687]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 23 10:55:25 volumiojw2 volumio[687]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 10:55:25 volumiojw2 volumio[687]: TypeError: Cannot read property 'length' of undefined Nov 23 10:55:25 volumiojw2 volumio[687]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 23 10:55:25 volumiojw2 volumio[687]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 23 10:55:25 volumiojw2 volumio[687]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 23 10:55:25 volumiojw2 volumio[687]: at Parser.emit (events.js:315:20) Nov 23 10:55:25 volumiojw2 volumio[687]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 23 10:55:25 volumiojw2 volumio[687]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 23 10:55:25 volumiojw2 volumio[687]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 23 10:55:25 volumiojw2 volumio[687]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 23 10:55:25 volumiojw2 volumio[687]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 23 10:55:25 volumiojw2 volumio[687]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 23 10:55:25 volumiojw2 volumio[687]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 23 10:55:25 volumiojw2 volumio[687]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 23 10:55:25 volumiojw2 volumio[687]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 23 10:55:25 volumiojw2 volumio[687]: at IncomingMessage.emit (events.js:327:22) Nov 23 10:55:25 volumiojw2 volumio[687]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 23 10:55:25 volumiojw2 volumio[687]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 23 10:55:25 volumiojw2 volumio[687]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 10:55:26 volumiojw2 sudo[1252]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-23 10:54 Nov 23 10:55:26 volumiojw2 sudo[1252]: 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"