-- Logs begin at Tue 2026-01-27 10:28:18 CET, end at Tue 2026-01-27 10:31:06 CET. -- Jan 27 10:30:05 volumioalrum go-librespot[2198]: time="2026-01-27T10:30:05+01: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" Jan 27 10:30:05 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:30:05 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:30:05 volumioalrum volumio[1043]: (node:1043) UnhandledPromiseRejectionWarning: Error: socket hang up Jan 27 10:30:05 volumioalrum volumio[1043]: at connResetException (internal/errors.js:639:14) Jan 27 10:30:05 volumioalrum volumio[1043]: at Socket.socketOnEnd (_http_client.js:499:23) Jan 27 10:30:05 volumioalrum volumio[1043]: at Socket.emit (events.js:412:35) Jan 27 10:30:05 volumioalrum volumio[1043]: at endReadableNT (internal/streams/readable.js:1333:12) Jan 27 10:30:05 volumioalrum volumio[1043]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jan 27 10:30:05 volumioalrum volumio[1043]: (Use `node --trace-warnings ...` to show where the warning was created) Jan 27 10:30:05 volumioalrum volumio[1043]: (node:1043) 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) Jan 27 10:30:05 volumioalrum volumio[1043]: (node:1043) [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. Jan 27 10:30:05 volumioalrum volumio[1043]: info: Connection to go-librespot Websocket closed Jan 27 10:30:05 volumioalrum volumio[1043]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.886&uuid=d1746440935241e3ca8e6b2ea71fa945" http://updates.volumio.org/downloader-v1/track-device Jan 27 10:30:05 volumioalrum volumio[1043]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 27 10:30:05 volumioalrum volumio[1043]: Dload Upload Total Spent Left Speed Jan 27 10:30:05 volumioalrum volumio[1043]: [1.6K blob data] Jan 27 10:30:05 volumioalrum volumio[1043]: retrying in 5 seconds, trial 2 Jan 27 10:30:05 volumioalrum volumio[1043]: info: Volumio Calling Home Jan 27 10:30:06 volumioalrum ntpd[989]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 27 10:30:08 volumioalrum volumio[1043]: info: Initializing connection to go-librespot Websocket Jan 27 10:30:08 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 27 10:30:08 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 10:30:08 volumioalrum systemd[1]: Stopped go-librespot Daemon. Jan 27 10:30:08 volumioalrum systemd[1]: Started go-librespot Daemon. Jan 27 10:30:08 volumioalrum go-librespot[2259]: go-librespot daemon starting... Jan 27 10:30:08 volumioalrum go-librespot[2259]: time="2026-01-27T10:30:08+01:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:30:08 volumioalrum go-librespot[2259]: time="2026-01-27T10:30:08+01:00" level=debug msg="app state loaded" Jan 27 10:30:08 volumioalrum go-librespot[2259]: time="2026-01-27T10:30:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:30:10 volumioalrum volumio-time-update[785]: volumio-time-update-util: Date not found in response Jan 27 10:30:10 volumioalrum volumio-time-update[785]: volumio-time-update-util: Retrying in 5 seconds... Jan 27 10:30:15 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 27 10:30:15 volumioalrum volumio-time-update[785]: volumio-time-update-util: Fetching time from Volumio... Jan 27 10:30:26 volumioalrum ntpd[989]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 27 10:30:28 volumioalrum go-librespot[2259]: time="2026-01-27T10:30:28+01: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" Jan 27 10:30:28 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:30:28 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:30:31 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 27 10:30:31 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 10:30:31 volumioalrum systemd[1]: Stopped go-librespot Daemon. Jan 27 10:30:31 volumioalrum systemd[1]: Started go-librespot Daemon. Jan 27 10:30:31 volumioalrum go-librespot[2347]: go-librespot daemon starting... Jan 27 10:30:31 volumioalrum go-librespot[2347]: time="2026-01-27T10:30:31+01:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:30:31 volumioalrum go-librespot[2347]: time="2026-01-27T10:30:31+01:00" level=debug msg="app state loaded" Jan 27 10:30:31 volumioalrum go-librespot[2347]: time="2026-01-27T10:30:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:30:34 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 27 10:30:36 volumioalrum volumio-time-update[785]: volumio-time-update-util: Date not found in response Jan 27 10:30:36 volumioalrum volumio-time-update[785]: volumio-time-update-util: Retrying in 5 seconds... Jan 27 10:30:41 volumioalrum volumio-time-update[785]: volumio-time-update-util: Fetching time from Volumio... Jan 27 10:30:43 volumioalrum dhcpcd[862]: eth0: offered 192.168.1.101 from 192.168.1.1 Jan 27 10:30:43 volumioalrum dhcpcd[1491]: eth0: offered 192.168.1.101 from 192.168.1.1 Jan 27 10:30:46 volumioalrum ntpd[989]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 27 10:30:49 volumioalrum dhcpcd[1491]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:50 volumioalrum dhcpcd[862]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:51 volumioalrum dhcpcd[862]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:51 volumioalrum dhcpcd[1491]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:51 volumioalrum go-librespot[2347]: time="2026-01-27T10:30:51+01: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" Jan 27 10:30:51 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:30:51 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:30:52 volumioalrum dhcpcd[862]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:52 volumioalrum dhcpcd[1491]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:53 volumioalrum dhcpcd[862]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:53 volumioalrum dhcpcd[1491]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:54 volumioalrum dhcpcd[862]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:54 volumioalrum dhcpcd[1491]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Jan 27 10:30:54 volumioalrum dhcpcd[862]: eth0: probing address 192.168.1.101/24 Jan 27 10:30:54 volumioalrum dhcpcd[1491]: eth0: probing address 192.168.1.101/24 Jan 27 10:30:54 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 27 10:30:54 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 10:30:54 volumioalrum systemd[1]: Stopped go-librespot Daemon. Jan 27 10:30:55 volumioalrum systemd[1]: Started go-librespot Daemon. Jan 27 10:30:55 volumioalrum go-librespot[2390]: go-librespot daemon starting... Jan 27 10:30:55 volumioalrum go-librespot[2390]: time="2026-01-27T10:30:55+01:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:30:55 volumioalrum go-librespot[2390]: time="2026-01-27T10:30:55+01:00" level=debug msg="app state loaded" Jan 27 10:30:55 volumioalrum go-librespot[2390]: time="2026-01-27T10:30:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:30:59 volumioalrum dhcpcd[1491]: eth0: leased 192.168.1.101 for 86400 seconds Jan 27 10:30:59 volumioalrum dhcpcd[1491]: eth0: adding route to 192.168.1.0/24 Jan 27 10:30:59 volumioalrum dhcpcd[1491]: eth0: changing default route via 192.168.1.1 Jan 27 10:30:59 volumioalrum dhcpcd[862]: eth0: deleted default route Jan 27 10:30:59 volumioalrum avahi-daemon[789]: Registering new address record for 192.168.1.101 on eth0.IPv4. Jan 27 10:30:59 volumioalrum ntpd[989]: ntpd exiting on signal 15 (Terminated) Jan 27 10:30:59 volumioalrum systemd[1]: Stopping Network Time Service... Jan 27 10:30:59 volumioalrum systemd[1]: ntp.service: Succeeded. Jan 27 10:30:59 volumioalrum systemd[1]: Stopped Network Time Service. Jan 27 10:31:00 volumioalrum systemd[1]: Starting Network Time Service... Jan 27 10:31:00 volumioalrum ntpd[2445]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 27 10:31:00 volumioalrum ntpd[2445]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jan 27 10:31:00 volumioalrum systemd[1]: Started Network Time Service. Jan 27 10:31:00 volumioalrum ntpd[2451]: proto: precision = 0.200 usec (-22) Jan 27 10:31:00 volumioalrum dhcpcd[1491]: eth0: deleting route to 169.254.0.0/16 Jan 27 10:31:00 volumioalrum ntpd[2451]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: deleted route to 169.254.0.0/16 Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: adding route to 169.254.0.0/16 Jan 27 10:31:00 volumioalrum dhcpcd[862]: if_route (ADD): Invalid argument Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: adding default route Jan 27 10:31:00 volumioalrum dhcpcd[862]: if_route (ADD): Invalid argument Jan 27 10:31:00 volumioalrum avahi-daemon[789]: Withdrawing address record for 169.254.251.118 on eth0. Jan 27 10:31:00 volumioalrum ntpd[2451]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 27 10:31:00 volumioalrum avahi-daemon[789]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.251.118. Jan 27 10:31:00 volumioalrum ntpd[2451]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1127 days ago Jan 27 10:31:00 volumioalrum avahi-daemon[789]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.101. Jan 27 10:31:00 volumioalrum ntpd[2451]: Listen and drop on 0 v6wildcard [::]:123 Jan 27 10:31:00 volumioalrum ntpd[2451]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 27 10:31:00 volumioalrum ntpd[2451]: Listen normally on 2 lo 127.0.0.1:123 Jan 27 10:31:00 volumioalrum ntpd[2451]: Listen normally on 3 eth0 192.168.1.101:123 Jan 27 10:31:00 volumioalrum ntpd[2451]: Listening on routing socket on fd #20 for interface updates Jan 27 10:31:00 volumioalrum ntpd[2451]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:00 volumioalrum ntpd[2451]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: leased 192.168.1.101 for 86400 seconds Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: adding route to 192.168.1.0/24 Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: adding default route via 192.168.1.1 Jan 27 10:31:00 volumioalrum dhcpcd[862]: eth0: adding route to 169.254.0.0/16 Jan 27 10:31:00 volumioalrum dhcpcd[862]: if_route (ADD): Invalid argument Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=info msg="zeroconf server listening on port 33517" Jan 27 10:31:00 volumioalrum ntpd[2451]: ntpd exiting on signal 15 (Terminated) Jan 27 10:31:00 volumioalrum systemd[1]: Stopping Network Time Service... Jan 27 10:31:00 volumioalrum systemd[1]: ntp.service: Succeeded. Jan 27 10:31:00 volumioalrum systemd[1]: Stopped Network Time Service. Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 27 10:31:00 volumioalrum systemd[1]: Starting Network Time Service... Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 27 10:31:00 volumioalrum ntpd[2503]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 27 10:31:00 volumioalrum ntpd[2503]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jan 27 10:31:00 volumioalrum systemd[1]: Started Network Time Service. Jan 27 10:31:00 volumioalrum ntpd[2509]: proto: precision = 0.200 usec (-22) Jan 27 10:31:00 volumioalrum kernel: traps: dhcpcd[862] general protection fault ip:56243acac075 sp:7ffc30fb13d0 error:0 in dhcpcd[56243ac97000+32000] Jan 27 10:31:00 volumioalrum ntpd[2509]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 27 10:31:00 volumioalrum ntpd[2509]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 27 10:31:00 volumioalrum ntpd[2509]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1127 days ago Jan 27 10:31:00 volumioalrum ntpd[2509]: Listen and drop on 0 v6wildcard [::]:123 Jan 27 10:31:00 volumioalrum ntpd[2509]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 27 10:31:00 volumioalrum ntpd[2509]: Listen normally on 2 lo 127.0.0.1:123 Jan 27 10:31:00 volumioalrum ntpd[2509]: Listen normally on 3 eth0 192.168.1.101:123 Jan 27 10:31:00 volumioalrum ntpd[2509]: Listening on routing socket on fd #20 for interface updates Jan 27 10:31:00 volumioalrum ntpd[2509]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:00 volumioalrum ntpd[2509]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="obtained new client token: AABCWm2hwFjSh+hY3142TxYzVNzoPFfniqJSd7XveIsSsVBlxKvqbN58mk3Yjx7Um1yCzAuyrIS5XNB0Ot95FvOotJoDQ8YzDttH3DTBgtnSMDyEBhUBPoJfZdXPwVDzJiZDMxqqilv/h+vpUYbLbXP0EiP3vGV87WZksRIG/8R/Q5Ya/Yx9jM0SA+JsAMDw4BXC0D5AWEfurCrIhtA2L82s6V0yhXhzEZHac52QhNe6JisFgkWSi/u6Gw==" Jan 27 10:31:00 volumioalrum systemd[1]: dhcpcd.service: Main process exited, code=killed, status=11/SEGV Jan 27 10:31:00 volumioalrum systemd[1]: dhcpcd.service: Failed with result 'signal'. Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="completed keyexchange" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="completed challenge" Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="new websocket client" Jan 27 10:31:00 volumioalrum volumio[1043]: info: Connection to go-librespot Websocket established Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=info msg="authenticated AP" username="th*****99" Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jan 27 10:31:00 volumioalrum systemd[1]: dhcpcd.service: Service RestartSec=100ms expired, scheduling restart. Jan 27 10:31:00 volumioalrum systemd[1]: dhcpcd.service: Scheduled restart job, restart counter is at 1. Jan 27 10:31:00 volumioalrum systemd[1]: Stopped DHCP Client Daemon. Jan 27 10:31:00 volumioalrum systemd[1]: Starting DHCP Client Daemon... Jan 27 10:31:00 volumioalrum dhcpcd[2511]: main: control_open: Connection refused Jan 27 10:31:00 volumioalrum dhcpcd[2511]: main: control_open: Connection refused Jan 27 10:31:00 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:00 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:00 volumioalrum volumio[1043]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 10:31:00 volumioalrum volumio[1043]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 10:31:00 volumioalrum volumio[1043]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 10:31:00 volumioalrum volumio[1043]: info: Aligning Spotify Volume to Volumio Volume Jan 27 10:31:00 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:00 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:00 volumioalrum volumio[1043]: info: Setting Spotify Volume from Volumio: 100 Jan 27 10:31:00 volumioalrum dhcpcd[2511]: DUID 00:04:56:cb:0d:48:9f:29:11:e6:9f:b8:9c:5c:8e:01:bc:2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: eth0: IAID 8e:01:bc:2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: eth0: adding address fe80::9e5c:8eff:fe01:bc2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: ipv6_addaddr1: Permission denied Jan 27 10:31:00 volumioalrum dhcpcd[2511]: dhcpcd_prestartinterface: wlan0: Operation not possible due to RF-kill Jan 27 10:31:00 volumioalrum dhcpcd[2511]: DUID 00:04:56:cb:0d:48:9f:29:11:e6:9f:b8:9c:5c:8e:01:bc:2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: wlan0: waiting for carrier Jan 27 10:31:00 volumioalrum dhcpcd[2511]: eth0: IAID 8e:01:bc:2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: eth0: adding address fe80::9e5c:8eff:fe01:bc2c Jan 27 10:31:00 volumioalrum dhcpcd[2511]: ipv6_addaddr1: Permission denied Jan 27 10:31:00 volumioalrum dhcpcd[2511]: dhcpcd_prestartinterface: wlan0: Operation not possible due to RF-kill Jan 27 10:31:00 volumioalrum dhcpcd[2511]: wlan0: waiting for carrier Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=info msg="authenticated Login5" username="th*****99" Jan 27 10:31:00 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:00+01:00" level=debug msg="initializing zeroconf session" username="th*****99" Jan 27 10:31:00 volumioalrum volumio[1043]: verbose: New Socket.io Connection to 192.168.1.101:3000 from 192.168.1.190 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 14 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: rebinding lease of 192.168.1.101 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: rebinding lease of 192.168.1.101 Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:01 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:01 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:01 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:01 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:01 volumioalrum volumio-time-update[785]: volumio-time-update-util: Date not found in response Jan 27 10:31:01 volumioalrum volumio-time-update[785]: volumio-time-update-util: Retrying in 5 seconds... Jan 27 10:31:01 volumioalrum volumio[1043]: verbose: New Socket.io Connection to 192.168.1.101:3000 from 192.168.1.190 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 15 Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:31:01 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="dealer connection opened" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=trace msg="starting accesspoint recv loop" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=trace msg="starting dealer recv loop" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=trace msg="received accesspoint ping" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="received connection id: NmMyMDJhMGUtMzJm...QTY0MTAxNkFCRA==" Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=trace msg="received accesspoint pong ack" Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 10:31:01 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 10:31:01 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:01+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 27 10:31:01 volumioalrum ntpd[2509]: Soliciting pool server 5.186.56.205 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: soliciting an IPv6 router Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: soliciting an IPv6 router Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: leased 192.168.1.101 for 86400 seconds Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: leased 192.168.1.101 for 86400 seconds Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: adding route to 192.168.1.0/24 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: adding default route via 192.168.1.1 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: adding route to 192.168.1.0/24 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: eth0: adding default route via 192.168.1.1 Jan 27 10:31:01 volumioalrum ntpd[2509]: ntpd exiting on signal 15 (Terminated) Jan 27 10:31:01 volumioalrum ntpd[2509]: 5.186.56.205 local addr 192.168.1.101 -> Jan 27 10:31:01 volumioalrum systemd[1]: Stopping Network Time Service... Jan 27 10:31:01 volumioalrum systemd[1]: ntp.service: Succeeded. Jan 27 10:31:01 volumioalrum systemd[1]: Stopped Network Time Service. Jan 27 10:31:01 volumioalrum systemd[1]: Starting Network Time Service... Jan 27 10:31:01 volumioalrum ntpd[2562]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 27 10:31:01 volumioalrum ntpd[2562]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jan 27 10:31:01 volumioalrum systemd[1]: Started Network Time Service. Jan 27 10:31:01 volumioalrum ntpd[2568]: proto: precision = 0.200 usec (-22) Jan 27 10:31:01 volumioalrum ntpd[2568]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 27 10:31:01 volumioalrum ntpd[2568]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 27 10:31:01 volumioalrum ntpd[2568]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1127 days ago Jan 27 10:31:01 volumioalrum ntpd[2568]: Listen and drop on 0 v6wildcard [::]:123 Jan 27 10:31:01 volumioalrum ntpd[2568]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 27 10:31:01 volumioalrum ntpd[2568]: Listen normally on 2 lo 127.0.0.1:123 Jan 27 10:31:01 volumioalrum ntpd[2568]: Listen normally on 3 eth0 192.168.1.101:123 Jan 27 10:31:01 volumioalrum ntpd[2568]: Listening on routing socket on fd #20 for interface updates Jan 27 10:31:01 volumioalrum ntpd[2568]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:01 volumioalrum ntpd[2568]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 27 10:31:01 volumioalrum dhcpcd[2511]: forked to background, child pid 2570 Jan 27 10:31:01 volumioalrum dhcpcd[2511]: forked to background, child pid 2570 Jan 27 10:31:01 volumioalrum systemd[1]: Started DHCP Client Daemon. Jan 27 10:31:02 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 10:31:02 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 10:31:02 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:31:02 volumioalrum volumio[1043]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 10:31:02 volumioalrum volumio[1043]: info: MyVolumio login type: Token Jan 27 10:31:02 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 10:31:02 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 10:31:02 volumioalrum ntpd[2568]: Soliciting pool server 80.209.68.118 Jan 27 10:31:03 volumioalrum volumio[1043]: info: Starting Streaming Service Transparent Proxy Jan 27 10:31:03 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 10:31:03 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 10:31:03 volumioalrum volumio[1043]: info: Streaming services startup Jan 27 10:31:03 volumioalrum volumio[1043]: info: Starting Streaming Daemon Jan 27 10:31:03 volumioalrum sudo[2580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 10:31:03 volumioalrum sudo[2580]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum sudo[2580]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:03 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 10:31:03 volumioalrum volumio[1043]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 27 10:31:03 volumioalrum volumio[1043]: info: Sending Spotify command with payload to local API: /player/volume Jan 27 10:31:03 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:03+01:00" level=debug msg="update volume requested to 65535/65535" Jan 27 10:31:03 volumioalrum volumio[1043]: error: Cannot start Volumio Streaming Daemon Jan 27 10:31:03 volumioalrum volumio[1043]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 10:31:03 volumioalrum volumio[1043]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 10:31:03 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Jan 27 10:31:03 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:03+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 27 10:31:03 volumioalrum go-librespot[2390]: time="2026-01-27T10:31:03+01:00" level=trace msg="emitting websocket event: volume" Jan 27 10:31:03 volumioalrum volumio[1043]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Jan 27 10:31:03 volumioalrum volumio[1043]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Jan 27 10:31:03 volumioalrum volumio[1043]: info: Getting Spotify volume Jan 27 10:31:03 volumioalrum volumio[1043]: info: Spotify volume: 100 Jan 27 10:31:03 volumioalrum volumio[1043]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Jan 27 10:31:03 volumioalrum volumio[1043]: error: MyVolumio Custom Token format not valid, refreshing it Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:03 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:03 volumioalrum volumio[1043]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:03 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:03 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Jan 27 10:31:03 volumioalrum volumio[1043]: STREAMING PROXY: Starting server on port 3245 Jan 27 10:31:03 volumioalrum volumio[1043]: Node JS runtime: 14 Jan 27 10:31:03 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 27 10:31:03 volumioalrum ntpd[2568]: Soliciting pool server 193.200.91.90 Jan 27 10:31:03 volumioalrum sudo[2587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 27 10:31:03 volumioalrum sudo[2587]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum ntpd[2568]: Soliciting pool server 77.37.97.124 Jan 27 10:31:03 volumioalrum sudo[2587]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:03 volumioalrum sudo[2593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 27 10:31:03 volumioalrum sudo[2593]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum sudo[2593]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:03 volumioalrum sudo[2601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 27 10:31:03 volumioalrum sudo[2601]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum sudo[2601]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:03 volumioalrum sudo[2607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 27 10:31:03 volumioalrum sudo[2607]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum sudo[2607]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:03 volumioalrum sudo[2613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:31:03 volumioalrum sudo[2613]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:03 volumioalrum sudo[2613]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:04 volumioalrum sudo[2616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:31:04 volumioalrum sudo[2616]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:04 volumioalrum sudo[2616]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:04 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:04 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:04 volumioalrum volumio[1043]: info: Received Get System Info Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:04 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:04 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:31:04 volumioalrum volumio[1043]: info: Discovery: Getting this device information Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:04 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioGetState Jan 27 10:31:04 volumioalrum volumio[1043]: info: CorePlayQueue::getTrack 0 Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: verbose: New Socket.io Connection to 192.168.1.101:3000 from 192.168.1.190 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 16 Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:31:04 volumioalrum volumio[1043]: info: MyVolumio login type: Token Jan 27 10:31:04 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 27 10:31:04 volumioalrum volumio[1043]: info: MyVolumio login type: Token Jan 27 10:31:04 volumioalrum ntpd[2568]: Soliciting pool server 91.229.203.9 Jan 27 10:31:04 volumioalrum ntpd[2568]: Soliciting pool server 5.186.54.149 Jan 27 10:31:04 volumioalrum ntpd[2568]: Soliciting pool server 185.181.223.169 Jan 27 10:31:05 volumioalrum volumio[1043]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 10:31:05 volumioalrum volumio[1043]: info: MyVolumio token set successfully Jan 27 10:31:05 volumioalrum volumio[1043]: info: MYVOLUMIO: Adding device Jan 27 10:31:05 volumioalrum volumio[1043]: info: MYVOLUMIO: Evaluating Server Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 212.99.225.86 Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 87.63.200.138 Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 5.186.56.205 Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 86.52.112.177 Jan 27 10:31:06 volumioalrum volumio-time-update[785]: volumio-time-update-util: Fetching time from Volumio... Jan 27 10:31:06 volumioalrum volumio[1043]: info: MyVolumio Plan changed: premium Jan 27 10:31:06 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jan 27 10:31:06 volumioalrum volumio[1043]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 10:31:06 volumioalrum volumio[1043]: info: Removing audio output: Jan 27 10:31:06 volumioalrum volumio[1043]: info: MYVOLUMIO: Adding device Jan 27 10:31:06 volumioalrum volumio[1043]: info: MYVOLUMIO: Evaluating Server Jan 27 10:31:06 volumioalrum volumio[1043]: info: Remote config written successfully Jan 27 10:31:06 volumioalrum volumio[1043]: info: Starting Tunnel 1 Jan 27 10:31:06 volumioalrum volumio[1043]: info: Starting Tunnel Connection Checker Jan 27 10:31:06 volumioalrum volumio-time-update[785]: volumio-time-update-util: Setting system time to: 2026-01-27 10:31:05 Jan 27 10:31:06 volumioalrum sudo[2643]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-01-27 10:31:05 Jan 27 10:31:06 volumioalrum sudo[2643]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:06 volumioalrum dbus-daemon[786]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=2644 comm="timedatectl set-time 2026-01-27 10:31:05 ") Jan 27 10:31:06 volumioalrum systemd[1]: Starting Time & Date Service... Jan 27 10:31:06 volumioalrum dbus-daemon[786]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 27 10:31:06 volumioalrum systemd[1]: Started Time & Date Service. Jan 27 10:31:05 volumioalrum systemd-timedated[2646]: Changed local time to Tue Jan 27 10:31:05 2026 Jan 27 10:31:05 volumioalrum sudo[2643]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:05 volumioalrum volumio-time-update[785]: volumio-time-update-util: System time updated successfully. Jan 27 10:31:05 volumioalrum systemd[1]: Started Volumio Time Update Utility. Jan 27 10:31:05 volumioalrum systemd[1]: Reached target Multi-User System. Jan 27 10:31:05 volumioalrum systemd[1]: Reached target Graphical Interface. Jan 27 10:31:05 volumioalrum systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 27 10:31:05 volumioalrum systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 27 10:31:05 volumioalrum systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 27 10:31:05 volumioalrum systemd[1]: Startup finished in 16.386s (firmware) + 2.487s (loader) + 10.069s (kernel) + 2min 49.175s (userspace) = 3min 18.118s. Jan 27 10:31:05 volumioalrum volumio[1043]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 10:31:05 volumioalrum volumio[1043]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:31:05 volumioalrum volumio[1043]: info: MYVolumio Device enabled Jan 27 10:31:05 volumioalrum volumio[1043]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jan 27 10:31:05 volumioalrum volumio[1043]: info: MyVolumio status changed Jan 27 10:31:05 volumioalrum volumio[1043]: info: Streaming services startup Jan 27 10:31:05 volumioalrum volumio[1043]: info: Starting Streaming Daemon Jan 27 10:31:05 volumioalrum sudo[2669]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 10:31:05 volumioalrum sudo[2669]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 27 10:31:05 volumioalrum volumio[1043]: info: Setting Geolocation for MyVolumio to eu8 Jan 27 10:31:05 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:31:05 volumioalrum volumio[1043]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:31:05 volumioalrum volumio[1043]: error: Failed to ping endpoint eu6.myvolumio.org : unknown error Jan 27 10:31:05 volumioalrum volumio[1043]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:31:05 volumioalrum volumio[1043]: Error: Unable to resolve or reject the same promise twice Jan 27 10:31:05 volumioalrum volumio[1043]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 27 10:31:05 volumioalrum volumio[1043]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Jan 27 10:31:05 volumioalrum volumio[1043]: at Socket.emit (events.js:400:28) Jan 27 10:31:05 volumioalrum volumio[1043]: at addChunk (internal/streams/readable.js:293:12) Jan 27 10:31:05 volumioalrum volumio[1043]: at readableAddChunk (internal/streams/readable.js:267:9) Jan 27 10:31:05 volumioalrum volumio[1043]: at Socket.Readable.push (internal/streams/readable.js:206:10) Jan 27 10:31:05 volumioalrum volumio[1043]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Jan 27 10:31:05 volumioalrum volumio[1043]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:31:05 volumioalrum sudo[2669]: pam_unix(sudo:session): session closed for user root Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 213.5.39.34 Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 87.104.58.9 Jan 27 10:31:05 volumioalrum ntpd[2568]: Soliciting pool server 162.159.200.123 Jan 27 10:31:05 volumioalrum sudo[2680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-27 10:30 Jan 27 10:31:05 volumioalrum sudo[2680]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:18:30 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="33f9369b544b4488ff4979d2ee3813a5"