-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-10-30 11:12:46 CET. -- Oct 30 11:12:31 alek systemd-timedated[1280]: Changed local time to Thu Oct 30 11:12:31 2025 Oct 30 11:12:31 alek sudo[1274]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:31 alek systemd[1]: Starting Daily man-db regeneration... Oct 30 11:12:31 alek systemd[1]: Starting Daily apt download activities... Oct 30 11:12:31 alek volumio[1144]: info: Loading plugin "network"... Oct 30 11:12:31 alek volumio-time-update[604]: volumio-time-update-util: System time updated successfully. Oct 30 11:12:31 alek systemd[1]: Started Volumio Time Update Utility. Oct 30 11:12:31 alek volumio[1144]: info: Refreshing Cached IP Addresses Oct 30 11:12:31 alek volumio[1144]: info: Loading plugin "services"... Oct 30 11:12:31 alek volumio[1144]: info: Loading plugin "alsa_controller"... Oct 30 11:12:31 alek sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 30 11:12:31 alek sudo[1291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 30 11:12:31 alek sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 30 11:12:31 alek sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:31 alek sudo[1291]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:31 alek sudo[1291]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:31 alek sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:31 alek sudo[1293]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:31 alek dhcpcd[1119]: eth0: using IPv4LL address 169.254.210.152 Oct 30 11:12:31 alek avahi-daemon[587]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.210.152. Oct 30 11:12:31 alek avahi-daemon[587]: New relevant interface eth0.IPv4 for mDNS. Oct 30 11:12:31 alek avahi-daemon[587]: Registering new address record for 169.254.210.152 on eth0.IPv4. Oct 30 11:12:31 alek dhcpcd[1119]: eth0: adding route to 169.254.0.0/16 Oct 30 11:12:31 alek systemd[1]: man-db.service: Succeeded. Oct 30 11:12:31 alek systemd[1]: Started Daily man-db regeneration. Oct 30 11:12:31 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 30 11:12:31 alek volumio[1144]: info: Loading plugin "wizard"... Oct 30 11:12:31 alek volumio[1144]: info: Loading plugin "networkfs"... Oct 30 11:12:31 alek volumio[1144]: info: Starting Udev Watcher for removable devices Oct 30 11:12:31 alek volumio[1144]: info: Ignoring mount for partition: BOOT Oct 30 11:12:31 alek volumio[1144]: info: Ignoring mount for partition: volumio Oct 30 11:12:31 alek volumio[1144]: info: Ignoring mount for partition: volumio_data Oct 30 11:12:31 alek volumio[1144]: info: Mounting Device Elements Oct 30 11:12:31 alek sh[506]: eth0: using IPv4LL address 169.254.210.152 Oct 30 11:12:31 alek sh[506]: eth0: adding route to 169.254.0.0/16 Oct 30 11:12:31 alek sh[506]: eth0: adding default route Oct 30 11:12:31 alek dhcpcd[553]: eth0: using IPv4LL address 169.254.210.152 Oct 30 11:12:31 alek dhcpcd[553]: eth0: adding route to 169.254.0.0/16 Oct 30 11:12:31 alek dhcpcd[553]: eth0: adding default route Oct 30 11:12:31 alek sudo[1387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Elements -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 30 11:12:31 alek sh[506]: forked to background, child pid 1404 Oct 30 11:12:31 alek dhcpcd[553]: forked to background, child pid 1404 Oct 30 11:12:31 alek sudo[1387]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:31 alek sudo[1302]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:31 alek sh[506]: eth0=eth0 Oct 30 11:12:31 alek ifplugd(eth0)[803]: client: ifup: interface eth0 already configured Oct 30 11:12:31 alek ifplugd(eth0)[803]: Program executed successfully. Oct 30 11:12:31 alek ifplugd[746]: Network Interface Plugging Daemon...start eth0...done. Oct 30 11:12:31 alek systemd[1]: Started LSB: Brings up/down network automatically. Oct 30 11:12:31 alek systemd[1]: Reached target Multi-User System. Oct 30 11:12:31 alek systemd[1]: Reached target Graphical Interface. Oct 30 11:12:31 alek systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 30 11:12:31 alek systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 30 11:12:31 alek systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 30 11:12:31 alek ntpd[1118]: Soliciting pool server 129.152.16.145 Oct 30 11:12:31 alek ntpd[1118]: Soliciting pool server 95.110.254.234 Oct 30 11:12:31 alek ntpd[1118]: Soliciting pool server 85.199.214.99 Oct 30 11:12:32 alek systemd[1]: apt-daily.service: Succeeded. Oct 30 11:12:32 alek systemd[1]: Started Daily apt download activities. Oct 30 11:12:32 alek systemd[1]: Starting Daily apt upgrade and clean activities... Oct 30 11:12:32 alek sudo[1387]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:32 alek ntfs-3g[1487]: Version 2017.3.23AR.3 integrated FUSE 28 Oct 30 11:12:32 alek ntfs-3g[1487]: Mounted /dev/sda1 (Read-Write, label "Elements", NTFS 3.1) Oct 30 11:12:32 alek ntfs-3g[1487]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 30 11:12:32 alek ntfs-3g[1487]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Oct 30 11:12:32 alek ntfs-3g[1487]: Global ownership and permissions enforced, configuration type 7 Oct 30 11:12:32 alek ntpd[1118]: Listen normally on 4 eth0 169.254.210.152:123 Oct 30 11:12:32 alek ntpd[1118]: 93.94.88.51 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: 31.14.133.122 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: 185.157.229.254 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: 151.22.209.90 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: 185.19.184.35 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: 172.232.208.229 local addr 192.168.1.66 -> 169.254.210.152 Oct 30 11:12:32 alek ntpd[1118]: new interface(s) found: waking up resolver Oct 30 11:12:32 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 30 11:12:32 alek volumio[1144]: info: Loading plugin "volumio_command_line_client"... Oct 30 11:12:32 alek volumio[1144]: info: Loading plugin "upnp"... Oct 30 11:12:32 alek volumio[1144]: info: [1761819152816] Starting Upmpd Daemon Oct 30 11:12:32 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 30 11:12:32 alek volumio[1144]: info: Loading plugin "my_music"... Oct 30 11:12:32 alek volumio[1144]: info: Loading plugin "mpd"... Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "upnp_browser"... Oct 30 11:12:33 alek systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 30 11:12:33 alek systemd[1]: Started Daily apt upgrade and clean activities. Oct 30 11:12:33 alek systemd[1]: Startup finished in 15.363s (kernel) + 20.209s (userspace) = 35.573s. Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "alarm-clock"... Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "airplay_emulation"... Oct 30 11:12:33 alek volumio[1144]: info: Starting Shairport Sync Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "last_100"... Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "webradio"... Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "i2s_dacs"... Oct 30 11:12:33 alek dhcpcd[1404]: eth0: leased 192.168.1.130 for 86400 seconds Oct 30 11:12:33 alek dhcpcd[1404]: eth0: adding route to 192.168.1.0/24 Oct 30 11:12:33 alek avahi-daemon[587]: Registering new address record for 192.168.1.130 on eth0.IPv4. Oct 30 11:12:33 alek dhcpcd[1404]: eth0: changing default route via 192.168.1.254 Oct 30 11:12:33 alek volumio[1144]: info: I2S DAC not set, start Auto-detection Oct 30 11:12:33 alek volumio[1144]: info: Loading plugin "volumiodiscovery"... Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 30 11:12:33 alek node[1144]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 30 11:12:33 alek node[1144]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** For more information see Oct 30 11:12:33 alek node[1144]: *** WARNING *** For more information see Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 30 11:12:33 alek node[1144]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 30 11:12:33 alek node[1144]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 30 11:12:33 alek volumio[1144]: *** WARNING *** For more information see Oct 30 11:12:33 alek node[1144]: *** WARNING *** For more information see Oct 30 11:12:33 alek volumio[1144]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 30 11:12:33 alek volumio[1144]: info: Discovery: Started advertising with name: Alek Oct 30 11:12:34 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 30 11:12:34 alek volumio[1144]: info: Loading plugin "spop"... Oct 30 11:12:34 alek ntpd[1118]: ntpd exiting on signal 15 (Terminated) Oct 30 11:12:34 alek ntpd[1118]: 172.232.209.103 local addr 192.168.1.66 -> Oct 30 11:12:34 alek systemd[1]: Stopping Network Time Service... Oct 30 11:12:34 alek ntpd[1118]: 172.232.208.229 local addr 169.254.210.152 -> Oct 30 11:12:34 alek ntpd[1118]: 195.32.70.195 local addr 192.168.1.66 -> Oct 30 11:12:34 alek ntpd[1118]: 185.19.184.35 local addr 169.254.210.152 -> Oct 30 11:12:34 alek ntpd[1118]: 212.6.50.243 local addr 192.168.1.66 -> Oct 30 11:12:34 alek ntpd[1118]: 193.204.114.232 local addr 192.168.1.66 -> Oct 30 11:12:34 alek ntpd[1118]: 151.22.209.90 local addr 169.254.210.152 -> Oct 30 11:12:34 alek ntpd[1118]: 185.157.229.254 local addr 169.254.210.152 -> Oct 30 11:12:34 alek ntpd[1118]: 31.14.133.122 local addr 169.254.210.152 -> Oct 30 11:12:34 alek ntpd[1118]: 93.94.88.51 local addr 169.254.210.152 -> Oct 30 11:12:34 alek systemd[1]: ntp.service: Succeeded. Oct 30 11:12:34 alek systemd[1]: Stopped Network Time Service. Oct 30 11:12:34 alek systemd[1]: Starting Network Time Service... Oct 30 11:12:34 alek ntpd[1571]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 30 11:12:34 alek ntpd[1571]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 30 11:12:34 alek systemd[1]: Started Network Time Service. Oct 30 11:12:34 alek avahi-daemon[587]: Withdrawing address record for 169.254.210.152 on eth0. Oct 30 11:12:34 alek avahi-daemon[587]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.210.152. Oct 30 11:12:34 alek dhcpcd[1404]: eth0: deleting route to 169.254.0.0/16 Oct 30 11:12:34 alek avahi-daemon[587]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.130. Oct 30 11:12:34 alek ntpd[1577]: proto: precision = 0.583 usec (-21) Oct 30 11:12:34 alek ntpd[1577]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 30 11:12:34 alek ntpd[1577]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 30 11:12:34 alek ntpd[1577]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1038 days ago Oct 30 11:12:34 alek ntpd[1577]: Listen and drop on 0 v6wildcard [::]:123 Oct 30 11:12:34 alek ntpd[1577]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 30 11:12:34 alek ntpd[1577]: Listen normally on 2 lo 127.0.0.1:123 Oct 30 11:12:34 alek ntpd[1577]: Listen normally on 3 eth0 192.168.1.130:123 Oct 30 11:12:34 alek ntpd[1577]: Listen normally on 4 wlan0 192.168.1.66:123 Oct 30 11:12:34 alek ntpd[1577]: Listening on routing socket on fd #21 for interface updates Oct 30 11:12:34 alek ntpd[1577]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Oct 30 11:12:34 alek ntpd[1577]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Oct 30 11:12:34 alek dhcpcd[1119]: eth0: leased 192.168.1.130 for 86400 seconds Oct 30 11:12:34 alek dhcpcd[1119]: eth0: adding route to 192.168.1.0/24 Oct 30 11:12:34 alek dhcpcd[1119]: eth0: adding default route via 192.168.1.254 Oct 30 11:12:34 alek ntpd[1577]: ntpd exiting on signal 15 (Terminated) Oct 30 11:12:34 alek systemd[1]: Stopping Network Time Service... Oct 30 11:12:34 alek systemd[1]: ntp.service: Succeeded. Oct 30 11:12:34 alek systemd[1]: Stopped Network Time Service. Oct 30 11:12:34 alek systemd[1]: Starting Network Time Service... Oct 30 11:12:35 alek ntpd[1634]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 30 11:12:35 alek ntpd[1634]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 30 11:12:35 alek systemd[1]: Started Network Time Service. Oct 30 11:12:35 alek dhcpcd[1119]: eth0: deleting route to 169.254.0.0/16 Oct 30 11:12:35 alek ntpd[1640]: proto: precision = 0.583 usec (-21) Oct 30 11:12:35 alek ntpd[1640]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 30 11:12:35 alek ntpd[1640]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 30 11:12:35 alek ntpd[1640]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1038 days ago Oct 30 11:12:35 alek ntpd[1640]: Listen and drop on 0 v6wildcard [::]:123 Oct 30 11:12:35 alek ntpd[1640]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 30 11:12:35 alek ntpd[1640]: Listen normally on 2 lo 127.0.0.1:123 Oct 30 11:12:35 alek ntpd[1640]: Listen normally on 3 eth0 192.168.1.130:123 Oct 30 11:12:35 alek ntpd[1640]: Listen normally on 4 wlan0 192.168.1.66:123 Oct 30 11:12:35 alek ntpd[1640]: Listening on routing socket on fd #21 for interface updates Oct 30 11:12:35 alek ntpd[1640]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 30 11:12:35 alek ntpd[1640]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "outputs"... Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "albumart"... Oct 30 11:12:35 alek volumio[1144]: info: Plugin example_plugin is not enabled Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "inputs"... Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "updater_comm"... Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252000, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 30 11:12:35 alek nmbd[749]: Packet send failed to 169.254.255.255(137) ERRNO=Invalid argument Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252193, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Oct 30 11:12:35 alek nmbd[749]: retransmit_or_expire_response_records: Failed to resend packet id 26960 to IP 169.254.255.255 on subnet 169.254.210.152 Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252256, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 30 11:12:35 alek nmbd[749]: Packet send failed to 169.254.255.255(137) ERRNO=Invalid argument Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252315, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Oct 30 11:12:35 alek nmbd[749]: retransmit_or_expire_response_records: Failed to resend packet id 26961 to IP 169.254.255.255 on subnet 169.254.210.152 Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252365, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 30 11:12:35 alek nmbd[749]: Packet send failed to 169.254.255.255(137) ERRNO=Invalid argument Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252417, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Oct 30 11:12:35 alek nmbd[749]: retransmit_or_expire_response_records: Failed to resend packet id 26962 to IP 169.254.255.255 on subnet 169.254.210.152 Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252473, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 30 11:12:35 alek nmbd[749]: Packet send failed to 169.254.255.255(137) ERRNO=Invalid argument Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252522, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Oct 30 11:12:35 alek nmbd[749]: retransmit_or_expire_response_records: Failed to resend packet id 26963 to IP 169.254.255.255 on subnet 169.254.210.152 Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252576, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 30 11:12:35 alek nmbd[749]: Packet send failed to 169.254.255.255(137) ERRNO=Invalid argument Oct 30 11:12:35 alek nmbd[749]: [2025/10/30 11:12:35.252623, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Oct 30 11:12:35 alek nmbd[749]: retransmit_or_expire_response_records: Failed to resend packet id 26964 to IP 169.254.255.255 on subnet 169.254.210.152 Oct 30 11:12:35 alek volumio[1144]: info: Plugin mpdemulation is not enabled Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "rest_api"... Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "websocket"... Oct 30 11:12:35 alek volumio[1144]: info: Starting Socket.io Server version 2.3.0 Oct 30 11:12:35 alek volumio[1144]: info: Loading plugin "fusiondsp"... Oct 30 11:12:35 alek volumio[1144]: Forking 3 albumart workers Oct 30 11:12:35 alek volumio[1144]: info: Applying required configuration parameters for plugin fusiondsp Oct 30 11:12:35 alek volumio[1144]: info: Loading i18n strings for locale it Oct 30 11:12:35 alek volumio[1144]: Updating browse sources language Oct 30 11:12:35 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 11:12:35 alek volumio[1144]: Starting albumart workers Oct 30 11:12:36 alek ntpd[1640]: Soliciting pool server 172.232.209.103 Oct 30 11:12:36 alek volumio[1144]: Starting albumart workers Oct 30 11:12:36 alek volumio[1144]: Starting albumart workers Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::initPlayerControls Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 11:12:36 alek volumio[1144]: Express server listening on port 3000 Oct 30 11:12:36 alek volumio[1144]: [Metrics] WebUI: 8s 13.73ms Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::resetVolumioState Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::getcurrentVolume Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:36 alek volumio[1144]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 30 11:12:36 alek volumio[1144]: info: Completed loading Core Plugins Oct 30 11:12:36 alek volumio[1144]: info: Preparing to generate the ALSA configuration file Oct 30 11:12:36 alek volumio[1144]: info: Volumio Network Manager: Network status updated: 2 Oct 30 11:12:36 alek volumio[1144]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 30 11:12:36 alek volumio[1144]: info: Reading ALSA contributions from plugins. Oct 30 11:12:36 alek volumio[1144]: info: Reloading queue from file Oct 30 11:12:36 alek volumio[1144]: info: VolumeController:: Volume=100 Mute =false Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::pushState Oct 30 11:12:36 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::volumioPushState Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::updateTrackBlock Oct 30 11:12:36 alek volumio[1144]: info: CorePlayQueue::getTrackBlock Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 11:12:36 alek volumio[1144]: info: Setting Device type: Tinkerboard Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::setRepeat null single undefined Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::pushState Oct 30 11:12:36 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::volumioPushState Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::setRandom null Oct 30 11:12:36 alek volumio[1144]: info: CoreStateMachine::pushState Oct 30 11:12:36 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:36 alek volumio[1144]: info: CoreCommandRouter::volumioPushState Oct 30 11:12:37 alek ntpd[1640]: Soliciting pool server 185.19.184.35 Oct 30 11:12:37 alek volumio[1144]: info: Asound.conf file unchanged, so no further update is needed Oct 30 11:12:37 alek volumio[1144]: info: Output device has changed, restarting MPD Oct 30 11:12:37 alek ntpd[1640]: Soliciting pool server 195.32.70.195 Oct 30 11:12:37 alek volumio[1144]: info: Output device has changed, restarting Shairport Sync Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: ___________ START PLUGINS ___________ Oct 30 11:12:37 alek volumio[1144]: info: ControllerMpd::onStart: Initializing MPD Oct 30 11:12:37 alek sudo[1774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 11:12:37 alek sudo[1776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 11:12:37 alek volumio[1144]: info: Creating MPD Configuration file Oct 30 11:12:37 alek sudo[1774]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek sudo[1774]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:37 alek sudo[1776]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek sudo[1799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 11:12:37 alek systemd[1]: Stopping Music Player Daemon... Oct 30 11:12:37 alek sudo[1799]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek sudo[1799]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 30 11:12:37 alek volumio[1144]: info: [1761819157201] CoreMusicLibrary::Adding element Server multimediali Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 11:12:37 alek sudo[1810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek sudo[1810]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 30 11:12:37 alek volumio[1144]: info: [1761819157393] CoreMusicLibrary::Adding element Last_100 Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 30 11:12:37 alek volumio[1144]: info: [1761819157395] CoreMusicLibrary::Adding element Webradio Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 30 11:12:37 alek volumio[1144]: info: Initializing BBC Radios Oct 30 11:12:37 alek systemd[1]: mpd.service: Succeeded. Oct 30 11:12:37 alek systemd[1]: Stopped Music Player Daemon. Oct 30 11:12:37 alek systemd[1]: Starting Music Player Daemon... Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: Creating Spotify config file Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: Loading i18n strings for locale it Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: FusionDsp - mixtype--------------------- Hardware Oct 30 11:12:37 alek volumio[1144]: info: Volumio Calling Home Oct 30 11:12:37 alek sudo[1834]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 30 11:12:37 alek sudo[1834]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek sudo[1834]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:37 alek volumio[1144]: info: Preparing to generate the ALSA configuration file Oct 30 11:12:37 alek volumio[1144]: info: Discovery: adding bb71b732-15f8-480b-8316-7f795866b0c2 Oct 30 11:12:37 alek volumio[1144]: info: Discovery: Found device Alek Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioGetState Oct 30 11:12:37 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:37 alek volumio[1144]: info: Discovery: this is already registered, bb71b732-15f8-480b-8316-7f795866b0c2 Oct 30 11:12:37 alek volumio[1144]: info: Discovery: Found device Alek Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioGetState Oct 30 11:12:37 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:37 alek volumio[1144]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 30 11:12:37 alek volumio[1144]: info: Reading ALSA contributions from plugins. Oct 30 11:12:37 alek volumio[1144]: info: MPD Permissions set Oct 30 11:12:37 alek volumio[1144]: info: MPD Permissions set Oct 30 11:12:37 alek volumio[1144]: info: VolumeController:: Volume=100 Mute =false Oct 30 11:12:37 alek volumio[1144]: info: CoreStateMachine::pushState Oct 30 11:12:37 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioPushState Oct 30 11:12:37 alek volumio[1144]: info: Volumio called home Oct 30 11:12:37 alek volumio[1144]: info: Spotify config file written Oct 30 11:12:37 alek volumio[1144]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 30 11:12:37 alek sudo[1870]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek sudo[1870]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek systemd[1]: Started go-librespot Daemon. Oct 30 11:12:37 alek go-librespot[1882]: go-librespot daemon starting... Oct 30 11:12:37 alek sudo[1870]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:37 alek volumio[1144]: info: No need to fix Spotify hosts Oct 30 11:12:37 alek volumio[1144]: info: Starting Shairport Sync Oct 30 11:12:37 alek volumio[1144]: info: Starting Shairport Sync Oct 30 11:12:37 alek volumio[1144]: info: Starting Shairport Sync Oct 30 11:12:37 alek sudo[1898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 11:12:37 alek volumio[1144]: info: CoreCommandRouter::volumioGetState Oct 30 11:12:37 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:37 alek go-librespot[1882]: time="2025-10-30T11:12:37+01:00" level=info msg="running go-librespot 0.4.0" Oct 30 11:12:37 alek go-librespot[1882]: time="2025-10-30T11:12:37+01:00" level=debug msg="app state loaded" Oct 30 11:12:37 alek go-librespot[1882]: time="2025-10-30T11:12:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 30 11:12:37 alek sudo[1903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 11:12:37 alek sudo[1898]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek volumio[1144]: info: Asound.conf file unchanged, so no further update is needed Oct 30 11:12:38 alek volumio[1144]: info: Output device has changed, restarting MPD Oct 30 11:12:38 alek sudo[1903]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek ntpd[1640]: Soliciting pool server 212.6.50.243 Oct 30 11:12:38 alek ntpd[1640]: Soliciting pool server 172.232.208.229 Oct 30 11:12:38 alek sudo[1904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 11:12:38 alek systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 11:12:38 alek systemd[1]: shairport-sync.service: Succeeded. Oct 30 11:12:38 alek systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek ntpd[1640]: Soliciting pool server 31.14.133.122 Oct 30 11:12:38 alek volumio[1144]: info: Output device has changed, restarting Shairport Sync Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:38 alek systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek sudo[1904]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek sudo[1898]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek sudo[1917]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 11:12:38 alek sudo[1920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 11:12:38 alek sudo[1917]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 11:12:38 alek sudo[1920]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 30 11:12:38 alek systemd[1]: shairport-sync.service: Succeeded. Oct 30 11:12:38 alek systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek sudo[1904]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek sudo[1903]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek sudo[1917]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek volumio[1144]: info: Shairport-Sync Started Oct 30 11:12:38 alek volumio[1144]: Error adding Membership: Error: addMembership EINVAL Oct 30 11:12:38 alek volumio[1144]: info: Shairport-Sync Started Oct 30 11:12:38 alek systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 30 11:12:38 alek systemd[1]: mpd.service: Succeeded. Oct 30 11:12:38 alek systemd[1]: Stopped Music Player Daemon. Oct 30 11:12:38 alek systemd[1]: Starting Music Player Daemon... Oct 30 11:12:38 alek volumio[1144]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 30 11:12:38 alek volumio[1144]: SPOTIFY: BQCOmxI7YJ4nRZbt1D7XhRWALi16J67-FmGJnG09R2AVdpvMcPwTTfcSw1DThtA_1fgy7QRLj5MiLdj-s_8Im9efdWiRd15w1BBsE_-sps1ndPz_Z6r2zgyPHe-4go5jNSi6HTMlwdeAMrP4u7NHs3_CQ9Qrzihvme0qLY2Rzhn7e2y8L-xUvwfhB3N-M6AL4K3beRNEanlCx5_xU_t8EQxlECJ_k7CNtW3QuZ628jRrf-KLCs5BjLrTiHibWqB7Tr5kLZi6DakunbWuBq7mJoLuerfURUQDukFvVHMyFWGDwx1qcFBBHd4 Oct 30 11:12:38 alek volumio[1144]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 30 11:12:38 alek volumio[1144]: info: New Spotify access token = BQCOmxI7YJ4nRZbt1D7XhRWALi16J67-FmGJnG09R2AVdpvMcPwTTfcSw1DThtA_1fgy7QRLj5MiLdj-s_8Im9efdWiRd15w1BBsE_-sps1ndPz_Z6r2zgyPHe-4go5jNSi6HTMlwdeAMrP4u7NHs3_CQ9Qrzihvme0qLY2Rzhn7e2y8L-xUvwfhB3N-M6AL4K3beRNEanlCx5_xU_t8EQxlECJ_k7CNtW3QuZ628jRrf-KLCs5BjLrTiHibWqB7Tr5kLZi6DakunbWuBq7mJoLuerfURUQDukFvVHMyFWGDwx1qcFBBHd4 Oct 30 11:12:38 alek volumio[1144]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 30 11:12:38 alek volumio[1144]: info: Shairport-Sync Started Oct 30 11:12:38 alek volumio[1144]: info: MPD Permissions set Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:38 alek volumio[1144]: info: Starting Shairport Sync Oct 30 11:12:38 alek sudo[1962]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 30 11:12:38 alek volumio[1144]: SPOTIFY: User informations: {"country":"IT","display_name":"ALESSANDRO","email":"ale.costa.ge@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31qvncskkpgvyqz3ax7gplueuhq4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31qvncskkpgvyqz3ax7gplueuhq4","id":"31qvncskkpgvyqz3ax7gplueuhq4","images":[],"product":"premium","type":"user","uri":"spotify:user:31qvncskkpgvyqz3ax7gplueuhq4"} Oct 30 11:12:38 alek volumio[1144]: info: Spotify Successfully logged in Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=info msg="zeroconf server listening on port 33558" Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 30 11:12:38 alek volumio[1144]: info: [1761819158707] CoreMusicLibrary::Adding element Spotify Oct 30 11:12:38 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 11:12:38 alek volumio[1144]: Cannot find translation for source Spotify Oct 30 11:12:38 alek sudo[1992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 11:12:38 alek sudo[1962]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek sudo[1962]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="obtained new client token: AADAG77z/MtlsToahSXhSXh8bN23rB4TDlNXAMLbGHrC5BRQimH6XtHCmX2zP1eftqK4q2kJu7bzZrCa6BmHIG6PWi6NiAkrpr7ELbsJTcYM4TG4sseUjEQdA/n+MLO5y2f7wtGQtaSr9wD60MTVvsL8b6pQ/HxA66x4opYUJYBrqZf+CvIvTUf6rsu48064PIMg3dHadWKqbiEGoe31JsUzcSgCiOVblC/BDPhb46dBSP5HzsgAlTSk" Oct 30 11:12:38 alek sudo[1992]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 30 11:12:38 alek systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 11:12:38 alek systemd[1]: shairport-sync.service: Succeeded. Oct 30 11:12:38 alek systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="completed keyexchange" Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=debug msg="completed challenge" Oct 30 11:12:38 alek systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 11:12:38 alek sudo[1992]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:38 alek go-librespot[1882]: time="2025-10-30T11:12:38+01:00" level=info msg="authenticated AP" username="31************************q4" Oct 30 11:12:38 alek volumio[1144]: info: Shairport-Sync Started Oct 30 11:12:39 alek ntpd[1640]: Soliciting pool server 95.110.254.234 Oct 30 11:12:39 alek ntpd[1640]: Soliciting pool server 151.22.209.90 Oct 30 11:12:39 alek ntpd[1640]: Soliciting pool server 93.94.88.51 Oct 30 11:12:39 alek ntpd[1640]: Soliciting pool server 185.157.229.254 Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=info msg="authenticated Login5" username="31************************q4" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="initializing zeroconf session" username="31************************q4" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="dealer connection opened" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=trace msg="starting accesspoint recv loop" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=trace msg="starting dealer recv loop" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=trace msg="received accesspoint ping" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="received connection id: ZjJiYTgyOTktNTYx...MkY4MkQ0Q0M0Qg==" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=trace msg="received accesspoint pong ack" Oct 30 11:12:39 alek go-librespot[1882]: time="2025-10-30T11:12:39+01:00" level=debug msg="put connect state because NEW_DEVICE" Oct 30 11:12:39 alek volumio[1144]: info: camilladsp service started and running in background, instance 1 Oct 30 11:12:39 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp loaded Oct 30 11:12:39 alek volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 30 11:12:39 alek volumio[1144]: info: Adding Signal Path Element [object Object] Oct 30 11:12:39 alek volumio[1144]: info: Adding fusiondspeq DSP Signal Path Element Oct 30 11:12:39 alek sudo[2055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp - ---- installed callbackRead Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 30 11:12:39 alek sudo[2055]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:39 alek volumio[1144]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 30 11:12:39 alek volumio[1144]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 30 11:12:39 alek systemd[1]: Started FusionDsp Daemon. Oct 30 11:12:39 alek sudo[2055]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:40 alek ntpd[1640]: Soliciting pool server 81.56.230.156 Oct 30 11:12:40 alek ntpd[1640]: Soliciting pool server 93.44.243.146 Oct 30 11:12:40 alek ntpd[1640]: Soliciting pool server 85.199.214.99 Oct 30 11:12:40 alek mpd[2021]: Oct 30 11:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 30 11:12:40 alek volumio[1144]: info: go-librespot daemon successfully initialized Oct 30 11:12:41 alek ntpd[1640]: Soliciting pool server 37.247.53.178 Oct 30 11:12:41 alek ntpd[1640]: Soliciting pool server 80.211.238.32 Oct 30 11:12:41 alek ntpd[1640]: Soliciting pool server 162.159.200.123 Oct 30 11:12:41 alek systemd[1]: Started Music Player Daemon. Oct 30 11:12:41 alek sudo[1776]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:41 alek sudo[1810]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:41 alek sudo[1920]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:41 alek volumio[1144]: info: Volumio Network Manager: Network status updated: 3 Oct 30 11:12:41 alek volumio[1144]: error: MPD error: The expression evaluated to a falsy value: Oct 30 11:12:41 alek volumio[1144]: assert.ok(self.idling) Oct 30 11:12:41 alek volumio[1144]: error: The expression evaluated to a falsy value: Oct 30 11:12:41 alek volumio[1144]: assert.ok(self.idling) Oct 30 11:12:41 alek volumio[1144]: info: Completed starting Core Plugins Oct 30 11:12:41 alek volumio[1144]: info: ------------------------------------------- Oct 30 11:12:41 alek volumio[1144]: info: ----- MyVolumio plugins startup ---- Oct 30 11:12:41 alek volumio[1144]: info: ------------------------------------------- Oct 30 11:12:41 alek volumio[1144]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 30 11:12:41 alek volumio[1144]: error: MPD error: The expression evaluated to a falsy value: Oct 30 11:12:41 alek volumio[1144]: assert.ok(self.idling) Oct 30 11:12:41 alek volumio[1144]: error: The expression evaluated to a falsy value: Oct 30 11:12:41 alek volumio[1144]: assert.ok(self.idling) Oct 30 11:12:41 alek volumio[1144]: error: updateQueue error: null Oct 30 11:12:41 alek volumio[1144]: info: MPD running with PID2021 Oct 30 11:12:41 alek volumio[1144]: ,establishing connection Oct 30 11:12:41 alek volumio[1144]: error: updateQueue error: null Oct 30 11:12:42 alek ntpd[1640]: Soliciting pool server 95.110.135.141 Oct 30 11:12:42 alek ntpd[1640]: Soliciting pool server 2a00:6d41:200:2::11 Oct 30 11:12:42 alek ntpd[1640]: Soliciting pool server 162.159.200.1 Oct 30 11:12:42 alek sudo[2099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 30 11:12:42 alek sudo[2099]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:42 alek sudo[2099]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:42 alek sudo[2106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 30 11:12:42 alek sudo[2104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 30 11:12:42 alek sudo[2106]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:42 alek sudo[2104]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 11:12:42 alek sudo[2104]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:42 alek systemd[1]: Started UPnP Renderer front-end to MPD. Oct 30 11:12:42 alek sudo[2106]: pam_unix(sudo:session): session closed for user root Oct 30 11:12:42 alek volumio[1144]: info: Upmpdcli Daemon Started Oct 30 11:12:43 alek volumio[2123]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 30 11:12:43 alek volumio[1144]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 3 Oct 30 11:12:43 alek volumio[2123]: ...........++++ Oct 30 11:12:43 alek volumio[1144]: info: Initializing connection to go-librespot Websocket Oct 30 11:12:43 alek go-librespot[1882]: time="2025-10-30T11:12:43+01:00" level=debug msg="new websocket client" Oct 30 11:12:43 alek volumio-remote-updater[585]: [2025-10-30 11:12:43] [connect] Successful connection Oct 30 11:12:43 alek volumio[1144]: info: Connection to go-librespot Websocket established Oct 30 11:12:43 alek volumio-remote-updater[585]: [2025-10-30 11:12:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1761819163 101 Oct 30 11:12:44 alek volumio[1144]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="handling transfer player command from 0188f06ed392dba4b793c48d683f762f3da06da0" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="resolved context of track" uri="spotify:album:6zTAW5oRuOmxJuUHhcQope" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="fetched new page 0 with 8 items (list: 8)" uri="spotify:album:6zTAW5oRuOmxJuUHhcQope" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="loading track (paused: true, position: 93043ms)" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="emitting websocket event: will_play" Oct 30 11:12:44 alek volumio[1144]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:6zTAW5oRuOmxJuUHhcQope","uri":"spotify:track:4Nckr2LBLkgNOdMadwNAxc","play_origin":"album"}} Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="selected format OGG_VORBIS_320 (7a6e92b8b4aae4167dc0d75747fa6bf1ad991eb6)" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="requested aes key for file 7a6e92b8b4aae4167dc0d75747fa6bf1ad991eb6, gid: 4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 391" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched first chunk of 22, total size is 11323540 bytes" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 7/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek volumio[1144]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 5 Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 9/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 6/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="seek to 93043ms (diff: 111ms, samples: 4103196, bytes: 3307234)" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 8/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="created new output device" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=info msg="loaded track \"Down Is The New Up\" (paused: true, position: 93043ms, duration: 299283ms, prefetched: false)" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:4Nckr2LBLkgNOdMadwNAxc" Oct 30 11:12:44 alek systemd[1]: systemd-fsckd.service: Succeeded. Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="emitting websocket event: metadata" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=trace msg="emitting websocket event: active" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="sending successful reply for dealer request" Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 30 11:12:44 alek go-librespot[1882]: time="2025-10-30T11:12:44+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 30 11:12:44 alek volumio[1144]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4Nckr2LBLkgNOdMadwNAxc","name":"Down Is The New Up","artist_names":["Radiohead"],"album_name":"In Rainbows (Disk 2)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024b88d5c1b3358cca2c94ec0b","position":93043,"duration":299283,"release_date":"year:2007","track_number":2,"disc_number":1}} Oct 30 11:12:44 alek volumio[1144]: SPOTIFY: received: {"type":"active","data":null} Oct 30 11:12:44 alek volumio[1144]: info: Aligning Spotify Volume to Volumio Volume Oct 30 11:12:44 alek volumio[1144]: info: CoreCommandRouter::volumioGetState Oct 30 11:12:44 alek volumio[1144]: info: CorePlayQueue::getTrack 0 Oct 30 11:12:44 alek volumio[1144]: info: Setting Spotify Volume from Volumio: 100 Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06e2668b does not match aorg 0000000000.00000000 from server@195.32.70.195 xmt 0xecadb89d.f7c7607c Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06dbf101 does not match aorg 0000000000.00000000 from server@81.56.230.156 xmt 0xecadb89d.f6f15619 Oct 30 11:12:45 alek go-librespot[1882]: time="2025-10-30T11:12:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 30 11:12:45 alek go-librespot[1882]: time="2025-10-30T11:12:45+01:00" level=trace msg="emitting websocket event: paused" Oct 30 11:12:45 alek volumio[1144]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:6zTAW5oRuOmxJuUHhcQope","uri":"spotify:track:4Nckr2LBLkgNOdMadwNAxc","play_origin":"album"}} Oct 30 11:12:45 alek volumio[1144]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06dd72ed does not match aorg 0000000000.00000000 from server@95.110.254.234 xmt 0xecadb89d.f8bfe206 Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06d28d8b does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xecadb89d.f912c800 Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06deb0ed does not match aorg 0000000000.00000000 from server@31.14.133.122 xmt 0xecadb89d.f8c28cdb Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06dff1c6 does not match aorg 0000000000.00000000 from server@212.6.50.243 xmt 0xecadb89d.f9550570 Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06d8b699 does not match aorg 0000000000.00000000 from server@80.211.238.32 xmt 0xecadb89d.f8bdf85e Oct 30 11:12:45 alek ntpd[1640]: receive: Unexpected origin timestamp 0xecadb89d.06da8d0b does not match aorg 0000000000.00000000 from server@93.44.243.146 xmt 0xecadb89d.f8ece3d2 Oct 30 11:12:45 alek volumio[1144]: TypeError: Cannot read property 'service' of undefined Oct 30 11:12:45 alek volumio[1144]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Oct 30 11:12:45 alek volumio[1144]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Oct 30 11:12:45 alek volumio[1144]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Oct 30 11:12:45 alek volumio[1144]: at WebSocket.emit (events.js:400:28) Oct 30 11:12:45 alek volumio[1144]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 30 11:12:45 alek volumio[1144]: at Receiver.emit (events.js:400:28) Oct 30 11:12:45 alek volumio[1144]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 30 11:12:45 alek volumio[1144]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 30 11:12:45 alek volumio[1144]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 30 11:12:45 alek volumio[1144]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 30 11:12:45 alek volumio[1144]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 30 11:12:45 alek volumio[1144]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 30 11:12:45 alek volumio[1144]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Oct 30 11:12:45 alek volumio[1144]: at Socket.emit (events.js:400:28) Oct 30 11:12:45 alek volumio[1144]: at addChunk (internal/streams/readable.js:293:12) Oct 30 11:12:45 alek volumio[1144]: at readableAddChunk (internal/streams/readable.js:267:9) Oct 30 11:12:45 alek volumio[1144]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 11:12:46 alek sudo[2164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-30 11:11 Oct 30 11:12:46 alek sudo[2164]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:55:15 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="2f3686ade78abf3b92c180a0c5b20c6b"