-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2025-04-30 16:37:46 CEST. -- Apr 30 16:37:41 volumio systemd-timedated[2064]: Changed local time to Wed Apr 30 16:37:41 2025 Apr 30 16:37:41 volumio sudo[2062]: pam_unix(sudo:session): session closed for user root Apr 30 16:37:41 volumio volumio-time-update[610]: volumio-time-update-util: System time updated successfully. Apr 30 16:37:41 volumio systemd[1]: Started Volumio Time Update Utility. Apr 30 16:37:41 volumio systemd[1]: Reached target Multi-User System. Apr 30 16:37:41 volumio systemd[1]: Reached target Graphical Interface. Apr 30 16:37:41 volumio ntpd[804]: Soliciting pool server 45.90.187.8 Apr 30 16:37:41 volumio ntpd[804]: Soliciting pool server 103.204.195.5 Apr 30 16:37:41 volumio volumio[997]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 30 16:37:41 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 30 16:37:41 volumio volumio[997]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 30 16:37:41 volumio volumio[997]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 30 16:37:41 volumio volumio[997]: info: Starting MyVolumio Remote Streaming Endpoints Apr 30 16:37:41 volumio volumio[997]: info: MyVolumio login type: Token Apr 30 16:37:41 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 30 16:37:41 volumio volumio[997]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 30 16:37:41 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 30 16:37:41 volumio volumio[997]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 30 16:37:41 volumio systemd[1]: Startup finished in 14.608s (kernel) + 5min 5.443s (userspace) = 5min 20.052s. Apr 30 16:37:42 volumio ntpd[804]: Soliciting pool server 195.123.221.21 Apr 30 16:37:42 volumio volumio[997]: info: Starting Streaming Service Transparent Proxy Apr 30 16:37:42 volumio volumio[997]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 30 16:37:42 volumio volumio[997]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 30 16:37:42 volumio volumio[997]: info: Streaming services startup Apr 30 16:37:42 volumio volumio[997]: info: Starting Streaming Daemon Apr 30 16:37:42 volumio sudo[2098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 30 16:37:42 volumio sudo[2098]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 16:37:42 volumio volumio[997]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 30 16:37:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 16:37:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Apr 30 16:37:42 volumio sudo[2098]: pam_unix(sudo:session): session closed for user root Apr 30 16:37:42 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 16:37:42 volumio volumio[997]: SPOTIFY: SETTING SPOTIFY VOLUME 79 Apr 30 16:37:42 volumio volumio[997]: info: Sending Spotify command with payload to local API: /player/volume Apr 30 16:37:42 volumio systemd[1]: Started go-librespot Daemon. Apr 30 16:37:42 volumio go-librespot[2104]: Librespot-go daemon starting... Apr 30 16:37:42 volumio volumio[997]: info: Getting Spotify volume Apr 30 16:37:42 volumio go-librespot[2104]: time="2025-04-30T16:37:42+02:00" level=info msg="generated new device id: b07da0e3755d1c6fb4b30212839bda4caf4d8673" Apr 30 16:37:42 volumio go-librespot[2104]: time="2025-04-30T16:37:42+02:00" level=debug msg="stored credentials found for fransbe" Apr 30 16:37:43 volumio volumio[997]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 16:37:43 volumio volumio[997]: (node:997) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 16:37:43 volumio volumio[997]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 16:37:43 volumio volumio[997]: (node:997) 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: 4) Apr 30 16:37:43 volumio ntpd[804]: Soliciting pool server 5.255.124.190 Apr 30 16:37:43 volumio volumio[997]: error: Cannot start Volumio Streaming Daemon Apr 30 16:37:43 volumio volumio[997]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 30 16:37:43 volumio volumio[997]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 30 16:37:43 volumio volumio[997]: info: Connection to go-librespot Websocket closed Apr 30 16:37:43 volumio volumio[997]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Apr 30 16:37:43 volumio volumio[997]: info: Discovery: A device disappeared from network Apr 30 16:37:43 volumio volumio[997]: info: Discovery: Device volumio disappeared from network Apr 30 16:37:43 volumio volumio[997]: info: Discovery: A device disappeared from network Apr 30 16:37:43 volumio volumio[997]: info: CoreCommandRouter::volumioGetState Apr 30 16:37:43 volumio volumio[997]: info: CorePlayQueue::getTrack 0 Apr 30 16:37:43 volumio volumio[997]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="zeroconf server listening on port 36327" Apr 30 16:37:43 volumio volumio[997]: info: Discovery: adding e7032222-063f-45d3-b317-868656542c8b Apr 30 16:37:43 volumio volumio[997]: info: Discovery: Found device Volumio Apr 30 16:37:43 volumio volumio[997]: info: CoreCommandRouter::volumioGetState Apr 30 16:37:43 volumio volumio[997]: info: CorePlayQueue::getTrack 0 Apr 30 16:37:43 volumio volumio[997]: info: Discovery: this is already registered, e7032222-063f-45d3-b317-868656542c8b Apr 30 16:37:43 volumio volumio[997]: info: Discovery: Found device Volumio Apr 30 16:37:43 volumio volumio[997]: info: CoreCommandRouter::volumioGetState Apr 30 16:37:43 volumio volumio[997]: info: CorePlayQueue::getTrack 0 Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="obtained new client token: AAAt1oSVNPTD+jxdQ4cXEAIrAy1fJHyQjMA0z3HVjg2UAG7py/bRXQ4110Mo8HSLwCxnCEbGQdSmeDAXBzqZQNoi113ftSlzVm0z4ZamS2kflOLmYtExZnEvJrqPudkLGHWiXBdhipnEyTqH4uaRDjp89ZnsR4fmJavEe9IZaV8BZ5H+c5BqdsibBqyCXZZFxT9z/s17QFBvRICUZ7a8DkoXNppJj3EKrNtupwStwKc8isP8sj6Ud0NbGS7V" Apr 30 16:37:43 volumio go-librespot[2104]: time="2025-04-30T16:37:43+02:00" level=debug msg="completed keyexchange" Apr 30 16:37:44 volumio ntpd[804]: Soliciting pool server 86.80.166.233 Apr 30 16:37:44 volumio volumio[997]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="completed challenge" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="authenticated as fransbe" Apr 30 16:37:44 volumio volumio[997]: STREAMING PROXY: Starting server on port 3245 Apr 30 16:37:44 volumio volumio[997]: Node JS runtime: 14 Apr 30 16:37:44 volumio volumio[997]: info: MyVolumio token set successfully Apr 30 16:37:44 volumio volumio[997]: info: MYVOLUMIO: Adding device Apr 30 16:37:44 volumio volumio[997]: info: MYVOLUMIO: Evaluating Server Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="authenticated as fransbe" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="dealer connection opened" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="initializing zeroconf session, username: fransbe" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="autoplay enabled: false" Apr 30 16:37:44 volumio go-librespot[2104]: time="2025-04-30T16:37:44+02:00" level=debug msg="received connection id: OWY4MDg0NWUtN2MxZC00NzM0LWI0ZTEtZjhjNWY2ZGUxYzhiK2RlYWxlcit0Y3A6Ly8wYWNhNTkyYS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMDM1NkYwREYyMDQzOTRFNTgzMzUwOUFBN0FGMjk0MDcwRTQ4QzZERTc1NTAxQzI1MEEzQzEwQTU3Qjk4N0Y3Qg==" Apr 30 16:37:44 volumio volumio[997]: info: MyVolumio Plan changed: premium Apr 30 16:37:44 volumio volumio[997]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 30 16:37:44 volumio volumio[997]: info: Removing browser output: myVolumio user plan is not superstar Apr 30 16:37:44 volumio volumio[997]: info: Removing audio output: Apr 30 16:37:44 volumio volumio[997]: info: MYVOLUMIO: Adding device Apr 30 16:37:44 volumio volumio[997]: info: MYVOLUMIO: Evaluating Server Apr 30 16:37:44 volumio volumio[997]: info: Remote config written successfully Apr 30 16:37:44 volumio volumio[997]: info: Starting Tunnel 1 Apr 30 16:37:44 volumio volumio[997]: info: Starting Tunnel Connection Checker Apr 30 16:37:45 volumio go-librespot[2104]: time="2025-04-30T16:37:45+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 30 16:37:45 volumio volumio[997]: info: MYVolumio Device enabled Apr 30 16:37:45 volumio volumio[997]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 30 16:37:45 volumio volumio[997]: info: Setting Geolocation for MyVolumio to eu2 Apr 30 16:37:45 volumio volumio[997]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 30 16:37:45 volumio volumio[997]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 30 16:37:45 volumio volumio[997]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 30 16:37:45 volumio volumio[997]: [2025-04-30T14:37:45.385Z] @firebase/database: FIREBASE WARNING: Exception was thrown by user callback. TypeError: Cannot read property 'replace' of null Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.fetchPluginKeys (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:8044) Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.loadMyVolumioPlugins (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:11563) Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.myVolumioDeviceStatusChanged (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:5527) Apr 30 16:37:45 volumio volumio[997]: at /myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:6807 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/v-conf/index.js:165:13 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/multimap/index.js:150:9 Apr 30 16:37:45 volumio volumio[997]: at Array.forEach () Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/multimap/index.js:149:13 Apr 30 16:37:45 volumio volumio[997]: at mapEach (/volumio/node_modules/multimap/index.js:9:5) Apr 30 16:37:45 volumio volumio[997]: at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5) Apr 30 16:37:45 volumio volumio[997]: at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10) Apr 30 16:37:45 volumio volumio[997]: at Config.set (/volumio/node_modules/v-conf/index.js:162:20) Apr 30 16:37:45 volumio volumio[997]: at myVolumio.togglePremiumPlugins (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:36237) Apr 30 16:37:45 volumio volumio[997]: at /myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:17857 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/@firebase/database/dist/index.node.cjs.js:4549:22 Apr 30 16:37:45 volumio volumio[997]: at exceptionGuard (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:698:9) Apr 30 16:37:45 volumio volumio[997]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 16:37:45 volumio volumio[997]: TypeError: Cannot read property 'replace' of null Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.fetchPluginKeys (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:8044) Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.loadMyVolumioPlugins (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:11563) Apr 30 16:37:45 volumio volumio[997]: at MyVolumioPluginManager.myVolumioDeviceStatusChanged (/myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:5527) Apr 30 16:37:45 volumio volumio[997]: at /myvolumio/app/myvolumio-pluginmanager/myvolumio_pluginmanager_real:1:6807 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/v-conf/index.js:165:13 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/multimap/index.js:150:9 Apr 30 16:37:45 volumio volumio[997]: at Array.forEach () Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/multimap/index.js:149:13 Apr 30 16:37:45 volumio volumio[997]: at mapEach (/volumio/node_modules/multimap/index.js:9:5) Apr 30 16:37:45 volumio volumio[997]: at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5) Apr 30 16:37:45 volumio volumio[997]: at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10) Apr 30 16:37:45 volumio volumio[997]: at Config.set (/volumio/node_modules/v-conf/index.js:162:20) Apr 30 16:37:45 volumio volumio[997]: at myVolumio.togglePremiumPlugins (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:36237) Apr 30 16:37:45 volumio volumio[997]: at /myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:17857 Apr 30 16:37:45 volumio volumio[997]: at /volumio/node_modules/@firebase/database/dist/index.node.cjs.js:4549:22 Apr 30 16:37:45 volumio volumio[997]: at exceptionGuard (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:698:9) Apr 30 16:37:45 volumio volumio[997]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 16:37:46 volumio sudo[2198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-30 16:36 Apr 30 16:37:46 volumio sudo[2198]: 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"