-- Logs begin at Wed 2025-04-09 18:41:25 CEST, end at Fri 2025-04-18 16:58:42 CEST. -- Apr 18 16:57:45 volofritz systemd-timedated[3392]: Changed local time to Fri Apr 18 16:57:45 2025 Apr 18 16:57:45 volofritz sudo[3390]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:45 volofritz volumio-time-update[2828]: volumio-time-update-util: System time updated successfully. Apr 18 16:57:45 volofritz systemd[1]: Started Volumio Time Update Utility. Apr 18 16:57:45 volofritz systemd[1]: Starting Daily apt download activities... Apr 18 16:57:45 volofritz systemd[1]: Starting Daily man-db regeneration... Apr 18 16:57:45 volofritz systemd[1]: man-db.service: Succeeded. Apr 18 16:57:45 volofritz systemd[1]: Started Daily man-db regeneration. Apr 18 16:57:45 volofritz wireless.js[2826]: trying... Apr 18 16:57:45 volofritz sudo[3411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:45 volofritz sudo[3411]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:45 volofritz sudo[3411]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:45 volofritz systemd[1]: systemd-rfkill.service: Succeeded. Apr 18 16:57:45 volofritz tailscaled[2837]: control: control server key from https://controlplane.tailscale.com: ts2021=[fSeS+], legacy=[nlFWp] Apr 18 16:57:45 volofritz tailscaled[2837]: control: RegisterReq: onode= node=[SC2NV] fup=false nks=false Apr 18 16:57:45 volofritz tailscaled[2837]: control: RegisterReq: got response; nodeKeyExpired=false, machineAuthorized=true; authURL=false Apr 18 16:57:45 volofritz tailscaled[2837]: health(warnable=login-state): ok Apr 18 16:57:45 volofritz tailscaled[2837]: health(warnable=not-in-map-poll): ok Apr 18 16:57:45 volofritz tailscaled[2837]: control: netmap: got new dial plan from control Apr 18 16:57:45 volofritz tailscaled[2837]: active login: devgianlu@github Apr 18 16:57:45 volofritz tailscaled[2837]: Switching ipn state NoState -> Starting (WantRunning=true, nm=true) Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: SetPrivateKey called (init) Apr 18 16:57:45 volofritz tailscaled[2837]: wgengine: Reconfig: configuring userspace WireGuard config (with 0/9 peers) Apr 18 16:57:45 volofritz tailscaled[2837]: wgengine: Reconfig: configuring router Apr 18 16:57:45 volofritz tailscaled[2837]: wgengine: Reconfig: configuring DNS Apr 18 16:57:45 volofritz tailscaled[2837]: dns: Set: {DefaultResolvers:[] Routes:{} SearchDomains:[] Hosts:10} Apr 18 16:57:45 volofritz tailscaled[2837]: dns: Resolvercfg: {Routes:{} Hosts:10 LocalDomains:[]} Apr 18 16:57:45 volofritz tailscaled[2837]: dns: OScfg: {} Apr 18 16:57:45 volofritz tailscaled[2837]: peerapi: serving on http://100.119.52.34:38356 Apr 18 16:57:45 volofritz tailscaled[2837]: peerapi: failed to do peerAPI listen, harmless (netstack available) but error was: listen tcp6 [fd7a:115c:a1e0:ab12:4843:cd96:6277:3422]:0: bind: cannot assign requested address Apr 18 16:57:45 volofritz tailscaled[2837]: peerapi: serving on http://[fd7a:115c:a1e0:ab12:4843:cd96:6277:3422]:1 Apr 18 16:57:45 volofritz tailscaled[2837]: portmapper: UPnP meta changed: [{Location:http://192.168.1.1:1900/igd.xml Server:ipos/7.0 UPnP/1.0 TL-WR940N/4.0 USN:uuid:060b7353-fca6-4070-85f4-1fbfb9add62c::urn:schemas-upnp-org:device:InternetGatewayDevice:1}] Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: home DERP changing from derp-0 [0ms] to derp-26 [29ms] Apr 18 16:57:45 volofritz tailscaled[2837]: health(warnable=no-derp-home): ok Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: home is now derp-26 (nue) Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: adding connection to derp-26 for home-keep-alive Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: 1 active derp conns: derp-26=cr0s,wr0s Apr 18 16:57:45 volofritz tailscaled[2837]: Switching ipn state Starting -> Running (WantRunning=true, nm=true) Apr 18 16:57:45 volofritz tailscaled[2837]: magicsock: endpoints changed: 147.53.226.10:41641 (stun), 192.168.1.7:41641 (local) Apr 18 16:57:45 volofritz tailscaled[2837]: derphttp.Client.Connect: connecting to derp-26 (nue) Apr 18 16:57:45 volofritz tailscaled[2837]: control: NetInfo: NetInfo{varies=false hairpin= ipv6=false ipv6os=false udp=true icmpv4=false derp=#26 portmap=U link="" firewallmode="ipt-default"} Apr 18 16:57:45 volofritz ntpd[3354]: Soliciting pool server 212.45.144.88 Apr 18 16:57:45 volofritz ntpd[3354]: Soliciting pool server 212.6.50.243 Apr 18 16:57:46 volofritz tailscaled[2837]: magicsock: derp-26 connected; connGen=1 Apr 18 16:57:46 volofritz tailscaled[2837]: health(warnable=no-derp-connection): ok Apr 18 16:57:46 volofritz wireless.js[2826]: trying... Apr 18 16:57:46 volofritz sudo[3446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:46 volofritz sudo[3446]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:46 volofritz sudo[3446]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:46 volofritz tailscaled[2837]: LinkChange: major, rebinding. New state: interfaces.State{defaultRoute=eth0 ifs={eth0:[192.168.1.7/24] tailscale0:[100.119.52.34/32]} v4=true v6=false} Apr 18 16:57:46 volofritz tailscaled[2837]: dns: Set: {DefaultResolvers:[] Routes:{} SearchDomains:[] Hosts:10} Apr 18 16:57:46 volofritz tailscaled[2837]: dns: Resolvercfg: {Routes:{} Hosts:10 LocalDomains:[]} Apr 18 16:57:46 volofritz tailscaled[2837]: dns: OScfg: {} Apr 18 16:57:46 volofritz tailscaled[2837]: wgengine: set DNS config again after major link change Apr 18 16:57:46 volofritz tailscaled[2837]: onPortUpdate(port=41641, network=udp6) Apr 18 16:57:46 volofritz tailscaled[2837]: onPortUpdate(port=41641, network=udp4) Apr 18 16:57:46 volofritz tailscaled[2837]: Rebind; defIf="eth0", ips=[192.168.1.7/24] Apr 18 16:57:46 volofritz tailscaled[2837]: magicsock: 1 active derp conns: derp-26=cr783ms,wr783ms Apr 18 16:57:46 volofritz tailscaled[2837]: post-rebind ping of DERP region 26 okay Apr 18 16:57:46 volofritz ntpd[3354]: Soliciting pool server 151.22.209.90 Apr 18 16:57:46 volofritz ntpd[3354]: Listen normally on 4 tailscale0 100.119.52.34:123 Apr 18 16:57:46 volofritz ntpd[3354]: new interface(s) found: waking up resolver Apr 18 16:57:46 volofritz ntpd[3354]: Soliciting pool server 162.159.200.1 Apr 18 16:57:47 volofritz systemd[1]: apt-daily.service: Succeeded. Apr 18 16:57:47 volofritz systemd[1]: Started Daily apt download activities. Apr 18 16:57:47 volofritz systemd[1]: Starting Daily apt upgrade and clean activities... Apr 18 16:57:47 volofritz wireless.js[2826]: trying... Apr 18 16:57:47 volofritz sudo[3496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:47 volofritz sudo[3496]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:47 volofritz sudo[3496]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:47 volofritz nmbd[3088]: [2025/04/18 16:57:47.915992, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 18 16:57:47 volofritz kernel: nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead. Apr 18 16:57:47 volofritz systemd[1]: Started Samba NMB Daemon. Apr 18 16:57:47 volofritz nmbd[3088]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 18 16:57:47 volofritz systemd[1]: Starting Samba Winbind Daemon... Apr 18 16:57:47 volofritz ntpd[3354]: Soliciting pool server 162.159.200.123 Apr 18 16:57:47 volofritz ntpd[3354]: Soliciting pool server 5.249.144.95 Apr 18 16:57:47 volofritz ntpd[3354]: Soliciting pool server 195.231.84.187 Apr 18 16:57:48 volofritz winbindd[3500]: [2025/04/18 16:57:48.271714, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 18 16:57:48 volofritz winbindd[3500]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 18 16:57:48 volofritz winbindd[3500]: [2025/04/18 16:57:48.285440, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 18 16:57:48 volofritz winbindd[3500]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 18 16:57:48 volofritz systemd[1]: Started Samba Winbind Daemon. Apr 18 16:57:48 volofritz systemd[1]: Starting Samba SMB Daemon... Apr 18 16:57:48 volofritz wireless.js[2826]: trying... Apr 18 16:57:48 volofritz sudo[3507]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:48 volofritz sudo[3507]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:48 volofritz sudo[3507]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:48 volofritz smbd[3505]: [2025/04/18 16:57:48.848960, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 18 16:57:48 volofritz smbd[3505]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 18 16:57:48 volofritz systemd[1]: Started Samba SMB Daemon. Apr 18 16:57:48 volofritz systemd[1]: apt-daily-upgrade.service: Succeeded. Apr 18 16:57:48 volofritz systemd[1]: Started Daily apt upgrade and clean activities. Apr 18 16:57:48 volofritz ntpd[3354]: Soliciting pool server 212.45.144.88 Apr 18 16:57:48 volofritz ntpd[3354]: Soliciting pool server 31.14.133.122 Apr 18 16:57:48 volofritz ntpd[3354]: Soliciting pool server 85.199.214.99 Apr 18 16:57:49 volofritz wireless.js[2826]: trying... Apr 18 16:57:49 volofritz sudo[3546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:49 volofritz sudo[3546]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:49 volofritz sudo[3546]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:49 volofritz ntpd[3354]: Soliciting pool server 89.46.74.148 Apr 18 16:57:49 volofritz ntpd[3354]: Soliciting pool server 185.19.184.35 Apr 18 16:57:50 volofritz wireless.js[2826]: trying... Apr 18 16:57:50 volofritz sudo[3549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:50 volofritz sudo[3549]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:50 volofritz sudo[3549]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:50 volofritz ntpd[3354]: Soliciting pool server 2a00:6d41:200:2::12 Apr 18 16:57:50 volofritz ntpd[3354]: Soliciting pool server 93.94.88.51 Apr 18 16:57:51 volofritz wireless.js[2826]: trying... Apr 18 16:57:51 volofritz sudo[3552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:51 volofritz sudo[3552]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:51 volofritz sudo[3552]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:51 volofritz ntpd[3354]: Soliciting pool server 93.94.88.50 Apr 18 16:57:52 volofritz wireless.js[2826]: trying... Apr 18 16:57:52 volofritz sudo[3555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:52 volofritz sudo[3555]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:52 volofritz sudo[3555]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:54 volofritz wireless.js[2826]: trying... Apr 18 16:57:54 volofritz sudo[3558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:54 volofritz sudo[3558]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:54 volofritz sudo[3558]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:55 volofritz volumio-remote-updater[2861]: [2025-04-18 16:57:55] [info] asio async_connect error: system:111 (Connection refused) Apr 18 16:57:55 volofritz volumio-remote-updater[2861]: [2025-04-18 16:57:55] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 18 16:57:55 volofritz volumio-remote-updater[2861]: [2025-04-18 16:57:55] [error] handle_connect error: Underlying Transport Error Apr 18 16:57:55 volofritz wireless.js[2826]: trying... Apr 18 16:57:55 volofritz sudo[3563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:55 volofritz sudo[3563]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:55 volofritz sudo[3563]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:56 volofritz wireless.js[2826]: trying... Apr 18 16:57:56 volofritz sudo[3567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 18 16:57:56 volofritz sudo[3567]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:57:56 volofritz sudo[3567]: pam_unix(sudo:session): session closed for user root Apr 18 16:57:57 volofritz wireless.js[2826]: Overtime, starting plan B Apr 18 16:57:57 volofritz systemd[1]: Started Wireless Services. Apr 18 16:57:57 volofritz systemd[1]: Started Volumio Backend Module. Apr 18 16:57:57 volofritz systemd[1]: Started Volumio Cpu Tweaker. Apr 18 16:57:57 volofritz systemd[1]: Reached target Multi-User System. Apr 18 16:57:57 volofritz systemd[1]: Reached target Graphical Interface. Apr 18 16:57:57 volofritz systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 18 16:57:57 volofritz systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 18 16:57:57 volofritz systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 18 16:57:57 volofritz systemd[1]: Startup finished in 12.899s (kernel) + 31.399s (userspace) = 44.298s. Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: Setting RT Priority for mpd Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: Setting MPD Affinity Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: pid 3142's current affinity mask: f Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: pid 3142's new affinity mask: 3 Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 18 16:57:57 volofritz volumio-cpu-tweak[3573]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 18 16:57:57 volofritz systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 18 16:57:59 volofritz systemd[1]: systemd-fsckd.service: Succeeded. Apr 18 16:58:00 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:00 volofritz volumio[3572]: info: ----- Volumio3 ---- Apr 18 16:58:00 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:00 volofritz volumio[3572]: info: ----- System startup ---- Apr 18 16:58:00 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:01 volofritz volumio[3572]: info: MYVOLUMIO Environment detected Apr 18 16:58:01 volofritz volumio[3572]: info: Plugin folders cleanup Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning into folder /volumio/app/plugins/ Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category audio_interface Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category miscellanea Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category music_service Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category plugins.json Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category system_controller Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category user_interface Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning into folder /data/plugins/ Apr 18 16:58:01 volofritz volumio[3572]: info: Scanning category music_service Apr 18 16:58:01 volofritz volumio[3572]: info: Plugin folders cleanup completed Apr 18 16:58:01 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:01 volofritz volumio[3572]: info: ----- Core plugins startup ---- Apr 18 16:58:01 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:01 volofritz volumio[3572]: info: Loading plugins from folder /volumio/app/plugins/ Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin bluetooth to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin multiroom to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin upnp to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin metavolumio to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin cd_controller to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin raat to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 18 16:58:01 volofritz volumio[3572]: info: Loading plugins from folder /data/plugins/ Apr 18 16:58:01 volofritz volumio[3572]: info: Loading plugin "system"... Apr 18 16:58:01 volofritz volumio[3572]: info: Loading plugin "appearance"... Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "network"... Apr 18 16:58:03 volofritz volumio[3572]: info: Refreshing Cached IP Addresses Apr 18 16:58:03 volofritz sudo[3614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 18 16:58:03 volofritz sudo[3614]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:03 volofritz sudo[3616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 18 16:58:03 volofritz sudo[3616]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "services"... Apr 18 16:58:03 volofritz sudo[3614]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "alsa_controller"... Apr 18 16:58:03 volofritz sudo[3616]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:03 volofritz sudo[3626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 18 16:58:03 volofritz sudo[3626]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:03 volofritz kernel: wl_escan_set_scan: ioctl_ver=2 Apr 18 16:58:03 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "wizard"... Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "networkfs"... Apr 18 16:58:03 volofritz volumio[3572]: info: Starting Udev Watcher for removable devices Apr 18 16:58:03 volofritz volumio[3572]: info: Ignoring mount for partition: BOOT Apr 18 16:58:03 volofritz volumio[3572]: info: Ignoring mount for partition: volumio Apr 18 16:58:03 volofritz volumio[3572]: info: Ignoring mount for partition: volumio_data Apr 18 16:58:03 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "volumio_command_line_client"... Apr 18 16:58:03 volofritz volumio[3572]: info: Loading plugin "upnp"... Apr 18 16:58:03 volofritz volumio[3572]: info: [1744988283998] Starting Upmpd Daemon Apr 18 16:58:03 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 16:58:04 volofritz volumio[3572]: info: Loading plugin "my_music"... Apr 18 16:58:04 volofritz volumio[3572]: info: Loading plugin "mpd"... Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:04 volofritz volumio[3572]: info: Loading plugin "upnp_browser"... Apr 18 16:58:05 volofritz volumio[3572]: info: Loading plugin "bluetooth"... Apr 18 16:58:05 volofritz volumio-remote-updater[2861]: [2025-04-18 16:58:05] [connect] Successful connection Apr 18 16:58:05 volofritz volumio[3572]: info: [1744988285258] Starting BluetoothController Apr 18 16:58:05 volofritz volumio[3572]: info: Loading plugin "alarm-clock"... Apr 18 16:58:05 volofritz sudo[3626]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:05 volofritz volumio[3572]: info: Loading plugin "manifestui"... Apr 18 16:58:05 volofritz volumio[3572]: info: Loading plugin "metavolumio"... Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:06 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 8 Apr 18 16:58:07 volofritz kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04e37e000 drv_status 0x0 e_type 69 e_states 0 Apr 18 16:58:07 volofritz volumio[3572]: info: Loading plugin "airplay_emulation"... Apr 18 16:58:07 volofritz volumio[3572]: info: Starting Shairport Sync Apr 18 16:58:07 volofritz volumio[3572]: info: Loading plugin "cd_controller"... Apr 18 16:58:08 volofritz volumio[3572]: info: Loading plugin "last_100"... Apr 18 16:58:08 volofritz volumio[3572]: info: Plugin raat is not enabled Apr 18 16:58:08 volofritz volumio[3572]: info: Loading plugin "streaming_services"... Apr 18 16:58:09 volofritz tailscaled[2837]: portmapper: saw UPnP type WANIPConnection1 at http://192.168.1.1:1900/igd.xml; Wireless Router TL-WR940N (TP-LINK), method=single Apr 18 16:58:09 volofritz volumio[3572]: info: Starting Streaming Service Transparent Proxy Apr 18 16:58:09 volofritz volumio[3572]: info: Loading plugin "tidalconnect"... Apr 18 16:58:10 volofritz volumio[3572]: info: Loading plugin "webradio"... Apr 18 16:58:10 volofritz volumio[3572]: info: Loading plugin "i2s_dacs"... Apr 18 16:58:10 volofritz volumio[3572]: info: I2S DAC not set, start Auto-detection Apr 18 16:58:10 volofritz volumio[3572]: info: Loading plugin "volumiodiscovery"... Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** For more information see Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 16:58:10 volofritz volumio[3572]: *** WARNING *** For more information see Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** For more information see Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 16:58:10 volofritz node[3572]: *** WARNING *** For more information see Apr 18 16:58:10 volofritz volumio[3572]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 18 16:58:10 volofritz volumio[3572]: info: Discovery: Started advertising with name: Volofritz Apr 18 16:58:10 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 16:58:10 volofritz volumio[3572]: info: Loading plugin "spop"... Apr 18 16:58:11 volofritz volumio[3572]: STREAMING PROXY: Starting server on port 3245 Apr 18 16:58:11 volofritz volumio[3572]: Node JS runtime: 14 Apr 18 16:58:11 volofritz systemd[1]: systemd-hostnamed.service: Succeeded. Apr 18 16:58:12 volofritz volumio[3572]: info: Loading plugin "youtube2"... Apr 18 16:58:13 volofritz volumio[3572]: info: Plugin multiroom is not enabled Apr 18 16:58:13 volofritz volumio[3572]: info: Loading plugin "outputs"... Apr 18 16:58:13 volofritz volumio[3572]: info: Loading plugin "albumart"... Apr 18 16:58:13 volofritz volumio[3572]: info: Plugin example_plugin is not enabled Apr 18 16:58:13 volofritz volumio[3572]: info: Loading plugin "hi_res_audio"... Apr 18 16:58:14 volofritz volumio[3572]: Forking 3 albumart workers Apr 18 16:58:15 volofritz volumio[3572]: Starting albumart workers Apr 18 16:58:15 volofritz volumio[3572]: Starting albumart workers Apr 18 16:58:15 volofritz volumio[3572]: Starting albumart workers Apr 18 16:58:15 volofritz kernel: fb: mem_free_work, free memory: addr:800000 Apr 18 16:58:15 volofritz volumio[3572]: info: Applying required configuration parameters for plugin hi_res_audio Apr 18 16:58:15 volofritz volumio[3572]: info: Loading plugin "inputs"... Apr 18 16:58:16 volofritz systemd[1]: systemd-timedated.service: Succeeded. Apr 18 16:58:16 volofritz volumio[3572]: info: Loading plugin "qobuz"... Apr 18 16:58:18 volofritz volumio[3572]: info: Loading plugin "smart_inputs"... Apr 18 16:58:18 volofritz volumio[3572]: info: Loading plugin "tidal"... Apr 18 16:58:20 volofritz volumio-remote-updater[2861]: [2025-04-18 16:58:20] [connect] Successful connection Apr 18 16:58:20 volofritz volumio[3572]: info: Loading plugin "primo2rev2control"... Apr 18 16:58:20 volofritz volumio[3572]: info: Adding this device properties Apr 18 16:58:20 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Apr 18 16:58:20 volofritz volumio[3572]: info: Setting Additional Device Volumio Properties: [object Object] Apr 18 16:58:20 volofritz volumio[3572]: info: Loading plugin "updater_comm"... Apr 18 16:58:21 volofritz volumio[3572]: info: Loading plugin "cec_controller"... Apr 18 16:58:21 volofritz volumio[3572]: info: Applying required configuration parameters for plugin cec_controller Apr 18 16:58:21 volofritz volumio[3572]: info: Plugin mpdemulation is not enabled Apr 18 16:58:21 volofritz volumio[3572]: info: Loading plugin "rest_api"... Apr 18 16:58:21 volofritz volumio[3572]: info: Loading plugin "websocket"... Apr 18 16:58:21 volofritz volumio[3572]: info: Starting Socket.io Server version 2.3.0 Apr 18 16:58:21 volofritz volumio[3572]: info: Loading plugin "amazonmusic"... Apr 18 16:58:22 volofritz volumio[3572]: info: Loading i18n strings for locale en Apr 18 16:58:22 volofritz volumio[3572]: Updating browse sources language Apr 18 16:58:22 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::initPlayerControls Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: Express server listening on port 3000 Apr 18 16:58:23 volofritz volumio[3572]: [Metrics] WebUI: 23s 787.06ms Apr 18 16:58:23 volofritz volumio[3572]: info: CoreStateMachine::resetVolumioState Apr 18 16:58:23 volofritz volumio[3572]: info: CoreStateMachine::getcurrentVolume Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioRetrievevolume Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:23 volofritz sudo[3744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 18 16:58:23 volofritz sudo[3744]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:23 volofritz sudo[3744]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:23 volofritz volumio[3572]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 18 16:58:23 volofritz sudo[3746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 18 16:58:23 volofritz sudo[3746]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:23 volofritz volumio[3572]: info: Completed loading Core Plugins Apr 18 16:58:23 volofritz volumio[3572]: info: Preparing to generate the ALSA configuration file Apr 18 16:58:23 volofritz sudo[3746]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:23 volofritz volumio[3572]: ******** CLOUD ENDPOINTS *********** Apr 18 16:58:23 volofritz volumio[3572]: BROWSE: https://stg.vlmapi.io/v2/qobuz/browse Apr 18 16:58:23 volofritz volumio[3572]: EXPLODE: https://stg.vlmapi.io/v2/qobuz/explodeUri Apr 18 16:58:23 volofritz volumio[3572]: SEARCH: https://stg.vlmapi.io/v2/qobuz/search Apr 18 16:58:23 volofritz volumio[3572]: STREAMURI: https://stg.vlmapi.io/v2/qobuz/streamurl Apr 18 16:58:23 volofritz volumio[3572]: ADDTOFAV: https://stg.vlmapi.io/v2/qobuz/addToFavourites Apr 18 16:58:23 volofritz volumio[3572]: REMFROMFAV: https://stg.vlmapi.io/v2/qobuz/removeFromFavourites Apr 18 16:58:23 volofritz volumio[3572]: *********************************** Apr 18 16:58:23 volofritz volumio[3572]: ******** CLOUD ENDPOINTS *********** Apr 18 16:58:23 volofritz volumio[3572]: BROWSE: https://stg.vlmapi.io/v2/tidal/browse Apr 18 16:58:23 volofritz volumio[3572]: EXPLODE: https://stg.vlmapi.io/v2/tidal/explodeUri Apr 18 16:58:23 volofritz volumio[3572]: SEARCH: https://stg.vlmapi.io/v2/tidal/search Apr 18 16:58:23 volofritz volumio[3572]: STREAMURI: https://stg.vlmapi.io/v2/tidal/streamurl Apr 18 16:58:23 volofritz volumio[3572]: ADDTOFAV: https://stg.vlmapi.io/v2/tidal/addToFavourites Apr 18 16:58:23 volofritz volumio[3572]: REMFROMFAV: https://stg.vlmapi.io/v2/tidal/removeFromFavourites Apr 18 16:58:23 volofritz volumio[3572]: *********************************** Apr 18 16:58:23 volofritz volumio[3572]: info: Volumio Network Manager: Network status updated: 1 Apr 18 16:58:23 volofritz volumio[3572]: Unable to parse: Apr 18 16:58:23 volofritz volumio[3572]: Simple mixer control 'Audio hdmi-out mute',0 Apr 18 16:58:23 volofritz volumio[3572]: Capabilities: pswitch pswitch-joined Apr 18 16:58:23 volofritz volumio[3572]: Playback channels: Mono Apr 18 16:58:23 volofritz volumio[3572]: Mono: Playback [on] Apr 18 16:58:23 volofritz volumio[3572]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Apr 18 16:58:23 volofritz volumio[3572]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 18 16:58:23 volofritz volumio[3572]: verbose: New Socket.io Connection to 192.168.1.7 from 192.168.1.75 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 18 16:58:23 volofritz volumio[3572]: verbose: New Socket.io Connection to 192.168.1.7 from 192.168.1.75 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 18 16:58:23 volofritz volumio[3572]: verbose: New Socket.io Connection to 192.168.1.7 from 192.168.1.75 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 18 16:58:23 volofritz volumio-remote-updater[2861]: [2025-04-18 16:58:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744988300 101 Apr 18 16:58:23 volofritz volumio[3572]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 18 16:58:23 volofritz volumio[3572]: Unable to parse: Apr 18 16:58:23 volofritz volumio[3572]: Simple mixer control 'Audio hdmi-out mute',0 Apr 18 16:58:23 volofritz volumio[3572]: Capabilities: pswitch pswitch-joined Apr 18 16:58:23 volofritz volumio[3572]: Playback channels: Mono Apr 18 16:58:23 volofritz volumio[3572]: Mono: Playback [on] Apr 18 16:58:23 volofritz volumio[3572]: info: VolumeController:: Volume=undefined Mute =false Apr 18 16:58:23 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:23 volofritz volumio[3572]: info: CoreStateMachine::updateTrackBlock Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrackBlock Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioRetrievevolume Apr 18 16:58:23 volofritz volumio[3572]: info: Reloading queue from file Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetVisibleSources Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetQueue Apr 18 16:58:23 volofritz volumio[3572]: info: CoreStateMachine::getQueue Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getQueue Apr 18 16:58:23 volofritz volumio[3572]: info: Listing playlists Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 18 16:58:23 volofritz volumio[3572]: info: Received Get System Info Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 18 16:58:23 volofritz volumio[3572]: info: Discovery: Getting this device information Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:23 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:23 volofritz volumio[3572]: info: Asound.conf file unchanged, so no further update is needed Apr 18 16:58:23 volofritz volumio[3572]: info: Output device has changed, restarting MPD Apr 18 16:58:23 volofritz sudo[3769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 18 16:58:23 volofritz sudo[3769]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:23 volofritz volumio[3572]: info: Output device has changed, restarting Shairport Sync Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:23 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:23 volofritz sudo[3769]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:23 volofritz sudo[3774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 18 16:58:23 volofritz sudo[3774]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:23 volofritz systemd[1]: Stopping Music Player Daemon... Apr 18 16:58:23 volofritz volumio[3572]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 16:58:23 volofritz volumio[3572]: info: ___________ START PLUGINS ___________ Apr 18 16:58:23 volofritz volumio[3572]: info: ControllerMpd::onStart: Initializing MPD Apr 18 16:58:23 volofritz volumio[3572]: info: Creating MPD Configuration file Apr 18 16:58:24 volofritz sudo[3787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 16:58:24 volofritz sudo[3787]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:24 volofritz volumio[3572]: info: [1744988304079] CoreMusicLibrary::Adding element Media Servers Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:24 volofritz sudo[3787]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz sudo[3789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 18 16:58:24 volofritz sudo[3789]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 16:58:24 volofritz systemd[1]: mpd.service: Succeeded. Apr 18 16:58:24 volofritz systemd[1]: Stopped Music Player Daemon. Apr 18 16:58:24 volofritz volumio[3572]: info: Adding METAVOLUMIO REST API Endpoints Apr 18 16:58:24 volofritz volumio[3572]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 18 16:58:24 volofritz volumio[3572]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 18 16:58:24 volofritz volumio[3572]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 18 16:58:24 volofritz volumio[3572]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:24 volofritz systemd[1]: Starting Music Player Daemon... Apr 18 16:58:24 volofritz sudo[3793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volofritz Apr 18 16:58:24 volofritz sudo[3793]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz sudo[3793]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz volumio[3572]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:24 volofritz volumio[3572]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 16:58:24 volofritz volumio[3572]: info: Preparing CD Folders Apr 18 16:58:24 volofritz volumio[3572]: info: Adding CD REST API Endpoints Apr 18 16:58:24 volofritz volumio[3572]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 18 16:58:24 volofritz volumio[3572]: info: Starting UDEV Watcher for CD Apr 18 16:58:24 volofritz volumio[3572]: info: Detecting CD presence with UDEV Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 18 16:58:24 volofritz sudo[3794]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 18 16:58:24 volofritz sudo[3794]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz sudo[3794]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:24 volofritz volumio[3572]: info: [1744988304342] CoreMusicLibrary::Adding element Last_100 Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:24 volofritz volumio[3572]: info: Streaming services startup Apr 18 16:58:24 volofritz volumio[3572]: info: Starting Streaming Daemon Apr 18 16:58:24 volofritz sudo[3812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 18 16:58:24 volofritz sudo[3812]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz sudo[3812]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:24 volofritz volumio[3572]: info: [1744988304487] CoreMusicLibrary::Adding element Webradio Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 16:58:24 volofritz volumio[3572]: info: Initializing BBC Radios Apr 18 16:58:24 volofritz sudo[3821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 18 16:58:24 volofritz sudo[3821]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz sudo[3821]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:24 volofritz volumio[3572]: info: Creating Spotify config file Apr 18 16:58:24 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:24 volofritz volumio[3572]: error: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA Apr 18 16:58:24 volofritz volumio[3572]: error: log_level: trace Apr 18 16:58:24 volofritz volumio[3572]: device_name: "${device_name}" Apr 18 16:58:24 volofritz volumio[3572]: server: Apr 18 16:58:24 volofritz volumio[3572]: enabled: true Apr 18 16:58:24 volofritz volumio[3572]: port: 9879 Apr 18 16:58:24 volofritz volumio[3572]: audio_device: "volumio" Apr 18 16:58:24 volofritz volumio[3572]: device_type: "${device_type}" Apr 18 16:58:24 volofritz volumio[3572]: bitrate: ${bitrate_number} Apr 18 16:58:24 volofritz volumio[3572]: external_volume: ${external_volume} Apr 18 16:58:24 volofritz volumio[3572]: normalisation_pregain: ${normalisation_pregain} Apr 18 16:58:24 volofritz volumio[3572]: zeroconf_enabled: true Apr 18 16:58:24 volofritz volumio[3572]: disable_autoplay: ${disable_autoplay} Apr 18 16:58:24 volofritz volumio[3572]: error: Hi Res Audio Failed Login: Missing Login Data Apr 18 16:58:24 volofritz volumio[3572]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 18 16:58:24 volofritz volumio[3572]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 18 16:58:24 volofritz volumio[3572]: info: Initializing Serial Communication on port /dev/ttyS3 Apr 18 16:58:24 volofritz volumio[3572]: info: Touch Event Listener Process Starting Apr 18 16:58:24 volofritz kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Apr 18 16:58:24 volofritz kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Apr 18 16:58:24 volofritz kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Apr 18 16:58:24 volofritz volumio[3572]: info: Refreshing QOBUZ token Apr 18 16:58:24 volofritz sudo[3835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Apr 18 16:58:24 volofritz sudo[3835]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:24 volofritz volumio[3572]: info: Adding inputs REST Endpoints Apr 18 16:58:24 volofritz volumio[3572]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 18 16:58:24 volofritz volumio[3572]: info: Scanning Audio Inputs Apr 18 16:58:24 volofritz sudo[3835]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:24 volofritz volumio[3572]: info: Checking against Known Cards name Apr 18 16:58:24 volofritz volumio[3572]: info: Checking against Known Cards name Apr 18 16:58:24 volofritz volumio[3572]: info: Checking against Known Cards name Apr 18 16:58:24 volofritz volumio[3572]: info: Checking against Known Cards name Apr 18 16:58:24 volofritz volumio[3572]: info: Checking against Known Cards name Apr 18 16:58:24 volofritz volumio[3572]: info: Adding Server instance for streaming Apr 18 16:58:24 volofritz volumio[3572]: info: Refreshing TIDAL token Apr 18 16:58:25 volofritz sudo[3843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Apr 18 16:58:25 volofritz sudo[3843]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz sudo[3843]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz sudo[3846]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Apr 18 16:58:25 volofritz sudo[3846]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz sudo[3846]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz sudo[3849]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Apr 18 16:58:25 volofritz sudo[3849]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz sudo[3849]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz sudo[3852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Apr 18 16:58:25 volofritz sudo[3852]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz sudo[3852]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz volumio[3572]: info: MP1 Muting HDMI Output Apr 18 16:58:25 volofritz volumio[3572]: info: Starting CEC Event listener Apr 18 16:58:25 volofritz volumio[3572]: info: Volumio Calling Home Apr 18 16:58:25 volofritz volumio[3572]: info: CoreStateMachine::setRepeat false single undefined Apr 18 16:58:25 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:25 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:25 volofritz volumio[3572]: info: CoreStateMachine::setRandom true Apr 18 16:58:25 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:25 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:25 volofritz volumio[3572]: Unable to parse: Apr 18 16:58:25 volofritz volumio[3572]: Simple mixer control 'Audio hdmi-out mute',0 Apr 18 16:58:25 volofritz volumio[3572]: Capabilities: pswitch pswitch-joined Apr 18 16:58:25 volofritz volumio[3572]: Playback channels: Mono Apr 18 16:58:25 volofritz volumio[3572]: Mono: Playback [on] Apr 18 16:58:25 volofritz volumio[3572]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Apr 18 16:58:25 volofritz volumio[3572]: info: Serial port opened successfully Apr 18 16:58:25 volofritz volumio[3572]: info: Sending serial start messages Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: Reporting MCU Network Status: 1 Apr 18 16:58:25 volofritz volumio[3572]: info: Touch Event Listener Process Closed Apr 18 16:58:25 volofritz volumio[3572]: error: Cannot start Volumio Streaming Daemon Apr 18 16:58:25 volofritz volumio[3572]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 18 16:58:25 volofritz volumio[3572]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 18 16:58:25 volofritz volumio[3572]: info: Bluetooth name changed to Volofritz Apr 18 16:58:25 volofritz volumio[3572]: info: MPD Permissions set Apr 18 16:58:25 volofritz volumio[3572]: info: MPD Permissions set Apr 18 16:58:25 volofritz sudo[3863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 18 16:58:25 volofritz volumio[3572]: Unable to parse: Apr 18 16:58:25 volofritz volumio[3572]: Simple mixer control 'Audio hdmi-out mute',0 Apr 18 16:58:25 volofritz volumio[3572]: Capabilities: pswitch pswitch-joined Apr 18 16:58:25 volofritz volumio[3572]: Playback channels: Mono Apr 18 16:58:25 volofritz volumio[3572]: Mono: Playback [on] Apr 18 16:58:25 volofritz volumio[3572]: info: VolumeController:: Volume=undefined Mute =false Apr 18 16:58:25 volofritz sudo[3863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:25 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:25 volofritz volumio[3572]: info: Volumio called home Apr 18 16:58:25 volofritz volumio[3572]: info: Spotify config file written Apr 18 16:58:25 volofritz systemd[1]: Started UPnP Renderer front-end to MPD. Apr 18 16:58:25 volofritz volumio[3572]: info: Discovery: adding 6b6df1aa-2473-4717-8035-7f545b32832b Apr 18 16:58:25 volofritz volumio[3572]: info: Discovery: Found device Volofritz Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:25 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:25 volofritz sudo[3863]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz sudo[3867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 18 16:58:25 volofritz sudo[3867]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:25 volofritz systemd[1]: Started go-librespot Daemon. Apr 18 16:58:25 volofritz sudo[3867]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:25 volofritz volumio[3572]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 18 16:58:25 volofritz go-librespot[3869]: go-librespot daemon starting... Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:25 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: No need to fix Spotify hosts Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Apr 18 16:58:26 volofritz volumio[3572]: info: Setting Device Volume Override Apr 18 16:58:26 volofritz volumio[3572]: info: Applying Volume Override Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 18 16:58:26 volofritz volumio[3572]: info: Updating Volume Controller Parameters: Device: 0,0 Name: Analog Outputs Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 18 16:58:26 volofritz volumio[3572]: info: Enabling external Volume Control Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 16:58:26 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:26 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Apr 18 16:58:26 volofritz volumio[3572]: info: Setting Additional System Software info: Hardware Revision: 2.1 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Apr 18 16:58:26 volofritz volumio[3572]: info: Setting HW Firmware info: undefined Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Apr 18 16:58:26 volofritz volumio[3572]: info: Setting HW Version info: 2.1 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Apr 18 16:58:26 volofritz volumio[3572]: info: Setting Additional System Software info: Hardware Revision: 2.1, Firmware Version: 0.3.7 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Apr 18 16:58:26 volofritz volumio[3572]: info: Setting HW Firmware info: 0.3.7 Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Apr 18 16:58:26 volofritz volumio[3572]: info: Setting HW Version info: 2.1 Apr 18 16:58:26 volofritz volumio[3572]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 18 16:58:26 volofritz volumio[3572]: info: MCU Signalled Headphone Mode Disabled Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Apr 18 16:58:26 volofritz volumio[3572]: info: MCU Signalled Sleep Mode Disabled Apr 18 16:58:26 volofritz volumio[3572]: info: Enabling Advanced system settings configuration Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Apr 18 16:58:26 volofritz volumio[3572]: info: Additional UI Settings Added for plugin music_service/inputs Apr 18 16:58:26 volofritz volumio[3572]: info: MCU Signalled Auto Boot Mode On Power Active Apr 18 16:58:26 volofritz sudo[3895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Apr 18 16:58:26 volofritz sudo[3895]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:26 volofritz sudo[3895]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:26 volofritz mpd[3810]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 18 16:58:26 volofritz mpd[3810]: output: No 'audio_output' defined in config file Apr 18 16:58:26 volofritz kernel: aml_tdm_open Apr 18 16:58:26 volofritz kernel: Not init audio effects Apr 18 16:58:26 volofritz kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 18 16:58:26 volofritz kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 18 16:58:26 volofritz kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 18 16:58:26 volofritz kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 Apr 18 16:58:26 volofritz kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050fb5818, id(1), clksel(1) Apr 18 16:58:26 volofritz kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 18 16:58:26 volofritz kernel: dump_pcm_setting(ffffffc050fb5818) Apr 18 16:58:26 volofritz kernel: pcm_mode(1) Apr 18 16:58:26 volofritz kernel: sysclk(12288000) Apr 18 16:58:26 volofritz kernel: sysclk_bclk_ratio(4) Apr 18 16:58:26 volofritz kernel: bclk(3072000) Apr 18 16:58:26 volofritz kernel: bclk_lrclk_ratio(64) Apr 18 16:58:26 volofritz kernel: lrclk(48000) Apr 18 16:58:26 volofritz kernel: tx_mask(0x3) Apr 18 16:58:26 volofritz kernel: rx_mask(0x3) Apr 18 16:58:26 volofritz kernel: slots(2) Apr 18 16:58:26 volofritz kernel: slot_width(32) Apr 18 16:58:26 volofritz kernel: lane_mask_in(0x2) Apr 18 16:58:26 volofritz kernel: lane_mask_out(0x1) Apr 18 16:58:26 volofritz kernel: lane_oe_mask_in(0x0) Apr 18 16:58:26 volofritz kernel: lane_oe_mask_out(0x0) Apr 18 16:58:26 volofritz kernel: lane_lb_mask_in(0x0) Apr 18 16:58:26 volofritz kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 18 16:58:26 volofritz kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 18 16:58:26 volofritz kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 Apr 18 16:58:26 volofritz kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 18 16:58:26 volofritz kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 18 16:58:26 volofritz kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 18 16:58:26 volofritz kernel: aml_tdm_prepare(), reset fddr Apr 18 16:58:26 volofritz kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Apr 18 16:58:26 volofritz kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 Apr 18 16:58:26 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:26 volofritz kernel: tdm playback mute: 0, lane_cnt = 8 Apr 18 16:58:26 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:26 volofritz kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 18 16:58:26 volofritz kernel: tdm playback mute: 1, lane_cnt = 8 Apr 18 16:58:26 volofritz mpd[3810]: output: Successfully detected a sndio audio device Apr 18 16:58:26 volofritz mpd[3810]: zeroconf: No global port, disabling zeroconf Apr 18 16:58:26 volofritz kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 18 16:58:26 volofritz systemd[1]: Started Music Player Daemon. Apr 18 16:58:26 volofritz sudo[3789]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:26 volofritz sudo[3774]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:26 volofritz volumio[3572]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 18 16:58:26 volofritz volumio[3572]: info: Upmpdcli Daemon Started Apr 18 16:58:26 volofritz volumio[3572]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Apr 18 16:58:26 volofritz volumio[3572]: info: Access Token successfully retrieved Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:26 volofritz volumio[3572]: info: [1744988306829] CoreMusicLibrary::Adding element QOBUZ Apr 18 16:58:26 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:26 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:26 volofritz volumio[3572]: info: Stopping AccessToken refresher cron for QOBUZ Apr 18 16:58:26 volofritz volumio[3572]: info: AccessToken refresher cron started for QOBUZ Apr 18 16:58:26 volofritz volumio[3572]: info: Adding QOBUZ REST API Endpoints Apr 18 16:58:26 volofritz volumio[3572]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Apr 18 16:58:26 volofritz volumio[3572]: info: Access Token successfully retrieved Apr 18 16:58:27 volofritz sudo[3939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Apr 18 16:58:27 volofritz sudo[3939]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz sudo[3939]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz sudo[3944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 18 16:58:27 volofritz sudo[3944]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz systemd[1]: Started Volumio Bluetooth Module. Apr 18 16:58:27 volofritz sudo[3944]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz sudo[3948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Apr 18 16:58:27 volofritz sudo[3948]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz volumiobt[3946]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Apr 18 16:58:27 volofritz sudo[3948]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz volumio[3572]: info: Amazon Music: access token refresher cron started Apr 18 16:58:27 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:27 volofritz volumio[3572]: info: [1744988307403] CoreMusicLibrary::Adding element Amazon Music Apr 18 16:58:27 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:27 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:27 volofritz volumio[3572]: Cannot find translation for source Amazon Music Apr 18 16:58:27 volofritz volumio[3572]: info: Starting Shairport Sync Apr 18 16:58:27 volofritz volumio[3572]: info: Starting Shairport Sync Apr 18 16:58:27 volofritz sudo[3955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 16:58:27 volofritz sudo[3955]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz volumio[3572]: info: Starting Shairport Sync Apr 18 16:58:27 volofritz sudo[3958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 16:58:27 volofritz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 16:58:27 volofritz sudo[3958]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz systemd[1]: shairport-sync.service: Succeeded. Apr 18 16:58:27 volofritz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz volumio[3572]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 16:58:27 volofritz volumio[3572]: SPOTIFY: BQD0B_hc6mjwmYe3wg9PZ4wgO9nkVXe81aKEa0_lxr14XgVvsjb_hgEMhKJGHrkoEdkGFjfELKz8kCz_aSuEHvTK4WKfaY04c1RdA1cStEw-vbNJJwe0Bn9DuqJsxBR2ROivr5u5s1Y3UVx0ZDi_Q-1pdXJhaAuaQKDgRP3Uejzs0bpni6-TMWRDC7g9AmWPBzQGu3WcqxKeLKh2xIddW-vuIaZQI2epYZGbdIrDxxd6Ib369G-MnSNaJN3rzVjcjsSWB2pguMJoNHk3N_eeaZTRyrBjhZSNbHirUJIlnEUID1NGK-4eHAwNQbhjnFAbAM9OmNlhrTWu5FAMEl8 Apr 18 16:58:27 volofritz volumio[3572]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 16:58:27 volofritz sudo[3955]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz volumio[3572]: info: New Spotify access token = BQD0B_hc6mjwmYe3wg9PZ4wgO9nkVXe81aKEa0_lxr14XgVvsjb_hgEMhKJGHrkoEdkGFjfELKz8kCz_aSuEHvTK4WKfaY04c1RdA1cStEw-vbNJJwe0Bn9DuqJsxBR2ROivr5u5s1Y3UVx0ZDi_Q-1pdXJhaAuaQKDgRP3Uejzs0bpni6-TMWRDC7g9AmWPBzQGu3WcqxKeLKh2xIddW-vuIaZQI2epYZGbdIrDxxd6Ib369G-MnSNaJN3rzVjcjsSWB2pguMJoNHk3N_eeaZTRyrBjhZSNbHirUJIlnEUID1NGK-4eHAwNQbhjnFAbAM9OmNlhrTWu5FAMEl8 Apr 18 16:58:27 volofritz volumio[3572]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 18 16:58:27 volofritz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 16:58:27 volofritz systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 18 16:58:27 volofritz systemd[1]: shairport-sync.service: Succeeded. Apr 18 16:58:27 volofritz sudo[3961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 16:58:27 volofritz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz sudo[3961]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:27 volofritz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz sudo[3958]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 16:58:27 volofritz systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 18 16:58:27 volofritz systemd[1]: shairport-sync.service: Succeeded. Apr 18 16:58:27 volofritz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 16:58:27 volofritz sudo[3961]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:27 volofritz volumio[3572]: error: MPD error: The expression evaluated to a falsy value: Apr 18 16:58:27 volofritz volumio[3572]: assert.ok(self.idling) Apr 18 16:58:27 volofritz volumio[3572]: error: The expression evaluated to a falsy value: Apr 18 16:58:27 volofritz volumio[3572]: assert.ok(self.idling) Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:28 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:28 volofritz volumio[3572]: info: Volumio BT Module successfully started Apr 18 16:58:28 volofritz volumio[3572]: info: MPD running with PID3810 Apr 18 16:58:28 volofritz volumio[3572]: ,establishing connection Apr 18 16:58:28 volofritz volumio[3572]: info: Adding Advanced Audio Settings via Serial API Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Apr 18 16:58:28 volofritz volumio[3572]: info: Additional UI Settings Added for plugin music_service/inputs Apr 18 16:58:28 volofritz volumio[3572]: info: Adding Inputs via Serial API Apr 18 16:58:28 volofritz volumio[3572]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Apr 18 16:58:28 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:28 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:28 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:28 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:28 volofritz volumio[3572]: error: updateQueue error: null Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:28 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:28 volofritz volumio[3572]: info: Shairport-Sync Started Apr 18 16:58:28 volofritz volumio[3572]: Error adding Membership: Error: addMembership EINVAL Apr 18 16:58:28 volofritz volumio[3572]: info: Shairport-Sync Started Apr 18 16:58:28 volofritz volumio[3572]: info: Shairport-Sync Started Apr 18 16:58:28 volofritz volumio[3572]: info: TidalConnect service stoped! Apr 18 16:58:28 volofritz volumio[3572]: info: Initializing I2S Bus Apr 18 16:58:28 volofritz volumio[3572]: info: Successfully retrieved User Session From TIDAL Apr 18 16:58:28 volofritz sudo[3980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Apr 18 16:58:28 volofritz sudo[3980]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:28 volofritz volumiobt[3946]: pulseaudio: no process found Apr 18 16:58:28 volofritz sudo[3980]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:28 volofritz volumio[3572]: error: updateQueue error: null Apr 18 16:58:28 volofritz dbus-daemon[2841]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.17' (uid=1000 pid=3995 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Apr 18 16:58:28 volofritz systemd[1]: Starting RealtimeKit Scheduling Policy Service... Apr 18 16:58:28 volofritz kernel: IPVS: Creating netns size=1928 id=3 Apr 18 16:58:28 volofritz volumio[3866]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 18 16:58:28 volofritz dbus-daemon[2841]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Apr 18 16:58:28 volofritz systemd[1]: Started RealtimeKit Scheduling Policy Service. Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Successfully called chroot. Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Successfully dropped privileges. Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Successfully limited resources. Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Running. Apr 18 16:58:28 volofritz dbus-daemon[2841]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.18' (uid=0 pid=4001 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Watchdog thread running. Apr 18 16:58:28 volofritz rtkit-daemon[4001]: Canary thread running. Apr 18 16:58:28 volofritz volumio[3572]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 18 16:58:28 volofritz systemd[1]: Starting Authorization Manager... Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::servicePushState Apr 18 16:58:28 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:28 volofritz volumio[3572]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received inputs Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::volumiosetSourceActiveno-source Apr 18 16:58:28 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:28 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:28 volofritz volumio[3572]: Cannot find translation for source Amazon Music Apr 18 16:58:28 volofritz volumio[3572]: info: MCU Signalled Playback Inactive Apr 18 16:58:28 volofritz volumio[3572]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 18 16:58:28 volofritz volumio[3572]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 18 16:58:28 volofritz volumio[3572]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 18 16:58:28 volofritz polkitd[4004]: started daemon version 0.105 using authority implementation `local' version `0.105' Apr 18 16:58:28 volofritz dbus-daemon[2841]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Apr 18 16:58:28 volofritz systemd[1]: Started Authorization Manager. Apr 18 16:58:28 volofritz sudo[4011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 18 16:58:28 volofritz sudo[4011]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 16:58:28 volofritz kernel: aml_tdm_open Apr 18 16:58:28 volofritz kernel: Not init audio effects Apr 18 16:58:28 volofritz systemd[1]: Started Volumio Tidal Connect Service. Apr 18 16:58:28 volofritz kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 18 16:58:28 volofritz sudo[4011]: pam_unix(sudo:session): session closed for user root Apr 18 16:58:28 volofritz kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 18 16:58:28 volofritz kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050fb5818, id(1), clksel(1) Apr 18 16:58:28 volofritz kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 18 16:58:28 volofritz kernel: dump_pcm_setting(ffffffc050fb5818) Apr 18 16:58:28 volofritz kernel: pcm_mode(1) Apr 18 16:58:28 volofritz kernel: sysclk(11289600) Apr 18 16:58:28 volofritz kernel: sysclk_bclk_ratio(4) Apr 18 16:58:28 volofritz kernel: bclk(2822400) Apr 18 16:58:28 volofritz kernel: bclk_lrclk_ratio(64) Apr 18 16:58:28 volofritz kernel: lrclk(44100) Apr 18 16:58:28 volofritz kernel: tx_mask(0x3) Apr 18 16:58:28 volofritz kernel: rx_mask(0x3) Apr 18 16:58:28 volofritz kernel: slots(2) Apr 18 16:58:28 volofritz kernel: slot_width(32) Apr 18 16:58:28 volofritz kernel: lane_mask_in(0x2) Apr 18 16:58:28 volofritz kernel: lane_mask_out(0x1) Apr 18 16:58:28 volofritz kernel: lane_oe_mask_in(0x0) Apr 18 16:58:28 volofritz kernel: lane_oe_mask_out(0x0) Apr 18 16:58:28 volofritz kernel: lane_lb_mask_in(0x0) Apr 18 16:58:28 volofritz kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 18 16:58:28 volofritz kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 18 16:58:28 volofritz kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 18 16:58:28 volofritz kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 18 16:58:28 volofritz kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 18 16:58:28 volofritz kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 18 16:58:28 volofritz kernel: aml_tdm_prepare(), reset fddr Apr 18 16:58:28 volofritz kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Apr 18 16:58:28 volofritz kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 18 16:58:28 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:28 volofritz kernel: tdm playback mute: 0, lane_cnt = 8 Apr 18 16:58:28 volofritz kernel: asoc-aml-card auge_sound: tdm playback enable Apr 18 16:58:28 volofritz kernel: spdif_a is set to enable Apr 18 16:58:29 volofritz volumio[3572]: SPOTIFY: User informations: {"country":"IT","display_name":"Gianluca Altomani","email":"altomanigianluca@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/11145089019"},"followers":{"href":null,"total":16},"href":"https://api.spotify.com/v1/users/11145089019","id":"11145089019","images":[{"height":300,"url":"https://scontent-lhr6-2.xx.fbcdn.net/v/t39.30808-1/246423769_2009988032485776_7475596875111725155_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=100&ccb=1-7&_nc_sid=79bf43&_nc_ohc=QhWwYTocn1IQ7kNvwH_mM8k&_nc_oc=Adl8Ex89gFXvKsFxoe-JT9Yox4LFNDRDY_I3CL3nRIf454u3DYL7_lLEuNIEeZELkapSl2W-Q1e_3u5fy9oKhBdF&_nc_zt=24&_nc_ht=scontent-lhr6-2.xx&edm=AP4hL3IEAAAA&_nc_gid=Ru6KUk18I8tTs9W8V6PtTg&oh=00_AfFnG_N671-FQck7a7bylINgM85sMGdUXaBPH3QT7s7mRw&oe=6807C737","width":300},{"height":64,"url":"https://scontent-lhr6-2.xx.fbcdn.net/v/t39.30808-1/246423769_2009988032485776_7475596875111725155_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=100&ccb=1-7&_nc_sid=fe756c&_nc_ohc=QhWwYTocn1IQ7kNvwH_mM8k&_nc_oc=Adl8Ex89gFXvKsFxoe-JT9Yox4LFNDRDY_I3CL3nRIf454u3DYL7_lLEuNIEeZELkapSl2W-Q1e_3u5fy9oKhBdF&_nc_zt=24&_nc_ht=scontent-lhr6-2.xx&edm=AP4hL3IEAAAA&_nc_gid=Ru6KUk18I8tTs9W8V6PtTg&oh=00_AfFN-oK7D54NKg9Pos1OMLpsZXsgdKt9Cj7kI-F-wkDPmg&oe=6807C737","width":64}],"product":"premium","type":"user","uri":"spotify:user:11145089019"} Apr 18 16:58:29 volofritz volumio[3572]: info: Spotify Successfully logged in Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:29 volofritz volumio[3572]: info: [1744988309047] CoreMusicLibrary::Adding element Spotify Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source Amazon Music Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source Spotify Apr 18 16:58:29 volofritz volumio[3572]: info: Successfully retrieved User Subscription From TIDAL Apr 18 16:58:29 volofritz volumio[3572]: info: Adding TIDAL to Browse Sources Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:29 volofritz volumio[3572]: info: [1744988309122] CoreMusicLibrary::Adding element TIDAL Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source Amazon Music Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source Spotify Apr 18 16:58:29 volofritz volumio[3572]: Cannot find translation for source TIDAL Apr 18 16:58:29 volofritz volumio[3572]: info: Stopping AccessToken refresher cron Apr 18 16:58:29 volofritz volumio[3572]: info: AccessToken refresher cron started Apr 18 16:58:29 volofritz volumio[3572]: info: Adding TIDAL REST API Endpoints Apr 18 16:58:29 volofritz volumio[3572]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Apr 18 16:58:29 volofritz pulseaudio[3995]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Apr 18 16:58:29 volofritz pulseaudio[3995]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Apr 18 16:58:29 volofritz pulseaudio[3995]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Apr 18 16:58:29 volofritz bluetoothd[3261]: Endpoint registered: sender=:1.38 path=/MediaEndpoint/A2DPSource Apr 18 16:58:29 volofritz volumio[3572]: info: Executing endpoint tc_getconfig Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 18 16:58:29 volofritz volumiobt[3946]: Applying permissions Apr 18 16:58:29 volofritz volumiobt[3946]: Setting BT discoverable and pairable Apr 18 16:58:29 volofritz bluetoothd[3261]: Endpoint registered: sender=:1.38 path=/MediaEndpoint/A2DPSink Apr 18 16:58:29 volofritz vtcs[4021]: CERT PATH: /tmp/Qa8CBdgsEX3qA3DHmMriu31MobiNoKpmddcuyAbof3AQ4f8AXeVYGiHhE08jq0aHJ577g2K3m72wG3o9XS4vuQ4tSHYgUjuuOUiI Apr 18 16:58:29 volofritz vtcs[4021]: STARTING TidalConnect services, version: 1.5.0.45 Apr 18 16:58:29 volofritz volumiobt[3946]: Agent registered Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# -e power on Apr 18 16:58:29 volofritz volumiobt[3946]: Invalid command in menu main: -e Apr 18 16:58:29 volofritz volumiobt[3946]: Apr 18 16:58:29 volofritz volumiobt[3946]: Use "help" for a list of available commands in a menu. Apr 18 16:58:29 volofritz volumiobt[3946]: Use "menu " if you want to enter any submenu. Apr 18 16:58:29 volofritz volumiobt[3946]: Use "back" if you want to return to menu main. Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# agent on Apr 18 16:58:29 volofritz volumiobt[3946]: Agent is already registered Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# discoverable on Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# pairable on Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# agent NoInputNoOutput Apr 18 16:58:29 volofritz volumiobt[3946]: Agent is already registered Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# default-agent Apr 18 16:58:29 volofritz volumiobt[3946]: [bluetooth]# quit Apr 18 16:58:29 volofritz volumiobt[3946]: [59B blob data] Apr 18 16:58:29 volofritz volumio[3572]: info: go-librespot daemon successfully initialized Apr 18 16:58:29 volofritz vtcs[4021]: STARTED TidalConnect services. Apr 18 16:58:29 volofritz volumio[3572]: info: Executing endpoint tc_connect Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 18 16:58:29 volofritz volumio[3572]: info: Connecting to TidalConnect Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::servicePushState Apr 18 16:58:29 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:29 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:29 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:29 volofritz volumio[3572]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::servicePushState Apr 18 16:58:29 volofritz volumio[3572]: info: CoreStateMachine::pushState Apr 18 16:58:29 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:29 volofritz volumio[3572]: info: CoreCommandRouter::volumioPushState Apr 18 16:58:29 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:29 volofritz volumio[3572]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 18 16:58:30 volofritz kernel: asoc-aml-card auge_sound: tdm playback stop Apr 18 16:58:30 volofritz kernel: spdif_a is set to disable Apr 18 16:58:30 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:30 volofritz kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 18 16:58:30 volofritz kernel: tdm playback mute: 1, lane_cnt = 8 Apr 18 16:58:30 volofritz kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 18 16:58:30 volofritz volumio[3572]: info: Successfully initialized Primo I2S Bus Apr 18 16:58:30 volofritz volumio[3572]: PlayerError: Failed to extract signature decipher algorithm Apr 18 16:58:30 volofritz volumio[3572]: at Function.extractSigSourceCode (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:21896:20) Apr 18 16:58:30 volofritz volumio[3572]: at Function. (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:21789:27) Apr 18 16:58:30 volofritz volumio[3572]: at Generator.next () Apr 18 16:58:30 volofritz volumio[3572]: at fulfilled (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:215:30) Apr 18 16:58:30 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:30 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:30 volofritz volumio[3572]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 18 16:58:30 volofritz volumio[3572]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 16:58:30 volofritz volumio[3572]: info: [1744988310399] CoreMusicLibrary::Adding element YouTube2 Apr 18 16:58:30 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 16:58:30 volofritz volumio[3572]: Cannot find translation for source QOBUZ Apr 18 16:58:30 volofritz volumio[3572]: Cannot find translation for source Amazon Music Apr 18 16:58:30 volofritz volumio[3572]: Cannot find translation for source Spotify Apr 18 16:58:30 volofritz volumio[3572]: Cannot find translation for source TIDAL Apr 18 16:58:30 volofritz volumio[3572]: Cannot find translation for source YouTube2 Apr 18 16:58:30 volofritz volumio[3572]: error: [youtube2] Error in ConfigModel.#fetchAccountMenu(): Request to https://www.youtube.com/youtubei/vnull/account/account_menu?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Error: Request to https://www.youtube.com/youtubei/vnull/account/account_menu?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Apr 18 16:58:30 volofritz volumio[3572]: at HTTPClient. (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:22010:13) Apr 18 16:58:30 volofritz volumio[3572]: at Generator.next () Apr 18 16:58:30 volofritz volumio[3572]: at fulfilled (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:215:30) Apr 18 16:58:30 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:30 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:30 volofritz volumio[3572]: (node:3572) UnhandledPromiseRejectionWarning: TypeError: Cannot convert undefined or null to object Apr 18 16:58:30 volofritz volumio[3572]: at Function.entries () Apr 18 16:58:30 volofritz volumio[3572]: at findInObject (/data/plugins/music_service/youtube2/dist/lib/util/index.js:27:43) Apr 18 16:58:30 volofritz volumio[3572]: at ConfigModel.getI18nOptions (/data/plugins/music_service/youtube2/dist/lib/model/ConfigModel.js:84:54) Apr 18 16:58:30 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:30 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:30 volofritz volumio[3572]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 18 16:58:30 volofritz volumio[3572]: (node:3572) 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: 1) Apr 18 16:58:30 volofritz volumio[3572]: (node:3572) [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. Apr 18 16:58:30 volofritz volumio[3866]: .......................++++ Apr 18 16:58:31 volofritz volumio[3572]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 18 16:58:31 volofritz volumio[3572]: error: [youtube2] Error in ConfigModel.#fetchAccountMenu(): Request to https://www.youtube.com/youtubei/vnull/account/account_menu?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Error: Request to https://www.youtube.com/youtubei/vnull/account/account_menu?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Apr 18 16:58:31 volofritz volumio[3572]: at HTTPClient. (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:22010:13) Apr 18 16:58:31 volofritz volumio[3572]: at Generator.next () Apr 18 16:58:31 volofritz volumio[3572]: at fulfilled (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:215:30) Apr 18 16:58:31 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:31 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:31 volofritz volumio[3572]: (node:3572) UnhandledPromiseRejectionWarning: TypeError: Cannot convert undefined or null to object Apr 18 16:58:31 volofritz volumio[3572]: at Function.entries () Apr 18 16:58:31 volofritz volumio[3572]: at findInObject (/data/plugins/music_service/youtube2/dist/lib/util/index.js:27:43) Apr 18 16:58:31 volofritz volumio[3572]: at ConfigModel.getI18nOptions (/data/plugins/music_service/youtube2/dist/lib/model/ConfigModel.js:84:54) Apr 18 16:58:31 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:31 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:31 volofritz volumio[3572]: (node:3572) 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) Apr 18 16:58:31 volofritz tailscaled[2837]: logtail: upload succeeded after 1 failures and 1m0s Apr 18 16:58:31 volofritz volumio[3572]: info: TidalConnect service started! Apr 18 16:58:32 volofritz volumio[3572]: info: Completed starting Core Plugins Apr 18 16:58:32 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:32 volofritz volumio[3572]: info: ----- MyVolumio plugins startup ---- Apr 18 16:58:32 volofritz volumio[3572]: info: ------------------------------------------- Apr 18 16:58:32 volofritz volumio[3572]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 18 16:58:32 volofritz mpd[3810]: exception: No database Apr 18 16:58:32 volofritz mpd[3810]: exception: No database Apr 18 16:58:32 volofritz volumio[3572]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database Apr 18 16:58:32 volofritz volumio[3572]: info: Initializing connection to go-librespot Websocket Apr 18 16:58:32 volofritz volumio[3572]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 18 16:58:35 volofritz tailscaled[2837]: portmapper: saw UPnP type WANIPConnection1 at http://192.168.1.1:1900/igd.xml; Wireless Router TL-WR940N (TP-LINK), method=single Apr 18 16:58:35 volofritz volumio[3572]: info: Checking for updated MCU Firmware Apr 18 16:58:35 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 16:58:35 volofritz volumio[3572]: info: Firware on device is on latest version, no need to update Apr 18 16:58:35 volofritz volumio[3572]: info: Initializing connection to go-librespot Websocket Apr 18 16:58:35 volofritz volumio[3572]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=info msg="running go-librespot dev" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="app state loaded" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02: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]" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02: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]" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02: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]" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=info msg="zeroconf server listening on port 34879" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="obtained new client token: AAAXfVfRpXGcOh5MCVUB2casEAmYLA5J5HHUcQy1U7RmhHoEEz7ShFwTsKvP0UL/ZrXas1uJFV4IIffhRYzP7trKOFgwTyr2oPM5D/6Om5Uv4spHLcSnWkNZAC2mIRPrbH7qptvzUYhFzFrjMGqW8SijembTWxHneVTAoLevyE1YiDgbvymvguTNO0SXzr8y5x8jjyAczy/QEY/429jCeRRZn0/1h6m6OQqMfqKCov4=" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="completed keyexchange" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="completed challenge" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=info msg="authenticated AP as 11145089019" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=info msg="authenticated Login5 as 11145089019" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="initializing zeroconf session, username: 11145089019" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="dealer connection opened" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=trace msg="starting accesspoint recv loop" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=trace msg="starting dealer recv loop" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=trace msg="received accesspoint ping" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 18 16:58:36 volofritz go-librespot[3869]: time="2025-04-18T16:58:36+02:00" level=debug msg="received connection id: MDI3MGQ5YTYtZGEzNC00MGVmLWExZTAtZmU3NDFlNTI4OTQzK2RlYWxlcit0Y3A6Ly8wYWNhNThhNi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArODJENjMyMjg5RjFGMjVBQkE5MTkxMTdFNDI4QkNCRjIwQUE3NzEyRDY2RDBCQjZDQzc5MTg2QTE4MUY3RjI4Nw==" Apr 18 16:58:37 volofritz go-librespot[3869]: time="2025-04-18T16:58:37+02:00" level=trace msg="received accesspoint pong ack" Apr 18 16:58:37 volofritz go-librespot[3869]: time="2025-04-18T16:58:37+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 18 16:58:38 volofritz go-librespot[3869]: time="2025-04-18T16:58:38+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 18 16:58:38 volofritz go-librespot[3869]: time="2025-04-18T16:58:38+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Apr 18 16:58:38 volofritz go-librespot[3869]: time="2025-04-18T16:58:38+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 18 16:58:38 volofritz go-librespot[3869]: time="2025-04-18T16:58:38+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3167" Apr 18 16:58:38 volofritz volumio[3572]: info: Initializing connection to go-librespot Websocket Apr 18 16:58:38 volofritz go-librespot[3869]: time="2025-04-18T16:58:38+02:00" level=debug msg="new websocket client" Apr 18 16:58:38 volofritz volumio[3572]: info: Connection to go-librespot Websocket established Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="handling transfer player command from dfa3b1b7f49fec306b3aa3c6b0e00a6256c12adc" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:7rB6d832sQEggLB5xhLybp" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=trace msg="fetched new page 0 with 63 items (list: 63)" uri="spotify:playlist:7rB6d832sQEggLB5xhLybp" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="shuffled context with seed 13310385343809665215 (len: 63, keep: 5)" uri="spotify:playlist:7rB6d832sQEggLB5xhLybp" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="loading track (paused: false, position: 2016ms)" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=trace msg="emitting websocket event: will_play" Apr 18 16:58:40 volofritz volumio[3572]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0DBTrH6kBbF8CzNVcu5MQR","play_origin":"playlist"}} Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 18 16:58:40 volofritz volumio[3572]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="selected format OGG_VORBIS_320 (7f3905210bc8fbf57978dc322dabfc9259a586a4)" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="requested aes key for file 7f3905210bc8fbf57978dc322dabfc9259a586a4, gid: 0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3194" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2042" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="fetched first chunk of 14, total size is 7012560 bytes" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=trace msg="seek to 2016ms (diff: 76ms, samples: 88905, bytes: 76002)" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="created new output device" Apr 18 16:58:40 volofritz kernel: aml_tdm_open Apr 18 16:58:40 volofritz kernel: Not init audio effects Apr 18 16:58:40 volofritz kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 18 16:58:40 volofritz kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 18 16:58:40 volofritz kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 18 16:58:40 volofritz kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 18 16:58:40 volofritz kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050fb5818, id(1), clksel(1) Apr 18 16:58:40 volofritz kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 18 16:58:40 volofritz kernel: dump_pcm_setting(ffffffc050fb5818) Apr 18 16:58:40 volofritz kernel: pcm_mode(1) Apr 18 16:58:40 volofritz kernel: sysclk(11289600) Apr 18 16:58:40 volofritz kernel: sysclk_bclk_ratio(4) Apr 18 16:58:40 volofritz kernel: bclk(2822400) Apr 18 16:58:40 volofritz kernel: bclk_lrclk_ratio(64) Apr 18 16:58:40 volofritz kernel: lrclk(44100) Apr 18 16:58:40 volofritz kernel: tx_mask(0x3) Apr 18 16:58:40 volofritz kernel: rx_mask(0x3) Apr 18 16:58:40 volofritz kernel: slots(2) Apr 18 16:58:40 volofritz kernel: slot_width(32) Apr 18 16:58:40 volofritz kernel: lane_mask_in(0x2) Apr 18 16:58:40 volofritz kernel: lane_mask_out(0x1) Apr 18 16:58:40 volofritz kernel: lane_oe_mask_in(0x0) Apr 18 16:58:40 volofritz kernel: lane_oe_mask_out(0x0) Apr 18 16:58:40 volofritz kernel: lane_lb_mask_in(0x0) Apr 18 16:58:40 volofritz kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 18 16:58:40 volofritz kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 18 16:58:40 volofritz kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 18 16:58:40 volofritz kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 18 16:58:40 volofritz kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 18 16:58:40 volofritz kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 18 16:58:40 volofritz kernel: aml_tdm_prepare(), reset fddr Apr 18 16:58:40 volofritz kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 18 16:58:40 volofritz kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 18 16:58:40 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:40 volofritz kernel: tdm playback mute: 0, lane_cnt = 8 Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Apr 18 16:58:40 volofritz go-librespot[3869]: time="2025-04-18T16:58:40+02:00" level=info msg="loaded track \"Pong Dance\" (paused: false, position: 2016ms, duration: 157500ms, prefetched: false)" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:40 volofritz kernel: aml_tdm_prepare(), reset fddr Apr 18 16:58:40 volofritz kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 18 16:58:40 volofritz kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 18 16:58:40 volofritz kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 18 16:58:40 volofritz kernel: tdm playback mute: 0, lane_cnt = 8 Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 18 16:58:41 volofritz kernel: asoc-aml-card auge_sound: tdm playback enable Apr 18 16:58:41 volofritz kernel: spdif_a is set to enable Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=trace msg="scheduling prefetch in 125s" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=trace msg="emitting websocket event: metadata" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=trace msg="emitting websocket event: active" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="sending successful reply for dealer request" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=trace msg="emitting websocket event: playing" Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 18 16:58:41 volofritz go-librespot[3869]: time="2025-04-18T16:58:41+02:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:0DBTrH6kBbF8CzNVcu5MQR" Apr 18 16:58:42 volofritz volumio[3572]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 18 16:58:42 volofritz volumio[3572]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 18 16:58:42 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:42 volofritz volumio[3572]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 16:58:42 volofritz volumio[3572]: info: Starting MyVolumio Remote Streaming Endpoints Apr 18 16:58:42 volofritz volumio[3572]: info: MyVolumio login type: Token Apr 18 16:58:42 volofritz volumio[3572]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 18 16:58:42 volofritz volumio[3572]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Apr 18 16:58:42 volofritz volumio[3572]: info: Getting Spotify volume Apr 18 16:58:42 volofritz volumio[3572]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0DBTrH6kBbF8CzNVcu5MQR","name":"Pong Dance","artist_names":["Vigiland"],"album_name":"Pong Dance","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023771989c097adbe1939e8771","position":2016,"duration":157500,"release_date":"year:2016 month:3 day:4","track_number":1,"disc_number":1}} Apr 18 16:58:42 volofritz volumio[3572]: SPOTIFY: received: {"type":"active","data":null} Apr 18 16:58:42 volofritz volumio[3572]: info: Aligning Spotify Volume to Volumio Volume Apr 18 16:58:42 volofritz volumio[3572]: info: CoreCommandRouter::volumioGetState Apr 18 16:58:42 volofritz volumio[3572]: info: CorePlayQueue::getTrack 0 Apr 18 16:58:42 volofritz volumio[3572]: info: Setting Spotify Volume from Volumio: 70 Apr 18 16:58:42 volofritz volumio[3572]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0DBTrH6kBbF8CzNVcu5MQR","resume":false,"play_origin":"playlist"}} Apr 18 16:58:42 volofritz volumio[3572]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 16:58:42 volofritz volumio[3572]: TypeError: Cannot read property 'service' of undefined Apr 18 16:58:42 volofritz volumio[3572]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Apr 18 16:58:42 volofritz volumio[3572]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Apr 18 16:58:42 volofritz volumio[3572]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Apr 18 16:58:42 volofritz volumio[3572]: at WebSocket.emit (events.js:400:28) Apr 18 16:58:42 volofritz volumio[3572]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1209:20) Apr 18 16:58:42 volofritz volumio[3572]: at Receiver.emit (events.js:400:28) Apr 18 16:58:42 volofritz volumio[3572]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Apr 18 16:58:42 volofritz volumio[3572]: at internal/process/task_queues.js:141:7 Apr 18 16:58:42 volofritz volumio[3572]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Apr 18 16:58:42 volofritz volumio[3572]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) Apr 18 16:58:42 volofritz volumio[3572]: at runMicrotasks () Apr 18 16:58:42 volofritz volumio[3572]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 18 16:58:42 volofritz volumio[3572]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 16:58:42 volofritz sudo[4147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-18 16:57 Apr 18 16:58:42 volofritz sudo[4147]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 08:39:28 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="53aa76f285b1e43196da79c067ac0c05"