-- Logs begin at Thu 2019-02-14 19:12:00 JST, end at Thu 2024-11-28 22:13:03 JST. -- Nov 28 22:12:00 volumio kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Nov 28 22:12:00 volumio kernel: [vc_sm_connected_init]: start Nov 28 22:12:00 volumio kernel: [vc_sm_connected_init]: installed successfully Nov 28 22:12:00 volumio kernel: mc: Linux media interface: v0.10 Nov 28 22:12:00 volumio kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 28 22:12:00 volumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 28 22:12:00 volumio systemd[1]: Found device /dev/ttyAMA0. Nov 28 22:12:00 volumio kernel: videodev: Linux video capture interface: v2.00 Nov 28 22:12:00 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:00 volumio kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 28 22:12:01 volumio kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Nov 28 22:12:01 volumio kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Nov 28 22:12:01 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Nov 28 22:12:01 volumio systemd-udevd[224]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 28 22:12:02 volumio systemd-udevd[227]: Using default interface naming scheme 'v240'. Nov 28 22:12:02 volumio systemd-udevd[227]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 28 22:12:02 volumio systemd[1]: Found device /dev/mmcblk0p1. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in SMSC9512/9514 Fast Ethernet Adapter being skipped. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in FUSE Control File System being skipped. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 28 22:12:04 volumio systemd[1]: Condition check resulted in Huge Pages File System being skipped. Nov 28 22:12:04 volumio systemd[1]: Starting File System Check on /dev/mmcblk0p1... Nov 28 22:12:04 volumio systemd[1]: Started File System Check Daemon to report status. Nov 28 22:12:05 volumio systemd-fsck[301]: fsck.fat 4.1 (2017-01-24) Nov 28 22:12:05 volumio systemd-fsck[301]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Nov 28 22:12:05 volumio systemd-fsck[301]: Automatically removing dirty bit. Nov 28 22:12:05 volumio systemd-fsck[301]: Performing changes. Nov 28 22:12:05 volumio systemd-fsck[301]: /dev/mmcblk0p1: 308 files, 109537/123044 clusters Nov 28 22:12:05 volumio systemd[1]: Started File System Check on /dev/mmcblk0p1. Nov 28 22:12:05 volumio systemd[1]: Mounting /boot... Nov 28 22:12:05 volumio systemd[1]: Mounted /boot. Nov 28 22:12:05 volumio systemd[1]: Reached target Local File Systems. Nov 28 22:12:05 volumio systemd[1]: Started ifup for eth0. Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Nov 28 22:12:05 volumio systemd[1]: Starting Raise network interfaces... Nov 28 22:12:05 volumio systemd[1]: Starting Create Volatile Files and Directories... Nov 28 22:12:05 volumio systemd[1]: Starting Preprocess NFS configuration... Nov 28 22:12:05 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Nov 28 22:12:05 volumio systemd[1]: Received SIGRTMIN+20 from PID 229 (plymouthd). Nov 28 22:12:05 volumio systemd[1]: plymouth-read-write.service: Succeeded. Nov 28 22:12:05 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Nov 28 22:12:05 volumio systemd[1]: nfs-config.service: Succeeded. Nov 28 22:12:05 volumio systemd[1]: Started Preprocess NFS configuration. Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Nov 28 22:12:05 volumio systemd[1]: Reached target NFS client services. Nov 28 22:12:05 volumio systemd[1]: Started Create Volatile Files and Directories. Nov 28 22:12:05 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Nov 28 22:12:05 volumio systemd[1]: Starting RPC bind portmap service... Nov 28 22:12:05 volumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Nov 28 22:12:05 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Nov 28 22:12:05 volumio systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Nov 28 22:12:05 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Nov 28 22:12:05 volumio systemd[1]: Reached target System Initialization. Nov 28 22:12:05 volumio systemd[1]: Listening on mpd.socket. Nov 28 22:12:05 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Nov 28 22:12:05 volumio systemd[1]: Listening on triggerhappy.socket. Nov 28 22:12:05 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Nov 28 22:12:05 volumio systemd[1]: Reached target Sockets. Nov 28 22:12:05 volumio systemd[1]: apt-daily.timer: Not using persistent file timestamp Sat 2025-01-11 10:58:31 JST as it is in the future. Nov 28 22:12:05 volumio systemd[1]: Started Daily apt download activities. Nov 28 22:12:05 volumio systemd[1]: Reached target Basic System. Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Nov 28 22:12:05 volumio systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Nov 28 22:12:06 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Nov 28 22:12:06 volumio systemd[1]: Started Manage Sound Card State (restore and store). Nov 28 22:12:06 volumio systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Nov 28 22:12:06 volumio systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Nov 28 22:12:06 volumio systemd[1]: Starting dhcpcd on all interfaces... Nov 28 22:12:06 volumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Nov 28 22:12:06 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Nov 28 22:12:06 volumio alsactl[342]: alsactl 1.1.8 daemon started Nov 28 22:12:06 volumio systemd[1]: Started volumio-remote-updater.service. Nov 28 22:12:06 volumio systemd[1]: Started D-Bus System Message Bus. Nov 28 22:12:06 volumio dhcpcd[344]: Not running dhcpcd because /etc/network/interfaces Nov 28 22:12:06 volumio dhcpcd[344]: defines some interfaces that will use a Nov 28 22:12:06 volumio dhcpcd[344]: DHCP client or static address Nov 28 22:12:06 volumio systemd[1]: Starting Login Service... Nov 28 22:12:06 volumio systemd[1]: Starting WPA supplicant... Nov 28 22:12:06 volumio ifup[307]: command failed: No such device (-19) Nov 28 22:12:06 volumio systemd[1]: Starting triggerhappy global hotkey daemon... Nov 28 22:12:06 volumio sh[306]: command failed: No such device (-19) Nov 28 22:12:06 volumio systemd[1]: Started Volumio Iptables Module. Nov 28 22:12:06 volumio systemd[1]: Starting Wireless Services... Nov 28 22:12:06 volumio systemd[1]: Starting Save/Restore Sound Card State... Nov 28 22:12:06 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Nov 28 22:12:06 volumio systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Sat 2025-01-11 10:58:31 JST as it is in the future. Nov 28 22:12:06 volumio kernel: cfg80211: loaded regulatory.db is malformed or signature is missing/invalid Nov 28 22:12:06 volumio systemd[1]: Started Daily apt upgrade and clean activities. Nov 28 22:12:06 volumio systemd[1]: Reached target Timers. Nov 28 22:12:06 volumio systemd[1]: Started RPC bind portmap service. Nov 28 22:12:06 volumio systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Nov 28 22:12:06 volumio systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Nov 28 22:12:06 volumio systemd[1]: Failed to start dhcpcd on all interfaces. Nov 28 22:12:06 volumio systemd[1]: Reached target RPC Port Mapper. Nov 28 22:12:06 volumio systemd[1]: Reached target Remote File Systems (Pre). Nov 28 22:12:06 volumio systemd[1]: Reached target Remote File Systems. Nov 28 22:12:06 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Nov 28 22:12:06 volumio thd[356]: Unable to parse trigger line: Nov 28 22:12:06 volumio thd[356]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Nov 28 22:12:06 volumio thd[356]: Unable to parse trigger line: Nov 28 22:12:06 volumio thd[356]: Unable to parse trigger line: Nov 28 22:12:06 volumio thd[356]: Found socket passed from systemd Nov 28 22:12:07 volumio systemd[1]: Started triggerhappy global hotkey daemon. Nov 28 22:12:07 volumio systemd[1]: Started Save/Restore Sound Card State. Nov 28 22:12:07 volumio avahi-daemon[348]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Nov 28 22:12:07 volumio avahi-daemon[348]: Successfully dropped root privileges. Nov 28 22:12:07 volumio avahi-daemon[348]: avahi-daemon 0.7 starting up. Nov 28 22:12:07 volumio ifup[307]: command failed: No such device (-19) Nov 28 22:12:07 volumio systemd[1]: Reached target Sound Card. Nov 28 22:12:07 volumio avahi-daemon[348]: Successfully called chroot(). Nov 28 22:12:07 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Nov 28 22:12:07 volumio avahi-daemon[348]: Successfully dropped remaining capabilities. Nov 28 22:12:07 volumio avahi-daemon[348]: No service file found in /etc/avahi/services. Nov 28 22:12:07 volumio avahi-daemon[348]: Network interface enumeration completed. Nov 28 22:12:07 volumio avahi-daemon[348]: Server startup complete. Host name is volumio.local. Local service cookie is 2900790803. Nov 28 22:12:07 volumio kernel: 8021q: 802.1Q VLAN Support v1.8 Nov 28 22:12:07 volumio systemd-logind[354]: New seat seat0. Nov 28 22:12:07 volumio loadcpufreq[366]: Loading cpufreq kernel modules...done (none). Nov 28 22:12:07 volumio systemd[1]: Started Login Service. Nov 28 22:12:07 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Nov 28 22:12:07 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Nov 28 22:12:09 volumio haveged[329]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Nov 28 22:12:09 volumio haveged[329]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Nov 28 22:12:09 volumio haveged[329]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00113 Nov 28 22:12:09 volumio haveged[329]: haveged: fills: 0, generated: 0 Nov 28 22:12:09 volumio kernel: random: crng init done Nov 28 22:12:09 volumio kernel: random: 7 urandom warning(s) missed due to ratelimiting Nov 28 22:12:09 volumio cpufrequtils[426]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Nov 28 22:12:09 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Nov 28 22:12:09 volumio kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:003:01, irq=POLL) Nov 28 22:12:09 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Nov 28 22:12:09 volumio sh[306]: eth0: waiting for carrier Nov 28 22:12:09 volumio dhcpcd[376]: eth0: waiting for carrier Nov 28 22:12:09 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Nov 28 22:12:09 volumio systemd[1]: Started Raise network interfaces. Nov 28 22:12:09 volumio systemd-udevd[224]: Process '/sbin/crda' failed with exit code 249. Nov 28 22:12:10 volumio systemd[1]: iptables.service: Succeeded. Nov 28 22:12:10 volumio systemd[1]: Started WPA supplicant. Nov 28 22:12:10 volumio wpa_supplicant[355]: Successfully initialized wpa_supplicant Nov 28 22:12:10 volumio systemd[1]: Reached target Network. Nov 28 22:12:10 volumio systemd[1]: Reached target Network is Online. Nov 28 22:12:10 volumio systemd[1]: Starting Samba NMB Daemon... Nov 28 22:12:10 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Nov 28 22:12:10 volumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Nov 28 22:12:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 28 22:12:10 volumio systemd[1]: Starting /etc/rc.local Compatibility... Nov 28 22:12:10 volumio systemd[1]: Starting Permit User Sessions... Nov 28 22:12:10 volumio systemd[1]: Starting Music Player Daemon... Nov 28 22:12:10 volumio systemd[1]: Starting Network Time Service... Nov 28 22:12:10 volumio systemd[1]: Started /etc/rc.local Compatibility. Nov 28 22:12:10 volumio systemd[1]: Started Permit User Sessions. Nov 28 22:12:11 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Nov 28 22:12:11 volumio systemd[1]: Starting Hold until boot process finishes up... Nov 28 22:12:11 volumio systemd[1]: Received SIGRTMIN+21 from PID 229 (plymouthd). Nov 28 22:12:11 volumio systemd[1]: plymouth-quit.service: Succeeded. Nov 28 22:12:11 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Nov 28 22:12:11 volumio systemd[1]: plymouth-start.service: Succeeded. Nov 28 22:12:11 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. Nov 28 22:12:11 volumio systemd[1]: Started Hold until boot process finishes up. Nov 28 22:12:11 volumio systemd[1]: Received SIGRTMIN+21 from PID 229 (n/a). Nov 28 22:12:11 volumio systemd[1]: Started Getty on tty1. Nov 28 22:12:11 volumio systemd[1]: Started Serial Getty on ttyAMA0. Nov 28 22:12:11 volumio systemd[1]: Reached target Login Prompts. Nov 28 22:12:11 volumio ifplugd(eth0)[518]: ifplugd 0.28 initializing. Nov 28 22:12:11 volumio ifplugd(eth0)[518]: Using interface eth0/B8:27:EB:B8:38:A5 with driver (version: 5.10.92-v7+) Nov 28 22:12:11 volumio ifplugd(eth0)[518]: Using detection mode: SIOCETHTOOL Nov 28 22:12:11 volumio ifplugd(eth0)[518]: Initialization complete, link beat not detected. Nov 28 22:12:11 volumio ifplugd[492]: Network Interface Plugging Daemon...start eth0...done. Nov 28 22:12:11 volumio systemd[1]: Started LSB: Brings up/down network automatically. Nov 28 22:12:11 volumio ntpd[500]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 28 22:12:11 volumio ntpd[500]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Nov 28 22:12:11 volumio systemd[1]: Started Network Time Service. Nov 28 22:12:11 volumio ntpd[524]: proto: precision = 1.145 usec (-20) Nov 28 22:12:11 volumio ntpd[524]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 28 22:12:11 volumio ntpd[524]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2023-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 28 22:12:11 volumio ntpd[524]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 520 days ago Nov 28 22:12:11 volumio ntpd[524]: Listen and drop on 0 v6wildcard [::]:123 Nov 28 22:12:11 volumio ntpd[524]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 28 22:12:11 volumio ntpd[524]: Listen normally on 2 lo 127.0.0.1:123 Nov 28 22:12:11 volumio ntpd[524]: Listening on routing socket on fd #19 for interface updates Nov 28 22:12:11 volumio ntpd[524]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 28 22:12:11 volumio ntpd[524]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 28 22:12:12 volumio volumio-remote-updater[349]: Error: No active session Nov 28 22:12:12 volumio volumio-remote-updater[349]: [2024-11-28 22:12:12] [info] asio async_connect error: system:111 (Connection refused) Nov 28 22:12:12 volumio volumio-remote-updater[349]: [2024-11-28 22:12:12] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 28 22:12:12 volumio volumio-remote-updater[349]: [2024-11-28 22:12:12] [error] handle_connect error: Underlying Transport Error Nov 28 22:12:12 volumio ifplugd(eth0)[518]: Link beat detected. Nov 28 22:12:12 volumio ifplugd(eth0)[518]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 28 22:12:12 volumio ifplugd(eth0)[518]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Nov 28 22:12:12 volumio sh[306]: eth0: carrier acquired Nov 28 22:12:12 volumio dhcpcd[376]: eth0: carrier acquired Nov 28 22:12:12 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Nov 28 22:12:12 volumio sh[306]: DUID 00:01:00:01:29:d8:61:aa:b8:27:eb:b8:38:a5 Nov 28 22:12:12 volumio sh[306]: eth0: IAID eb:b8:38:a5 Nov 28 22:12:12 volumio dhcpcd[376]: DUID 00:01:00:01:29:d8:61:aa:b8:27:eb:b8:38:a5 Nov 28 22:12:12 volumio dhcpcd[376]: eth0: IAID eb:b8:38:a5 Nov 28 22:12:12 volumio sh[306]: eth0: adding address fe80::6aac:f488:ef24:682a Nov 28 22:12:12 volumio sh[306]: ipv6_addaddr1: Permission denied Nov 28 22:12:12 volumio dhcpcd[376]: eth0: adding address fe80::6aac:f488:ef24:682a Nov 28 22:12:12 volumio dhcpcd[376]: ipv6_addaddr1: Permission denied Nov 28 22:12:12 volumio sh[306]: eth0: rebinding lease of 192.168.10.115 Nov 28 22:12:12 volumio dhcpcd[376]: eth0: rebinding lease of 192.168.10.115 Nov 28 22:12:12 volumio sh[306]: eth0: probing address 192.168.10.115/24 Nov 28 22:12:12 volumio dhcpcd[376]: eth0: probing address 192.168.10.115/24 Nov 28 22:12:12 volumio ntpd[524]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 28 22:12:12 volumio volumio[340]: Could not open config: /tmp/upmpdcli.conf Nov 28 22:12:13 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 28 22:12:13 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 28 22:12:13 volumio sh[306]: eth0: soliciting an IPv6 router Nov 28 22:12:13 volumio dhcpcd[376]: eth0: soliciting an IPv6 router Nov 28 22:12:13 volumio ntpd[524]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 28 22:12:14 volumio kernel: cam1-reg: disabling Nov 28 22:12:14 volumio kernel: cam-dummy-reg: disabling Nov 28 22:12:14 volumio ntpd[524]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 28 22:12:14 volumio nmbd[501]: [2024/11/28 22:12:14.868989, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Nov 28 22:12:14 volumio nmbd[501]: started asyncdns process 534 Nov 28 22:12:14 volumio nmbd[501]: [2024/11/28 22:12:14.875309, 0] ../lib/util/become_daemon.c:149(daemon_status) Nov 28 22:12:14 volumio nmbd[501]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Nov 28 22:12:14 volumio nmbd[501]: [2024/11/28 22:12:14.875842, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Nov 28 22:12:14 volumio nmbd[501]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Nov 28 22:12:15 volumio ntpd[524]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 28 22:12:17 volumio sh[306]: eth0: leased 192.168.10.115 for 86400 seconds Nov 28 22:12:17 volumio sh[306]: eth0: adding route to 192.168.10.0/24 Nov 28 22:12:17 volumio sh[306]: eth0: adding default route via 192.168.10.1 Nov 28 22:12:17 volumio dhcpcd[376]: eth0: leased 192.168.10.115 for 86400 seconds Nov 28 22:12:17 volumio dhcpcd[376]: eth0: adding route to 192.168.10.0/24 Nov 28 22:12:17 volumio dhcpcd[376]: eth0: adding default route via 192.168.10.1 Nov 28 22:12:17 volumio avahi-daemon[348]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.10.115. Nov 28 22:12:17 volumio avahi-daemon[348]: New relevant interface eth0.IPv4 for mDNS. Nov 28 22:12:17 volumio avahi-daemon[348]: Registering new address record for 192.168.10.115 on eth0.IPv4. Nov 28 22:12:17 volumio volumio-remote-updater[349]: [2024-11-28 22:12:17] [info] asio async_connect error: system:111 (Connection refused) Nov 28 22:12:17 volumio volumio-remote-updater[349]: [2024-11-28 22:12:17] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 28 22:12:17 volumio volumio-remote-updater[349]: [2024-11-28 22:12:17] [error] handle_connect error: Underlying Transport Error Nov 28 22:12:17 volumio sh[306]: forked to background, child pid 566 Nov 28 22:12:17 volumio dhcpcd[376]: forked to background, child pid 566 Nov 28 22:12:17 volumio wireless.js[360]: WIRELESS: No wireless interface, exiting Nov 28 22:12:17 volumio iw[569]: command failed: No such device (-19) Nov 28 22:12:17 volumio systemd[1]: wireless.service: Control process exited, code=exited, status=237/KEYRING Nov 28 22:12:17 volumio systemd[1]: wireless.service: Failed with result 'exit-code'. Nov 28 22:12:17 volumio systemd[1]: Failed to start Wireless Services. Nov 28 22:12:17 volumio systemd[1]: Started Volumio Backend Module. Nov 28 22:12:17 volumio ifplugd(eth0)[518]: client: ifup: interface eth0 already configured Nov 28 22:12:17 volumio sh[306]: eth0=eth0 Nov 28 22:12:17 volumio ifplugd(eth0)[518]: Program executed successfully. Nov 28 22:12:18 volumio mpd[522]: Nov 28 22:12 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 28 22:12:18 volumio ntpd[524]: Listen normally on 3 eth0 192.168.10.115:123 Nov 28 22:12:18 volumio ntpd[524]: new interface(s) found: waking up resolver Nov 28 22:12:18 volumio mpd[522]: Nov 28 22:12 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 28 22:12:18 volumio mpd[522]: Nov 28 22:12 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 28 22:12:18 volumio systemd[1]: Started Music Player Daemon. Nov 28 22:12:19 volumio nmbd[501]: [2024/11/28 22:12:19.901603, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 28 22:12:19 volumio nmbd[501]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 28 22:12:19 volumio systemd[1]: Started Samba NMB Daemon. Nov 28 22:12:19 volumio systemd[1]: Starting Samba Winbind Daemon... Nov 28 22:12:20 volumio winbindd[604]: [2024/11/28 22:12:20.500731, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 28 22:12:20 volumio winbindd[604]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 28 22:12:20 volumio winbindd[604]: [2024/11/28 22:12:20.623264, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 28 22:12:20 volumio winbindd[604]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 28 22:12:20 volumio systemd[1]: Started Samba Winbind Daemon. Nov 28 22:12:20 volumio systemd[1]: Starting Samba SMB Daemon... Nov 28 22:12:22 volumio winbindd[604]: [2024/11/28 22:12:22.652081, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Nov 28 22:12:22 volumio winbindd[604]: res_names->count = 3, expected 4 Nov 28 22:12:22 volumio smbd[609]: [2024/11/28 22:12:22.717570, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 28 22:12:22 volumio systemd[1]: Started Samba SMB Daemon. Nov 28 22:12:22 volumio smbd[609]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 28 22:12:22 volumio systemd[1]: Reached target Multi-User System. Nov 28 22:12:22 volumio systemd[1]: Reached target Graphical Interface. Nov 28 22:12:22 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 28 22:12:22 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 28 22:12:22 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 28 22:12:22 volumio systemd[1]: Startup finished in 17.129s (kernel) + 26.246s (userspace) = 43.376s. Nov 28 22:12:24 volumio volumio-remote-updater[349]: [2024-11-28 22:12:24] [connect] Successful connection Nov 28 22:12:25 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:12:25 volumio volumio[588]: info: ----- Volumio3 ---- Nov 28 22:12:25 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:12:25 volumio volumio[588]: info: ----- System startup ---- Nov 28 22:12:25 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:12:27 volumio volumio[588]: info: MYVOLUMIO Environment detected Nov 28 22:12:27 volumio volumio[588]: info: Plugin folders cleanup Nov 28 22:12:27 volumio volumio[588]: info: Scanning into folder /volumio/app/plugins/ Nov 28 22:12:27 volumio volumio[588]: info: Scanning category audio_interface Nov 28 22:12:27 volumio volumio[588]: info: Scanning category miscellanea Nov 28 22:12:27 volumio volumio[588]: info: Scanning category music_service Nov 28 22:12:27 volumio volumio[588]: info: Scanning category plugins.json Nov 28 22:12:27 volumio volumio[588]: info: Scanning category system_controller Nov 28 22:12:27 volumio volumio[588]: info: Scanning category user_interface Nov 28 22:12:27 volumio volumio[588]: info: Scanning into folder /data/plugins/ Nov 28 22:12:27 volumio volumio[588]: info: Scanning category music_service Nov 28 22:12:27 volumio volumio[588]: info: Plugin folders cleanup completed Nov 28 22:12:27 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:12:27 volumio volumio[588]: info: ----- Core plugins startup ---- Nov 28 22:12:27 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:12:27 volumio volumio[588]: info: Loading plugins from folder /volumio/app/plugins/ Nov 28 22:12:27 volumio volumio[588]: info: Adding plugin upnp to MyMusic Plugins Nov 28 22:12:27 volumio volumio[588]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 28 22:12:27 volumio volumio[588]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 28 22:12:27 volumio volumio[588]: info: Loading plugins from folder /data/plugins/ Nov 28 22:12:27 volumio volumio[588]: info: Loading plugin "system"... Nov 28 22:12:27 volumio volumio[588]: info: Loading plugin "appearance"... Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "network"... Nov 28 22:12:31 volumio volumio[588]: info: Refreshing Cached IP Addresses Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "services"... Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "alsa_controller"... Nov 28 22:12:31 volumio sudo[629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 28 22:12:31 volumio sudo[631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 28 22:12:31 volumio sudo[633]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 28 22:12:31 volumio sudo[629]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:31 volumio sudo[633]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:31 volumio sudo[631]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:31 volumio sudo[629]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:31 volumio sudo[631]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:31 volumio sudo[633]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:31 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "wizard"... Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "volumio_command_line_client"... Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "upnp"... Nov 28 22:12:31 volumio volumio[588]: info: [1732799551818] Starting Upmpd Daemon Nov 28 22:12:31 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "my_music"... Nov 28 22:12:31 volumio volumio[588]: info: Loading plugin "mpd"... Nov 28 22:12:32 volumio volumio[588]: info: Creating MPD Configuration file Nov 28 22:12:32 volumio volumio[588]: info: Loading plugin "upnp_browser"... Nov 28 22:12:32 volumio sudo[644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 28 22:12:32 volumio sudo[644]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:32 volumio sudo[644]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:32 volumio sudo[646]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 28 22:12:32 volumio sudo[646]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:32 volumio systemd[1]: Stopping Music Player Daemon... Nov 28 22:12:35 volumio systemd[1]: systemd-fsckd.service: Succeeded. Nov 28 22:12:36 volumio systemd[1]: mpd.service: Succeeded. Nov 28 22:12:36 volumio systemd[1]: Stopped Music Player Daemon. Nov 28 22:12:36 volumio systemd[1]: Starting Music Player Daemon... Nov 28 22:12:37 volumio volumio[588]: info: Loading plugin "networkfs"... Nov 28 22:12:38 volumio volumio[588]: info: Starting Udev Watcher for removable devices Nov 28 22:12:38 volumio sudo[654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.10.108/Yoshio /mnt/NAS/Yoshio Nov 28 22:12:38 volumio sudo[654]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:38 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching Nov 28 22:12:38 volumio kernel: Key type cifs.spnego registered Nov 28 22:12:38 volumio kernel: Key type cifs.idmap registered Nov 28 22:12:38 volumio kernel: CIFS: Attempting to mount //192.168.10.108/Yoshio Nov 28 22:12:38 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Nov 28 22:12:38 volumio mpd[651]: Nov 28 22:12 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 28 22:12:38 volumio mpd[651]: Nov 28 22:12 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 28 22:12:38 volumio mpd[651]: Nov 28 22:12 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 28 22:12:38 volumio systemd[1]: Started Music Player Daemon. Nov 28 22:12:38 volumio sudo[646]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:39 volumio volumio[588]: info: Ignoring mount for partition: boot Nov 28 22:12:39 volumio volumio[588]: info: Ignoring mount for partition: volumio Nov 28 22:12:39 volumio volumio[588]: info: Ignoring mount for partition: volumio_data Nov 28 22:12:39 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 22:12:39 volumio volumio[588]: info: Loading plugin "alarm-clock"... Nov 28 22:12:39 volumio volumio-remote-updater[349]: [2024-11-28 22:12:39] [connect] Successful connection Nov 28 22:12:41 volumio volumio[588]: info: Loading plugin "airplay_emulation"... Nov 28 22:12:41 volumio volumio[588]: info: Starting Shairport Sync Nov 28 22:12:41 volumio volumio[588]: info: Loading plugin "last_100"... Nov 28 22:12:41 volumio volumio[588]: info: Loading plugin "webradio"... Nov 28 22:12:41 volumio volumio[588]: info: Loading plugin "i2s_dacs"... Nov 28 22:12:41 volumio volumio[588]: info: Loading plugin "volumiodiscovery"... Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 22:12:41 volumio node[588]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** For more information see Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 22:12:41 volumio volumio[588]: *** WARNING *** For more information see Nov 28 22:12:41 volumio node[588]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 22:12:41 volumio node[588]: *** WARNING *** For more information see Nov 28 22:12:41 volumio node[588]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 28 22:12:41 volumio node[588]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 22:12:41 volumio node[588]: *** WARNING *** For more information see Nov 28 22:12:41 volumio volumio[588]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 28 22:12:41 volumio volumio[588]: info: Discovery: Started advertising with name: Volumio Nov 28 22:12:41 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 22:12:42 volumio volumio[588]: info: Loading plugin "spop"... Nov 28 22:12:44 volumio sudo[654]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:44 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 28 22:12:44 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Nov 28 22:12:45 volumio volumio[588]: info: Loading plugin "youtube2"... Nov 28 22:12:54 volumio volumio-remote-updater[349]: [2024-11-28 22:12:54] [connect] Successful connection Nov 28 22:12:56 volumio volumio[588]: info: Loading plugin "outputs"... Nov 28 22:12:56 volumio volumio[588]: info: Loading plugin "albumart"... Nov 28 22:12:56 volumio volumio[588]: info: Plugin example_plugin is not enabled Nov 28 22:12:56 volumio volumio[588]: info: Loading plugin "inputs"... Nov 28 22:12:56 volumio volumio[588]: info: Loading plugin "updater_comm"... Nov 28 22:12:57 volumio volumio[588]: info: Plugin mpdemulation is not enabled Nov 28 22:12:57 volumio volumio[588]: info: Loading plugin "rest_api"... Nov 28 22:12:57 volumio volumio[588]: info: Loading plugin "websocket"... Nov 28 22:12:57 volumio volumio[588]: info: Loading i18n strings for locale ja Nov 28 22:12:57 volumio volumio[588]: Updating browse sources language Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 22:12:57 volumio volumio[588]: Forking 3 albumart workers Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::initPlayerControls Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 22:12:57 volumio volumio[588]: Express server listening on port 3000 Nov 28 22:12:57 volumio volumio[588]: [Metrics] WebUI: 35s 420.18ms Nov 28 22:12:57 volumio volumio[588]: info: CoreStateMachine::resetVolumioState Nov 28 22:12:57 volumio volumio[588]: info: CoreStateMachine::getcurrentVolume Nov 28 22:12:57 volumio volumio[588]: info: CoreCommandRouter::volumioRetrievevolume Nov 28 22:12:57 volumio volumio[588]: info: CoreStateMachine::pushState Nov 28 22:12:58 volumio volumio[588]: info: CorePlayQueue::getTrack 0 Nov 28 22:12:58 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 28 22:12:58 volumio volumio[588]: info: CoreCommandRouter::volumioPushState Nov 28 22:12:58 volumio sudo[702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 28 22:12:58 volumio sudo[702]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:58 volumio sudo[702]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:58 volumio volumio[588]: info: Cannot mount NAS Yoshio at system boot, trial number 1 ,retrying in 5 seconds Nov 28 22:12:58 volumio sudo[704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 28 22:12:58 volumio sudo[704]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:58 volumio volumio[588]: info: MPD Permissions set Nov 28 22:12:58 volumio volumio[588]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 28 22:12:58 volumio volumio[588]: wlan0 Interface doesn't support scanning. Nov 28 22:12:58 volumio volumio[588]: info: Cannot use regular scanning, forcing with ap-force Nov 28 22:12:58 volumio sudo[704]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:58 volumio sudo[712]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 28 22:12:58 volumio sudo[712]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:12:58 volumio sudo[712]: pam_unix(sudo:session): session closed for user root Nov 28 22:12:58 volumio volumio[588]: command failed: No such device (-19) Nov 28 22:12:58 volumio volumio[588]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Nov 28 22:12:58 volumio volumio[588]: command failed: No such device (-19) Nov 28 22:12:58 volumio volumio-remote-updater[349]: [2024-11-28 22:12:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1732799574 101 Nov 28 22:12:58 volumio volumio[588]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Nov 28 22:12:58 volumio volumio[588]: info: MPD running with PID651 Nov 28 22:12:58 volumio volumio[588]: ,establishing connection Nov 28 22:12:59 volumio volumio[588]: error: MPD error: The expression evaluated to a falsy value: Nov 28 22:12:59 volumio volumio[588]: assert.ok(self.idling) Nov 28 22:12:59 volumio volumio[588]: error: The expression evaluated to a falsy value: Nov 28 22:12:59 volumio volumio[588]: assert.ok(self.idling) Nov 28 22:12:59 volumio volumio[588]: error: MPD error: The expression evaluated to a falsy value: Nov 28 22:12:59 volumio volumio[588]: assert.ok(self.idling) Nov 28 22:12:59 volumio volumio[588]: error: The expression evaluated to a falsy value: Nov 28 22:12:59 volumio volumio[588]: assert.ok(self.idling) Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:12:59 volumio volumio[588]: info: Reloading queue from file Nov 28 22:12:59 volumio volumio[588]: Starting albumart workers Nov 28 22:12:59 volumio volumio[588]: info: CoreStateMachine::setRepeat null single undefined Nov 28 22:12:59 volumio volumio[588]: info: CoreStateMachine::pushState Nov 28 22:12:59 volumio volumio[588]: info: CorePlayQueue::getTrack 0 Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::volumioPushState Nov 28 22:12:59 volumio volumio[588]: info: CoreStateMachine::setRandom null Nov 28 22:12:59 volumio volumio[588]: info: CoreStateMachine::pushState Nov 28 22:12:59 volumio volumio[588]: info: CorePlayQueue::getTrack 0 Nov 28 22:12:59 volumio volumio[588]: info: CoreCommandRouter::volumioPushState Nov 28 22:12:59 volumio volumio[588]: Starting albumart workers Nov 28 22:12:59 volumio volumio[588]: info: Setting Device type: Raspberry PI Nov 28 22:12:59 volumio volumio[588]: Starting albumart workers Nov 28 22:12:59 volumio volumio[588]: error: updateQueue error: null Nov 28 22:12:59 volumio volumio[588]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 28 22:12:59 volumio volumio[588]: info: Completed loading Core Plugins Nov 28 22:12:59 volumio volumio[588]: info: Preparing to generate the ALSA configuration file Nov 28 22:12:59 volumio volumio[588]: info: Asound.conf file unchanged, so no further update is needed Nov 28 22:12:59 volumio volumio[588]: info: Output device has changed, restarting MPD Nov 28 22:13:00 volumio sudo[726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 28 22:13:00 volumio sudo[726]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:13:00 volumio sudo[729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 28 22:13:00 volumio sudo[729]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:13:00 volumio volumio[588]: info: Output device has changed, restarting Shairport Sync Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:13:00 volumio sudo[729]: pam_unix(sudo:session): session closed for user root Nov 28 22:13:00 volumio sudo[731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 28 22:13:00 volumio sudo[731]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:13:00 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Nov 28 22:13:00 volumio sudo[726]: pam_unix(sudo:session): session closed for user root Nov 28 22:13:00 volumio systemd[1]: Stopping Music Player Daemon... Nov 28 22:13:00 volumio volumio[588]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 22:13:00 volumio volumio[588]: info: ___________ START PLUGINS ___________ Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 22:13:00 volumio volumio[588]: info: [1732799580295] CoreMusicLibrary::Adding element Media Servers Nov 28 22:13:00 volumio systemd[1]: mpd.service: Succeeded. Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 22:13:00 volumio systemd[1]: Stopped Music Player Daemon. Nov 28 22:13:00 volumio volumio[588]: Cannot find translation for sourceMedia Servers Nov 28 22:13:00 volumio systemd[1]: Starting Music Player Daemon... Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:13:00 volumio volumio[588]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 22:13:00 volumio volumio[588]: info: [1732799580960] CoreMusicLibrary::Adding element Last_100 Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 22:13:00 volumio volumio[588]: Cannot find translation for sourceMedia Servers Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 22:13:00 volumio volumio[588]: info: [1732799580989] CoreMusicLibrary::Adding element Webradio Nov 28 22:13:00 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 22:13:00 volumio volumio[588]: Cannot find translation for sourceMedia Servers Nov 28 22:13:01 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 22:13:01 volumio volumio[588]: info: Creating Spotify config file Nov 28 22:13:01 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:01 volumio volumio[588]: info: [youtube2-auth] Starting auth flow... Nov 28 22:13:01 volumio volumio[588]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 22:13:01 volumio volumio[588]: info: [1732799581561] CoreMusicLibrary::Adding element YouTube2 Nov 28 22:13:01 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 22:13:01 volumio volumio[588]: Cannot find translation for sourceMedia Servers Nov 28 22:13:01 volumio volumio[588]: Cannot find translation for sourceYouTube2 Nov 28 22:13:01 volumio volumio[588]: info: Volumio Calling Home Nov 28 22:13:01 volumio volumio[588]: info: Completed starting Core Plugins Nov 28 22:13:01 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:13:01 volumio volumio[588]: info: ----- MyVolumio plugins startup ---- Nov 28 22:13:01 volumio volumio[588]: info: ------------------------------------------- Nov 28 22:13:01 volumio volumio[588]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 28 22:13:02 volumio volumio[588]: info: Discovery: adding d1dfa324-4afd-4978-9955-82e371951dcd Nov 28 22:13:02 volumio volumio[588]: info: Discovery: Found device Volumio Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::volumioGetState Nov 28 22:13:02 volumio volumio[588]: info: CorePlayQueue::getTrack 0 Nov 28 22:13:02 volumio volumio[588]: info: MPD Permissions set Nov 28 22:13:02 volumio volumio[588]: info: Upmpdcli Daemon Started Nov 28 22:13:02 volumio volumio[588]: info: Spotify config file written Nov 28 22:13:02 volumio sudo[775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 28 22:13:02 volumio sudo[775]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 22:13:02 volumio volumio[588]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio systemd[1]: Started go-librespot Daemon. Nov 28 22:13:02 volumio sudo[775]: pam_unix(sudo:session): session closed for user root Nov 28 22:13:02 volumio go-librespot[781]: Librespot-go daemon starting... Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 22:13:02 volumio volumio[588]: info: No need to fix Spotify hosts Nov 28 22:13:02 volumio volumio[588]: info: An error occurred while refreshing Spotify Token Error: certificate is not yet valid Nov 28 22:13:02 volumio volumio[588]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 22:13:02 volumio volumio[588]: ReferenceError: deferred is not defined Nov 28 22:13:02 volumio volumio[588]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Nov 28 22:13:02 volumio volumio[588]: at ClientRequest.emit (events.js:315:20) Nov 28 22:13:02 volumio volumio[588]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Nov 28 22:13:02 volumio volumio[588]: at TLSSocket.emit (events.js:315:20) Nov 28 22:13:02 volumio volumio[588]: at emitErrorNT (internal/streams/destroy.js:106:8) Nov 28 22:13:02 volumio volumio[588]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Nov 28 22:13:02 volumio volumio[588]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 28 22:13:02 volumio volumio[588]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 22:13:02 volumio go-librespot[781]: time="2024-11-28T22:13:02+09:00" level=info msg="generated new device id: fd7a656e6fcef14550605e4b33ca70e39cd60434" Nov 28 22:13:02 volumio go-librespot[781]: time="2024-11-28T22:13:02+09:00" level=debug msg="stored credentials found for pxc01330" Nov 28 22:13:03 volumio mpd[746]: Nov 28 22:13 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 28 22:13:03 volumio mpd[746]: Nov 28 22:13 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 28 22:13:03 volumio mpd[746]: Nov 28 22:13 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 28 22:13:03 volumio systemd[1]: Started Music Player Daemon. Nov 28 22:13:03 volumio sudo[731]: pam_unix(sudo:session): session closed for user root Nov 28 22:13:03 volumio go-librespot[781]: time="2024-11-28T22:13:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-11-28T22:13:03+09:00 is before 2025-01-06T00:00:00Z" Nov 28 22:13:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 22:13:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 22:13:03 volumio sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-28 22:12 Nov 28 22:13:03 volumio sudo[800]: 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="c87c6e2b1ae33dc5801986cbcbe970898b92e7b4" VOLUMIO_FE_VERSION="c433755e569617abac52264d17ad61be303ef463" VOLUMIO_FE3_VERSION="2419ddd8e895c5bdc456962163c9dc7c0f187aa7" VOLUMIO_BE_VERSION="b949d6001d7e656b4668f31c119d2247cdf45158" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 30 Mar 2023 05:45:03 PM CEST" VOLUMIO_VERSION="3.449" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6428d8e2c06e98483f5c5d77e8f01989"