-- Logs begin at Thu 2024-10-10 18:37:34 CEST, end at Thu 2024-10-10 18:39:01 CEST. -- Oct 10 18:38:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 10 18:38:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 10 18:38:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 10 18:38:05 volumio systemd[1]: systemd-fsckd.service: Succeeded. Oct 10 18:38:07 volumio go-librespot[1742]: time="2024-10-10T18:38:07+02:00" level=debug msg="new websocket client" Oct 10 18:38:07 volumio volumio[803]: info: Connection to go-librespot Websocket established Oct 10 18:38:09 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Oct 10 18:38:09 volumio dhcpcd[737]: eth0: offered 192.168.1.43 from 192.168.1.1 Oct 10 18:38:09 volumio dhcpcd[737]: eth0: probing address 192.168.1.43/24 Oct 10 18:38:09 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 10 18:38:09 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:09 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 10 18:38:09 volumio go-librespot[1742]: time="2024-10-10T18:38:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Oct 10 18:38:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 18:38:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 18:38:09 volumio volumio[803]: info: Connection to go-librespot Websocket closed Oct 10 18:38:10 volumio volumio[803]: info: Getting Spotify volume Oct 10 18:38:10 volumio volumio[803]: (node:803) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 18:38:10 volumio volumio[803]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 10 18:38:10 volumio volumio[803]: (Use `node --trace-warnings ...` to show where the warning was created) Oct 10 18:38:10 volumio volumio[803]: (node:803) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Oct 10 18:38:10 volumio volumio[803]: (node:803) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Oct 10 18:38:12 volumio volumio[803]: info: Initializing connection to go-librespot Websocket Oct 10 18:38:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 18:38:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Oct 10 18:38:12 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 18:38:12 volumio systemd[1]: Started go-librespot Daemon. Oct 10 18:38:12 volumio go-librespot[1784]: Librespot-go daemon starting... Oct 10 18:38:12 volumio go-librespot[1784]: time="2024-10-10T18:38:12+02:00" level=info msg="generated new device id: f4110c3776197c9b20b6a8bf11c3919fe79fa3e6" Oct 10 18:38:12 volumio go-librespot[1784]: time="2024-10-10T18:38:12+02:00" level=debug msg="stored credentials found for sloam8" Oct 10 18:38:13 volumio dhcpcd[737]: eth0: leased 192.168.1.43 for 86400 seconds Oct 10 18:38:13 volumio avahi-daemon[673]: Registering new address record for 192.168.1.43 on eth0.IPv4. Oct 10 18:38:13 volumio dhcpcd[737]: eth0: adding route to 192.168.1.0/24 Oct 10 18:38:13 volumio dhcpcd[737]: eth0: changing default route via 192.168.1.1 Oct 10 18:38:13 volumio ntpd[1411]: ntpd exiting on signal 15 (Terminated) Oct 10 18:38:13 volumio systemd[1]: Stopping Network Time Service... Oct 10 18:38:13 volumio systemd[1]: ntp.service: Succeeded. Oct 10 18:38:13 volumio systemd[1]: Stopped Network Time Service. Oct 10 18:38:13 volumio systemd[1]: Starting Network Time Service... Oct 10 18:38:13 volumio ntpd[1824]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 10 18:38:13 volumio ntpd[1824]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 10 18:38:13 volumio systemd[1]: Started Network Time Service. Oct 10 18:38:13 volumio ntpd[1831]: proto: precision = 0.052 usec (-24) Oct 10 18:38:13 volumio dhcpcd[737]: eth0: deleting route to 169.254.0.0/16 Oct 10 18:38:13 volumio ntpd[1831]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 10 18:38:13 volumio avahi-daemon[673]: Withdrawing address record for 169.254.83.5 on eth0. Oct 10 18:38:13 volumio avahi-daemon[673]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.83.5. Oct 10 18:38:13 volumio avahi-daemon[673]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.43. Oct 10 18:38:13 volumio ntpd[1831]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 10 18:38:13 volumio ntpd[1831]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 653 days ago Oct 10 18:38:13 volumio ntpd[1831]: Listen and drop on 0 v6wildcard [::]:123 Oct 10 18:38:13 volumio ntpd[1831]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 10 18:38:13 volumio ntpd[1831]: Listen normally on 2 lo 127.0.0.1:123 Oct 10 18:38:13 volumio ntpd[1831]: Listen normally on 3 eth0 192.168.1.43:123 Oct 10 18:38:13 volumio ntpd[1831]: Listening on routing socket on fd #20 for interface updates Oct 10 18:38:13 volumio ntpd[1831]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 10 18:38:13 volumio ntpd[1831]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 10 18:38:14 volumio ntpd[1831]: Soliciting pool server 195.154.226.102 Oct 10 18:38:15 volumio ntpd[1831]: Soliciting pool server 37.59.63.125 Oct 10 18:38:15 volumio ntpd[1831]: Soliciting pool server 194.177.34.116 Oct 10 18:38:16 volumio ntpd[1831]: Soliciting pool server 37.187.150.174 Oct 10 18:38:16 volumio ntpd[1831]: Soliciting pool server 82.165.252.100 Oct 10 18:38:16 volumio ntpd[1831]: Soliciting pool server 129.250.35.250 Oct 10 18:38:17 volumio go-librespot[1784]: time="2024-10-10T18:38:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Oct 10 18:38:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 18:38:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 18:38:17 volumio volumio[803]: info: Discovery: adding eb9b3290-37de-4349-bebb-1ddb1aa86c99 Oct 10 18:38:17 volumio volumio[803]: info: Discovery: Found device Volumio Oct 10 18:38:17 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:17 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:17 volumio ntpd[1831]: Soliciting pool server 162.159.200.1 Oct 10 18:38:17 volumio ntpd[1831]: Soliciting pool server 82.64.81.218 Oct 10 18:38:17 volumio ntpd[1831]: Soliciting pool server 162.159.200.1 Oct 10 18:38:17 volumio volumio[803]: 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 10 18:38:17 volumio ntpd[1831]: Soliciting pool server 176.137.36.37 Oct 10 18:38:17 volumio volumio[803]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 18:38:17 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:17 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:17 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:17 volumio volumio[803]: SPOTIFY: SPOTIFY VOLUME undefined Oct 10 18:38:17 volumio volumio[803]: SPOTIFY: VOLUMIO VOLUME 75 Oct 10 18:38:17 volumio volumio[803]: info: Aligning Spotify Volume to Volumio Volume Oct 10 18:38:17 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:17 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:17 volumio volumio[803]: info: Setting Spotify Volume from Volumio: 75 Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 10 18:38:18 volumio volumio[803]: info: Received Get System Info Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:18 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:18 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:18 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 10 18:38:18 volumio ntpd[1831]: Soliciting pool server 178.32.23.17 Oct 10 18:38:18 volumio ntpd[1831]: Soliciting pool server 194.57.169.1 Oct 10 18:38:18 volumio ntpd[1831]: Soliciting pool server 82.65.248.56 Oct 10 18:38:19 volumio volumio[803]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.701&uuid=ccb7e8e0b6dee9fcc9b182c2ea29fa40" http://updates.volumio.org/downloader-v1/track-device Oct 10 18:38:19 volumio volumio[803]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 10 18:38:19 volumio volumio[803]: Dload Upload Total Spent Left Speed Oct 10 18:38:19 volumio volumio[803]: [1.5K blob data] Oct 10 18:38:19 volumio volumio[803]: retrying in 5 seconds, trial 1 Oct 10 18:38:19 volumio volumio[803]: info: Volumio Calling Home Oct 10 18:38:19 volumio volumio[803]: SPOTIFY: SETTING SPOTIFY VOLUME 75 Oct 10 18:38:19 volumio volumio[803]: info: Sending Spotify command with payload to local API: /player/volume Oct 10 18:38:19 volumio volumio[803]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 18:38:19 volumio volumio[803]: info: Volumio called home Oct 10 18:38:19 volumio ntpd[1831]: Soliciting pool server 51.68.44.27 Oct 10 18:38:19 volumio ntpd[1831]: Soliciting pool server 129.151.225.244 Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin bluetooth to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin multiroom to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin metavolumio to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin cd_controller to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 10 18:38:20 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:20 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:20 volumio volumio[803]: info: Starting MyVolumio Remote Streaming Endpoints Oct 10 18:38:20 volumio volumio[803]: info: MyVolumio login type: Token Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 10 18:38:20 volumio volumio[803]: info: Starting Streaming Service Transparent Proxy Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 10 18:38:20 volumio volumio[803]: info: Streaming services startup Oct 10 18:38:20 volumio volumio[803]: info: Starting Streaming Daemon Oct 10 18:38:20 volumio sudo[1875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 10 18:38:20 volumio sudo[1875]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:20 volumio sudo[1875]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:20 volumio volumio[803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 10 18:38:20 volumio volumio[803]: error: Cannot start Volumio Streaming Daemon Oct 10 18:38:20 volumio volumio[803]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 10 18:38:20 volumio volumio[803]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 10 18:38:20 volumio volumio[803]: STREAMING PROXY: Starting server on port 3245 Oct 10 18:38:20 volumio volumio[803]: Node JS runtime: 14 Oct 10 18:38:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 18:38:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Oct 10 18:38:20 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 18:38:20 volumio ntpd[1831]: Soliciting pool server 2001:41d0:303:21d0:: Oct 10 18:38:20 volumio systemd[1]: Started go-librespot Daemon. Oct 10 18:38:20 volumio go-librespot[1882]: Librespot-go daemon starting... Oct 10 18:38:20 volumio go-librespot[1882]: time="2024-10-10T18:38:20+02:00" level=info msg="generated new device id: 820df9f5856ba349479dd3774be95cc53323680e" Oct 10 18:38:20 volumio go-librespot[1882]: time="2024-10-10T18:38:20+02:00" level=debug msg="stored credentials found for sloam8" Oct 10 18:38:20 volumio volumio[803]: info: Initializing connection to go-librespot Websocket Oct 10 18:38:20 volumio go-librespot[1882]: time="2024-10-10T18:38:20+02:00" level=debug msg="new websocket client" Oct 10 18:38:20 volumio volumio[803]: info: Connection to go-librespot Websocket established Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="zeroconf server listening on port 46225" Oct 10 18:38:21 volumio volumio[803]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="obtained new client token: AAB/7TMd2shlip0OlWrK69gomPWuHLMXxhCWK1lyO0ihFvHIWlR1cYuqRbDr6E7ICK+/d1NNW46oUM59I5T2CCNlXj5wi50svpt7Iwl/jmKnjVxoE1Ru33NnbS4X+n5H63SGCEu7LwN2KJODvHq2ojdXPNdjVJLqDHm3wK1QYa1kvHQMXQ4uRA1YTXkVG8xilVlfaJtbeHDtaafvlmjrP6YpzLsJdKAr6+F39zCM56ibTatsAJtWU/d7PKa9" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="completed keyexchange" Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="completed challenge" Oct 10 18:38:21 volumio volumio[803]: info: MyVolumio token set successfully Oct 10 18:38:21 volumio volumio[803]: info: MYVOLUMIO: Adding device Oct 10 18:38:21 volumio volumio[803]: info: MYVOLUMIO: Evaluating Server Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="authenticated as sloam8" Oct 10 18:38:21 volumio volumio[803]: info: MyVolumio Plan changed: premium Oct 10 18:38:21 volumio volumio[803]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Oct 10 18:38:21 volumio volumio[803]: info: Removing browser output: myVolumio user plan is not superstar Oct 10 18:38:21 volumio volumio[803]: info: Removing audio output: Oct 10 18:38:21 volumio volumio[803]: info: MYVOLUMIO: Adding device Oct 10 18:38:21 volumio volumio[803]: info: MYVOLUMIO: Evaluating Server Oct 10 18:38:21 volumio volumio[803]: info: Remote config written successfully Oct 10 18:38:21 volumio volumio[803]: info: Starting Tunnel 1 Oct 10 18:38:21 volumio volumio[803]: info: Starting Tunnel Connection Checker Oct 10 18:38:21 volumio go-librespot[1882]: time="2024-10-10T18:38:21+02:00" level=debug msg="authenticated as sloam8" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="dealer connection opened" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="initializing zeroconf session, username: sloam8" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="autoplay enabled: false" Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="received connection id: MjM1ZjgxMGItMjhmZi00YTI2LWIxOWItM2NmNTQ2YzRlYWVjK2RlYWxlcit0Y3A6Ly8wYWNhNDBmZC5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNzRENjJEOUU5OEVBQTg2OUNBQzc0QkNCNjdCNjlGNTFEMjUwREYwMjM2NjY0QzM3MEI1NUVCRkI0OEEwNzhFQw==" Oct 10 18:38:22 volumio volumio[803]: info: MYVolumio Device enabled Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Oct 10 18:38:22 volumio volumio[803]: info: MyVolumio status changed Oct 10 18:38:22 volumio volumio[803]: info: Streaming services startup Oct 10 18:38:22 volumio volumio[803]: info: Starting Streaming Daemon Oct 10 18:38:22 volumio sudo[1923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Oct 10 18:38:22 volumio sudo[1923]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Oct 10 18:38:22 volumio sudo[1923]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: [1728578302177] Starting BluetoothController Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Oct 10 18:38:22 volumio go-librespot[1882]: time="2024-10-10T18:38:22+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Oct 10 18:38:22 volumio sudo[1926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 10 18:38:22 volumio sudo[1926]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio sudo[1926]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: MRS: MultiRoom plugin initialized Oct 10 18:38:22 volumio volumio[803]: info: MRS: STOPPING SNAPCLIENT Oct 10 18:38:22 volumio volumio[803]: info: MRS: Snap server stop Oct 10 18:38:22 volumio sudo[1942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 10 18:38:22 volumio sudo[1942]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio volumio[803]: info: MRS: STOPPING volumioStreaming Oct 10 18:38:22 volumio sudo[1945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 10 18:38:22 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio sudo[1942]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio sudo[1948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 10 18:38:22 volumio sudo[1948]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Oct 10 18:38:22 volumio sudo[1951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 10 18:38:22 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio sudo[1948]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Oct 10 18:38:22 volumio volumio[803]: info: Preparing to generate the ALSA configuration file Oct 10 18:38:22 volumio volumio[803]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 10 18:38:22 volumio volumio[803]: info: Reading ALSA contributions from plugins. Oct 10 18:38:22 volumio volumio[803]: info: Setting Geolocation for MyVolumio to eu7 Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: Setting Geolocation for MyVolumio to eu10 Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: MRS: Removed streaming files Oct 10 18:38:22 volumio volumio[803]: info: MRS: volumioStreaming STOPPED Oct 10 18:38:22 volumio volumio[803]: info: MRS: SNAPSERVER STOPPED Oct 10 18:38:22 volumio volumio[803]: info: MRS: SNAPCLIENT STOPPED Oct 10 18:38:22 volumio volumio[803]: error: Cannot start Volumio Streaming Daemon Oct 10 18:38:22 volumio volumio[803]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 10 18:38:22 volumio volumio[803]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 10 18:38:22 volumio volumio[803]: info: Asound.conf file written Oct 10 18:38:22 volumio sudo[1954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 10 18:38:22 volumio sudo[1954]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio sudo[1954]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: Output device has changed, restarting MPD Oct 10 18:38:22 volumio sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 10 18:38:22 volumio sudo[1959]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio sudo[1959]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: Output device has changed, restarting Shairport Sync Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:22 volumio sudo[1962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 10 18:38:22 volumio sudo[1962]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio systemd[1]: Stopping Music Player Daemon... Oct 10 18:38:22 volumio volumio[803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 10 18:38:22 volumio volumio[803]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 10 18:38:22 volumio systemd[1]: mpd.service: Succeeded. Oct 10 18:38:22 volumio systemd[1]: Stopped Music Player Daemon. Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 10 18:38:22 volumio volumio[803]: info: MRS: Pushing multiroomSync output for this device Oct 10 18:38:22 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:22 volumio volumio[803]: info: Adding audio output: Oct 10 18:38:22 volumio volumio[803]: info: Adding audio output: Oct 10 18:38:22 volumio sudo[1971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Oct 10 18:38:22 volumio sudo[1971]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio volumio[803]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Oct 10 18:38:22 volumio volumio[803]: info: Adding METAVOLUMIO REST API Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 10 18:38:22 volumio volumio[803]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 10 18:38:22 volumio volumio[803]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 10 18:38:22 volumio volumio[803]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Oct 10 18:38:22 volumio volumio[803]: info: Adding Manifest REST API Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Oct 10 18:38:22 volumio volumio[803]: info: Preparing CD Folders Oct 10 18:38:22 volumio volumio[803]: info: Adding CD REST API Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 10 18:38:22 volumio volumio[803]: info: Starting UDEV Watcher for CD Oct 10 18:38:22 volumio volumio[803]: info: Detecting CD presence with UDEV Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Oct 10 18:38:22 volumio volumio[803]: info: Adding inputs REST Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 10 18:38:22 volumio volumio[803]: info: Scanning Audio Inputs Oct 10 18:38:22 volumio sudo[1971]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio systemd[1]: Starting Music Player Daemon... Oct 10 18:38:22 volumio volumio[803]: info: Checking against Known Cards name Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 10 18:38:22 volumio volumio[803]: info: [1728578302702] CoreMusicLibrary::Adding element Expert Pro USB Audio 2.0 Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 10 18:38:22 volumio volumio[803]: Cannot find translation for source Expert Pro USB Audio 2.0 Oct 10 18:38:22 volumio volumio[803]: info: Checking against Known Cards name Oct 10 18:38:22 volumio volumio[803]: info: Adding Server instance for streaming Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Oct 10 18:38:22 volumio volumio[803]: error: Hi Res Audio Failed Login: Missing Login Data Oct 10 18:38:22 volumio volumio[803]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Oct 10 18:38:22 volumio volumio[803]: info: Refreshing TIDAL token Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Oct 10 18:38:22 volumio volumio[803]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Oct 10 18:38:22 volumio sudo[1979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 10 18:38:22 volumio sudo[1979]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio volumio[803]: info: Stopping AccessToken refresher cron for QOBUZ Oct 10 18:38:22 volumio sudo[1979]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: AccessToken refresher cron started for QOBUZ Oct 10 18:38:22 volumio volumio[803]: info: Adding QOBUZ REST API Endpoints Oct 10 18:38:22 volumio volumio[803]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Oct 10 18:38:22 volumio volumio[803]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'Volumio' Oct 10 18:38:22 volumio volumio[803]: Can't get device info: No such device Oct 10 18:38:22 volumio volumio[803]: info: MPD Permissions set Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 10 18:38:22 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:22 volumio volumio[803]: info: Starting Shairport Sync Oct 10 18:38:22 volumio sudo[1989]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 10 18:38:22 volumio sudo[1989]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:22 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 10 18:38:22 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 10 18:38:22 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 10 18:38:22 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 10 18:38:22 volumio sudo[1989]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: info: Shairport-Sync Started Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d79a074c does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xeab2817e.a4c5226e Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d79a4a7b does not match aorg 0000000000.00000000 from server@194.177.34.116 xmt 0xeab2817e.a518b6ad Oct 10 18:38:22 volumio mpd[1970]: Oct 10 18:38 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 10 18:38:22 volumio systemd[1]: Started Music Player Daemon. Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d799199b does not match aorg 0000000000.00000000 from server@178.32.23.17 xmt 0xeab2817e.a546ef9d Oct 10 18:38:22 volumio sudo[1962]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:22 volumio volumio[803]: error: updateQueue error: null Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d7976e87 does not match aorg 0000000000.00000000 from server@129.151.225.244 xmt 0xeab2817e.a62c38e0 Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d799c9b6 does not match aorg 0000000000.00000000 from server@82.64.81.218 xmt 0xeab2817e.a66e8952 Oct 10 18:38:22 volumio ntpd[1831]: receive: Unexpected origin timestamp 0xeab2817e.d7997269 does not match aorg 0000000000.00000000 from server@176.137.36.37 xmt 0xeab2817e.a5c28ff8 Oct 10 18:38:22 volumio volumio[803]: info: Successfully Added MyVolumio device Oct 10 18:38:22 volumio volumio[803]: info: Successfully Added MyVolumio device Oct 10 18:38:23 volumio volumio[803]: info: Access Token successfully retrieved Oct 10 18:38:23 volumio volumio[803]: info: Successfully retrieved User Session From TIDAL Oct 10 18:38:23 volumio volumio[803]: info: Updating MyVolumio device info Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: Updating MyVolumio device info Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 10 18:38:23 volumio volumio[803]: info: Getting Spotify volume Oct 10 18:38:23 volumio volumio[803]: info: Spotify volume: 100 Oct 10 18:38:23 volumio volumio[803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 10 18:38:23 volumio volumio[803]: info: Successfully retrieved User Subscription From TIDAL Oct 10 18:38:23 volumio volumio[803]: info: Adding TIDAL to Browse Sources Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 10 18:38:23 volumio volumio[803]: info: [1728578303681] CoreMusicLibrary::Adding element TIDAL Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 10 18:38:23 volumio volumio[803]: Cannot find translation for source Expert Pro USB Audio 2.0 Oct 10 18:38:23 volumio volumio[803]: Cannot find translation for source TIDAL Oct 10 18:38:23 volumio volumio[803]: info: Stopping AccessToken refresher cron Oct 10 18:38:23 volumio volumio[803]: info: AccessToken refresher cron started Oct 10 18:38:23 volumio volumio[803]: info: Adding TIDAL REST API Endpoints Oct 10 18:38:23 volumio volumio[803]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Oct 10 18:38:23 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:23 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:23 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:23 volumio volumio[803]: SPOTIFY: SPOTIFY VOLUME 100 Oct 10 18:38:23 volumio volumio[803]: SPOTIFY: VOLUMIO VOLUME 75 Oct 10 18:38:23 volumio volumio[803]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 10 18:38:23 volumio volumio[803]: info: Setting Spotify Volume from Volumio: 75 Oct 10 18:38:23 volumio volumio[803]: info: Successfully Updated MyVolumio device Oct 10 18:38:24 volumio volumio[803]: info: Successfully Updated MyVolumio device Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: SETTING SPOTIFY VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: info: Sending Spotify command with payload to local API: /player/volume Oct 10 18:38:25 volumio go-librespot[1882]: time="2024-10-10T18:38:25+02:00" level=debug msg="update volume to 49151/65535" Oct 10 18:38:25 volumio go-librespot[1882]: time="2024-10-10T18:38:25+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 10 18:38:25 volumio go-librespot[1882]: time="2024-10-10T18:38:25+02:00" level=trace msg="emitting websocket event: volume" Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: received: {"type":"volume","data":{"value":75,"max":100}} Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED SPOTIFY VOLUME 75 Oct 10 18:38:25 volumio sudo[1998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 10 18:38:25 volumio sudo[1998]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:25 volumio systemd[1]: Started Volumio Bluetooth Module. Oct 10 18:38:25 volumio sudo[1998]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:25 volumio volumio[803]: info: Volumio BT Module successfully started Oct 10 18:38:25 volumio sudo[2001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Oct 10 18:38:25 volumio sudo[2001]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:25 volumio volumiobt[2000]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Oct 10 18:38:25 volumio sudo[2001]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:25 volumio volumio[803]: info: TidalConnect service stoped! Oct 10 18:38:25 volumio volumio[803]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 10 18:38:25 volumio volumio[803]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 10 18:38:25 volumio sudo[2013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 10 18:38:25 volumio sudo[2013]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:25 volumio systemd[1]: Started Volumio Tidal Connect Service. Oct 10 18:38:25 volumio sudo[2013]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:25 volumio volumio[803]: info: Executing endpoint tc_getconfig Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 10 18:38:25 volumio vtcs[2015]: STARTING TidalConnect services, version: 1.4.0.34 Oct 10 18:38:25 volumio vtcs[2015]: STARTED TidalConnect services. Oct 10 18:38:25 volumio volumio[803]: info: Executing endpoint tc_connect Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 10 18:38:25 volumio volumio[803]: info: Connecting to TidalConnect Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::servicePushState Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Oct 10 18:38:25 volumio volumio[803]: verbose: CURRENT POSITION 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::syncState stateService stop Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::syncState currentStatus stop Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: info: No code Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::servicePushState Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Oct 10 18:38:25 volumio volumio[803]: verbose: CURRENT POSITION 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::syncState stateService stop Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::syncState currentStatus stop Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: info: No code Oct 10 18:38:25 volumio volumio[803]: info: CoreStateMachine::pushState Oct 10 18:38:25 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:25 volumio volumio[803]: info: CoreCommandRouter::volumioPushState Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output update for this device Oct 10 18:38:25 volumio volumio[803]: info: MRS: Pushing multiroomSync output Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:25 volumio volumio[803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Oct 10 18:38:26 volumio sudo[2034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Oct 10 18:38:26 volumio sudo[2034]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:26 volumio volumiobt[2000]: pulseaudio: no process found Oct 10 18:38:26 volumio sudo[2034]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:26 volumio dbus-daemon[662]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.21' (uid=1000 pid=2038 comm="/usr/bin/pulseaudio --high-priority=true ") Oct 10 18:38:26 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Oct 10 18:38:26 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 18:38:26 volumio dbus-daemon[662]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Oct 10 18:38:26 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Successfully called chroot. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Successfully dropped privileges. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Successfully limited resources. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Running. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Canary thread running. Oct 10 18:38:26 volumio rtkit-daemon[2039]: Watchdog thread running. Oct 10 18:38:26 volumio dbus-daemon[662]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.22' (uid=0 pid=2039 comm="/usr/lib/rtkit/rtkit-daemon ") Oct 10 18:38:26 volumio systemd[1]: Starting Authorization Manager... Oct 10 18:38:26 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 18:38:26 volumio polkitd[2042]: started daemon version 0.105 using authority implementation `local' version `0.105' Oct 10 18:38:26 volumio dbus-daemon[662]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 10 18:38:26 volumio systemd[1]: Started Authorization Manager. Oct 10 18:38:26 volumio pulseaudio[2038]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 10 18:38:26 volumio pulseaudio[2038]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 10 18:38:26 volumio volumiobt[2000]: Applying permissions Oct 10 18:38:26 volumio volumiobt[2000]: Setting BT discoverable and pairable Oct 10 18:38:26 volumio pulseaudio[2038]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# -e power on Oct 10 18:38:26 volumio volumiobt[2000]: Invalid command in menu main: -e Oct 10 18:38:26 volumio volumiobt[2000]: Oct 10 18:38:26 volumio volumiobt[2000]: Use "help" for a list of available commands in a menu. Oct 10 18:38:26 volumio volumiobt[2000]: Use "menu " if you want to enter any submenu. Oct 10 18:38:26 volumio volumiobt[2000]: Use "back" if you want to return to menu main. Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# agent on Oct 10 18:38:26 volumio volumiobt[2000]: Failed to register agent object Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# discoverable on Oct 10 18:38:26 volumio volumiobt[2000]: No default controller available Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# pairable on Oct 10 18:38:26 volumio volumiobt[2000]: No default controller available Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# agent NoInputNoOutput Oct 10 18:38:26 volumio volumiobt[2000]: Failed to register agent object Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# default-agent Oct 10 18:38:26 volumio volumiobt[2000]: No agent is registered Oct 10 18:38:26 volumio volumiobt[2000]: [bluetooth]# quit Oct 10 18:38:26 volumio volumiobt[2000]: [59B blob data] Oct 10 18:38:26 volumio sudo[2055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 10 18:38:26 volumio sudo[2055]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:26 volumio systemd[1]: Started MyVolumio SSH Tunnel. Oct 10 18:38:26 volumio sudo[2055]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:26 volumio volumio[803]: info: Remote SSH Started Oct 10 18:38:26 volumio autossh[2058]: port set to 0, monitoring disabled Oct 10 18:38:26 volumio autossh[2058]: starting ssh (count 1) Oct 10 18:38:26 volumio autossh[2058]: ssh child pid is 2061 Oct 10 18:38:26 volumio volumio[803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 10 18:38:26 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:26 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:26 volumio volumiossh-tunnel[2057]: Warning: Permanently added '[eu10.myvolumio.org]:2222,[46.101.141.203]:2222' (RSA) to the list of known hosts. Oct 10 18:38:27 volumio volumio[803]: info: MRS: Getting audio outputs on start Oct 10 18:38:27 volumio volumio[803]: info: MRS: Requesting all other devices output Oct 10 18:38:28 volumio volumio[803]: info: TidalConnect service started! Oct 10 18:38:35 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 10 18:38:35 volumio volumio[803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 10 18:38:35 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:35 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::volumioGetBrowseSources Oct 10 18:38:40 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:46 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:46 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:46 volumio volumio[803]: verbose: New Socket.io Connection to 192.168.1.43:3000 from 192.168.1.20 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:46 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 10 18:38:46 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 10 18:38:49 volumio sudo[2110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 10 18:38:49 volumio sudo[2110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:49 volumio sudo[2110]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:49 volumio sudo[2113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 10 18:38:49 volumio sudo[2113]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:49 volumio sudo[2113]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:49 volumio volumio[803]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.81 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 10 18:38:50 volumio sudo[2118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 10 18:38:50 volumio sudo[2118]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:50 volumio sudo[2118]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:50 volumio sudo[2121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 10 18:38:50 volumio sudo[2121]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:38:50 volumio sudo[2121]: pam_unix(sudo:session): session closed for user root Oct 10 18:38:50 volumio volumio[803]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.81 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::volumioGetVisibleSources Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:50 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 10 18:38:50 volumio volumio[803]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 10 18:38:50 volumio volumio[803]: info: Received Get System Info Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:50 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:50 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:50 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:50 volumio volumio[803]: info: Listing playlists Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 10 18:38:50 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 10 18:38:51 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:51 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:51 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:51 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:51 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:51 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 10 18:38:52 volumio volumio[803]: info: Received Get System Info Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:52 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:52 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 10 18:38:52 volumio volumio[803]: info: Received Get System Info Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 18:38:52 volumio volumio[803]: info: Discovery: Getting this device information Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::volumioGetState Oct 10 18:38:52 volumio volumio[803]: info: CorePlayQueue::getTrack 0 Oct 10 18:38:52 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: Retrieving Cloud Streaming UI Oct 10 18:38:55 volumio volumio[803]: info: Getting Tidal Cloud Configuration Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: Getting Qobuz Cloud Configuration Oct 10 18:38:55 volumio volumio[803]: info: Asking plugin for UI Config Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: Getting Spotify Cloud Configuration Oct 10 18:38:55 volumio volumio[803]: info: Asking plugin for UI Config Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: Saving Spotify Acccount Oct 10 18:38:55 volumio volumio[803]: info: Got it Oct 10 18:38:55 volumio volumio[803]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 10 18:38:55 volumio volumio[803]: info: Got Tidal Cloud Configuration Oct 10 18:38:55 volumio volumio[803]: info: Got it Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::volumioGetBrowseSources Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::volumioGetBrowseSources Oct 10 18:38:55 volumio volumio[803]: info: CoreCommandRouter::volumioGetBrowseSources Oct 10 18:38:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 10 18:38:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 10 18:39:00 volumio volumio[803]: info: Disabling MyMusic plugin upnp Oct 10 18:39:00 volumio sudo[2126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Oct 10 18:39:00 volumio sudo[2126]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 18:39:00 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Oct 10 18:39:00 volumio volumio[803]: error: Upnp client error: Error: This socket has been ended by the other party Oct 10 18:39:00 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 18:39:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 10 18:39:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 10 18:39:01 volumio volumio[803]: info: Enabling MyMusic plugin upnp Oct 10 18:39:01 volumio volumio[803]: info: Enabling plugin upnp Oct 10 18:39:01 volumio volumio[803]: info: Loading plugin "upnp"... Oct 10 18:39:01 volumio volumio[803]: info: [1728578341594] Starting Upmpd Daemon Oct 10 18:39:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 10 18:39:01 volumio volumio[803]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 18:39:01 volumio volumio[803]: Error: listen EADDRINUSE: address already in use :::6599 Oct 10 18:39:01 volumio volumio[803]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Oct 10 18:39:01 volumio volumio[803]: at listenInCluster (net.js:1379:12) Oct 10 18:39:01 volumio volumio[803]: at Server.listen (net.js:1465:7) Oct 10 18:39:01 volumio volumio[803]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Oct 10 18:39:01 volumio volumio[803]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Oct 10 18:39:01 volumio volumio[803]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 10 18:39:01 volumio volumio[803]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 10 18:39:01 volumio volumio[803]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Oct 10 18:39:01 volumio volumio[803]: code: 'EADDRINUSE', Oct 10 18:39:01 volumio volumio[803]: errno: -98, Oct 10 18:39:01 volumio volumio[803]: syscall: 'listen', Oct 10 18:39:01 volumio volumio[803]: address: '::', Oct 10 18:39:01 volumio volumio[803]: port: 6599 Oct 10 18:39:01 volumio volumio[803]: } Oct 10 18:39:01 volumio volumio[803]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 18:39:01 volumio sudo[2137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-10 18:38 Oct 10 18:39:01 volumio sudo[2137]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="51755a7ab41793587aa858aae43b662293a9df12" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 02 Jun 2024 06:47:43 PM CEST" VOLUMIO_VERSION="3.701" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="8eb45a242542e25a312faab4e134aa8d"