-- Logs begin at Sun 2024-10-20 12:03:21 +07, end at Sun 2024-10-20 12:06:12 +07. -- Oct 20 12:05:06 volumio-gow ntpd[682]: receive: Unexpected origin timestamp 0xeabf0dea.e39163c4 does not match aorg 0000000000.00000000 from server@202.28.116.236 xmt 0xeabf0e02.5467c583 Oct 20 12:05:07 volumio-gow volumio[893]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 20 12:05:07 volumio-gow volumio[893]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 20 12:05:07 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:07 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:07 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:07 volumio-gow volumio[893]: info: Starting MyVolumio Remote Streaming Endpoints Oct 20 12:05:07 volumio-gow volumio[893]: info: MyVolumio login type: Token Oct 20 12:05:07 volumio-gow volumio[893]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 20 12:05:07 volumio-gow volumio[893]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 20 12:05:08 volumio-gow volumio-remote-updater[491]: [2024-10-20 12:05:08] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Oct 20 12:05:12 volumio-gow volumio[893]: info: Starting Streaming Service Transparent Proxy Oct 20 12:05:12 volumio-gow volumio[893]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 20 12:05:12 volumio-gow volumio[893]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 20 12:05:12 volumio-gow volumio[893]: info: Streaming services startup Oct 20 12:05:12 volumio-gow volumio[893]: info: Starting Streaming Daemon Oct 20 12:05:12 volumio-gow volumio[893]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 20 12:05:13 volumio-gow sudo[1668]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 20 12:05:13 volumio-gow sudo[1668]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 12:05:13 volumio-gow volumio[893]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 20 12:05:13 volumio-gow sudo[1668]: pam_unix(sudo:session): session closed for user root Oct 20 12:05:13 volumio-gow volumio[893]: error: Cannot start Volumio Streaming Daemon Oct 20 12:05:13 volumio-gow volumio[893]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 20 12:05:13 volumio-gow volumio[893]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 20 12:05:13 volumio-gow volumio-remote-updater[491]: [2024-10-20 12:05:13] [connect] Successful connection Oct 20 12:05:13 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.107 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 20 12:05:13 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.107 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 20 12:05:13 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.107 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 20 12:05:13 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103:3000 from 192.168.1.102 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:13 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:13 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:13 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:13 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:13 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:14 volumio-gow volumio-remote-updater[491]: [2024-10-20 12:05:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729400713 101 Oct 20 12:05:14 volumio-gow volumio[893]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 8 Oct 20 12:05:14 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:14 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:14 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:14 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:14 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:14 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:14 volumio-gow volumio[893]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 20 12:05:14 volumio-gow volumio[893]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 20 12:05:15 volumio-gow volumio[893]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 20 12:05:15 volumio-gow volumio-remote-updater[491]: No test mode Oct 20 12:05:15 volumio-gow volumio-remote-updater[491]: No alpha test mode Oct 20 12:05:15 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.107 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetVisibleSources Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:15 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:15 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 20 12:05:15 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:15 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:15 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:15 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:15 volumio-gow volumio[893]: info: Listing playlists Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetQueue Oct 20 12:05:15 volumio-gow volumio[893]: info: CoreStateMachine::getQueue Oct 20 12:05:15 volumio-gow volumio[893]: info: CorePlayQueue::getQueue Oct 20 12:05:18 volumio-gow volumio[893]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 20 12:05:18 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 20 12:05:18 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 20 12:05:19 volumio-gow volumio[893]: info: MyVolumio token set successfully Oct 20 12:05:19 volumio-gow volumio[893]: info: MYVOLUMIO: Adding device Oct 20 12:05:19 volumio-gow volumio[893]: info: MYVOLUMIO: Evaluating Server Oct 20 12:05:19 volumio-gow volumio[893]: info: MyVolumio status changed Oct 20 12:05:19 volumio-gow volumio[893]: info: Streaming services startup Oct 20 12:05:19 volumio-gow volumio[893]: info: Starting Streaming Daemon Oct 20 12:05:19 volumio-gow volumio[893]: info: Removing browser output: myVolumio user plan is not superstar Oct 20 12:05:19 volumio-gow volumio[893]: info: Removing audio output: Oct 20 12:05:19 volumio-gow volumio[893]: info: Stoppping Tunnel 1 Oct 20 12:05:20 volumio-gow volumio[893]: info: Setting Geolocation for MyVolumio to as1 Oct 20 12:05:20 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:20 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:20 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:20 volumio-gow sudo[1702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 20 12:05:20 volumio-gow sudo[1704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 20 12:05:20 volumio-gow sudo[1702]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 12:05:20 volumio-gow sudo[1704]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 12:05:20 volumio-gow volumio[893]: STREAMING PROXY: Starting server on port 3245 Oct 20 12:05:20 volumio-gow volumio[893]: Node JS runtime: 14 Oct 20 12:05:20 volumio-gow sudo[1702]: pam_unix(sudo:session): session closed for user root Oct 20 12:05:20 volumio-gow volumio[893]: error: Cannot start Volumio Streaming Daemon Oct 20 12:05:20 volumio-gow volumio[893]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 20 12:05:20 volumio-gow volumio[893]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 20 12:05:20 volumio-gow sudo[1704]: pam_unix(sudo:session): session closed for user root Oct 20 12:05:20 volumio-gow volumio[893]: info: Remote SSH Stopped Oct 20 12:05:20 volumio-gow volumio[893]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 20 12:05:21 volumio-gow volumio[893]: info: Updating MyVolumio device info Oct 20 12:05:21 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:21 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:21 volumio-gow volumio[893]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 20 12:05:21 volumio-gow volumio[893]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Oct 20 12:05:22 volumio-gow volumio[893]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 8.0.0; LGM-X800L Build/OPR1.170623.032; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetVisibleSources Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:22 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 20 12:05:22 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:22 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:22 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:22 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:22 volumio-gow volumio[893]: info: Listing playlists Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetQueue Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreStateMachine::getQueue Oct 20 12:05:22 volumio-gow volumio[893]: info: CorePlayQueue::getQueue Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 20 12:05:22 volumio-gow volumio[893]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 20 12:05:22 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:22 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:23 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 20 12:05:24 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 20 12:05:24 volumio-gow volumio[893]: info: MYVOLUMIO: Adding device Oct 20 12:05:24 volumio-gow volumio[893]: info: MYVOLUMIO: Evaluating Server Oct 20 12:05:25 volumio-gow volumio[893]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Oct 20 12:05:25 volumio-gow volumio[893]: info: Setting Geolocation for MyVolumio to as1 Oct 20 12:05:25 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:25 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:25 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:25 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:26 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 20 12:05:26 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 20 12:05:26 volumio-gow volumio[893]: info: Updating MyVolumio device info Oct 20 12:05:26 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:26 volumio-gow volumio[893]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 20 12:05:26 volumio-gow volumio[893]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetVisibleSources Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:27 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 20 12:05:27 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:27 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:27 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:27 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:27 volumio-gow volumio[893]: info: Listing playlists Oct 20 12:05:27 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetBrowseSources Oct 20 12:05:27 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 20 12:05:29 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:29 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:29 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:29 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 20 12:05:30 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:30 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:30 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:30 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:31 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:05:31 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:05:32 volumio-gow volumio[893]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 20 12:05:32 volumio-gow volumio[893]: info: Completed starting MyVolumio Plugin Oct 20 12:05:32 volumio-gow volumio[893]: info: BOOT COMPLETED Oct 20 12:05:32 volumio-gow volumio[893]: [Metrics] CommandRouter: 71s 413.83ms Oct 20 12:05:32 volumio-gow volumio[893]: info: CoreCommandRouter::volumiosetStartupVolume Oct 20 12:05:32 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 12:05:32 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 12:05:32 volumio-gow volumio[893]: info: CoreCommandRouter::Close All Modals sent Oct 20 12:05:32 volumio-gow volumio[893]: info: CoreCommandRouter::Close All Modals sent Oct 20 12:05:33 volumio-gow volumio[893]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Oct 20 12:05:33 volumio-gow volumio[893]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 20 12:05:33 volumio-gow volumio[893]: aplay: main:828: audio open error: No such device Oct 20 12:05:33 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 20 12:05:33 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 20 12:05:33 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 20 12:05:34 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:05:34 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:05:35 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 20 12:05:38 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:38 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:38 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:38 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:38 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:38 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 20 12:05:43 volumio-gow volumio[893]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 20 12:05:43 volumio-gow volumio[893]: info: Received Get System Version Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 12:05:43 volumio-gow volumio[893]: info: Received Get System Info Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:05:43 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:05:43 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:05:43 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:05:47 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:05:48 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:05:56 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:05:57 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{0005689F-6AD1-457A-B136-F83F9A590FE7}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{484FE4A2-FBCE-441A-AE33-6110D3A223AD}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{C0E60716-5930-4507-944A-B5AFF7B0DE8B}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{CC48F9A1-8B5E-4A33-BC36-31DEE0B99D49}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{5140EA61-793E-4BCD-9BDC-5FC47591B4D5}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Preloading song: upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{FBFFFFD9-129F-4070-B5F4-D0B50563D19C}.0.4 Oct 20 12:05:57 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{0005689F-6AD1-457A-B136-F83F9A590FE7}.0.4 in service upnp_browser Oct 20 12:05:57 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{484FE4A2-FBCE-441A-AE33-6110D3A223AD}.0.4 in service upnp_browser Oct 20 12:05:57 volumio-gow volumio[893]: info: No valid Plugin REST Endpoint Oct 20 12:05:57 volumio-gow volumio[893]: info: No valid Plugin REST Endpoint Oct 20 12:05:57 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{C0E60716-5930-4507-944A-B5AFF7B0DE8B}.0.4 in service upnp_browser Oct 20 12:05:57 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{CC48F9A1-8B5E-4A33-BC36-31DEE0B99D49}.0.4 in service upnp_browser Oct 20 12:05:57 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{5140EA61-793E-4BCD-9BDC-5FC47591B4D5}.0.4 in service upnp_browser Oct 20 12:05:58 volumio-gow volumio[893]: info: Exploding uri upnp/http://192.168.1.107:2869/upnphost/udhisapi.dll?control=uuid:f89874f8-451a-42f5-bf25-755fa0b0763a+urn:upnp-org:serviceId:ContentDirectory@{FBFFFFD9-129F-4070-B5F4-D0B50563D19C}.0.4 in service upnp_browser Oct 20 12:06:03 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:06:03 volumio-gow volumio[893]: info: Preload queue cleared Oct 20 12:06:08 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 12:06:08 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 12:06:08 volumio-gow volumio[893]: info: Discovery: Getting this device information Oct 20 12:06:08 volumio-gow volumio[893]: info: CoreCommandRouter::volumioGetState Oct 20 12:06:08 volumio-gow volumio[893]: info: CorePlayQueue::getTrack 0 Oct 20 12:06:08 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 12:06:09 volumio-gow ntpd[682]: Soliciting pool server 2406:3100:1010:c03::149 Oct 20 12:06:11 volumio-gow volumio[893]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 20 12:06:11 volumio-gow volumio[893]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 12:06:11 volumio-gow volumio[893]: TypeError: Cannot read property 'length' of undefined Oct 20 12:06:11 volumio-gow volumio[893]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 20 12:06:11 volumio-gow volumio[893]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 20 12:06:11 volumio-gow volumio[893]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 20 12:06:11 volumio-gow volumio[893]: at Parser.emit (events.js:315:20) Oct 20 12:06:11 volumio-gow volumio[893]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 20 12:06:11 volumio-gow volumio[893]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 20 12:06:11 volumio-gow volumio[893]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 20 12:06:11 volumio-gow volumio[893]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 20 12:06:11 volumio-gow volumio[893]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 20 12:06:11 volumio-gow volumio[893]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 20 12:06:11 volumio-gow volumio[893]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 20 12:06:11 volumio-gow volumio[893]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 20 12:06:11 volumio-gow volumio[893]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 20 12:06:11 volumio-gow volumio[893]: at IncomingMessage.emit (events.js:327:22) Oct 20 12:06:11 volumio-gow volumio[893]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 20 12:06:11 volumio-gow volumio[893]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 20 12:06:11 volumio-gow volumio[893]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 12:06:12 volumio-gow sudo[1774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-20 12:05 Oct 20 12:06:12 volumio-gow sudo[1774]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"