-- Logs begin at Fri 2024-04-05 18:10:53 -02, end at Fri 2024-04-05 18:12:03 -02. --
Apr 05 18:11:00 volumio-pi4 bluetoothd[607]: Failed to set privacy: Rejected (0x0b)
Apr 05 18:11:00 volumio-pi4 systemd[1]: Started LSB: set CPUFreq kernel parameters.
Apr 05 18:11:00 volumio-pi4 systemd[1]: Starting Hostname Service...
Apr 05 18:11:00 volumio-pi4 dbus-daemon[465]: [system] Successfully activated service 'org.freedesktop.hostname1'
Apr 05 18:11:00 volumio-pi4 systemd[1]: Started Hostname Service.
Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.443423, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns)
Apr 05 18:11:00 volumio-pi4 nmbd[613]: started asyncdns process 679
Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.445540, 0] ../lib/util/become_daemon.c:149(daemon_status)
Apr 05 18:11:00 volumio-pi4 nmbd[613]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ...
Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.445712, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets)
Apr 05 18:11:00 volumio-pi4 nmbd[613]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6).
Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K
Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488
Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99864
Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: fills: 0, generated: 0
Apr 05 18:11:00 volumio-pi4 ntpd[652]: error resolving pool 0.debian.pool.ntp.org: System error (-11)
Apr 05 18:11:00 volumio-pi4 wireless.js[480]: Cleaning previous...
Apr 05 18:11:00 volumio-pi4 sudo[687]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
Apr 05 18:11:00 volumio-pi4 sudo[687]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:00 volumio-pi4 sudo[687]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:00 volumio-pi4 sudo[689]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
Apr 05 18:11:00 volumio-pi4 sudo[689]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:01 volumio-pi4 sudo[689]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:01 volumio-pi4 wireless.js[480]: Stopped aP
Apr 05 18:11:01 volumio-pi4 sudo[696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 05 18:11:01 volumio-pi4 sudo[696]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:01 volumio-pi4 sudo[696]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:01 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Apr 05 18:11:01 volumio-pi4 sudo[698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
Apr 05 18:11:01 volumio-pi4 sudo[698]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:01 volumio-pi4 sudo[698]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:01 volumio-pi4 ntpd[652]: error resolving pool 1.debian.pool.ntp.org: System error (-11)
Apr 05 18:11:01 volumio-pi4 sudo[705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 05 18:11:01 volumio-pi4 sudo[705]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:01 volumio-pi4 sudo[705]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:01 volumio-pi4 sudo[707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
Apr 05 18:11:01 volumio-pi4 sudo[707]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:01 volumio-pi4 systemd[1]: systemd-rfkill.service: Succeeded.
Apr 05 18:11:02 volumio-pi4 ntpd[652]: error resolving pool 2.debian.pool.ntp.org: System error (-11)
Apr 05 18:11:03 volumio-pi4 ntpd[652]: error resolving pool 3.debian.pool.ntp.org: System error (-11)
Apr 05 18:11:03 volumio-pi4 bthelper[537]: Changing power off succeeded
Apr 05 18:11:03 volumio-pi4 bthelper[537]: [CHG] Controller E4:5F:01:D5:85:BA Class: 0x0000041c
Apr 05 18:11:03 volumio-pi4 bthelper[537]: Changing power on succeeded
Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [info] asio async_connect error: system:111 (Connection refused)
Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [error] handle_connect error: Underlying Transport Error
Apr 05 18:11:04 volumio-pi4 sudo[707]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: SETTING APPROPRIATE REG DOMAIN: DE
Apr 05 18:11:04 volumio-pi4 sudo[718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 05 18:11:04 volumio-pi4 sudo[718]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:04 volumio-pi4 sudo[718]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:04 volumio-pi4 sudo[720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE
Apr 05 18:11:04 volumio-pi4 sudo[720]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:04 volumio-pi4 sudo[720]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: SUCCESSFULLY SET NEW REGDOMAIN: DE
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Start wireless flow
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Stopped hotspot (if there)..
Apr 05 18:11:04 volumio-pi4 sudo[725]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
Apr 05 18:11:04 volumio-pi4 sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:04 volumio-pi4 sudo[725]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:04 volumio-pi4 sudo[727]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
Apr 05 18:11:04 volumio-pi4 sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:04 volumio-pi4 sudo[727]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: DHCP IP
Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Start ap
Apr 05 18:11:04 volumio-pi4 wpa_supplicant[729]: Successfully initialized wpa_supplicant
Apr 05 18:11:04 volumio-pi4 sudo[730]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd
Apr 05 18:11:04 volumio-pi4 sudo[730]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:04 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Apr 05 18:11:04 volumio-pi4 dhcpcd[731]: dev: loaded udev
Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[749]: wlan0: starting wpa_supplicant
Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[754]: wlan0: failed to start wpa_supplicant
Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[755]: wlan0: Successfully initialized wpa_supplicant
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Match already configured
nl80211: kernel reports: Ma
Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: wlan0: connected to Access Point `'
Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: no interfaces have a carrier
Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: forked to background, child pid 765
Apr 05 18:11:05 volumio-pi4 dhcpcd[765]: eth0: waiting for carrier
Apr 05 18:11:05 volumio-pi4 dhcpcd[765]: wlan0: waiting for carrier
Apr 05 18:11:05 volumio-pi4 sudo[730]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:05 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:05 volumio-pi4 sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:05 volumio-pi4 sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:05 volumio-pi4 sudo[767]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:06 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:06 volumio-pi4 sudo[770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:06 volumio-pi4 sudo[770]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:06 volumio-pi4 sudo[770]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:07 volumio-pi4 wpa_supplicant[753]: wlan0: Trying to associate with SSID 'FRITZ!Box RD'
Apr 05 18:11:07 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:07 volumio-pi4 sudo[773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:07 volumio-pi4 sudo[773]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:07 volumio-pi4 sudo[773]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:08 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:08 volumio-pi4 sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:08 volumio-pi4 sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:08 volumio-pi4 sudo[776]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:09 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:09 volumio-pi4 sudo[779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:09 volumio-pi4 sudo[779]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:09 volumio-pi4 sudo[779]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier acquired
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: connected to Access Point `FRITZ!Box RD'
Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: Associated with 5c:49:79:dc:da:b5
Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:49:79:dc:da:b5 completed [id=0 id_str=]
Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: DUID 00:01:00:01:29:d8:62:59:b8:27:eb:ec:94:ba
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: IAID 01:d5:85:b9
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: adding address fe80::5607:7467:a774:304d
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: ipv6_addaddr1: Permission denied
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier lost
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier acquired
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: IAID 01:d5:85:b9
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: soliciting an IPv6 router
Apr 05 18:11:10 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: rebinding lease of 192.168.111.78
Apr 05 18:11:10 volumio-pi4 sudo[794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:10 volumio-pi4 sudo[794]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:10 volumio-pi4 sudo[794]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:11 volumio-pi4 dhcpcd[765]: wlan0: probing address 192.168.111.78/24
Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [info] asio async_connect error: system:111 (Connection refused)
Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [error] handle_connect error: Underlying Transport Error
Apr 05 18:11:11 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:11 volumio-pi4 sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:11 volumio-pi4 sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:11 volumio-pi4 sudo[797]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:12 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:12 volumio-pi4 sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:12 volumio-pi4 sudo[800]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:12 volumio-pi4 sudo[800]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:13 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:13 volumio-pi4 sudo[803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:13 volumio-pi4 sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:13 volumio-pi4 sudo[803]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:14 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:14 volumio-pi4 sudo[806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:14 volumio-pi4 sudo[806]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:14 volumio-pi4 sudo[806]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:15 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:15 volumio-pi4 sudo[809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:15 volumio-pi4 sudo[809]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:15 volumio-pi4 sudo[809]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: leased 192.168.111.78 for 864000 seconds
Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.111.78.
Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: New relevant interface wlan0.IPv4 for mDNS.
Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: adding route to 192.168.111.0/24
Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: Registering new address record for 192.168.111.78 on wlan0.IPv4.
Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: adding default route via 192.168.111.1
Apr 05 18:11:16 volumio-pi4 wireless.js[480]: trying...
Apr 05 18:11:16 volumio-pi4 sudo[833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 05 18:11:16 volumio-pi4 sudo[833]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:16 volumio-pi4 sudo[833]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:16 volumio-pi4 wireless.js[480]: Connected to: ----FRITZ!Box RD
Apr 05 18:11:16 volumio-pi4 wireless.js[480]: ----
Apr 05 18:11:16 volumio-pi4 sudo[836]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 05 18:11:16 volumio-pi4 sudo[836]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:16 volumio-pi4 sudo[836]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:16 volumio-pi4 wireless.js[480]: ... joined AP, wlan0 IPv4 is 192.168.111.78, ipV6 is undefined
Apr 05 18:11:16 volumio-pi4 wireless.js[480]: It's done! AP
Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Wireless Services.
Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Volumio Backend Module.
Apr 05 18:11:17 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Volumio Cpu Tweaker.
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: Setting RT Priority for mpd
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 35's current scheduling policy: SCHED_OTHER
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 35's current scheduling priority: 0
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: Setting MPD Affinity
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 3's current affinity mask: f
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input
Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance
Apr 05 18:11:17 volumio-pi4 systemd[1]: volumio_cpu_tweak.service: Succeeded.
Apr 05 18:11:17 volumio-pi4 ntpd[652]: Listen normally on 3 wlan0 192.168.111.78:123
Apr 05 18:11:17 volumio-pi4 ntpd[652]: new interface(s) found: waking up resolver
Apr 05 18:11:18 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ----- Volumio3 ----
Apr 05 18:11:18 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ----- System startup ----
Apr 05 18:11:18 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: MYVOLUMIO Environment detected
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Plugin folders cleanup
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning into folder /volumio/app/plugins/
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category audio_interface
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category miscellanea
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category music_service
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category plugins.json
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category system_controller
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category user_interface
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning into folder /data/plugins/
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category audio_interface
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category music_service
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Plugin folders cleanup completed
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: ----- Core plugins startup ----
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugins from folder /volumio/app/plugins/
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin upnp to MyMusic Plugins
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin airplay_emulation to MyMusic Plugins
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin upnp_browser to MyMusic Plugins
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugins from folder /data/plugins/
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugin "system"...
Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugin "appearance"...
Apr 05 18:11:20 volumio-pi4 nmbd[613]: [2024/04/05 18:11:20.450719, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 05 18:11:20 volumio-pi4 systemd[1]: Started Samba NMB Daemon.
Apr 05 18:11:20 volumio-pi4 nmbd[613]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections
Apr 05 18:11:20 volumio-pi4 systemd[1]: Starting Samba Winbind Daemon...
Apr 05 18:11:20 volumio-pi4 winbindd[871]: [2024/04/05 18:11:20.753353, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache)
Apr 05 18:11:20 volumio-pi4 winbindd[871]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "network"...
Apr 05 18:11:20 volumio-pi4 winbindd[871]: [2024/04/05 18:11:20.785129, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 05 18:11:20 volumio-pi4 systemd[1]: Started Samba Winbind Daemon.
Apr 05 18:11:20 volumio-pi4 winbindd[871]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Refreshing Cached IP Addresses
Apr 05 18:11:20 volumio-pi4 sudo[877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 05 18:11:20 volumio-pi4 sudo[877]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "services"...
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "alsa_controller"...
Apr 05 18:11:20 volumio-pi4 sudo[877]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:20 volumio-pi4 sudo[879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 05 18:11:20 volumio-pi4 sudo[879]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:20 volumio-pi4 systemd[1]: Starting Samba SMB Daemon...
Apr 05 18:11:20 volumio-pi4 sudo[879]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:20 volumio-pi4 sudo[882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Apr 05 18:11:20 volumio-pi4 sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "wizard"...
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "networkfs"...
Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Starting Udev Watcher for removable devices
Apr 05 18:11:20 volumio-pi4 sudo[889]: 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.111.55/Media /mnt/NAS/Media
Apr 05 18:11:20 volumio-pi4 sudo[889]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: boot
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: volumio
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: volumio_data
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "volumio_command_line_client"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "upnp"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: [1712347881042] Starting Upmpd Daemon
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "my_music"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "mpd"...
Apr 05 18:11:21 volumio-pi4 kernel: Key type cifs.spnego registered
Apr 05 18:11:21 volumio-pi4 kernel: Key type cifs.idmap registered
Apr 05 18:11:21 volumio-pi4 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.
Apr 05 18:11:21 volumio-pi4 kernel: CIFS: Attempting to mount \\192.168.111.55\Media
Apr 05 18:11:21 volumio-pi4 systemd[1]: Started Samba SMB Daemon.
Apr 05 18:11:21 volumio-pi4 systemd[1]: Reached target Multi-User System.
Apr 05 18:11:21 volumio-pi4 smbd[884]: [2024/04/05 18:11:21.218737, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 05 18:11:21 volumio-pi4 systemd[1]: Reached target Graphical Interface.
Apr 05 18:11:21 volumio-pi4 smbd[884]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
Apr 05 18:11:21 volumio-pi4 systemd[1]: Starting Update UTMP about System Runlevel Changes...
Apr 05 18:11:21 volumio-pi4 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Apr 05 18:11:21 volumio-pi4 systemd[1]: Started Update UTMP about System Runlevel Changes.
Apr 05 18:11:21 volumio-pi4 systemd[1]: Startup finished in 9.735s (kernel) + 30.111s (userspace) = 39.846s.
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "upnp_browser"...
Apr 05 18:11:21 volumio-pi4 sudo[889]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:21 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:21] [connect] Successful connection
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "alarm-clock"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Plugin airplay_emulation is not enabled
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "last_100"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "webradio"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "i2s_dacs"...
Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "volumiodiscovery"...
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** For more information see
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** For more information see
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** For more information see
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** For more information see
Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Applying required configuration parameters for plugin volumiodiscovery
Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Discovery: Started advertising with name: Volumio PI4
Apr 05 18:11:22 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Loading plugin "mixcloud"...
Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Loading plugin "spop"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "outputs"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "albumart"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Plugin example_plugin is not enabled
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "inputs"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "updater_comm"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Plugin mpdemulation is not enabled
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "rest_api"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "websocket"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "fusiondsp"...
Apr 05 18:11:23 volumio-pi4 volumio[841]: Forking 3 albumart workers
Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Applying required configuration parameters for plugin fusiondsp
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Plugin minidlna is not enabled
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Loading plugin "podcast"...
Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers
Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers
Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: ControllerPodcast::constructor
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Loading i18n strings for locale de
Apr 05 18:11:24 volumio-pi4 sudo[882]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:24 volumio-pi4 volumio[841]: Updating browse sources language
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::initPlayerControls
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 05 18:11:24 volumio-pi4 volumio[841]: Express server listening on port 3000
Apr 05 18:11:24 volumio-pi4 volumio[841]: [Metrics] WebUI: 6s 545.66ms
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::resetVolumioState
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::getcurrentVolume
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioRetrievevolume
Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 1
Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 2
Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 3
Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 4
Apr 05 18:11:24 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712347881 101
Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 5
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::updateTrackBlock
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrackBlock
Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioRetrievevolume
Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 6
Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 7
Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 8
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Reloading queue from file
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Setting Device type: Raspberry PI
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::setRepeat true single undefined
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::setRandom true
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Discovery: adding d9036297-85a0-4406-a0ff-51b00fe556bf
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Discovery: Found device Volumio PI4
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 9
Apr 05 18:11:27 volumio-pi4 systemd[1]: systemd-fsckd.service: Succeeded.
Apr 05 18:11:27 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 10
Apr 05 18:11:28 volumio-pi4 sh[409]: timed out
Apr 05 18:11:28 volumio-pi4 dhcpcd[450]: timed out
Apr 05 18:11:28 volumio-pi4 sh[409]: dhcpcd exited
Apr 05 18:11:28 volumio-pi4 dhcpcd[450]: dhcpcd exited
Apr 05 18:11:28 volumio-pi4 sh[409]: ifup: failed to bring up eth0
Apr 05 18:11:28 volumio-pi4 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE
Apr 05 18:11:28 volumio-pi4 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'.
Apr 05 18:11:30 volumio-pi4 systemd[1]: systemd-hostnamed.service: Succeeded.
Apr 05 18:11:31 volumio-pi4 sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 05 18:11:31 volumio-pi4 sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:31 volumio-pi4 sudo[1000]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:31 volumio-pi4 sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 05 18:11:31 volumio-pi4 sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:31 volumio-pi4 sudo[1002]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:31 volumio-pi4 sudo[1006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Apr 05 18:11:31 volumio-pi4 sudo[1006]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:31 volumio-pi4 systemd[1]: Started UPnP Renderer front-end to MPD.
Apr 05 18:11:31 volumio-pi4 sudo[1006]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:31 volumio-pi4 volumio[841]: info: Upmpdcli Daemon Started
Apr 05 18:11:31 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600
Apr 05 18:11:35 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600
Apr 05 18:11:41 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: Discovery: Getting this device information
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 05 18:11:50 volumio-pi4 sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 05 18:11:50 volumio-pi4 sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:50 volumio-pi4 sudo[1010]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:50 volumio-pi4 sudo[1012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 05 18:11:50 volumio-pi4 sudo[1012]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:50 volumio-pi4 sudo[1012]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:50 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 11
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Received Get System Info
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Discovery: Getting this device information
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Listing playlists
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 05 18:11:51 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600
Apr 05 18:11:51 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: unknown Total Clients: 12
Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Received Get System Info
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Discovery: Getting this device information
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Received Get System Info
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Discovery: Getting this device information
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Apr 05 18:11:53 volumio-pi4 wpa_supplicant[753]: RRM: Ignoring radio measurement request: Not RRM network
Apr 05 18:11:54 volumio-pi4 volumio[841]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Preparing to generate the ALSA configuration file
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Reading ALSA contributions from plugins.
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Asound.conf file unchanged, so no further update is needed
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Output device has changed, restarting MPD
Apr 05 18:11:54 volumio-pi4 sudo[1016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 05 18:11:54 volumio-pi4 sudo[1016]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: ___________ START PLUGINS ___________
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: ControllerMpd::onStart: Initializing MPD
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Creating MPD Configuration file
Apr 05 18:11:54 volumio-pi4 sudo[1016]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:54 volumio-pi4 sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 05 18:11:54 volumio-pi4 sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:54 volumio-pi4 sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 05 18:11:54 volumio-pi4 sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914595] CoreMusicLibrary::Adding element Medienserver
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:54 volumio-pi4 sudo[1022]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:54 volumio-pi4 sudo[1024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 05 18:11:54 volumio-pi4 sudo[1024]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914620] CoreMusicLibrary::Adding element Last_100
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914622] CoreMusicLibrary::Adding element Webradio
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914634] CoreMusicLibrary::Adding element Mixcloud
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Mixcloud
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Creating Spotify config file
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Loading i18n strings for locale de
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: FusionDsp - mixtype--------------------- Software
Apr 05 18:11:54 volumio-pi4 systemd[1]: Listening on mpd.socket.
Apr 05 18:11:54 volumio-pi4 systemd[1]: Starting Music Player Daemon...
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914669] CoreMusicLibrary::Adding element Podcast
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Mixcloud
Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Podcast
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Volumio Calling Home
Apr 05 18:11:54 volumio-pi4 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM
Apr 05 18:11:54 volumio-pi4 systemd[1]: mpd.service: Succeeded.
Apr 05 18:11:54 volumio-pi4 systemd[1]: Stopped Music Player Daemon.
Apr 05 18:11:54 volumio-pi4 systemd[1]: Starting Music Player Daemon...
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Preparing to generate the ALSA configuration file
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Reading ALSA contributions from plugins.
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: MPD Permissions set
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: MPD Permissions set
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Volumio called home
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Spotify config file written
Apr 05 18:11:54 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 sudo[1034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Apr 05 18:11:54 volumio-pi4 sudo[1034]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:54 volumio-pi4 systemd[1]: Started go-librespot Daemon.
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: Librespot-go daemon starting...
Apr 05 18:11:55 volumio-pi4 sudo[1034]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: Asound.conf file unchanged, so no further update is needed
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: Output device has changed, restarting MPD
Apr 05 18:11:55 volumio-pi4 sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 05 18:11:55 volumio-pi4 sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:55 volumio-pi4 sudo[1047]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:55 volumio-pi4 sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 05 18:11:55 volumio-pi4 sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:55 volumio-pi4 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM
Apr 05 18:11:55 volumio-pi4 systemd[1]: mpd.service: Succeeded.
Apr 05 18:11:55 volumio-pi4 systemd[1]: Stopped Music Player Daemon.
Apr 05 18:11:55 volumio-pi4 systemd[1]: Starting Music Player Daemon...
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: MPD Permissions set
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=info msg="generated new device id: fdf24893e1bc91a172217684aa3dfc7c1f562b28"
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="zeroconf server listening on port 44215"
Apr 05 18:11:56 volumio-pi4 mpd[1052]: Apr 05 18:11 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 05 18:11:56 volumio-pi4 systemd[1]: Started Music Player Daemon.
Apr 05 18:11:56 volumio-pi4 sudo[1049]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:56 volumio-pi4 sudo[1018]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:56 volumio-pi4 sudo[1024]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Completed starting Core Plugins
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: ----- MyVolumio plugins startup ----
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: -------------------------------------------
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: MPD error: The expression evaluated to a falsy value:
Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling)
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: The expression evaluated to a falsy value:
Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling)
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: MPD error: The expression evaluated to a falsy value:
Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling)
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: The expression evaluated to a falsy value:
Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling)
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: MPD running with PID1052
Apr 05 18:11:56 volumio-pi4 volumio[841]: ,establishing connection
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: updateQueue error: null
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: updateQueue error: null
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: camilladsp spawned new process with pid 1073, instance 1, run: true
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: camilladsp service started and running in background, instance 1
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 05 18:11:56 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp loaded
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 05 18:11:56 volumio-pi4 sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service
Apr 05 18:11:56 volumio-pi4 sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - Reporting Fusion DSP Enabled
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Adding Signal Path Element [object Object]
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Adding fusiondspeq DSP Signal Path Element
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - ---- installed callbackRead
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - Effects disabled
Apr 05 18:11:56 volumio-pi4 volumio[841]: error: FusionDsp - WebSocket error: [object Object]
Apr 05 18:11:56 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 14
Apr 05 18:11:56 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Apr 05 18:11:56 volumio-pi4 systemd[1]: Started FusionDsp Daemon.
Apr 05 18:11:56 volumio-pi4 sudo[1077]: pam_unix(sudo:session): session closed for user root
Apr 05 18:11:58 volumio-pi4 volumio[841]: info: go-librespot daemon successfully initialized
Apr 05 18:11:58 volumio-pi4 volumiologrotate[484]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory
Apr 05 18:11:58 volumio-pi4 volumiologrotate[484]: ls: cannot access 'PI4': No such file or directory
Apr 05 18:12:00 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:00-02:00" level=debug msg="obtained new client token: AABp9VrhSqzumJhkAcyJtlBrWgtAf10mPdEx+iydP1p73v/2hNq/znBl7oYzdkX7n80CSFRgkOVKYigxLSf2JESlhbcpC0RcbJOK9vpkGmi/94LQCX/1CHd5AwyBYi4xXV4va4fGThfkonXDozZbU+BlEX1AY6UxS29eLMIIshElX1/sl6qEQJmUMu6YIKShNqMvsut7yPqfRsHinZs+W3iYH7RmhlZQkHGBmP842ZXp8T1msLgHUHLZK5AWGw=="
Apr 05 18:12:00 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:00-02:00" level=debug msg="completed keyexchange"
Apr 05 18:12:01 volumio-pi4 volumio[841]: info: Initializing connection to go-librespot Websocket
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="new websocket client"
Apr 05 18:12:01 volumio-pi4 volumio[841]: info: Connection to go-librespot Websocket established
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="completed challenge"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="authenticated as 3gur3xe35s7qop2giwk9bklfz"
Apr 05 18:12:01 volumio-pi4 volumio[841]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="authenticated as 3gur3xe35s7qop2giwk9bklfz"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="dealer connection opened"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=info msg="accepted zeroconf user 3gur3xe35s7qop2giwk9bklfz from iPhone"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513"
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="received connection id: NjcwZjM1MTQtZTBlMy00Njg4LWJmZDAtMmFjMDM5ZDY1NTVmK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLWtwMzEuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwK0RCNTM3MEQ2MTkzQUIwOTU4RkM2QzE2RkVFMkU0NjZEREU1OEYyMUFCOThBRDZFNUNENDkyRjQ0Q0ZCNjUwNTA="
Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="put connect state because NEW_DEVICE"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="handling transfer player command from da2907fe9749dbf2065e93d59bf9bdf1373d5912"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="fetched new page 0 with 81 items (list: 81)"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="loading track spotify:track:09t5pNK7TPmboRJb69I1y6 (paused: true, position: 19571ms)"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: will_play"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:09t5pNK7TPmboRJb69I1y6"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="requested aes key for file 0d6179886af0687bf27c21c8776a7fae74c4177f, gid: 09t5pNK7TPmboRJb69I1y6"
Apr 05 18:12:02 volumio-pi4 volumio[841]: Cannot compose Albumart path
Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","play_origin":"playlist/ondemand"}}
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched first chunk of 34, total size is 17384660 bytes"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched chunk 1/33, size: 524288"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="seek to 19571ms (diff: 202ms, samples: 863081, bytes: 812749)"
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate, raw:
Apr 05 18:12:02 volumio-pi4 volumio[841]: error: FusionDsp - invalid sample rate
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp stopping service pid 1073...
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=info msg="loaded track \"Graf Twerk\" (uri: spotify:track:09t5pNK7TPmboRJb69I1y6, paused: true, position: 19571ms, duration: 413386ms)"
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp service terminated, instance 1
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - Effects disabled
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp service started and running in background, instance 1
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp spawned new process with pid 1131, instance 1, run: true
Apr 05 18:12:02 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: metadata"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: active"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="sending successful reply for delaer request"
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","name":"Graf Twerk","artist_names":["Drahthaus"],"album_name":"Drahthaus","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028cbc39c3c721901e3c1c8ff3","position":19571,"duration":413386,"release_date":"year:2020 month:4 day:24","track_number":1,"disc_number":1}}
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"active","data":null}
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: Aligning Spotify Volume to Volumio Volume
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0
Apr 05 18:12:02 volumio-pi4 volumio[841]: info: Setting Spotify Volume from Volumio: 100
Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched chunk 3/33, size: 524288"
Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=trace msg="emitting websocket event: paused"
Apr 05 18:12:03 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","play_origin":"playlist/ondemand"}}
Apr 05 18:12:03 volumio-pi4 volumio[841]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 05 18:12:03 volumio-pi4 volumio[841]: TypeError: Cannot read property 'service' of undefined
Apr 05 18:12:03 volumio-pi4 volumio[841]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at WebSocket.emit (events.js:315:20)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at Receiver.emit (events.js:315:20)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16
Apr 05 18:12:03 volumio-pi4 volumio[841]: at internal/process/task_queues.js:149:7
Apr 05 18:12:03 volumio-pi4 volumio[841]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8)
Apr 05 18:12:03 volumio-pi4 volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:93:5)
Apr 05 18:12:03 volumio-pi4 volumio[841]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="fetched chunk 2/33, size: 524288"
Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="fetched chunk 4/33, size: 524288"
Apr 05 18:12:03 volumio-pi4 sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-05 18:11
Apr 05 18:12:03 volumio-pi4 sudo[1147]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET"
VOLUMIO_VERSION="3.631"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"