-- Logs begin at Sun 2024-10-13 18:18:51 KST, end at Sun 2024-10-13 18:23:43 KST. -- Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="authenticated as 315qwx3mljr4qa5wmt65voiq7qjq" Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="dealer connection opened" Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="initializing zeroconf session, username: 315qwx3mljr4qa5wmt65voiq7qjq" Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="received connection id: NDFmNWIzYjItNmRkYy00MDQyLWExZjctMzMwZWFjOTFhMjliK2RlYWxlcit0Y3A6Ly8wYWM5NDhlOC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArRDVDNTkyQ0M3MUE5NDQ2QTZDOTlGQUFBQjYyRjM1NEZBNDdBRjFCQkQzOTQ2NTBEOEFGMENCREE1NjQyM0RBRA==" Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="put connect state because NEW_DEVICE" Oct 13 18:22:00 neocurpi go-librespot[858]: time="2024-10-13T18:22:00+09:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 13 18:22:01 neocurpi go-librespot[858]: time="2024-10-13T18:22:01+09:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 13 18:22:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:22:01 neocurpi go-librespot[858]: time="2024-10-13T18:22:01+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 13 18:22:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:22:01 neocurpi go-librespot[858]: time="2024-10-13T18:22:01+09:00" level=debug msg="autoplay enabled: false" Oct 13 18:22:01 neocurpi volumio[675]: info: No need to fix Spotify hosts Oct 13 18:22:02 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: personal_radio , handleBrowseUri Oct 13 18:22:03 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:03 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:03 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:03 neocurpi volumio[675]: (node:675) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Oct 13 18:22:03 neocurpi volumio[675]: (Use `node --trace-deprecation ...` to show where the warning was created) Oct 13 18:22:03 neocurpi volumio[675]: (node:675) [DEP0106] DeprecationWarning: crypto.createDecipher is deprecated. Oct 13 18:22:03 neocurpi volumio[675]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 13 18:22:03 neocurpi volumio[675]: SPOTIFY: BQDPX1KauGUDymW7-UHZROAUVFoX86OJQNV-uZeD5xaghyvvrZcA21CZjYjuUfByaPP3L9jfLPy-5ibNAJI7oWpFqxo6IHzzaYKVzc6LZ-J4bh5zYm_e3V00D2TQN4x3OgTOgyqhKaIRgzxB86WgHYbGT9eaV9ftMAPTy1vMYw9MPcqH8YpJYq5x3VRKE9fThrXUEDlj3PyNpI-VrzkSUt-jEN8giexQV3wsSs1Ot2WezKJigdQo4bbske5x0uUtGfMYYFUxMu6SpAr-lfo Oct 13 18:22:03 neocurpi volumio[675]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 13 18:22:03 neocurpi volumio[675]: info: New Spotify access token = BQDPX1KauGUDymW7-UHZROAUVFoX86OJQNV-uZeD5xaghyvvrZcA21CZjYjuUfByaPP3L9jfLPy-5ibNAJI7oWpFqxo6IHzzaYKVzc6LZ-J4bh5zYm_e3V00D2TQN4x3OgTOgyqhKaIRgzxB86WgHYbGT9eaV9ftMAPTy1vMYw9MPcqH8YpJYq5x3VRKE9fThrXUEDlj3PyNpI-VrzkSUt-jEN8giexQV3wsSs1Ot2WezKJigdQo4bbske5x0uUtGfMYYFUxMu6SpAr-lfo Oct 13 18:22:03 neocurpi volumio[675]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 13 18:22:03 neocurpi volumio[675]: info: Starting Shairport Sync Oct 13 18:22:04 neocurpi volumio[675]: info: Starting Shairport Sync Oct 13 18:22:04 neocurpi volumio[675]: info: Starting Shairport Sync Oct 13 18:22:04 neocurpi sudo[878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 13 18:22:04 neocurpi sudo[878]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:22:05 neocurpi sudo[886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 13 18:22:05 neocurpi sudo[886]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:22:05 neocurpi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 13 18:22:05 neocurpi systemd[1]: shairport-sync.service: Succeeded. Oct 13 18:22:05 neocurpi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:05 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:05 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:05 neocurpi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:06 neocurpi sudo[894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 13 18:22:06 neocurpi sudo[878]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:06 neocurpi sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:22:06 neocurpi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 13 18:22:06 neocurpi systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 13 18:22:06 neocurpi systemd[1]: shairport-sync.service: Succeeded. Oct 13 18:22:06 neocurpi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:06 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:06 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:07 neocurpi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:07 neocurpi sudo[886]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:07 neocurpi volumio[675]: info: go-librespot daemon successfully initialized Oct 13 18:22:07 neocurpi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 13 18:22:07 neocurpi systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 13 18:22:07 neocurpi systemd[1]: shairport-sync.service: Succeeded. Oct 13 18:22:07 neocurpi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:07 neocurpi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 13 18:22:07 neocurpi sudo[894]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:07 neocurpi volumio[675]: info: Shairport-Sync Started Oct 13 18:22:07 neocurpi volumio[675]: Error adding Membership: Error: addMembership EINVAL Oct 13 18:22:07 neocurpi volumio[675]: info: Shairport-Sync Started Oct 13 18:22:08 neocurpi volumio[675]: info: Shairport-Sync Started Oct 13 18:22:08 neocurpi volumio[675]: SPOTIFY: User informations: {"display_name":"Neocur","external_urls":{"spotify":"https://open.spotify.com/user/315qwx3mljr4qa5wmt65voiq7qjq"},"href":"https://api.spotify.com/v1/users/315qwx3mljr4qa5wmt65voiq7qjq","id":"315qwx3mljr4qa5wmt65voiq7qjq","images":[],"type":"user","uri":"spotify:user:315qwx3mljr4qa5wmt65voiq7qjq","followers":{"href":null,"total":0},"country":"KR","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"neocur@naver.com"} Oct 13 18:22:08 neocurpi volumio[675]: info: Spotify Successfully logged in Oct 13 18:22:09 neocurpi volumio[675]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 13 18:22:09 neocurpi volumio[675]: info: [1728811329026] CoreMusicLibrary::Adding element Spotify Oct 13 18:22:09 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 18:22:09 neocurpi volumio[675]: Cannot find translation for source 개인 라디오 Oct 13 18:22:09 neocurpi volumio[675]: Cannot find translation for source Spotify Oct 13 18:22:10 neocurpi volumio[675]: info: Initializing connection to go-librespot Websocket Oct 13 18:22:10 neocurpi go-librespot[858]: time="2024-10-13T18:22:10+09:00" level=debug msg="new websocket client" Oct 13 18:22:10 neocurpi volumio[675]: info: Connection to go-librespot Websocket established Oct 13 18:22:11 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:22:11 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:13 neocurpi mpd[841]: Oct 13 18:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 13 18:22:13 neocurpi systemd[1]: Started Music Player Daemon. Oct 13 18:22:13 neocurpi volumio[675]: Upnp client error: Error: This socket has been ended by the other party Oct 13 18:22:13 neocurpi volumio[675]: Upnp client error: Error: This socket has been ended by the other party Oct 13 18:22:13 neocurpi sudo[828]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:13 neocurpi sudo[817]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:13 neocurpi volumio[675]: Upnp client error: Error: This socket has been ended by the other party Oct 13 18:22:13 neocurpi volumio[675]: info: Getting Spotify volume Oct 13 18:22:13 neocurpi volumio[675]: info: Completed starting Core Plugins Oct 13 18:22:13 neocurpi volumio[675]: info: ------------------------------------------- Oct 13 18:22:13 neocurpi volumio[675]: info: ----- MyVolumio plugins startup ---- Oct 13 18:22:13 neocurpi volumio[675]: info: ------------------------------------------- Oct 13 18:22:13 neocurpi volumio[675]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 13 18:22:13 neocurpi volumio[675]: info: Spotify volume: 100 Oct 13 18:22:14 neocurpi volumio[675]: error: MPD error: The expression evaluated to a falsy value: Oct 13 18:22:14 neocurpi volumio[675]: assert.ok(self.idling) Oct 13 18:22:14 neocurpi volumio[675]: error: The expression evaluated to a falsy value: Oct 13 18:22:14 neocurpi volumio[675]: assert.ok(self.idling) Oct 13 18:22:14 neocurpi volumio[675]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 13 18:22:14 neocurpi volumio[675]: info: MPD running with PID841 Oct 13 18:22:14 neocurpi volumio[675]: ,establishing connection Oct 13 18:22:14 neocurpi volumio[675]: error: updateQueue error: null Oct 13 18:22:14 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: personal_radio , handleBrowseUri Oct 13 18:22:14 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:14 neocurpi volumio[675]: error: updateQueue error: null Oct 13 18:22:14 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:14 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:15 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 18:22:15 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:22:15 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 18:22:15 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:22:15 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:16 neocurpi volumio[805]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 13 18:22:17 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:22:17 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:22:19 neocurpi volumio[675]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 13 18:22:22 neocurpi volumio[805]: ...........++++ Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin bluetooth to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin multiroom to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin metavolumio to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin cd_controller to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 13 18:22:23 neocurpi volumio[675]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 13 18:22:30 neocurpi volumio-remote-updater[477]: [2024-10-13 18:22:30] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Oct 13 18:22:35 neocurpi volumio-remote-updater[477]: [2024-10-13 18:22:35] [connect] Successful connection Oct 13 18:22:40 neocurpi volumio[675]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 13 18:22:40 neocurpi volumio[675]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 13 18:22:40 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:22:40 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:22:40 neocurpi volumio[675]: info: Starting MyVolumio Remote Streaming Endpoints Oct 13 18:22:41 neocurpi volumio[675]: info: MyVolumio login type: Token Oct 13 18:22:41 neocurpi volumio[675]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 13 18:22:41 neocurpi volumio[675]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 13 18:22:42 neocurpi volumio[805]: .........................++++ Oct 13 18:22:42 neocurpi volumio[805]: e is 65537 (0x010001) Oct 13 18:22:42 neocurpi volumio[805]: writing RSA key Oct 13 18:22:48 neocurpi volumio-remote-updater[477]: [2024-10-13 18:22:48] [connect] Successful connection Oct 13 18:22:49 neocurpi volumio[675]: info: Starting Streaming Service Transparent Proxy Oct 13 18:22:49 neocurpi volumio[675]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 13 18:22:49 neocurpi volumio[675]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 13 18:22:49 neocurpi volumio[675]: info: Streaming services startup Oct 13 18:22:49 neocurpi volumio[675]: info: Starting Streaming Daemon Oct 13 18:22:49 neocurpi sudo[962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 13 18:22:49 neocurpi sudo[962]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:22:50 neocurpi volumio[675]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 13 18:22:50 neocurpi sudo[962]: pam_unix(sudo:session): session closed for user root Oct 13 18:22:51 neocurpi volumio[675]: error: Cannot start Volumio Streaming Daemon Oct 13 18:22:51 neocurpi volumio[675]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 13 18:22:51 neocurpi volumio[675]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 13 18:22:51 neocurpi volumio[675]: verbose: New Socket.io Connection to 192.168.31.11 from 192.168.31.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 13 18:22:51 neocurpi volumio[675]: verbose: New Socket.io Connection to 192.168.31.11 from 192.168.31.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 13 18:22:51 neocurpi volumio[675]: verbose: New Socket.io Connection to 192.168.31.11 from 192.168.31.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 13 18:22:51 neocurpi volumio[675]: verbose: New Socket.io Connection to 192.168.31.11 from 192.168.31.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 13 18:22:51 neocurpi volumio-remote-updater[477]: [2024-10-13 18:22:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728811368 101 Oct 13 18:22:51 neocurpi volumio[675]: 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: 5 Oct 13 18:22:52 neocurpi volumio[675]: verbose: New Socket.io Connection to 192.168.31.11 from 192.168.31.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:52 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:52 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 13 18:22:52 neocurpi volumio[675]: info: Received Get System Info Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 18:22:52 neocurpi volumio[675]: info: Discovery: Getting this device information Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:52 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:22:52 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:22:52 neocurpi volumio[675]: info: Listing playlists Oct 13 18:22:52 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetQueue Oct 13 18:22:53 neocurpi volumio[675]: info: CoreStateMachine::getQueue Oct 13 18:22:53 neocurpi volumio[675]: info: CorePlayQueue::getQueue Oct 13 18:22:56 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 18:22:57 neocurpi volumio[675]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 13 18:22:57 neocurpi volumio[675]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 13 18:22:57 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 18:23:00 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetBrowseSources Oct 13 18:23:01 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 18:23:01 neocurpi volumio[675]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 13 18:23:02 neocurpi volumio[675]: 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 13 18:23:02 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:23:02 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:23:03 neocurpi volumio[675]: info: CoreCommandRouter::volumioGetState Oct 13 18:23:03 neocurpi volumio[675]: info: CorePlayQueue::getTrack 0 Oct 13 18:23:04 neocurpi volumio[675]: info: MyVolumio token set successfully Oct 13 18:23:04 neocurpi volumio[675]: info: MYVOLUMIO: Adding device Oct 13 18:23:04 neocurpi volumio[675]: info: MYVOLUMIO: Evaluating Server Oct 13 18:23:08 neocurpi volumio[675]: info: MyVolumio status changed Oct 13 18:23:08 neocurpi volumio[675]: info: Streaming services startup Oct 13 18:23:08 neocurpi volumio[675]: info: Starting Streaming Daemon Oct 13 18:23:08 neocurpi volumio[675]: info: Removing browser output: myVolumio user plan is not superstar Oct 13 18:23:08 neocurpi volumio[675]: info: Removing audio output: Oct 13 18:23:08 neocurpi volumio[675]: info: Stoppping Tunnel 1 Oct 13 18:23:09 neocurpi sudo[1026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 13 18:23:09 neocurpi sudo[1026]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:23:09 neocurpi sudo[1028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 13 18:23:09 neocurpi sudo[1028]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 18:23:09 neocurpi sudo[1026]: pam_unix(sudo:session): session closed for user root Oct 13 18:23:09 neocurpi volumio[675]: info: Setting Geolocation for MyVolumio to as1 Oct 13 18:23:09 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:09 neocurpi sudo[1028]: pam_unix(sudo:session): session closed for user root Oct 13 18:23:09 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:09 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:09 neocurpi volumio[675]: error: Cannot start Volumio Streaming Daemon Oct 13 18:23:09 neocurpi volumio[675]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 13 18:23:09 neocurpi volumio[675]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 13 18:23:09 neocurpi volumio[675]: info: Remote SSH Stopped Oct 13 18:23:09 neocurpi volumio[675]: STREAMING PROXY: Starting server on port 3245 Oct 13 18:23:09 neocurpi volumio[675]: Node JS runtime: 14 Oct 13 18:23:10 neocurpi volumio[675]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 13 18:23:10 neocurpi volumio[675]: info: Completed starting MyVolumio Plugin Oct 13 18:23:10 neocurpi volumio[675]: info: BOOT COMPLETED Oct 13 18:23:10 neocurpi volumio[675]: [Metrics] CommandRouter: 146s 19.34ms Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::volumiosetStartupVolume Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::Close All Modals sent Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::Close All Modals sent Oct 13 18:23:10 neocurpi volumio[675]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 13 18:23:10 neocurpi volumio[675]: info: Updating MyVolumio device info Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:10 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:11 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 13 18:23:11 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 13 18:23:11 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 13 18:23:11 neocurpi volumio[675]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 13 18:23:14 neocurpi volumio[675]: info: MYVOLUMIO: Adding device Oct 13 18:23:14 neocurpi volumio[675]: info: MYVOLUMIO: Evaluating Server Oct 13 18:23:16 neocurpi volumio[675]: info: Setting Geolocation for MyVolumio to as1 Oct 13 18:23:16 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:16 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:16 neocurpi volumio[675]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 13 18:23:17 neocurpi volumio[675]: info: Updating MyVolumio device info Oct 13 18:23:17 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 18:23:18 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , removeMyWebRadio Oct 13 18:23:18 neocurpi volumio[675]: info: {"name":"KBS 1Radio"} Oct 13 18:23:18 neocurpi volumio[675]: info: Saving local item my-web-radio Oct 13 18:23:18 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:23:18 neocurpi volumio[675]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 13 18:23:20 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:23:20 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:23:24 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 18:23:24 neocurpi volumio[675]: info: Preload queue cleared Oct 13 18:23:40 neocurpi volumio[675]: info: Oct 13 18:23:40 neocurpi volumio[675]: ---------------------------- My WebRadio Reloaded test Oct 13 18:23:40 neocurpi volumio[675]: info: CoreCommandRouter::executeOnPlugin: webradio , reloadMyKBSRadio Oct 13 18:23:40 neocurpi volumio[675]: info: "test" Oct 13 18:23:40 neocurpi volumio[675]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 18:23:40 neocurpi volumio[675]: ReferenceError: kbsRadios is not defined Oct 13 18:23:40 neocurpi volumio[675]: at Promise._successFn (/volumio/app/plugins/user_interface/rest_api/playback.js:264:15) Oct 13 18:23:40 neocurpi volumio[675]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 13 18:23:40 neocurpi volumio[675]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 13 18:23:40 neocurpi volumio[675]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 18:23:43 neocurpi sudo[1059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-13 18:22 Oct 13 18:23:43 neocurpi sudo[1059]: 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"