May 27 19:18:00 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:00 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:00 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:00 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:01 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:01 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:01 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:01 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:02 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:02 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:02 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:02 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:03 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:03 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:03 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:03 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:04 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:04 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:04 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:04 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:05 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:05 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:05 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:05 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:06 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:06 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:06 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:06 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:07 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:07 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:07 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:07 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:08 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:08 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:08 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:08 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:09 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:09 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:09 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:09 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:10 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:10 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:10 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:10 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:11 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:11 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:11 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:11 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:12 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:12 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:12 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:12 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:13 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:13 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:13 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:13 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:14 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:14 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:14 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:14 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:15 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:15 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:15 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:15 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:16 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:16 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:16 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:16 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:17 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:17 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:17 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:17 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:18 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:18 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:18 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:18 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:19 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:19 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:19 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:19 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:20 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:20 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:20 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:20 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:20 ode-spk-grefsen-02 volumio[1102]: info: [ode-hardware-controls] Tick heartbeat #50485 (duration=20ms, skipped=1447, errors=0, potSwitch=false, slideSwitch=true, volumeLocked=false, intentGate=none, potRaw=0). May 27 19:18:21 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:21 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:21 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:21 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:22 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:22 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:22 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:22 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:23 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:23 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:23 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:23 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:24 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:24 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:24 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:24 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:25 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:25 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:25 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:25 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:25 ode-spk-grefsen-02 volumio[1102]: info: [ode-hardware-controls] -> GET /api/internal/speaker/settings (speakerId=spk_grefsen_02). May 27 19:18:26 ode-spk-grefsen-02 volumio[1102]: info: [ode-hardware-controls] <- GET /api/internal/speaker/settings 200 (635ms, speakerId=spk_grefsen_02). May 27 19:18:26 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:26 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:27 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:27 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:27 ode-spk-grefsen-02 tailscaled[13786]: magicsock: disco: node [WqqGI] d:4b8a86231f32412f now using 10.0.0.33:41641 mtu=1360 tx=2fa9f52504de May 27 19:18:27 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:27 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171827-b16662dd3e: handling conn: 100.119.250.89:62719->volumio@100.71.127.10:22 May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171827-b16662dd3e: starting session: sess-20260527T171828-f849979c11 May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171828-f849979c11): handling new SSH connection from jakobhn@github (100.119.250.89) to ssh-user "volumio" May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171828-f849979c11): access granted to jakobhn@github as ssh-user "volumio" May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: audit: SSH login: user=volumio uid=1000 from=100.119.250.89 ts_user=jakobhn@github node=jakobs-macbook-pro-1.tail56347c.ts.net. May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171828-f849979c11): starting non-pty command: [/usr/sbin/tailscaled be-child ssh --login-shell=/bin/bash --uid=1000 --gid=1000 --groups=1000,4,7,20,24,25,29,30,44,46,102,103,108,994,993 --local-user=volumio --home-dir=/home/volumio --remote-user=jakobhn@github --remote-ip=100.119.250.89 --has-tty=false --tty-name= --force-v1-behavior --cmd=echo host=$(hostname); curl -sS --max-time 5 http://127.0.0.1:3000/api/v1/getState; echo; ping -c 5 -W 2 10.0.0.138 | tail -2; ping -c 5 -W 2 1.1.1.1 | tail -2; python3 - <<"PY" May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: import json May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: p="/data/configuration/plugins.json" May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: d=json.load(open(p)) May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: for cat,slug in [("system_controller","ode_speaker_bridge"),("system_hardware","ode_hardware_controls")]: print(cat, slug, d.get(cat,{}).get(slug)) May 27 19:18:28 ode-spk-grefsen-02 tailscaled[13786]: PY] May 27 19:18:28 ode-spk-grefsen-02 systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. May 27 19:18:28 ode-spk-grefsen-02 systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 27 19:18:28 ode-spk-grefsen-02 systemd-logind[613]: New session c28 of user volumio. May 27 19:18:28 ode-spk-grefsen-02 systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 27 19:18:28 ode-spk-grefsen-02 systemd[1]: Starting user@1000.service - User Manager for UID 1000... May 27 19:18:28 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:28 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:28 ode-spk-grefsen-02 (systemd)[11215]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) May 27 19:18:28 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:28 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Queued start job for default target default.target. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Created slice app.slice - User Application Slice. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Reached target paths.target - Paths. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Reached target timers.target - Timers. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Listening on dirmngr.socket - GnuPG network certificate management daemon. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Reached target sockets.target - Sockets. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Reached target basic.target - Basic System. May 27 19:18:29 ode-spk-grefsen-02 systemd[1]: Started user@1000.service - User Manager for UID 1000. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Started mpris-proxy.service - Bluetooth mpris proxy. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Reached target default.target - Main User Target. May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: Startup finished in 717ms. May 27 19:18:29 ode-spk-grefsen-02 systemd[1]: Started session-c28.scope - Session c28 of User volumio. May 27 19:18:29 ode-spk-grefsen-02 mpris-proxy[11230]: Can't get on session bus May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE May 27 19:18:29 ode-spk-grefsen-02 systemd[11215]: mpris-proxy.service: Failed with result 'exit-code'. May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:29 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:30 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:30 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:30 ode-spk-grefsen-02 tailscaled[13786]: portmapper: UPnP discovery response from non-UPnP port 45817 May 27 19:18:30 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:30 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:31 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:31 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:31 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:31 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:32 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:32 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:32 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:32 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:33 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:33 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:33 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:33 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:34 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:34 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:34 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:34 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:35 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:35 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:35 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:35 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:36 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:36 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:36 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:36 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:37 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:37 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:37 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171828-f849979c11): Session complete May 27 19:18:37 ode-spk-grefsen-02 systemd-logind[613]: Session c28 logged out. Waiting for processes to exit. May 27 19:18:37 ode-spk-grefsen-02 systemd[1]: session-c28.scope: Deactivated successfully. May 27 19:18:37 ode-spk-grefsen-02 systemd-logind[613]: Removed session c28. May 27 19:18:37 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:37 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:38 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:38 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:38 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:38 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:39 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:39 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:39 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:39 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:40 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:40 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:40 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:40 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:41 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:41 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:41 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:41 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:42 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:42 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:42 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:42 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:43 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:43 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:43 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:43 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:44 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:44 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:44 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:44 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:45 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:45 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:45 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:45 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:46 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:46 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171846-53bb5525fe: handling conn: 100.119.250.89:62745->volumio@100.71.127.10:22 May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171846-53bb5525fe: starting session: sess-20260527T171846-516e98667a May 27 19:18:46 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:46 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171846-516e98667a): handling new SSH connection from jakobhn@github (100.119.250.89) to ssh-user "volumio" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171846-516e98667a): access granted to jakobhn@github as ssh-user "volumio" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: audit: SSH login: user=volumio uid=1000 from=100.119.250.89 ts_user=jakobhn@github node=jakobs-macbook-pro-1.tail56347c.ts.net. May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171846-516e98667a): starting non-pty command: [/usr/sbin/tailscaled be-child ssh --login-shell=/bin/bash --uid=1000 --gid=1000 --groups=1000,4,7,20,24,25,29,30,44,46,102,103,108,994,993 --local-user=volumio --home-dir=/home/volumio --remote-user=jakobhn@github --remote-ip=100.119.250.89 --has-tty=false --tty-name= --force-v1-behavior --cmd=set -eu May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: now=$(date -u +%Y%m%dT%H%M%SZ) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: cp /data/configuration/plugins.json /data/configuration/plugins.json.pre-ode-isolation-${now} May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: python3 - <<"PY" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: import json May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: p="/data/configuration/plugins.json" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: d=json.load(open(p)) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: for cat, slug in [("system_controller","ode_speaker_bridge"),("system_hardware","ode_hardware_controls")]: May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: e=d.setdefault(cat,{}).setdefault(slug,{}) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: e["enabled"]={"type":"boolean","value":False} May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: e["status"]={"type":"string","value":"STOPPED"} May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: json.dump(d, open(p,"w")) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: PY May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: volumio pause >/dev/null || true May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: volumio volume 0 >/dev/null || true May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: volumio vrestart May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: sleep 18 May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: python3 - <<"PY" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: import json May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: p="/data/configuration/plugins.json" May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: d=json.load(open(p)) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: for cat, slug in [("system_controller","ode_speaker_bridge"),("system_hardware","ode_hardware_controls")]: print(cat, slug, d.get(cat,{}).get(slug)) May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: PY May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: curl -sS --max-time 5 http://127.0.0.1:3000/api/v1/getState || true May 27 19:18:46 ode-spk-grefsen-02 tailscaled[13786]: echo] May 27 19:18:46 ode-spk-grefsen-02 systemd-logind[613]: New session c29 of user volumio. May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: Started session-c29.scope - Session c29 of User volumio. May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: ---------------------------- Client requests Volumio pause May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioPause May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreStateMachine::pause May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: ---------------------------- Client requests Volume 0 May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: VolumeController::SetAlsaVolume0 May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreStateMachine::pushState May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioPushState May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: MRS: Pushing multiroomSync output update for this device May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: MRS: Pushing multiroomSync output May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CoreCommandRouter::volumioGetState May 27 19:18:47 ode-spk-grefsen-02 volumio[1102]: info: CorePlayQueue::getTrack 7 May 27 19:18:47 ode-spk-grefsen-02 sudo[11289]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/systemctl stop volumio.service May 27 19:18:47 ode-spk-grefsen-02 sudo[11289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: Stopping volumio.service - Volumio Backend Module... May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: volumio.service: Deactivated successfully. May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: Stopped volumio.service - Volumio Backend Module. May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: volumio.service: Consumed 1h 6min 42.451s CPU time. May 27 19:18:47 ode-spk-grefsen-02 sudo[11289]: pam_unix(sudo:session): session closed for user root May 27 19:18:47 ode-spk-grefsen-02 sudo[11296]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/systemctl start volumio.service May 27 19:18:47 ode-spk-grefsen-02 sudo[11296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:18:47 ode-spk-grefsen-02 volumio-remote-updater[620]: [2026-05-27 19:18:47] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 27 19:18:47 ode-spk-grefsen-02 volumio-remote-updater[620]: [2026-05-27 19:18:47] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: Started dynamicswap.service - dynamicswap service. May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: Started volumio.service - Volumio Backend Module. May 27 19:18:47 ode-spk-grefsen-02 sudo[11296]: pam_unix(sudo:session): session closed for user root May 27 19:18:47 ode-spk-grefsen-02 systemd[1]: dynamicswap.service: Deactivated successfully. May 27 19:18:51 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:18:51 ode-spk-grefsen-02 volumio[11302]: info: ----- Volumio3 ---- May 27 19:18:51 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:18:51 ode-spk-grefsen-02 volumio[11302]: info: ----- System startup ---- May 27 19:18:51 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:18:52 ode-spk-grefsen-02 volumio-remote-updater[620]: [2026-05-27 19:18:52] [connect] Successful connection May 27 19:18:52 ode-spk-grefsen-02 volumio[11302]: info: MYVOLUMIO Environment detected May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Plugin folders cleanup May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning into folder /volumio/app/plugins/ May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category audio_interface May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category miscellanea May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category music_service May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category plugins.json May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category system_controller May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category user_interface May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning into folder /data/plugins/ May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category system_controller May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Scanning category system_hardware May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Plugin folders cleanup completed May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: ----- Core plugins startup ---- May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Loading plugins from folder /volumio/app/plugins/ May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin upnp to MyMusic Plugins May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin airplay_emulation to MyMusic Plugins May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin upnp_browser to MyMusic Plugins May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Loading plugins from folder /data/plugins/ May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "system"... May 27 19:18:53 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "appearance"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "network"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Refreshing Cached IP Addresses May 27 19:18:55 ode-spk-grefsen-02 sudo[11335]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "services"... May 27 19:18:55 ode-spk-grefsen-02 sudo[11335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Plugin volumio5onboarding is not enabled May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "alsa_controller"... May 27 19:18:55 ode-spk-grefsen-02 sudo[11335]: pam_unix(sudo:session): session closed for user root May 27 19:18:55 ode-spk-grefsen-02 sudo[11333]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 19:18:55 ode-spk-grefsen-02 sudo[11333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:18:55 ode-spk-grefsen-02 sudo[11345]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 27 19:18:55 ode-spk-grefsen-02 sudo[11345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:18:55 ode-spk-grefsen-02 sudo[11333]: pam_unix(sudo:session): session closed for user root May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "wizard"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "networkfs"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Starting Udev Watcher for removable devices May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Ignoring mount for partition: boot May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Ignoring mount for partition: volumio May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Ignoring mount for partition: volumio_data May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "volumio_command_line_client"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "upnp"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: [1779902335689] Starting Upmpd Daemon May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "my_music"... May 27 19:18:55 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "mpd"... May 27 19:18:56 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "upnp_browser"... May 27 19:18:56 ode-spk-grefsen-02 sudo[11345]: pam_unix(sudo:session): session closed for user root May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Starting UPNP Browser May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Plugin ode_hardware_controls is not enabled May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "alarm-clock"... May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Plugin airplay_emulation is not enabled May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "last_100"... May 27 19:18:58 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "webradio"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "i2s_dacs"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "volumiodiscovery"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** Please fix your application to use the native API of Avahi! May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** For more information see May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** Please fix your application to use the native API of Avahi! May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: *** WARNING *** For more information see May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** Please fix your application to use the native API of Avahi! May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** For more information see May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** Please fix your application to use the native API of Avahi! May 27 19:18:59 ode-spk-grefsen-02 node[11302]: *** WARNING *** For more information see May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Applying required configuration parameters for plugin volumiodiscovery May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Started advertising with name: ode-spk-grefsen-02 May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Plugin ode_speaker_bridge is not enabled May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "outputs"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Plugin albumart is not enabled May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Plugin example_plugin is not enabled May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "inputs"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "updater_comm"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Plugin mpdemulation is not enabled May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "rest_api"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading plugin "websocket"... May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Starting Socket.io Server version 1.7.4 May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Loading i18n strings for locale en May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: Updating browse sources language May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::initPlayerControls May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: Express server listening on port 3000 May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: [Metrics] WebUI: 9s 372.05ms May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::resetVolumioState May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::getcurrentVolume May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioRetrievevolume May 27 19:18:59 ode-spk-grefsen-02 volumio[11302]: info: Volumio Network Manager: Network status updated: 2 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::updateTrackBlock May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrackBlock May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioRetrievevolume May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Reloading queue from file May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::setRepeat null single undefined May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::setRandom null May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPushState May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Setting Device type: Raspberry PI May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Completed loading Core Plugins May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Preparing to generate the ALSA configuration file May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Reading ALSA contributions from plugins. May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.50 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.49 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.49 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.47 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.47 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.50 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 315c7a84-c9a9-4db1-8b7b-027eefc2d5fd May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-03 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.51 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.51 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding dbe2ad45-d84f-47f9-8562-806a5f56f909 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-08 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.49 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.48 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding ed24b499-6f24-45ec-96b1-949a190bc791 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-09 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.50 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Asound.conf file written May 27 19:19:00 ode-spk-grefsen-02 sudo[11403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 27 19:19:00 ode-spk-grefsen-02 sudo[11403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:00 ode-spk-grefsen-02 sudo[11403]: pam_unix(sudo:session): session closed for user root May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Output device has changed, restarting MPD May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: ___________ START PLUGINS ___________ May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: ControllerMpd::onStart: Initializing MPD May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Creating MPD Configuration file May 27 19:19:00 ode-spk-grefsen-02 sudo[11411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 27 19:19:00 ode-spk-grefsen-02 sudo[11411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:00 ode-spk-grefsen-02 sudo[11411]: pam_unix(sudo:session): session closed for user root May 27 19:19:00 ode-spk-grefsen-02 sudo[11413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 19:19:00 ode-spk-grefsen-02 sudo[11413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: [1779902340807] CoreMusicLibrary::Adding element Media Servers May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: UPNP Browser: Client initialized successfully May 27 19:19:00 ode-spk-grefsen-02 sudo[11416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 27 19:19:00 ode-spk-grefsen-02 sudo[11416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:00 ode-spk-grefsen-02 sudo[11416]: pam_unix(sudo:session): session closed for user root May 27 19:19:00 ode-spk-grefsen-02 sudo[11419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 27 19:19:00 ode-spk-grefsen-02 sudo[11419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: [1779902340874] CoreMusicLibrary::Adding element Last_100 May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: [1779902340879] CoreMusicLibrary::Adding element Webradio May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Initializing BBC Radios May 27 19:19:00 ode-spk-grefsen-02 systemd[1]: Stopping mpd.service - Music Player Daemon... May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:00 ode-spk-grefsen-02 volumio[11302]: info: Volumio Calling Home May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.41 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 81fa4136-a8b5-4c56-9aef-7133de62b174 May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-01 May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.42 May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 30456a51-be62-46d8-a94b-9c613455486a May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-05 May 27 19:19:01 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.46 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.41 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: MPD Permissions set May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: MPD Permissions set May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 6546d65d-8d40-4386-9007-923abe961991 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-07 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.48 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 35ec32b7-983a-4dc9-9466-51586d7f2705 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-06 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.47 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.48 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Volumio called home May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 6db68563-f2b9-408a-9aed-6e746ffcdc98 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-10 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.41 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 58341cfd-a4ac-4ee5-b4c2-fc4689c8a086 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-04 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connecting to remote: 10.0.0.44 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: adding 254ed160-a917-4a2a-99d6-d9763d0d5b9d May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-02 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.49 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: this is already registered, 254ed160-a917-4a2a-99d6-d9763d0d5b9d May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Found device ode-spk-grefsen-02 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.47 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.49 May 27 19:19:02 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.51 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.47 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.50 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.46 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.42 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.47 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.48 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.48 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.41 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.42 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 31 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 10.0.0.43:3000 from 10.0.0.44 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: Discovery: Connected to remote: 10.0.0.44 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 34 May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:03 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: mpd.service: Deactivated successfully. May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: Stopped mpd.service - Music Player Daemon. May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: mpd.service: Consumed 1min 20.403s CPU time. May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: mpd.socket: Deactivated successfully. May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: error: Upnp client error: Error: read ECONNRESET May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: error: Upnp client error: Error: read ECONNRESET May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 27 19:19:04 ode-spk-grefsen-02 systemd[1]: Starting mpd.service - Music Player Daemon... May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:04 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:04 ode-spk-grefsen-02 sudo[11456]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 27 19:19:04 ode-spk-grefsen-02 sudo[11456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 27 19:19:04 ode-spk-grefsen-02 sudo[11456]: pam_unix(sudo:session): session closed for user root May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:05 ode-spk-grefsen-02 volumio-remote-updater[620]: [2026-05-27 19:19:05] [connect] Successful connection May 27 19:19:05 ode-spk-grefsen-02 volumio-remote-updater[620]: [2026-05-27 19:19:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1779902345 101 May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 35 May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:05 ode-spk-grefsen-02 sudo[11474]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 19:19:05 ode-spk-grefsen-02 sudo[11474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:05 ode-spk-grefsen-02 sudo[11476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 19:19:05 ode-spk-grefsen-02 sudo[11476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:05 ode-spk-grefsen-02 sudo[11476]: pam_unix(sudo:session): session closed for user root May 27 19:19:05 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:05 ode-spk-grefsen-02 sudo[11482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 27 19:19:05 ode-spk-grefsen-02 sudo[11482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:06 ode-spk-grefsen-02 sudo[11474]: pam_unix(sudo:session): session closed for user root May 27 19:19:06 ode-spk-grefsen-02 sudo[11482]: pam_unix(sudo:session): session closed for user root May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: Upmpdcli Daemon Started May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:06 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:07 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:07 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:07 ode-spk-grefsen-02 systemd[1]: session-c29.scope: Deactivated successfully. May 27 19:19:07 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171846-516e98667a): Session complete May 27 19:19:07 ode-spk-grefsen-02 systemd[1]: session-c29.scope: Consumed 1.121s CPU time. May 27 19:19:07 ode-spk-grefsen-02 systemd-logind[613]: Session c29 logged out. Waiting for processes to exit. May 27 19:19:07 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 27 19:19:07 ode-spk-grefsen-02 systemd-logind[613]: Removed session c29. May 27 19:19:07 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:07 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:12 ode-spk-grefsen-02 mpd[11458]: 2026-05-27T19:19:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 27 19:19:12 ode-spk-grefsen-02 systemd[1]: Started mpd.service - Music Player Daemon. May 27 19:19:12 ode-spk-grefsen-02 sudo[11413]: pam_unix(sudo:session): session closed for user root May 27 19:19:12 ode-spk-grefsen-02 sudo[11419]: pam_unix(sudo:session): session closed for user root May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: Completed starting Core Plugins May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: ----- MyVolumio plugins startup ---- May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: ------------------------------------------- May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Fetching plans data.... May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: error: MPD error: The expression evaluated to a falsy value: May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: assert.ok(self.idling) May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: error: The expression evaluated to a falsy value: May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: assert.ok(self.idling) May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: info: MPD running with PID11458 May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: ,establishing connection May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: error: updateQueue error: null May 27 19:19:12 ode-spk-grefsen-02 volumio[11302]: error: updateQueue error: null May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: Stopping user@1000.service - User Manager for UID 1000... May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Activating special unit exit.target... May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Stopped target default.target - Main User Target. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Stopped target basic.target - Basic System. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Stopped target paths.target - Paths. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Stopped target sockets.target - Sockets. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Stopped target timers.target - Timers. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Closed dirmngr.socket - GnuPG network certificate management daemon. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Removed slice app.slice - User Application Slice. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Reached target shutdown.target - Shutdown. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Finished systemd-exit.service - Exit the Session. May 27 19:19:17 ode-spk-grefsen-02 systemd[11215]: Reached target exit.target - Exit the Session. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: user@1000.service: Deactivated successfully. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: Stopped user@1000.service - User Manager for UID 1000. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: run-user-1000.mount: Deactivated successfully. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. May 27 19:19:17 ode-spk-grefsen-02 systemd[1]: user-1000.slice: Consumed 2.234s CPU time. May 27 19:19:17 ode-spk-grefsen-02 volumio[11302]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171920-46e164061c: handling conn: 100.119.250.89:62767->volumio@100.71.127.10:22 May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ssh-conn-20260527T171920-46e164061c: starting session: sess-20260527T171921-1f2500cfe7 May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171921-1f2500cfe7): handling new SSH connection from jakobhn@github (100.119.250.89) to ssh-user "volumio" May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171921-1f2500cfe7): access granted to jakobhn@github as ssh-user "volumio" May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: audit: SSH login: user=volumio uid=1000 from=100.119.250.89 ts_user=jakobhn@github node=jakobs-macbook-pro-1.tail56347c.ts.net. May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ssh-session(sess-20260527T171921-1f2500cfe7): starting non-pty command: [/usr/sbin/tailscaled be-child ssh --login-shell=/bin/bash --uid=1000 --gid=1000 --groups=1000,4,7,20,24,25,29,30,44,46,102,103,108,994,993 --local-user=volumio --home-dir=/home/volumio --remote-user=jakobhn@github --remote-ip=100.119.250.89 --has-tty=false --tty-name= --force-v1-behavior --cmd=python3 - <<"PY" May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: import json, subprocess, time May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: def curl(path, method="GET", body=None): May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: cmd=["curl","-sS","--max-time","10"] May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: if method=="POST": May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: cmd += ["-X","POST","-H","content-type: application/json","--data",body or "{}"] May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: cmd.append("http://127.0.0.1:3000"+path) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: return subprocess.run(cmd, text=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT).stdout May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: def state(): May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: try: return json.loads(curl("/api/v1/getState")) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: except Exception as e: return {"error":repr(e)} May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: def wait_status(status="play", timeout=30): May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: start=time.time(); last=None May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: while time.time()-start < timeout: May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: last=state() May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: if last.get("status")==status: May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: return round(time.time()-start,3), last May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: time.sleep(0.25) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: return None, last May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: print("== TIDAL stop->play N=0 ==") May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: curl("/api/v1/commands/?cmd=pause"); curl("/api/v1/commands/?cmd=volume&volume=0"); time.sleep(1) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: print("before", state()) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: t=time.time(); r=curl("/api/v1/commands/?cmd=play&N=0"); print("cmd_ms", round((time.time()-t)*1000), "resp", r.strip()) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: lat,s=wait_status("play", 35); print("lat_s", lat, "state", s) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: print("== TIDAL next ==") May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: t=time.time(); r=curl("/api/v1/commands/?cmd=next"); print("cmd_ms", round((time.time()-t)*1000), "resp", r.strip()) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: lat,s=wait_status("play", 35); print("lat_s", lat, "state", s) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: print("== WEBRADIO replaceAndPlay ==") May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: radio={"service":"webradio","type":"webradio","title":"NRK P1","name":"NRK P1","uri":"https://lyd.nrk.no/nrk_radio_p1_ostlandssendingen_mp3_h"} May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: payload=json.dumps({"list":[radio]}) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: t=time.time(); r=curl("/api/v1/replaceAndPlay", "POST", payload); print("cmd_ms", round((time.time()-t)*1000), "resp", r.strip()[:500]) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: lat,s=wait_status("play", 20); print("lat_s", lat, "state", s) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: curl("/api/v1/commands/?cmd=pause"); curl("/api/v1/commands/?cmd=volume&volume=0") May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: print("after", state()) May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: PY May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: printf "\n== logs ==\n" May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: journalctl -u volumio --since "4 minutes ago" --no-pager | egrep -i "ControllerTidal|clearAddPlayTrack|Could not get TIDAL Stream URL|updateQueue error|STATE SERVICE|replaceAndPlay|webradio|FATAL|Failed initialization|Decoder is too slow|SoftMaster|error" | tail -240 || true May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: printf "\n== ping after ==\n" May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ping -c 5 -W 2 10.0.0.138 | tail -2 May 27 19:19:21 ode-spk-grefsen-02 tailscaled[13786]: ping -c 5 -W 2 1.1.1.1 | tail -2] May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin bluetooth to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin multiroom to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin metavolumio to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin cd_controller to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin qobuzconnect to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin smart_inputs to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: Adding plugin tidalconnect to MyMusic Plugins May 27 19:19:21 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 27 19:19:21 ode-spk-grefsen-02 systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. May 27 19:19:21 ode-spk-grefsen-02 systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 27 19:19:21 ode-spk-grefsen-02 systemd-logind[613]: New session c30 of user volumio. May 27 19:19:21 ode-spk-grefsen-02 systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 27 19:19:21 ode-spk-grefsen-02 systemd[1]: Starting user@1000.service - User Manager for UID 1000... May 27 19:19:21 ode-spk-grefsen-02 (systemd)[11519]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Queued start job for default target default.target. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Created slice app.slice - User Application Slice. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Reached target paths.target - Paths. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Reached target timers.target - Timers. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Listening on dirmngr.socket - GnuPG network certificate management daemon. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Reached target sockets.target - Sockets. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Reached target basic.target - Basic System. May 27 19:19:22 ode-spk-grefsen-02 systemd[1]: Started user@1000.service - User Manager for UID 1000. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Started mpris-proxy.service - Bluetooth mpris proxy. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Reached target default.target - Main User Target. May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: Startup finished in 1.047s. May 27 19:19:22 ode-spk-grefsen-02 systemd[1]: Started session-c30.scope - Session c30 of User volumio. May 27 19:19:22 ode-spk-grefsen-02 mpris-proxy[11537]: Can't get on session bus May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE May 27 19:19:22 ode-spk-grefsen-02 systemd[11519]: mpris-proxy.service: Failed with result 'exit-code'. May 27 19:19:23 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 27 19:19:23 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 27 19:19:23 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:23 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:23 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 19:19:24 ode-spk-grefsen-02 volumio[11302]: info: Starting MyVolumio Remote Streaming Endpoints May 27 19:19:24 ode-spk-grefsen-02 volumio[11302]: info: MyVolumio login type: Token May 27 19:19:24 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 27 19:19:24 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 27 19:19:25 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 27 19:19:25 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 27 19:19:25 ode-spk-grefsen-02 volumio[11302]: info: Streaming services startup May 27 19:19:25 ode-spk-grefsen-02 volumio[11302]: info: Starting Streaming Daemon May 27 19:19:25 ode-spk-grefsen-02 volumio[11302]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 27 19:19:25 ode-spk-grefsen-02 sudo[11554]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service May 27 19:19:25 ode-spk-grefsen-02 sudo[11554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 19:19:26 ode-spk-grefsen-02 sudo[11554]: pam_unix(sudo:session): session closed for user root May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: ---------------------------- Client requests Volumio pause May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPause May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pause May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: error: Cannot start Volumio Streaming Daemon May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: ---------------------------- Client requests Volume 0 May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: VolumeController::SetAlsaVolume0 May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::pushState May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPushState May 27 19:19:26 ode-spk-grefsen-02 volumio[11302]: error: MyVolumio Custom Token format not valid, refreshing it May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioGetState May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: ---------------------------- Client requests Volumio play at index 0 May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreCommandRouter::volumioPlay May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::play index 0 May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::stop May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::play index undefined May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CoreStateMachine::startPlaybackTimer May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: info: CorePlayQueue::getTrack 0 May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: TypeError: Cannot read properties of undefined (reading 'clearAddPlayTrack') May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: at Promise._successFn (/volumio/app/statemachine.js:1027:33) May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) May 27 19:19:27 ode-spk-grefsen-02 volumio[11302]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 19:19:28 ode-spk-grefsen-02 sudo[11580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 19:18' May 27 19:19:28 ode-spk-grefsen-02 sudo[11580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"