-- Logs begin at Thu 2019-02-14 23:11:59 NZDT, end at Sun 2024-12-01 20:30:21 NZDT. -- Dec 01 20:29:00 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:00+13:00" level=debug msg="completed keyexchange" Dec 01 20:29:00 volumio-lakay volumio[5896]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 01 20:29:00 volumio-lakay volumio[5896]: SPOTIFY: BQAIDZbLAs0heDVYnCveU--0EMmtRM-3uNo8fm7yZRdIAo38OIYG0fx6NqKEnQ5g1K96cYx5Fm0rT0GXedZ_6XJQKKTi0bCqhrThz00sZ5atetDtaXTby_2OyUORhUy59PY9HgY0AQLYSBhpF91Q4geqcX3jvZ3EOlte1cr_UHLqKs5U6cct5hRXeXfhHR5ev3VEMaowCRj2UVtePojfKyyhX-KnoU_DCm4M1Qil9aaOT0NP6YOqO88oLQM Dec 01 20:29:00 volumio-lakay volumio[5896]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 01 20:29:00 volumio-lakay volumio[5896]: info: New Spotify access token = BQAIDZbLAs0heDVYnCveU--0EMmtRM-3uNo8fm7yZRdIAo38OIYG0fx6NqKEnQ5g1K96cYx5Fm0rT0GXedZ_6XJQKKTi0bCqhrThz00sZ5atetDtaXTby_2OyUORhUy59PY9HgY0AQLYSBhpF91Q4geqcX3jvZ3EOlte1cr_UHLqKs5U6cct5hRXeXfhHR5ev3VEMaowCRj2UVtePojfKyyhX-KnoU_DCm4M1Qil9aaOT0NP6YOqO88oLQM Dec 01 20:29:00 volumio-lakay volumio[5896]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 01 20:29:00 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:00+13:00" level=debug msg="completed challenge" Dec 01 20:29:00 volumio-lakay volumio[5896]: SPOTIFY: User informations: {"country":"NZ","display_name":"Lakay64","email":"gteneza@xtra.co.nz","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1243942409"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/1243942409","id":"1243942409","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85e9b18ca9c1f9664b28d68d8b","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82e9b18ca9c1f9664b28d68d8b","width":64}],"product":"premium","type":"user","uri":"spotify:user:1243942409"} Dec 01 20:29:00 volumio-lakay volumio[5896]: info: Spotify Successfully logged in Dec 01 20:29:00 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 01 20:29:00 volumio-lakay volumio[5896]: info: [1733038140760] CoreMusicLibrary::Adding element Spotify Dec 01 20:29:00 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 20:29:00 volumio-lakay volumio[5896]: Cannot find translation for source YouTube Music Dec 01 20:29:00 volumio-lakay volumio[5896]: Cannot find translation for source 80s80s Radio Dec 01 20:29:00 volumio-lakay volumio[5896]: Cannot find translation for source Mother Earth Radio Dec 01 20:29:00 volumio-lakay volumio[5896]: Cannot find translation for source Radio Paradise Dec 01 20:29:00 volumio-lakay volumio[5896]: Cannot find translation for source Spotify Dec 01 20:29:00 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:00+13:00" level=debug msg="authenticated as 1243942409" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="authenticated as 1243942409" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="dealer connection opened" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="initializing zeroconf session, username: 1243942409" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="autoplay enabled: false" Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="received connection id: YWE3ODk3ODItMzMyNS00MjE4LWFlMDItNjk4ZTVjMzMzNjNkK2RlYWxlcit0Y3A6Ly8wYWM5NDg5ZC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArNUQ0QjBFMTFDMTE1QTZGRDZCNENDNkNCOTFCN0QwRTk3OEM2QzJBNkE1MTgwQjRBNzlBNkNGNkFCRkExQTlFRA==" Dec 01 20:29:01 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:01+13:00" level=debug msg="put connect state because NEW_DEVICE" Dec 01 20:29:02 volumio-lakay volumio[5896]: info: go-librespot daemon successfully initialized Dec 01 20:29:04 volumio-lakay volumio[5896]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 01 20:29:05 volumio-lakay volumio[5896]: info: Initializing connection to go-librespot Websocket Dec 01 20:29:05 volumio-lakay go-librespot[6056]: time="2024-12-01T20:29:05+13:00" level=debug msg="new websocket client" Dec 01 20:29:05 volumio-lakay volumio[5896]: info: Connection to go-librespot Websocket established Dec 01 20:29:05 volumio-lakay sudo[6105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 20:29:05 volumio-lakay sudo[6105]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:05 volumio-lakay sudo[6105]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:05 volumio-lakay sudo[6108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 20:29:05 volumio-lakay sudo[6108]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:05 volumio-lakay sudo[6108]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:05 volumio-lakay sudo[6111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 01 20:29:05 volumio-lakay sudo[6111]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:05 volumio-lakay systemd[1]: Started UPnP Renderer front-end to MPD. Dec 01 20:29:05 volumio-lakay sudo[6111]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:05 volumio-lakay volumio[5896]: info: Upmpdcli Daemon Started Dec 01 20:29:05 volumio-lakay volumio[6113]: writing RSA key Dec 01 20:29:05 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:08 volumio-lakay volumio[5896]: info: Getting Spotify volume Dec 01 20:29:08 volumio-lakay volumio[5896]: info: Spotify volume: 100 Dec 01 20:29:08 volumio-lakay volumio[5896]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 01 20:29:08 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:29:08 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin bluetooth to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin multiroom to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin metavolumio to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin cd_controller to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 01 20:29:09 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 01 20:29:10 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:10 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:10 volumio-lakay volumio[5896]: info: Starting MyVolumio Remote Streaming Endpoints Dec 01 20:29:10 volumio-lakay volumio[5896]: info: MyVolumio login type: Token Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 01 20:29:10 volumio-lakay volumio[5896]: info: Starting Streaming Service Transparent Proxy Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 01 20:29:10 volumio-lakay volumio[5896]: info: Streaming services startup Dec 01 20:29:10 volumio-lakay volumio[5896]: info: Starting Streaming Daemon Dec 01 20:29:10 volumio-lakay sudo[6156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 01 20:29:10 volumio-lakay sudo[6156]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:10 volumio-lakay sudo[6156]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:10 volumio-lakay volumio[5896]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 01 20:29:10 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:10 volumio-lakay volumio[5896]: error: Cannot start Volumio Streaming Daemon Dec 01 20:29:10 volumio-lakay volumio[5896]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 01 20:29:10 volumio-lakay volumio[5896]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 01 20:29:11 volumio-lakay volumio[5896]: STREAMING PROXY: Starting server on port 3245 Dec 01 20:29:11 volumio-lakay volumio[5896]: Node JS runtime: 14 Dec 01 20:29:12 volumio-lakay volumio[5896]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 01 20:29:13 volumio-lakay volumio[5896]: info: MyVolumio token set successfully Dec 01 20:29:13 volumio-lakay volumio[5896]: info: MYVOLUMIO: Adding device Dec 01 20:29:13 volumio-lakay volumio[5896]: info: MYVOLUMIO: Evaluating Server Dec 01 20:29:13 volumio-lakay volumio[5896]: info: MyVolumio status changed Dec 01 20:29:13 volumio-lakay volumio[5896]: info: Streaming services startup Dec 01 20:29:13 volumio-lakay volumio[5896]: info: Starting Streaming Daemon Dec 01 20:29:13 volumio-lakay volumio[5896]: info: Removing browser output: myVolumio user plan is not superstar Dec 01 20:29:13 volumio-lakay volumio[5896]: info: Removing audio output: Dec 01 20:29:13 volumio-lakay volumio[5896]: info: Stoppping Tunnel 1 Dec 01 20:29:13 volumio-lakay sudo[6221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 01 20:29:13 volumio-lakay sudo[6221]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:13 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:13 volumio-lakay sudo[6221]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:13 volumio-lakay volumio[5896]: error: Cannot start Volumio Streaming Daemon Dec 01 20:29:13 volumio-lakay volumio[5896]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 01 20:29:13 volumio-lakay volumio[5896]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 01 20:29:13 volumio-lakay sudo[6224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 01 20:29:13 volumio-lakay sudo[6224]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:13 volumio-lakay sudo[6224]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:14 volumio-lakay volumio[5896]: info: Remote SSH Stopped Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 20:29:15 volumio-lakay volumio[5896]: info: Discovery: Getting this device information Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 20:29:15 volumio-lakay volumio[5896]: info: Setting Geolocation for MyVolumio to au1 Dec 01 20:29:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:16 volumio-lakay volumio[5896]: info: Updating MyVolumio device info Dec 01 20:29:16 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:17 volumio-lakay volumio[5896]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 01 20:29:17 volumio-lakay volumio[5896]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 01 20:29:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:21 volumio-lakay volumio[5896]: info: MYVOLUMIO: Adding device Dec 01 20:29:21 volumio-lakay volumio[5896]: info: MYVOLUMIO: Evaluating Server Dec 01 20:29:21 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:22 volumio-lakay volumio[5896]: info: Setting Geolocation for MyVolumio to au1 Dec 01 20:29:22 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:22 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:22 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:23 volumio-lakay volumio[5896]: info: Updating MyVolumio device info Dec 01 20:29:23 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:24 volumio-lakay volumio[5896]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 01 20:29:24 volumio-lakay volumio[5896]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 01 20:29:25 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 20:29:25 volumio-lakay volumio[5896]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 01 20:29:25 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:29:25 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:29:25 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:28 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 20:29:28 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:28 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 01 20:29:29 volumio-lakay volumio-remote-updater[644]: No test mode Dec 01 20:29:29 volumio-lakay volumio-remote-updater[644]: No alpha test mode Dec 01 20:29:29 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 01 20:29:29 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetBrowseSources Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 20:29:30 volumio-lakay volumio[5896]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 01 20:29:30 volumio-lakay volumio[5896]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 01 20:29:30 volumio-lakay volumio[5896]: info: Completed starting MyVolumio Plugin Dec 01 20:29:30 volumio-lakay volumio[5896]: [Metrics] CommandRouter: 36s 973.88ms Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumiosetStartupVolume Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::Close All Modals sent Dec 01 20:29:30 volumio-lakay volumio[5896]: info: CoreCommandRouter::Close All Modals sent Dec 01 20:29:30 volumio-lakay kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Dec 01 20:29:31 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 01 20:29:31 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 01 20:29:31 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 01 20:29:33 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:37 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:37 volumio-lakay volumio[5896]: info: BOOT COMPLETED Dec 01 20:29:41 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 20:29:45 volumio-lakay volumio[5896]: info: Discovery: Getting this device information Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 20:29:45 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:49 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:53 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:57 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:29:59 volumio-lakay sudo[6334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 20:29:59 volumio-lakay sudo[6334]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:59 volumio-lakay sudo[6334]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:59 volumio-lakay sudo[6337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 20:29:59 volumio-lakay sudo[6337]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:59 volumio-lakay sudo[6337]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:59 volumio-lakay volumio[5896]: verbose: New Socket.io Connection to 192.168.0.101 from 192.168.0.31 UA: Mozilla/5.0 (Linux; Android 14; SM-A556E Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 01 20:29:59 volumio-lakay sudo[6340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 20:29:59 volumio-lakay sudo[6340]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:59 volumio-lakay sudo[6340]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:59 volumio-lakay sudo[6343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 20:29:59 volumio-lakay sudo[6343]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:29:59 volumio-lakay sudo[6343]: pam_unix(sudo:session): session closed for user root Dec 01 20:29:59 volumio-lakay volumio[5896]: verbose: New Socket.io Connection to 192.168.0.101 from 192.168.0.31 UA: Mozilla/5.0 (Linux; Android 14; SM-A556E Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 01 20:29:59 volumio-lakay volumio[5896]: info: Listing playlists Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 01 20:29:59 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioPlay Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CoreStateMachine::play index undefined Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CoreStateMachine::startPlaybackTimer Dec 01 20:30:01 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:01 volumio-lakay volumio[5896]: info: [1733038201148] ControllerSpotify::clearAddPlayTrack Dec 01 20:30:01 volumio-lakay volumio[5896]: info: Sending Spotify command with payload to local API: /player/play Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="resolved context of track" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=trace msg="emitting websocket event: will_play" Dec 01 20:30:01 volumio-lakay volumio[5896]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","play_origin":"go-librespot"}} Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1281" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="selected format OGG_VORBIS_320 (b1e23bb425ba567b5f1075414795d44a09c309f0)" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:01 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:01+13:00" level=debug msg="requested aes key for file b1e23bb425ba567b5f1075414795d44a09c309f0, gid: 3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:02 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="fetched first chunk of 18, total size is 9369140 bytes" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="created new output device" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=info msg="loaded track \"September\" (paused: false, position: 0ms, duration: 215080ms, prefetched: false)" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=trace msg="scheduling prefetch in 185s" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=trace msg="emitting websocket event: metadata" Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","name":"September","artist_names":["Earth, Wind \u0026 Fire"],"album_name":"The Essential Earth, Wind \u0026 Fire","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d8cf89522a24e6c9b90cb2c2","position":0,"duration":215080,"release_date":"year:2014 month:3 day:25","track_number":14,"disc_number":1}} Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 20:30:03 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:03+13:00" level=trace msg="emitting websocket event: playing" Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","play_origin":"go-librespot"}} Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: PUSH STATE SPOTIFY Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: {"status":"play","service":"spop","title":"September","artist":"Earth, Wind & Fire","album":"The Essential Earth, Wind & Fire","albumart":"https://i.scdn.co/image/ab67616d00001e02d8cf89522a24e6c9b90cb2c2","uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","trackType":"spotify","seek":0,"duration":215,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreCommandRouter::servicePushState Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"September","artist":"Earth, Wind & Fire","album":"The Essential Earth, Wind & Fire","albumart":"https://i.scdn.co/image/ab67616d00001e02d8cf89522a24e6c9b90cb2c2","uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","trackType":"spotify","seek":0,"duration":215,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 01 20:30:03 volumio-lakay volumio[5896]: verbose: CURRENT POSITION 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::syncState stateService play Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::syncState currentStatus stop Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: PUSH STATE SPOTIFY Dec 01 20:30:03 volumio-lakay volumio[5896]: SPOTIFY: {"status":"play","service":"spop","title":"September","artist":"Earth, Wind & Fire","album":"The Essential Earth, Wind & Fire","albumart":"https://i.scdn.co/image/ab67616d00001e02d8cf89522a24e6c9b90cb2c2","uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","trackType":"spotify","seek":0,"duration":215,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreCommandRouter::servicePushState Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"September","artist":"Earth, Wind & Fire","album":"The Essential Earth, Wind & Fire","albumart":"https://i.scdn.co/image/ab67616d00001e02d8cf89522a24e6c9b90cb2c2","uri":"spotify:track:3wpLkju0bJy89kjgdRys0j","trackType":"spotify","seek":0,"duration":215,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 01 20:30:03 volumio-lakay volumio[5896]: verbose: CURRENT POSITION 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::syncState stateService play Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::syncState currentStatus play Dec 01 20:30:03 volumio-lakay volumio[5896]: info: Received an update from plugin. extracting info from payload Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::pushState Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioPushState Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreStateMachine::pushState Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:03 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioPushState Dec 01 20:30:06 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:30:08 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetVisibleSources Dec 01 20:30:08 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 20:30:08 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetQueue Dec 01 20:30:08 volumio-lakay volumio[5896]: info: CoreStateMachine::getQueue Dec 01 20:30:08 volumio-lakay volumio[5896]: info: CorePlayQueue::getQueue Dec 01 20:30:10 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:30:14 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:30:14 volumio-lakay go-librespot[6056]: time="2024-12-01T20:30:14+13:00" level=debug msg="fetched chunk 4/17, size: 524288" uri="spotify:track:3wpLkju0bJy89kjgdRys0j" Dec 01 20:30:14 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 20:30:14 volumio-lakay volumio[5896]: info: Preload queue cleared Dec 01 20:30:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 20:30:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 20:30:15 volumio-lakay volumio[5896]: info: Discovery: Getting this device information Dec 01 20:30:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:30:15 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:15 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 20:30:17 volumio-lakay volumio[5896]: info: Preload queue cleared Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 01 20:30:17 volumio-lakay volumio[5896]: info: Received Get System Version Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 20:30:17 volumio-lakay volumio[5896]: info: Received Get System Info Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 20:30:17 volumio-lakay volumio[5896]: info: Discovery: Getting this device information Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::volumioGetState Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CorePlayQueue::getTrack 0 Dec 01 20:30:17 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 20:30:18 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:30:19 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 20:30:20 volumio-lakay volumio[5896]: info: Preload queue cleared Dec 01 20:30:21 volumio-lakay volumio[5896]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 20:30:21 volumio-lakay volumio[5896]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 20:30:21 volumio-lakay volumio[5896]: TypeError: Cannot read property 'length' of undefined Dec 01 20:30:21 volumio-lakay volumio[5896]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Dec 01 20:30:21 volumio-lakay volumio[5896]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Dec 01 20:30:21 volumio-lakay volumio[5896]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Dec 01 20:30:21 volumio-lakay volumio[5896]: at Parser.emit (events.js:315:20) Dec 01 20:30:21 volumio-lakay volumio[5896]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Dec 01 20:30:21 volumio-lakay volumio[5896]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Dec 01 20:30:21 volumio-lakay volumio[5896]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Dec 01 20:30:21 volumio-lakay volumio[5896]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Dec 01 20:30:21 volumio-lakay volumio[5896]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Dec 01 20:30:21 volumio-lakay volumio[5896]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Dec 01 20:30:21 volumio-lakay volumio[5896]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Dec 01 20:30:21 volumio-lakay volumio[5896]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Dec 01 20:30:21 volumio-lakay volumio[5896]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Dec 01 20:30:21 volumio-lakay volumio[5896]: at IncomingMessage.emit (events.js:327:22) Dec 01 20:30:21 volumio-lakay volumio[5896]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 01 20:30:21 volumio-lakay volumio[5896]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 01 20:30:21 volumio-lakay volumio[5896]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 20:30:21 volumio-lakay sudo[6429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 20:29 Dec 01 20:30:21 volumio-lakay sudo[6429]: 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"