-- Logs begin at Thu 2019-02-14 04:11:59 CST, end at Sat 2025-05-24 09:08:26 CDT. -- May 24 09:07:00 tessa volumio-time-update[555]: volumio-time-update-util: Date not found in response May 24 09:07:00 tessa volumio-time-update[555]: volumio-time-update-util: Retrying in 5 seconds... May 24 09:07:00 tessa systemd[1]: iptables.service: Succeeded. May 24 09:07:00 tessa systemd[1]: Started Raise network interfaces. May 24 09:07:00 tessa systemd[1]: Reached target Network. May 24 09:07:00 tessa bluetoothd[664]: Bluetooth daemon 5.50 May 24 09:07:00 tessa bluetoothd[664]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf May 24 09:07:00 tessa haveged[551]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K May 24 09:07:00 tessa haveged[551]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 May 24 09:07:00 tessa haveged[551]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99734 May 24 09:07:00 tessa haveged[551]: haveged: fills: 0, generated: 0 May 24 09:07:00 tessa systemd[1]: Starting OpenBSD Secure Shell server... May 24 09:07:00 tessa bluetoothd[664]: Starting SDP server May 24 09:07:00 tessa bluetoothd[664]: Excluding (cli) sap May 24 09:07:00 tessa systemd[1]: Starting Network Time Service... May 24 09:07:00 tessa systemd[1]: Starting Music Player Daemon... May 24 09:07:00 tessa systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. May 24 09:07:00 tessa loadcpufreq[639]: Loading cpufreq kernel modules...done (none). May 24 09:07:00 tessa systemd[1]: Starting Permit User Sessions... May 24 09:07:00 tessa systemd[1]: Reached target Network is Online. May 24 09:07:00 tessa systemd[1]: Starting /etc/rc.local Compatibility... May 24 09:07:00 tessa systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:07:00 tessa kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 May 24 09:07:00 tessa kernel: Bluetooth: BNEP filters: protocol multicast May 24 09:07:00 tessa kernel: Bluetooth: BNEP socket layer initialized May 24 09:07:00 tessa systemd[1]: Starting Samba NMB Daemon... May 24 09:07:00 tessa systemd[1]: Starting LSB: Brings up/down network automatically... May 24 09:07:00 tessa dbus-daemon[573]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=664 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") May 24 09:07:00 tessa bluetoothd[664]: Bluetooth management interface 1.22 initialized May 24 09:07:00 tessa kernel: Bluetooth: MGMT ver 1.22 May 24 09:07:00 tessa systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. May 24 09:07:00 tessa systemd[1]: Started Permit User Sessions. May 24 09:07:00 tessa systemd[1]: Started /etc/rc.local Compatibility. May 24 09:07:00 tessa systemd[1]: Started Bluetooth service. May 24 09:07:00 tessa bluetoothd[664]: Failed to set privacy: Rejected (0x0b) May 24 09:07:00 tessa ntpd[737]: ntpd 4.2.8p12@1.3728-o (1): Starting May 24 09:07:00 tessa ntpd[737]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 May 24 09:07:00 tessa ntpd[762]: proto: precision = 0.796 usec (-20) May 24 09:07:00 tessa ntpd[762]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 24 09:07:00 tessa ntpd[762]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 24 09:07:00 tessa ntpd[762]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 148 days ago May 24 09:07:00 tessa ntpd[762]: Listen and drop on 0 v6wildcard [::]:123 May 24 09:07:00 tessa ntpd[762]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 24 09:07:00 tessa ntpd[762]: Listen normally on 2 lo 127.0.0.1:123 May 24 09:07:00 tessa ntpd[762]: Listening on routing socket on fd #19 for interface updates May 24 09:07:00 tessa ntpd[762]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 24 09:07:00 tessa ntpd[762]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 24 09:07:00 tessa systemd[1]: Started Network Time Service. May 24 09:07:00 tessa systemd[1]: Starting Hostname Service... May 24 09:07:00 tessa systemd[1]: Reached target Bluetooth. May 24 09:07:00 tessa sshd[766]: Server listening on 0.0.0.0 port 22. May 24 09:07:00 tessa systemd[1]: Starting Hold until boot process finishes up... May 24 09:07:00 tessa sshd[766]: Server listening on :: port 22. May 24 09:07:00 tessa systemd[1]: Starting Terminate Plymouth Boot Screen... May 24 09:07:00 tessa systemd[1]: Starting LSB: set CPUFreq kernel parameters... May 24 09:07:00 tessa systemd[1]: Started OpenBSD Secure Shell server. May 24 09:07:00 tessa sudo[738]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 24 09:07:00 tessa sudo[738]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:00 tessa sudo[738]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 24 09:07:00 tessa systemd[1]: Received SIGRTMIN+21 from PID 192 (plymouthd). May 24 09:07:00 tessa sudo[738]: pam_unix(sudo:session): session closed for user root May 24 09:07:00 tessa ifplugd(eth0)[784]: ifplugd 0.28 initializing. May 24 09:07:00 tessa ifplugd(eth0)[784]: Using interface eth0/D8:3A:DD:26:E1:84 with driver (version: 6.6.62-v7l+) May 24 09:07:00 tessa ifplugd(eth0)[784]: Using detection mode: SIOCETHTOOL May 24 09:07:00 tessa ifplugd(eth0)[784]: Initialization complete, link beat not detected. May 24 09:07:00 tessa systemd[1]: plymouth-quit-wait.service: Succeeded. May 24 09:07:00 tessa systemd[1]: Started Hold until boot process finishes up. May 24 09:07:00 tessa systemd[1]: plymouth-quit.service: Succeeded. May 24 09:07:00 tessa systemd[1]: Started Terminate Plymouth Boot Screen. May 24 09:07:00 tessa systemd[1]: Received SIGRTMIN+21 from PID 192 (n/a). May 24 09:07:00 tessa systemd[1]: Started Getty on tty1. May 24 09:07:00 tessa dbus-daemon[573]: [system] Successfully activated service 'org.freedesktop.hostname1' May 24 09:07:00 tessa systemd[1]: Reached target Login Prompts. May 24 09:07:00 tessa systemd[1]: Started Hostname Service. May 24 09:07:00 tessa cpufrequtils[770]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. May 24 09:07:00 tessa systemd[1]: Started LSB: set CPUFreq kernel parameters. May 24 09:07:00 tessa ifplugd[746]: Network Interface Plugging Daemon...start eth0...done. May 24 09:07:00 tessa systemd[1]: Started LSB: Brings up/down network automatically. May 24 09:07:01 tessa nmbd[749]: [2025/05/24 09:07:01.327282, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) May 24 09:07:01 tessa nmbd[749]: started asyncdns process 795 May 24 09:07:01 tessa nmbd[749]: [2025/05/24 09:07:01.328930, 0] ../lib/util/become_daemon.c:149(daemon_status) May 24 09:07:01 tessa nmbd[749]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... May 24 09:07:01 tessa nmbd[749]: [2025/05/24 09:07:01.329038, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) May 24 09:07:01 tessa nmbd[749]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). May 24 09:07:01 tessa wireless.js[558]: Cleaning previous... May 24 09:07:01 tessa ntpd[762]: error resolving pool 0.debian.pool.ntp.org: System error (-11) May 24 09:07:01 tessa sudo[803]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 24 09:07:01 tessa sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:01 tessa sudo[803]: pam_unix(sudo:session): session closed for user root May 24 09:07:01 tessa sudo[805]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 24 09:07:01 tessa sudo[805]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:02 tessa sudo[805]: pam_unix(sudo:session): session closed for user root May 24 09:07:02 tessa wireless.js[558]: Stopped aP May 24 09:07:02 tessa wireless.js[558]: Wireless Networking DISABLED, not starting wireless flow May 24 09:07:02 tessa systemd[1]: wireless.service: Succeeded. May 24 09:07:02 tessa systemd[1]: Started Wireless Services. May 24 09:07:02 tessa systemd[1]: Started Volumio Backend Module. May 24 09:07:02 tessa systemd[1]: Started Volumio Cpu Tweaker. May 24 09:07:02 tessa volumio-cpu-tweak[814]: Setting RT Priority for mpd May 24 09:07:02 tessa volumio-cpu-tweak[814]: Setting MPD Affinity May 24 09:07:02 tessa volumio-cpu-tweak[814]: pid 779's current affinity mask: f May 24 09:07:02 tessa volumio-cpu-tweak[814]: pid 779's new affinity mask: 3 May 24 09:07:02 tessa volumio-cpu-tweak[814]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input May 24 09:07:02 tessa volumio-cpu-tweak[814]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance May 24 09:07:02 tessa ntpd[762]: error resolving pool 1.debian.pool.ntp.org: System error (-11) May 24 09:07:02 tessa systemd[1]: volumio_cpu_tweak.service: Succeeded. May 24 09:07:03 tessa mpd[779]: May 24 09:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 24 09:07:03 tessa systemd[1]: Started Music Player Daemon. May 24 09:07:03 tessa mpd_monitor.sh[569]: MPD Monitor Service: MPD restarted due to no mpc output. May 24 09:07:03 tessa ntpd[762]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 24 09:07:03 tessa systemd[1]: systemd-rfkill.service: Succeeded. May 24 09:07:03 tessa sh[516]: eth0: carrier acquired May 24 09:07:03 tessa dhcpcd[549]: eth0: carrier acquired May 24 09:07:03 tessa sh[516]: DUID 00:01:00:01:29:53:65:b4:b8:27:eb:3d:a0:60 May 24 09:07:03 tessa sh[516]: eth0: IAID dd:26:e1:84 May 24 09:07:03 tessa sh[516]: eth0: adding address fe80::da3a:ddff:fe26:e184 May 24 09:07:03 tessa sh[516]: ipv6_addaddr1: Permission denied May 24 09:07:03 tessa dhcpcd[549]: DUID 00:01:00:01:29:53:65:b4:b8:27:eb:3d:a0:60 May 24 09:07:03 tessa dhcpcd[549]: eth0: IAID dd:26:e1:84 May 24 09:07:03 tessa dhcpcd[549]: eth0: adding address fe80::da3a:ddff:fe26:e184 May 24 09:07:03 tessa dhcpcd[549]: ipv6_addaddr1: Permission denied May 24 09:07:03 tessa kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx May 24 09:07:04 tessa ifplugd(eth0)[784]: Link beat detected. May 24 09:07:04 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:04 tessa volumio[813]: info: ----- Volumio3 ---- May 24 09:07:04 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:04 tessa volumio[813]: info: ----- System startup ---- May 24 09:07:04 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:04 tessa ifplugd(eth0)[784]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. May 24 09:07:04 tessa ifplugd(eth0)[784]: client: ifup: waiting for lock on /run/network/ifstate.eth0 May 24 09:07:04 tessa sh[516]: eth0: soliciting an IPv6 router May 24 09:07:04 tessa dhcpcd[549]: eth0: soliciting an IPv6 router May 24 09:07:04 tessa ntpd[762]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 24 09:07:04 tessa sh[516]: eth0: soliciting a DHCP lease May 24 09:07:04 tessa dhcpcd[549]: eth0: soliciting a DHCP lease May 24 09:07:04 tessa volumio-remote-updater[554]: [2025-05-24 09:07:04] [connect] Successful connection May 24 09:07:04 tessa volumio[813]: info: MYVOLUMIO Environment detected May 24 09:07:04 tessa bthelper[636]: Changing power off succeeded May 24 09:07:05 tessa volumio-time-update[555]: volumio-time-update-util: Fetching time from Volumio... May 24 09:07:05 tessa volumio-time-update[555]: volumio-time-update-util: Date not found in response May 24 09:07:05 tessa volumio-time-update[555]: volumio-time-update-util: Retrying in 5 seconds... May 24 09:07:05 tessa volumio[813]: info: Plugin folders cleanup May 24 09:07:05 tessa volumio[813]: info: Scanning into folder /volumio/app/plugins/ May 24 09:07:05 tessa volumio[813]: info: Scanning category audio_interface May 24 09:07:05 tessa volumio[813]: info: Scanning category miscellanea May 24 09:07:05 tessa volumio[813]: info: Scanning category music_service May 24 09:07:05 tessa volumio[813]: info: Scanning category plugins.json May 24 09:07:05 tessa volumio[813]: info: Scanning category system_controller May 24 09:07:05 tessa volumio[813]: info: Scanning category user_interface May 24 09:07:05 tessa volumio[813]: info: Scanning into folder /data/plugins/ May 24 09:07:05 tessa volumio[813]: info: Scanning category miscellanea May 24 09:07:05 tessa volumio[813]: info: Scanning category music_service May 24 09:07:05 tessa bthelper[636]: [CHG] Controller D8:3A:DD:26:E1:87 Class: 0x0000041c May 24 09:07:05 tessa bthelper[636]: Changing power on succeeded May 24 09:07:05 tessa bthelper[636]: [CHG] Controller D8:3A:DD:26:E1:87 Powered: yes May 24 09:07:05 tessa volumio[813]: info: Scanning category user_interface May 24 09:07:05 tessa volumio[813]: info: Plugin folders cleanup completed May 24 09:07:05 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:05 tessa volumio[813]: info: ----- Core plugins startup ---- May 24 09:07:05 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:05 tessa volumio[813]: info: Loading plugins from folder /volumio/app/plugins/ May 24 09:07:05 tessa volumio[813]: info: Adding plugin upnp to MyMusic Plugins May 24 09:07:05 tessa volumio[813]: info: Adding plugin airplay_emulation to MyMusic Plugins May 24 09:07:05 tessa volumio[813]: info: Adding plugin upnp_browser to MyMusic Plugins May 24 09:07:05 tessa volumio[813]: info: Loading plugins from folder /data/plugins/ May 24 09:07:05 tessa volumio[813]: info: Loading plugin "system"... May 24 09:07:05 tessa volumio[813]: info: Loading plugin "appearance"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "network"... May 24 09:07:06 tessa volumio[813]: info: Refreshing Cached IP Addresses May 24 09:07:06 tessa sudo[866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 24 09:07:06 tessa sudo[866]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:06 tessa sudo[866]: pam_unix(sudo:session): session closed for user root May 24 09:07:06 tessa sudo[868]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 24 09:07:06 tessa sudo[868]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:06 tessa volumio[813]: info: Loading plugin "services"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "alsa_controller"... May 24 09:07:06 tessa sudo[868]: pam_unix(sudo:session): session closed for user root May 24 09:07:06 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:07:06 tessa volumio[813]: info: Loading plugin "wizard"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "networkfs"... May 24 09:07:06 tessa volumio[813]: info: Starting Udev Watcher for removable devices May 24 09:07:06 tessa volumio[813]: info: Ignoring mount for partition: boot May 24 09:07:06 tessa volumio[813]: info: Ignoring mount for partition: volumio May 24 09:07:06 tessa volumio[813]: info: Ignoring mount for partition: volumio_data May 24 09:07:06 tessa volumio[813]: info: Mounting Device D975-7683 May 24 09:07:06 tessa sudo[892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/D975-7683 -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 24 09:07:06 tessa sudo[892]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:06 tessa kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 24 09:07:06 tessa sudo[892]: pam_unix(sudo:session): session closed for user root May 24 09:07:06 tessa kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 24 09:07:06 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 24 09:07:06 tessa volumio[813]: info: Loading plugin "volumio_command_line_client"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "upnp"... May 24 09:07:06 tessa volumio[813]: info: [1748095626525] Starting Upmpd Daemon May 24 09:07:06 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 24 09:07:06 tessa volumio[813]: info: Loading plugin "my_music"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "mpd"... May 24 09:07:06 tessa volumio[813]: info: Loading plugin "upnp_browser"... May 24 09:07:07 tessa volumio[813]: info: Loading plugin "alarm-clock"... May 24 09:07:07 tessa volumio[813]: info: Loading plugin "airplay_emulation"... May 24 09:07:07 tessa volumio[813]: info: Starting Shairport Sync May 24 09:07:07 tessa volumio[813]: info: Loading plugin "last_100"... May 24 09:07:07 tessa volumio[813]: info: Loading plugin "webradio"... May 24 09:07:07 tessa volumio[813]: info: Loading plugin "i2s_dacs"... May 24 09:07:07 tessa volumio[813]: info: Loading plugin "volumiodiscovery"... May 24 09:07:07 tessa volumio[813]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 24 09:07:07 tessa volumio[813]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:07:07 tessa node[813]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 24 09:07:07 tessa volumio[813]: *** WARNING *** For more information see May 24 09:07:07 tessa volumio[813]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 24 09:07:07 tessa volumio[813]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:07:07 tessa volumio[813]: *** WARNING *** For more information see May 24 09:07:07 tessa node[813]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:07:07 tessa node[813]: *** WARNING *** For more information see May 24 09:07:07 tessa node[813]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 24 09:07:07 tessa node[813]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:07:07 tessa node[813]: *** WARNING *** For more information see May 24 09:07:07 tessa volumio[813]: info: Applying required configuration parameters for plugin volumiodiscovery May 24 09:07:07 tessa volumio[813]: info: Discovery: Started advertising with name: tessa May 24 09:07:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 24 09:07:07 tessa volumio[813]: info: Loading plugin "spop"... May 24 09:07:08 tessa sh[516]: eth0: offered 192.168.10.67 from 192.168.10.1 May 24 09:07:08 tessa dhcpcd[549]: eth0: offered 192.168.10.67 from 192.168.10.1 May 24 09:07:08 tessa sh[516]: eth0: probing address 192.168.10.67/24 May 24 09:07:08 tessa dhcpcd[549]: eth0: probing address 192.168.10.67/24 May 24 09:07:08 tessa volumio[813]: info: Loading plugin "now_playing"... May 24 09:07:09 tessa volumio[813]: info: Loading plugin "outputs"... May 24 09:07:09 tessa volumio[813]: info: Loading plugin "albumart"... May 24 09:07:09 tessa volumio[813]: info: Plugin example_plugin is not enabled May 24 09:07:09 tessa volumio[813]: info: Loading plugin "inputs"... May 24 09:07:09 tessa volumio[813]: info: Loading plugin "updater_comm"... May 24 09:07:09 tessa volumio[813]: info: Plugin mpdemulation is not enabled May 24 09:07:09 tessa volumio[813]: info: Loading plugin "rest_api"... May 24 09:07:09 tessa volumio[813]: info: Loading plugin "websocket"... May 24 09:07:09 tessa volumio[813]: info: Starting Socket.io Server version 2.3.0 May 24 09:07:09 tessa volumio[813]: info: Loading plugin "m3u_importer"... May 24 09:07:09 tessa volumio[813]: Forking 3 albumart workers May 24 09:07:09 tessa volumio[813]: info: Applying required configuration parameters for plugin m3u_importer May 24 09:07:09 tessa volumio[813]: info: Loading plugin "80s80s"... May 24 09:07:10 tessa volumio[813]: Starting albumart workers May 24 09:07:10 tessa volumio[813]: Starting albumart workers May 24 09:07:10 tessa volumio[813]: Starting albumart workers May 24 09:07:10 tessa volumio-time-update[555]: volumio-time-update-util: Fetching time from Volumio... May 24 09:07:10 tessa volumio-time-update[555]: volumio-time-update-util: Date not found in response May 24 09:07:10 tessa volumio-time-update[555]: volumio-time-update-util: Retrying in 5 seconds... May 24 09:07:10 tessa volumio[813]: info: Applying required configuration parameters for plugin 80s80s May 24 09:07:10 tessa volumio[813]: info: [1748095630295] [80s80s] API delay: 30 May 24 09:07:10 tessa volumio[813]: info: Plugin hotelradio is not enabled May 24 09:07:10 tessa volumio[813]: info: Loading plugin "minidlna"... May 24 09:07:10 tessa volumio[813]: info: Applying required configuration parameters for plugin minidlna May 24 09:07:10 tessa volumio[813]: info: Loading plugin "radio_paradise"... May 24 09:07:10 tessa volumio[813]: info: Applying required configuration parameters for plugin radio_paradise May 24 09:07:10 tessa volumio[813]: info: [1748095630792] [RadioParadise] API delay: 5 May 24 09:07:10 tessa volumio[813]: info: Loading plugin "volumio-livemusicarchive"... May 24 09:07:11 tessa volumio[813]: info: Applying required configuration parameters for plugin volumio-livemusicarchive May 24 09:07:11 tessa volumio[813]: info: Loading plugin "volumio-phishin"... May 24 09:07:11 tessa volumio[813]: info: Applying required configuration parameters for plugin volumio-phishin May 24 09:07:12 tessa volumio[813]: info: Loading plugin "Systeminfo"... May 24 09:07:12 tessa volumio[813]: info: Loading i18n strings for locale en May 24 09:07:12 tessa volumio[813]: Updating browse sources language May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::initPlayerControls May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:07:12 tessa volumio[813]: Express server listening on port 3000 May 24 09:07:12 tessa volumio[813]: [Metrics] WebUI: 8s 869.22ms May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::resetVolumioState May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::getcurrentVolume May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioRetrievevolume May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::pushState May 24 09:07:12 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioPushState May 24 09:07:12 tessa volumio[813]: info: Volumio Network Manager: Network status updated: 0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:12 tessa volumio[813]: info: Reloading queue from file May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::setRepeat false single undefined May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::pushState May 24 09:07:12 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioPushState May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::setRandom false May 24 09:07:12 tessa volumio[813]: info: CoreStateMachine::pushState May 24 09:07:12 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioPushState May 24 09:07:12 tessa volumio[813]: info: Setting Device type: Raspberry PI May 24 09:07:12 tessa volumio[813]: info: Completed loading Core Plugins May 24 09:07:12 tessa volumio[813]: info: Preparing to generate the ALSA configuration file May 24 09:07:12 tessa volumio[813]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb May 24 09:07:12 tessa volumio[813]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 May 24 09:07:12 tessa volumio[813]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI May 24 09:07:12 tessa volumio[813]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 24 09:07:12 tessa volumio[813]: info: Reading ALSA contributions from plugins. May 24 09:07:12 tessa volumio[813]: info: Asound.conf file unchanged, so no further update is needed May 24 09:07:12 tessa volumio[813]: info: Output device has changed, restarting MPD May 24 09:07:12 tessa sudo[962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:07:12 tessa volumio[813]: info: Output device has changed, restarting Shairport Sync May 24 09:07:12 tessa sudo[962]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:12 tessa sudo[962]: pam_unix(sudo:session): session closed for user root May 24 09:07:12 tessa sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:07:12 tessa sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:12 tessa systemd[1]: Stopping Music Player Daemon... May 24 09:07:12 tessa volumio[813]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:07:12 tessa volumio[813]: info: ___________ START PLUGINS ___________ May 24 09:07:12 tessa volumio[813]: info: ControllerMpd::onStart: Initializing MPD May 24 09:07:12 tessa volumio[813]: info: Creating MPD Configuration file May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:12 tessa volumio[813]: info: [1748095632854] CoreMusicLibrary::Adding element Media Servers May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:12 tessa sudo[971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:07:12 tessa sudo[971]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:12 tessa sudo[971]: pam_unix(sudo:session): session closed for user root May 24 09:07:12 tessa sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:12 tessa sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:12 tessa volumio[813]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:12 tessa systemd[1]: mpd.service: Succeeded. May 24 09:07:12 tessa systemd[1]: Stopped Music Player Daemon. May 24 09:07:12 tessa volumio[813]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:12 tessa volumio[813]: info: [1748095632950] CoreMusicLibrary::Adding element Last_100 May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:12 tessa volumio[813]: info: [1748095632952] CoreMusicLibrary::Adding element Webradio May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:12 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:07:12 tessa volumio[813]: info: Initializing BBC Radios May 24 09:07:13 tessa systemd[1]: Starting Music Player Daemon... May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:13 tessa volumio[813]: info: Creating Spotify config file May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa sudo[982]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 24 09:07:13 tessa sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa sudo[982]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa volumio[813]: info: Loading i18n strings for locale en May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:13 tessa volumio[813]: info: [1748095633106] CoreMusicLibrary::Adding element 80s80s Radio May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:13 tessa volumio[813]: Cannot find translation for source 80s80s Radio May 24 09:07:13 tessa volumio[813]: info: Loading i18n strings for locale en May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:13 tessa volumio[813]: info: [1748095633141] CoreMusicLibrary::Adding element Radio Paradise May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:13 tessa volumio[813]: Cannot find translation for source 80s80s Radio May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Radio Paradise May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:13 tessa volumio[813]: info: [1748095633144] CoreMusicLibrary::Adding element Live Music Archive May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:13 tessa volumio[813]: Cannot find translation for source 80s80s Radio May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Radio Paradise May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Live Music Archive May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:07:13 tessa volumio[813]: info: [1748095633150] CoreMusicLibrary::Adding element Phish.in May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:13 tessa volumio[813]: Cannot find translation for source 80s80s Radio May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Radio Paradise May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Live Music Archive May 24 09:07:13 tessa volumio[813]: Cannot find translation for source Phish.in May 24 09:07:13 tessa volumio[813]: info: Volumio Calling Home May 24 09:07:13 tessa volumio[813]: info: [now-playing-app] App is listening on port 4004. May 24 09:07:13 tessa volumio[813]: Unhandled rejection Error: No sockets available, cannot start. May 24 09:07:13 tessa volumio[813]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 24 09:07:13 tessa volumio[813]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 24 09:07:13 tessa volumio[813]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 24 09:07:13 tessa volumio[813]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 24 09:07:13 tessa volumio[813]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 24 09:07:13 tessa volumio[813]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 24 09:07:13 tessa volumio[813]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 24 09:07:13 tessa volumio[813]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 24 09:07:13 tessa volumio[813]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 24 09:07:13 tessa volumio[813]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 24 09:07:13 tessa volumio[813]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 24 09:07:13 tessa volumio[813]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 24 09:07:13 tessa volumio[813]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 24 09:07:13 tessa volumio[813]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 24 09:07:13 tessa volumio[813]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 24 09:07:13 tessa volumio[813]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 24 09:07:13 tessa volumio[813]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io May 24 09:07:13 tessa volumio[813]: info: MPD Permissions set May 24 09:07:13 tessa volumio[813]: info: MPD Permissions set May 24 09:07:13 tessa volumio[813]: info: Spotify config file written May 24 09:07:13 tessa sudo[1001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 24 09:07:13 tessa sudo[1001]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: No need to fix Spotify hosts May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:13 tessa systemd[1]: Started go-librespot Daemon. May 24 09:07:13 tessa sudo[1001]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa go-librespot[1004]: Librespot-go daemon starting... May 24 09:07:13 tessa volumio[813]: info: minidlna: Found miniDLNA version 1.2.1 May 24 09:07:13 tessa volumio[813]: info: minidlna: Starting minidlna.service May 24 09:07:13 tessa sh[516]: eth0: leased 192.168.10.67 for 86400 seconds May 24 09:07:13 tessa dhcpcd[549]: eth0: leased 192.168.10.67 for 86400 seconds May 24 09:07:13 tessa sh[516]: eth0: adding route to 192.168.10.0/24 May 24 09:07:13 tessa sh[516]: eth0: adding default route via 192.168.10.1 May 24 09:07:13 tessa dhcpcd[549]: eth0: adding route to 192.168.10.0/24 May 24 09:07:13 tessa dhcpcd[549]: eth0: adding default route via 192.168.10.1 May 24 09:07:13 tessa avahi-daemon[572]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.10.67. May 24 09:07:13 tessa avahi-daemon[572]: New relevant interface eth0.IPv4 for mDNS. May 24 09:07:13 tessa avahi-daemon[572]: Registering new address record for 192.168.10.67 on eth0.IPv4. May 24 09:07:13 tessa volumio[813]: info: Starting Shairport Sync May 24 09:07:13 tessa sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service May 24 09:07:13 tessa sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa volumio[813]: info: Starting Shairport Sync May 24 09:07:13 tessa volumio[813]: info: Starting Shairport Sync May 24 09:07:13 tessa sudo[1025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:13 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:13 tessa systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. May 24 09:07:13 tessa sudo[1025]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa sudo[1036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:07:13 tessa sudo[1030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:07:13 tessa sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa sudo[1036]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:13 tessa sh[516]: forked to background, child pid 1051 May 24 09:07:13 tessa dhcpcd[549]: forked to background, child pid 1051 May 24 09:07:13 tessa sudo[1014]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa volumio[813]: verbose: New Socket.io Connection to 192.168.10.67 from 192.168.10.15 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 May 24 09:07:13 tessa systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 24 09:07:13 tessa systemd[1]: shairport-sync.service: Succeeded. May 24 09:07:13 tessa systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 24 09:07:13 tessa volumio[813]: verbose: New Socket.io Connection to 192.168.10.67 from 192.168.10.15 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 3 May 24 09:07:13 tessa volumio[813]: info: minidlna: systemctl start minidlna.service succeeded. May 24 09:07:13 tessa systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:07:13 tessa sudo[1036]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa sudo[1025]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa sudo[1030]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa volumio[813]: verbose: New Socket.io Connection to 192.168.10.67 from 192.168.10.15 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 4 May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:07:13 tessa volumio[813]: info: Shairport-Sync Started May 24 09:07:13 tessa volumio[813]: Error adding Membership: Error: addMembership EINVAL May 24 09:07:13 tessa volumio[813]: info: Shairport-Sync Started May 24 09:07:13 tessa volumio[813]: info: Shairport-Sync Started May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetVisibleSources May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:13 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:13 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 24 09:07:13 tessa volumio[813]: info: Received Get System Info May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:07:13 tessa volumio[813]: info: Discovery: Getting this device information May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:13 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:07:13 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:13 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:13 tessa volumio[813]: info: Listing playlists May 24 09:07:13 tessa volumio[813]: info: Discovery: adding 3f015315-a7f9-4c86-8fd3-88ca39379e73 May 24 09:07:13 tessa volumio[813]: info: Discovery: Found device Serena May 24 09:07:13 tessa volumio[813]: info: Discovery: Connecting to remote: 192.168.10.53 May 24 09:07:13 tessa ifplugd(eth0)[784]: client: ifup: interface eth0 already configured May 24 09:07:13 tessa sh[516]: eth0=eth0 May 24 09:07:13 tessa volumio[813]: info: Discovery: Connected to remote: 192.168.10.53 May 24 09:07:13 tessa ifplugd(eth0)[784]: Program executed successfully. May 24 09:07:13 tessa mpd[994]: May 24 09:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 24 09:07:13 tessa systemd[1]: Started Music Player Daemon. May 24 09:07:13 tessa sudo[973]: pam_unix(sudo:session): session closed for user root May 24 09:07:13 tessa sudo[964]: pam_unix(sudo:session): session closed for user root May 24 09:07:14 tessa volumio[813]: info: Completed starting Core Plugins May 24 09:07:14 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:14 tessa volumio[813]: info: ----- MyVolumio plugins startup ---- May 24 09:07:14 tessa volumio[813]: info: ------------------------------------------- May 24 09:07:14 tessa volumio[813]: info: [MyVolumio PluginManager] Fetching plans data.... May 24 09:07:14 tessa volumio[813]: info: MPD running with PID994 May 24 09:07:14 tessa volumio[813]: ,establishing connection May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=info msg="generated new device id: 7cb0f9a1f4db9dfd803b0050fc765f4c87dccd6d" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="stored credentials found for 1282099804" May 24 09:07:14 tessa volumio[813]: error: MPD error: The expression evaluated to a falsy value: May 24 09:07:14 tessa volumio[813]: assert.ok(self.idling) May 24 09:07:14 tessa volumio[813]: error: The expression evaluated to a falsy value: May 24 09:07:14 tessa volumio[813]: assert.ok(self.idling) May 24 09:07:14 tessa volumio[813]: error: MPD error: The expression evaluated to a falsy value: May 24 09:07:14 tessa volumio[813]: assert.ok(self.idling) May 24 09:07:14 tessa volumio[813]: error: The expression evaluated to a falsy value: May 24 09:07:14 tessa volumio[813]: assert.ok(self.idling) May 24 09:07:14 tessa volumio[813]: error: updateQueue error: null May 24 09:07:14 tessa volumio[813]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="zeroconf server listening on port 36589" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="obtained new client token: AABIgA3ezxpf4RiOHZ2tiEwUmh42f6hmb4Ff8afY9BfcLCTIGBj/UwCp4bHEyX9CZx2L6Jplp+1iN+Ue1pWhA4DeLa5Z/HrtqWd3MkqYyMAOHH0BmMvW7y/WYOI8mym4+6if4oCLy6b2/qOWZGlONMfMBmuE4dwNDYX6Y5Hsvg0PZimYzsmLWqdmK6DdNw+DzSpxgVGP+wkoNGmLoCLnsTWXQGFe+JDtVAWqOv6Mi8b4nN+TwkbGv+MMIueznA==" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=info msg="connected to ap-gue1.spotify.com:4070" May 24 09:07:14 tessa go-librespot[1004]: time="2025-05-24T09:07:14-05:00" level=debug msg="completed keyexchange" May 24 09:07:14 tessa ntpd[762]: Listen normally on 3 eth0 192.168.10.67:123 May 24 09:07:14 tessa ntpd[762]: new interface(s) found: waking up resolver May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="completed challenge" May 24 09:07:15 tessa volumio-time-update[555]: volumio-time-update-util: Fetching time from Volumio... May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="authenticated as 1282099804" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="authenticated as 1282099804" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="dealer connection opened" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="initializing zeroconf session, username: 1282099804" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="autoplay enabled: false" May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="received connection id: M2E0OTQ2YTEtZWU1YS00MWI5LTkyYWItNzZkY2ZmZWEyZGExK2RlYWxlcit0Y3A6Ly8wYWNiZjg2MS5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArMDA5MDMwMTk0QjY5QjE1NjYxQzRGMEM0MEQ3MkIyODNDRjk1OTVGMTk4NUUzNUM1QjA0RkExNEYyOTYwQkVENA==" May 24 09:07:15 tessa volumio-time-update[555]: volumio-time-update-util: Setting system time to: 2025-05-24 09:07:41 May 24 09:07:15 tessa sudo[1097]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-24 09:07:41 May 24 09:07:15 tessa sudo[1097]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:15 tessa dbus-daemon[573]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.14' (uid=0 pid=1098 comm="timedatectl set-time 2025-05-24 09:07:41 ") May 24 09:07:15 tessa systemd[1]: Starting Time & Date Service... May 24 09:07:15 tessa go-librespot[1004]: time="2025-05-24T09:07:15-05:00" level=debug msg="put connect state because NEW_DEVICE" May 24 09:07:16 tessa volumio[813]: info: Volumio Network Manager: Network status updated: 1 May 24 09:07:16 tessa nmbd[749]: [2025/05/24 09:07:16.332863, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:07:16 tessa nmbd[749]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 24 09:07:16 tessa systemd[1]: Started Samba NMB Daemon. May 24 09:07:16 tessa systemd[1]: Starting Samba Winbind Daemon... May 24 09:07:16 tessa volumio[813]: info: go-librespot daemon successfully initialized May 24 09:07:16 tessa sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 24 09:07:16 tessa sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:16 tessa sudo[1117]: pam_unix(sudo:session): session closed for user root May 24 09:07:16 tessa sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 24 09:07:16 tessa sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:16 tessa winbindd[1114]: [2025/05/24 09:07:16.582096, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 24 09:07:16 tessa winbindd[1114]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 24 09:07:16 tessa sudo[1120]: pam_unix(sudo:session): session closed for user root May 24 09:07:16 tessa sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 24 09:07:16 tessa sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:16 tessa winbindd[1114]: [2025/05/24 09:07:16.632403, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:07:16 tessa winbindd[1114]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 24 09:07:16 tessa systemd[1]: Started UPnP Renderer front-end to MPD. May 24 09:07:16 tessa systemd[1]: Started Samba Winbind Daemon. May 24 09:07:16 tessa systemd[1]: Starting Samba SMB Daemon... May 24 09:07:16 tessa sudo[1124]: pam_unix(sudo:session): session closed for user root May 24 09:07:16 tessa volumio[813]: info: Upmpdcli Daemon Started May 24 09:07:16 tessa volumio[1126]: Generating RSA private key, 4096 bit long modulus (2 primes) May 24 09:07:16 tessa dbus-daemon[573]: [system] Successfully activated service 'org.freedesktop.timedate1' May 24 09:07:16 tessa systemd[1]: Started Time & Date Service. May 24 09:07:41 tessa systemd-timedated[1099]: Changed local time to Sat May 24 09:07:41 2025 May 24 09:07:41 tessa sudo[1097]: pam_unix(sudo:session): session closed for user root May 24 09:07:41 tessa volumio-time-update[555]: volumio-time-update-util: System time updated successfully. May 24 09:07:41 tessa systemd[1]: Started Volumio Time Update Utility. May 24 09:07:41 tessa smbd[1129]: [2025/05/24 09:07:41.172633, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:07:41 tessa smbd[1129]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 24 09:07:41 tessa systemd[1]: Started Samba SMB Daemon. May 24 09:07:41 tessa systemd[1]: Reached target Multi-User System. May 24 09:07:41 tessa systemd[1]: Reached target Graphical Interface. May 24 09:07:41 tessa systemd[1]: Starting Update UTMP about System Runlevel Changes... May 24 09:07:41 tessa systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 24 09:07:41 tessa systemd[1]: Started Update UTMP about System Runlevel Changes. May 24 09:07:41 tessa systemd[1]: Startup finished in 12.335s (kernel) + 21.427s (userspace) = 33.762s. May 24 09:07:41 tessa volumio-remote-updater[554]: [2025-05-24 09:07:41] [connect] Successful connection May 24 09:07:41 tessa volumio-remote-updater[554]: [2025-05-24 09:07:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748095661 101 May 24 09:07:41 tessa volumio[813]: 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: 5 May 24 09:07:43 tessa volumio[813]: info: Initializing connection to go-librespot Websocket May 24 09:07:43 tessa go-librespot[1004]: time="2025-05-24T09:07:43-05:00" level=debug msg="new websocket client" May 24 09:07:43 tessa volumio[813]: info: Connection to go-librespot Websocket established May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 24 09:07:46 tessa volumio[813]: info: Adding plugin bluetooth to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin multiroom to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin metavolumio to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin cd_controller to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin qobuzconnect to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin smart_inputs to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: Adding plugin tidalconnect to MyMusic Plugins May 24 09:07:46 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 24 09:07:47 tessa volumio[813]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 24 09:07:47 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 24 09:07:47 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:47 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:47 tessa volumio[813]: info: Starting MyVolumio Remote Streaming Endpoints May 24 09:07:47 tessa volumio[813]: info: MyVolumio login type: Token May 24 09:07:47 tessa volumio[813]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 24 09:07:47 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 24 09:07:48 tessa volumio[813]: info: Starting Streaming Service Transparent Proxy May 24 09:07:48 tessa volumio[813]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 24 09:07:48 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 24 09:07:48 tessa volumio[813]: info: Streaming services startup May 24 09:07:48 tessa volumio[813]: info: Starting Streaming Daemon May 24 09:07:48 tessa sudo[1163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 24 09:07:48 tessa sudo[1163]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:48 tessa volumio[813]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 24 09:07:48 tessa sudo[1163]: pam_unix(sudo:session): session closed for user root May 24 09:07:48 tessa volumio[813]: info: Getting Spotify volume May 24 09:07:48 tessa volumio[813]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.812&uuid=5d527a615933a1006375baf3421f9a7f" http://updates.volumio.org/downloader-v1/track-device May 24 09:07:48 tessa volumio[813]: % Total % Received % Xferd Average Speed Time Time Time Current May 24 09:07:48 tessa volumio[813]: Dload Upload Total Spent Left Speed May 24 09:07:48 tessa volumio[813]: [132B blob data] May 24 09:07:48 tessa volumio[813]: retrying in 5 seconds, trial 0 May 24 09:07:48 tessa volumio[813]: info: Volumio Calling Home May 24 09:07:48 tessa volumio[813]: error: Cannot start Volumio Streaming Daemon May 24 09:07:48 tessa volumio[813]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 24 09:07:48 tessa volumio[813]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 24 09:07:48 tessa volumio[813]: info: Spotify volume: 100 May 24 09:07:48 tessa volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 24 09:07:48 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:48 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:48 tessa volumio[813]: error: MyVolumio Custom Token format not valid, refreshing it May 24 09:07:48 tessa volumio[813]: info: Volumio called home May 24 09:07:48 tessa volumio[813]: STREAMING PROXY: Starting server on port 3245 May 24 09:07:48 tessa volumio[813]: Node JS runtime: 14 May 24 09:07:49 tessa volumio[813]: info: MyVolumio login type: Token May 24 09:07:49 tessa volumio[813]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 24 09:07:50 tessa volumio[813]: info: MyVolumio token set successfully May 24 09:07:50 tessa volumio[813]: info: MYVOLUMIO: Adding device May 24 09:07:50 tessa volumio[813]: info: MYVOLUMIO: Evaluating Server May 24 09:07:50 tessa volumio[813]: info: MyVolumio Plan changed: premium May 24 09:07:50 tessa volumio[813]: info: [MyVolumio PluginManager] Subscribed plan changed to premium May 24 09:07:50 tessa volumio[813]: info: Removing browser output: myVolumio user plan is not superstar May 24 09:07:50 tessa volumio[813]: info: Removing audio output: May 24 09:07:50 tessa volumio[813]: info: MYVOLUMIO: Adding device May 24 09:07:50 tessa volumio[813]: info: MYVOLUMIO: Evaluating Server May 24 09:07:50 tessa volumio[813]: info: Remote config written successfully May 24 09:07:50 tessa volumio[813]: info: Starting Tunnel 1 May 24 09:07:50 tessa volumio[813]: info: Starting Tunnel Connection Checker May 24 09:07:50 tessa volumio[813]: info: Completed starting MyVolumio Plugin May 24 09:07:50 tessa volumio[813]: info: MYVolumio Device enabled May 24 09:07:50 tessa volumio[813]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... May 24 09:07:50 tessa volumio[813]: info: MyVolumio status changed May 24 09:07:50 tessa volumio[813]: info: Streaming services startup May 24 09:07:50 tessa volumio[813]: info: Starting Streaming Daemon May 24 09:07:50 tessa sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 24 09:07:50 tessa sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:50 tessa sudo[1205]: pam_unix(sudo:session): session closed for user root May 24 09:07:51 tessa volumio[813]: info: Setting Geolocation for MyVolumio to us3 May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: error: Cannot start Volumio Streaming Daemon May 24 09:07:51 tessa volumio[813]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 24 09:07:51 tessa volumio[813]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid May 24 09:07:51 tessa volumio[813]: error: [MyVolumio PluginManager] Cache data is invalid! May 24 09:07:51 tessa volumio[813]: info: Setting Geolocation for MyVolumio to us3 May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:51 tessa volumio[813]: info: Successfully Added MyVolumio device May 24 09:07:51 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... May 24 09:07:51 tessa volumio[813]: info: [1748095671698] Starting BluetoothController May 24 09:07:51 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... May 24 09:07:52 tessa volumio[813]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom May 24 09:07:52 tessa sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom May 24 09:07:52 tessa sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:52 tessa sudo[1223]: pam_unix(sudo:session): session closed for user root May 24 09:07:52 tessa systemd[1]: systemd-fsckd.service: Succeeded. May 24 09:07:52 tessa volumio[813]: info: MRS: MultiRoom plugin initialized May 24 09:07:52 tessa volumio[813]: info: MRS: STOPPING SNAPCLIENT May 24 09:07:52 tessa volumio[813]: info: MRS: Snap server stop May 24 09:07:52 tessa sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient May 24 09:07:52 tessa sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:52 tessa volumio[813]: info: MRS: STOPPING volumioStreaming May 24 09:07:52 tessa sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver May 24 09:07:52 tessa sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:52 tessa sudo[1239]: pam_unix(sudo:session): session closed for user root May 24 09:07:52 tessa sudo[1242]: pam_unix(sudo:session): session closed for user root May 24 09:07:52 tessa sudo[1245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming May 24 09:07:52 tessa sudo[1245]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... May 24 09:07:53 tessa sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* May 24 09:07:53 tessa sudo[1245]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa sudo[1248]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "tidal"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... May 24 09:07:53 tessa volumio[813]: info: Preparing to generate the ALSA configuration file May 24 09:07:53 tessa volumio[813]: info: Updating MyVolumio device info May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: Updating MyVolumio device info May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid May 24 09:07:53 tessa volumio[813]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 24 09:07:53 tessa volumio[813]: info: Reading ALSA contributions from plugins. May 24 09:07:53 tessa volumio[813]: info: Successfully Added MyVolumio device May 24 09:07:53 tessa volumio[813]: info: MRS: Removed streaming files May 24 09:07:53 tessa volumio[813]: info: MRS: volumioStreaming STOPPED May 24 09:07:53 tessa volumio[813]: info: MRS: SNAPSERVER STOPPED May 24 09:07:53 tessa volumio[813]: info: MRS: SNAPCLIENT STOPPED May 24 09:07:53 tessa volumio[813]: info: Asound.conf file unchanged, so no further update is needed May 24 09:07:53 tessa volumio[813]: info: Output device has changed, restarting MPD May 24 09:07:53 tessa sudo[1251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:07:53 tessa sudo[1251]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa volumio[813]: info: Output device has changed, restarting Shairport Sync May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa sudo[1251]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa sudo[1254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:07:53 tessa sudo[1254]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa systemd[1]: Stopping Music Player Daemon... May 24 09:07:53 tessa volumio[813]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:07:53 tessa volumio[813]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa systemd[1]: mpd.service: Succeeded. May 24 09:07:53 tessa systemd[1]: Stopped Music Player Daemon. May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 24 09:07:53 tessa sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name tessa May 24 09:07:53 tessa sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa volumio[813]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio May 24 09:07:53 tessa volumio[813]: info: Adding METAVOLUMIO REST API Endpoints May 24 09:07:53 tessa volumio[813]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 24 09:07:53 tessa volumio[813]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 24 09:07:53 tessa volumio[813]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 24 09:07:53 tessa volumio[813]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs May 24 09:07:53 tessa volumio[813]: info: Adding inputs REST Endpoints May 24 09:07:53 tessa volumio[813]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs May 24 09:07:53 tessa volumio[813]: info: Scanning Audio Inputs May 24 09:07:53 tessa systemd[1]: Starting Music Player Daemon... May 24 09:07:53 tessa sudo[1263]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: Checking against Known Cards name May 24 09:07:53 tessa volumio[813]: info: Checking against Known Cards name May 24 09:07:53 tessa volumio[813]: info: Adding Server instance for streaming May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio May 24 09:07:53 tessa volumio[813]: error: Hi Res Audio Failed Login: Missing Login Data May 24 09:07:53 tessa volumio[813]: info: Adding HIGHRESAUDIO REST API Endpoints May 24 09:07:53 tessa volumio[813]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting May 24 09:07:53 tessa volumio[813]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect May 24 09:07:53 tessa volumio[813]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect May 24 09:07:53 tessa volumio[813]: info: QobuzConnect: Starting Qobuz Connect socket and service May 24 09:07:53 tessa sudo[1261]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 24 09:07:53 tessa sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa sudo[1261]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections May 24 09:07:53 tessa volumio[813]: info: Stopping AccessToken refresher cron May 24 09:07:53 tessa sudo[1275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 24 09:07:53 tessa sudo[1275]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa sudo[1275]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: AccessToken refresher cron started May 24 09:07:53 tessa volumio[813]: info: Stopping AccessToken refresher cron for QOBUZ May 24 09:07:53 tessa volumio[813]: info: AccessToken refresher cron started for QOBUZ May 24 09:07:53 tessa volumio[813]: info: Adding TIDAL REST API Endpoints May 24 09:07:53 tessa volumio[813]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 24 09:07:53 tessa volumio[813]: info: Adding QOBUZ REST API Endpoints May 24 09:07:53 tessa volumio[813]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 24 09:07:53 tessa sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 24 09:07:53 tessa sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa volumio[813]: info: Bluetooth name changed to tessa May 24 09:07:53 tessa volumio[813]: info: MPD Permissions set May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa systemd[1]: Started Volumio Qobuz Connect Service. May 24 09:07:53 tessa sudo[1278]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: [Metrics] CommandRouter: 25s 361.64ms May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::volumiosetStartupVolume May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::Close All Modals sent May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::Close All Modals sent May 24 09:07:53 tessa volumio[813]: info: Starting Shairport Sync May 24 09:07:53 tessa sudo[1287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:07:53 tessa sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:53 tessa volumio[813]: info: Executing endpoint qc_getconfig May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.775 [1281.1281] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 24 09:07:53 tessa volumio[813]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 24 09:07:53 tessa volumio[813]: info: QobuzConnect: QOBUZ Connect daemon connected May 24 09:07:53 tessa systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 24 09:07:53 tessa volumio[813]: info: MRS: Found cast device: C4A-15c6dbc6d5033a14d636ac15eb8f1d00 May 24 09:07:53 tessa systemd[1]: shairport-sync.service: Succeeded. May 24 09:07:53 tessa volumio[813]: info: Adding audio output: May 24 09:07:53 tessa systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.876 [1281.1281] INFO VolumeManager: [0x127cc50]: Setting new playback volume: 75 May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.876 [1281.1281] INFO VolumeManager: [0x127cc50]: Setting new mute state: 0 May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.877 [1281.1281] INFO QobuzConnect: [0x127d620]: Client initialized! May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.877 [1281.1281] INFO SampleApp: Starting Avahi advertising, name: tessa, service name: _qobuz-connect._tcp May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.884 [1281.1281] INFO LocalConfigManager: [0x127c530]: Starting Local Configuration server May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.884 [1281.1281] INFO SampleApp: Starting Local configuration server May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.885 [1281.1281] INFO SampleApp: Connected to UNIX socket client 0x1271f60 May 24 09:07:53 tessa volumio[813]: info: Successfully Updated MyVolumio device May 24 09:07:53 tessa volumio[813]: info: Successfully Updated MyVolumio device May 24 09:07:53 tessa systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:07:53 tessa sudo[1287]: pam_unix(sudo:session): session closed for user root May 24 09:07:53 tessa volumio[813]: info: Shairport-Sync Started May 24 09:07:53 tessa qobuz-connect[1281]: 20250524 09:07:53.925 [1281.1281] INFO SampleApp: Playback volume changed: 75 May 24 09:07:53 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:53 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:54 tessa mpd[1276]: May 24 09:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 24 09:07:54 tessa systemd[1]: Started Music Player Daemon. May 24 09:07:54 tessa sudo[1254]: pam_unix(sudo:session): session closed for user root May 24 09:07:54 tessa volumio[813]: error: updateQueue error: null May 24 09:07:54 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 24 09:07:54 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 24 09:07:54 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 24 09:07:54 tessa systemd[1]: systemd-hostnamed.service: Succeeded. May 24 09:07:55 tessa sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service May 24 09:07:55 tessa sudo[1305]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:55 tessa systemd[1]: Started MyVolumio SSH Tunnel. May 24 09:07:55 tessa sudo[1305]: pam_unix(sudo:session): session closed for user root May 24 09:07:55 tessa volumio[813]: info: Remote SSH Started May 24 09:07:55 tessa autossh[1308]: port set to 0, monitoring disabled May 24 09:07:55 tessa autossh[1308]: starting ssh (count 1) May 24 09:07:55 tessa autossh[1308]: ssh child pid is 1311 May 24 09:07:56 tessa volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 24 09:07:56 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:07:56 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:07:56 tessa volumiossh-tunnel[1307]: Warning: Permanently added '[us3.myvolumio.org]:2222,[159.203.57.91]:2222' (RSA) to the list of known hosts. May 24 09:07:56 tessa sudo[1313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 24 09:07:56 tessa sudo[1313]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:56 tessa systemd[1]: Started Volumio Bluetooth Module. May 24 09:07:56 tessa sudo[1313]: pam_unix(sudo:session): session closed for user root May 24 09:07:56 tessa sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 24 09:07:56 tessa sudo[1316]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:56 tessa volumiobt[1315]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 24 09:07:56 tessa volumio[813]: info: Volumio BT Module successfully started May 24 09:07:56 tessa sudo[1316]: pam_unix(sudo:session): session closed for user root May 24 09:07:57 tessa volumio[813]: info: Discovery: adding 232d2322-2bde-4751-abde-d5d4ccc208a4 May 24 09:07:57 tessa volumio[813]: info: Discovery: Found device Freckles May 24 09:07:57 tessa volumio[813]: info: Discovery: Connecting to remote: 192.168.10.201 May 24 09:07:57 tessa sudo[1320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 24 09:07:57 tessa sudo[1320]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:07:57 tessa volumiobt[1315]: pulseaudio: no process found May 24 09:07:57 tessa sudo[1320]: pam_unix(sudo:session): session closed for user root May 24 09:07:57 tessa dbus-daemon[573]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.24' (uid=1000 pid=1324 comm="/usr/bin/pulseaudio --high-priority=true ") May 24 09:07:57 tessa systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 24 09:07:57 tessa volumio[813]: ------------------------------------ BT MESSAGE: BT STATUS: running May 24 09:07:57 tessa dbus-daemon[573]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 24 09:07:57 tessa systemd[1]: Started RealtimeKit Scheduling Policy Service. May 24 09:07:57 tessa rtkit-daemon[1325]: Successfully called chroot. May 24 09:07:57 tessa rtkit-daemon[1325]: Successfully dropped privileges. May 24 09:07:57 tessa rtkit-daemon[1325]: Successfully limited resources. May 24 09:07:57 tessa rtkit-daemon[1325]: Running. May 24 09:07:57 tessa rtkit-daemon[1325]: Canary thread running. May 24 09:07:57 tessa rtkit-daemon[1325]: Watchdog thread running. May 24 09:07:57 tessa dbus-daemon[573]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.25' (uid=0 pid=1325 comm="/usr/lib/rtkit/rtkit-daemon ") May 24 09:07:57 tessa systemd[1]: Starting Authorization Manager... May 24 09:07:57 tessa volumio[813]: ------------------------------------ BT MESSAGE: BT STATUS: running May 24 09:07:57 tessa polkitd[1328]: started daemon version 0.105 using authority implementation `local' version `0.105' May 24 09:07:57 tessa dbus-daemon[573]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 24 09:07:57 tessa systemd[1]: Started Authorization Manager. May 24 09:07:57 tessa volumio[1126]: ............................................................................................................................................................................................++++ May 24 09:07:58 tessa pulseaudio[1324]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 24 09:07:58 tessa pulseaudio[1324]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 24 09:07:58 tessa volumiobt[1315]: Applying permissions May 24 09:07:58 tessa volumiobt[1315]: Setting BT discoverable and pairable May 24 09:07:58 tessa bluetoothd[664]: Endpoint registered: sender=:1.45 path=/MediaEndpoint/A2DPSource May 24 09:07:58 tessa pulseaudio[1324]: 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 May 24 09:07:58 tessa bluetoothd[664]: Endpoint registered: sender=:1.45 path=/MediaEndpoint/A2DPSink May 24 09:07:58 tessa kernel: Bluetooth: RFCOMM TTY layer initialized May 24 09:07:58 tessa kernel: Bluetooth: RFCOMM socket layer initialized May 24 09:07:58 tessa kernel: Bluetooth: RFCOMM ver 1.11 May 24 09:07:58 tessa volumiobt[1315]: [CHG] Controller D8:3A:DD:26:E1:87 UUIDs: 00001112-0000-1000-8000-00805f9b34fb May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [55B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [117B blob data] May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# -e power on May 24 09:07:58 tessa volumiobt[1315]: Invalid command in menu main: -e May 24 09:07:58 tessa volumiobt[1315]: May 24 09:07:58 tessa volumiobt[1315]: Use "help" for a list of available commands in a menu. May 24 09:07:58 tessa volumiobt[1315]: Use "menu " if you want to enter any submenu. May 24 09:07:58 tessa volumiobt[1315]: Use "back" if you want to return to menu main. May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# agent on May 24 09:07:58 tessa volumiobt[1315]: Agent is already registered May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# discoverable on May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# pairable on May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# agent NoInputNoOutput May 24 09:07:58 tessa volumiobt[1315]: Agent is already registered May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# default-agent May 24 09:07:58 tessa volumiobt[1315]: [bluetooth]# quit May 24 09:07:58 tessa volumiobt[1315]: [59B blob data] May 24 09:07:58 tessa volumio[813]: info: MRS: Getting audio outputs on start May 24 09:07:58 tessa volumio[813]: info: MRS: Requesting all other devices output May 24 09:07:59 tessa volumio[813]: info: MRS: Pushing audio output on request May 24 09:07:59 tessa volumio[813]: info: MRS: Pushing multiroomSync output May 24 09:07:59 tessa volumio[813]: info: Discovery: Connected to remote: 192.168.10.201 May 24 09:08:00 tessa volumio[813]: verbose: New Socket.io Connection to 192.168.10.67:3000 from 192.168.10.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 24 09:08:00 tessa volumio[1126]: ........................++++ May 24 09:08:00 tessa volumio[1126]: e is 65537 (0x010001) May 24 09:08:00 tessa volumio[1126]: writing RSA key May 24 09:08:00 tessa volumio[813]: info: BOOT COMPLETED May 24 09:08:01 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 24 09:08:01 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:08:01 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:08:02 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 24 09:08:02 tessa volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 24 09:08:02 tessa volumio[813]: info: CoreCommandRouter::volumioGetState May 24 09:08:02 tessa volumio[813]: info: CorePlayQueue::getTrack 0 May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::volumioGetBrowseSources May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:08:07 tessa volumio-remote-updater[554]: No test mode May 24 09:08:07 tessa volumio-remote-updater[554]: No alpha test mode May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 24 09:08:07 tessa volumio[813]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 24 09:08:07 tessa volumio[813]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 24 09:08:11 tessa systemd[1]: systemd-timedated.service: Succeeded. May 24 09:08:26 tessa volumio[813]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:08:26 tessa volumio[813]: TypeError: Cannot read property 'id' of null May 24 09:08:26 tessa volumio[813]: at multiroom.disableMultiroomSyncOutput (/myvolumio/plugins/audio_interface/multiroom/multiroom_real:1:17182) May 24 09:08:26 tessa volumio[813]: at CoreCommandRouter.disableMultiroomSyncOutput (/volumio/app/index.js:1298:23) May 24 09:08:26 tessa volumio[813]: at Socket. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:285:28) May 24 09:08:26 tessa volumio[813]: at Socket.Emitter.emit (/volumio/node_modules/socket.io-client/node_modules/component-emitter/index.js:133:20) May 24 09:08:26 tessa volumio[813]: at Socket.onevent (/volumio/node_modules/socket.io-client/lib/socket.js:278:10) May 24 09:08:26 tessa volumio[813]: at Socket.onpacket (/volumio/node_modules/socket.io-client/lib/socket.js:236:12) May 24 09:08:26 tessa volumio[813]: at Manager. (/volumio/node_modules/component-bind/index.js:21:15) May 24 09:08:26 tessa volumio[813]: at Manager.Emitter.emit (/volumio/node_modules/socket.io-client/node_modules/component-emitter/index.js:133:20) May 24 09:08:26 tessa volumio[813]: at Manager.ondecoded (/volumio/node_modules/socket.io-client/lib/manager.js:345:8) May 24 09:08:26 tessa volumio[813]: at Decoder. (/volumio/node_modules/component-bind/index.js:21:15) May 24 09:08:26 tessa volumio[813]: at Decoder.Emitter.emit (/volumio/node_modules/socket.io-client/node_modules/socket.io-parser/node_modules/component-emitter/index.js:145:20) May 24 09:08:26 tessa volumio[813]: at Decoder.add (/volumio/node_modules/socket.io-client/node_modules/socket.io-parser/index.js:254:12) May 24 09:08:26 tessa volumio[813]: at Manager.ondata (/volumio/node_modules/socket.io-client/lib/manager.js:335:16) May 24 09:08:26 tessa volumio[813]: at Socket. (/volumio/node_modules/component-bind/index.js:21:15) May 24 09:08:26 tessa volumio[813]: at Socket.Emitter.emit (/volumio/node_modules/engine.io-client/node_modules/component-emitter/index.js:145:20) May 24 09:08:26 tessa volumio[813]: at Socket.onPacket (/volumio/node_modules/engine.io-client/lib/socket.js:461:14) May 24 09:08:26 tessa volumio[813]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:08:26 tessa sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-24 09:07 May 24 09:08:26 tessa sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"