-- Logs begin at Fri 2023-01-06 04:29:16 UTC, end at Fri 2023-01-06 04:31:22 UTC. -- Jan 06 04:30:00 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:00 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:00 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:00 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:00 command-ctr-volumio kernel: random: crng init done Jan 06 04:30:00 command-ctr-volumio kernel: random: 7 urandom warning(s) missed due to ratelimiting Jan 06 04:30:02 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:02 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:02 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:02 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:03 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:03] [info] asio async_connect error: system:111 (Connection refused) Jan 06 04:30:03 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:03] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 06 04:30:03 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:03] [error] handle_connect error: Underlying Transport Error Jan 06 04:30:04 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:04 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:04 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:04 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:06 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:06 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:06 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:06 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:07 command-ctr-volumio wireless.js[572]: WIRELESS DAEMON: start Jan 06 04:30:07 command-ctr-volumio wireless.js[572]: WIRELESS: Loaded configuration Jan 06 04:30:07 command-ctr-volumio wireless.js[572]: Cleaning previous... Jan 06 04:30:07 command-ctr-volumio systemd[1]: Started LSB: start Samba daemons for the AD DC. Jan 06 04:30:08 command-ctr-volumio systemd[1]: Stopped hotspot.service. Jan 06 04:30:08 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:08 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:08 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:08 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:08 command-ctr-volumio sudo[673]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 06 04:30:08 command-ctr-volumio sudo[673]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:09 command-ctr-volumio sudo[673]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:09 command-ctr-volumio sudo[681]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 06 04:30:09 command-ctr-volumio sudo[681]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:10 command-ctr-volumio sudo[681]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:10 command-ctr-volumio systemd[1]: Started Music Player Daemon. Jan 06 04:30:10 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:10 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:10 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:10 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:10 command-ctr-volumio wireless.js[572]: Stopped aP Jan 06 04:30:10 command-ctr-volumio wireless.js[572]: Start wireless flow Jan 06 04:30:10 command-ctr-volumio wireless.js[572]: Stopped hotspot (if there).. Jan 06 04:30:11 command-ctr-volumio sudo[704]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 06 04:30:11 command-ctr-volumio winbind[478]: Starting the Winbind daemon: winbindmkdir failed on directory /var/log/samba/cores: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to setup corepath for winbindd: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: mkdir failed on directory /var/log/samba/cores: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to setup corepath for winbindd: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../source3/winbindd/winbindd.c:1549(main) Jan 06 04:30:11 command-ctr-volumio winbind[478]: winbindd version 4.2.14-Debian started. Jan 06 04:30:11 command-ctr-volumio winbind[478]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../lib/util/util.c:220(directory_create_or_exist) Jan 06 04:30:11 command-ctr-volumio winbind[478]: mkdir failed on directory /var/log/samba/cores: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to setup corepath for winbindd: No such file or directory Jan 06 04:30:11 command-ctr-volumio winbindd[667]: [2023/01/06 04:30:11.247705, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbindd[667]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio sudo[704]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:11 command-ctr-volumio winbindd[667]: [2023/01/06 04:30:11.270740, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbindd[667]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbindd[708]: [2023/01/06 04:30:11.358104, 0] ../source3/winbindd/winbindd_cache.c:3235(initialize_winbindd_cache) Jan 06 04:30:11 command-ctr-volumio winbindd[708]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 06 04:30:11 command-ctr-volumio sudo[704]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:11 command-ctr-volumio systemd[1]: Started LSB: start Winbind daemon. Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11.247705, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: [2023/01/06 04:30:11.270740, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbind[478]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbind[478]: . Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Starting NetBIOS name server: nmbdmkdir failed on directory /var/log/samba/cores: No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Unable to setup corepath for nmbd: No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[485]: [2023/01/06 04:30:11, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[485]: [2023/01/06 04:30:11, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[485]: [2023/01/06 04:30:11, 0] ../source3/nmbd/nmbd.c:908(main) Jan 06 04:30:11 command-ctr-volumio nmbd[485]: nmbd version 4.2.14-Debian started. Jan 06 04:30:11 command-ctr-volumio nmbd[485]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Jan 06 04:30:11 command-ctr-volumio nmbd[688]: [2023/01/06 04:30:11.580828, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio nmbd[688]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[688]: [2023/01/06 04:30:11.585091, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio nmbd[688]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:11 command-ctr-volumio winbindd[708]: [2023/01/06 04:30:11.591348, 0] ../lib/util/become_daemon.c:124(daemon_ready) Jan 06 04:30:11 command-ctr-volumio winbindd[708]: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 06 04:30:11 command-ctr-volumio sudo[713]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 06 04:30:11 command-ctr-volumio nmbd[714]: [2023/01/06 04:30:11.638297, 0] ../source3/nmbd/asyncdns.c:157(start_async_dns) Jan 06 04:30:11 command-ctr-volumio nmbd[714]: started asyncdns process 718 Jan 06 04:30:11 command-ctr-volumio winbindd[715]: [2023/01/06 04:30:11.668206, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:11 command-ctr-volumio winbindd[715]: Unable to open new log file '/var/log/samba/log.wb-COMMAND-CTR-VOLUMIO': No such file or directory Jan 06 04:30:11 command-ctr-volumio nmbd[714]: [2023/01/06 04:30:11.696732, 0] ../lib/util/become_daemon.c:135(daemon_status) Jan 06 04:30:11 command-ctr-volumio nmbd[714]: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ...NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jan 06 04:30:11 command-ctr-volumio sudo[713]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:11 command-ctr-volumio sudo[713]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:11 command-ctr-volumio systemd[1]: Started LSB: start Samba NetBIOS nameserver (nmbd). Jan 06 04:30:11 command-ctr-volumio systemd[1]: Starting LSB: start Samba SMB/CIFS daemon (smbd)... Jan 06 04:30:11 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:11 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:11 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:11 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:11 command-ctr-volumio nmbd[485]: [2023/01/06 04:30:11.580828, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:12 command-ctr-volumio nmbd[485]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:12 command-ctr-volumio nmbd[485]: [2023/01/06 04:30:11.585091, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:12 command-ctr-volumio nmbd[485]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Jan 06 04:30:12 command-ctr-volumio nmbd[485]: . Jan 06 04:30:12 command-ctr-volumio wireless.js[572]: DHCP IP Jan 06 04:30:12 command-ctr-volumio wireless.js[572]: Start ap Jan 06 04:30:12 command-ctr-volumio sudo[734]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jan 06 04:30:12 command-ctr-volumio sudo[734]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:12 command-ctr-volumio dhcpcd[738]: version 6.0.5 starting Jan 06 04:30:12 command-ctr-volumio kernel: brcmfmac: power management disabled Jan 06 04:30:12 command-ctr-volumio wpa_supplicant[729]: Successfully initialized wpa_supplicant Jan 06 04:30:13 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:13 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:13 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:13 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:13 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:13 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:13] [info] asio async_connect error: system:111 (Connection refused) Jan 06 04:30:13 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:13] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 06 04:30:13 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:13] [error] handle_connect error: Underlying Transport Error Jan 06 04:30:13 command-ctr-volumio dhcpcd[738]: wlan0: waiting for carrier Jan 06 04:30:13 command-ctr-volumio sudo[754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:13 command-ctr-volumio sudo[754]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:14 command-ctr-volumio sudo[754]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:14 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:14 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:14 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:14 command-ctr-volumio systemd[1]: Started Xbindrc. Jan 06 04:30:14 command-ctr-volumio wpa_supplicant[760]: wlan0: Trying to associate with SSID 'NETGEAR_11N' Jan 06 04:30:15 command-ctr-volumio wpa_supplicant[760]: wlan0: Associated with 38:94:ed:ff:91:98 Jan 06 04:30:15 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:15 command-ctr-volumio wpa_supplicant[760]: wlan0: WPA: Key negotiation completed with 38:94:ed:ff:91:98 [PTK=CCMP GTK=TKIP] Jan 06 04:30:15 command-ctr-volumio wpa_supplicant[760]: wlan0: CTRL-EVENT-CONNECTED - Connection to 38:94:ed:ff:91:98 completed [id=0 id_str=] Jan 06 04:30:15 command-ctr-volumio dhcpcd[738]: wlan0: carrier acquired Jan 06 04:30:15 command-ctr-volumio wpa_supplicant[760]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jan 06 04:30:15 command-ctr-volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Jan 06 04:30:15 command-ctr-volumio systemd[1]: Stopping Xbindrc... Jan 06 04:30:15 command-ctr-volumio systemd[1]: Starting Xbindrc... Jan 06 04:30:15 command-ctr-volumio systemd[1]: xbindkeysrc.service start request repeated too quickly, refusing to start. Jan 06 04:30:15 command-ctr-volumio systemd[1]: Failed to start Xbindrc. Jan 06 04:30:15 command-ctr-volumio systemd[1]: Unit xbindkeysrc.service entered failed state. Jan 06 04:30:15 command-ctr-volumio sudo[777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:15 command-ctr-volumio sudo[777]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:15 command-ctr-volumio sudo[777]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:15 command-ctr-volumio dhcpcd[738]: wlan0: rebinding lease of 192.168.1.4 Jan 06 04:30:16 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:16 command-ctr-volumio sudo[795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:16 command-ctr-volumio sudo[795]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:16 command-ctr-volumio sudo[795]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:17 command-ctr-volumio smbd[720]: Starting SMB/CIFS daemon: smbd[2023/01/06 04:30:17, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17, 0] ../lib/util/util.c:220(directory_create_or_exist) Jan 06 04:30:17 command-ctr-volumio smbd[720]: mkdir failed on directory /var/log/samba/cores: No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to setup corepath for smbd: No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17, 0] ../source3/smbd/server.c:1241(main) Jan 06 04:30:17 command-ctr-volumio smbd[720]: smbd version 4.2.14-Debian started. Jan 06 04:30:17 command-ctr-volumio smbd[720]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Jan 06 04:30:17 command-ctr-volumio smbd[804]: [2023/01/06 04:30:17.806314, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[804]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[804]: [2023/01/06 04:30:17.813691, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[804]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[804]: [2023/01/06 04:30:17.814400, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[804]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17.806314, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17.813691, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio smbd[720]: [2023/01/06 04:30:17.814400, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio smbd[720]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:17 command-ctr-volumio systemd[1]: Started LSB: start Samba SMB/CIFS daemon (smbd). Jan 06 04:30:17 command-ctr-volumio smbd[720]: . Jan 06 04:30:17 command-ctr-volumio winbindd[808]: [2023/01/06 04:30:17.980531, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:17 command-ctr-volumio winbindd[808]: Unable to open new log file '/var/log/samba/log.winbindd-idmap': No such file or directory Jan 06 04:30:17 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:18 command-ctr-volumio sudo[810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:18 command-ctr-volumio sudo[810]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:18 command-ctr-volumio smbd[805]: [2023/01/06 04:30:18.177231, 0] ../lib/util/become_daemon.c:124(daemon_ready) Jan 06 04:30:18 command-ctr-volumio smbd[805]: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 06 04:30:18 command-ctr-volumio sudo[810]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:18 command-ctr-volumio smbd[815]: [2023/01/06 04:30:18.218723, 0] ../lib/util/debug.c:603(reopen_logs_internal) Jan 06 04:30:18 command-ctr-volumio smbd[815]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Jan 06 04:30:19 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:19 command-ctr-volumio sudo[821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:19 command-ctr-volumio sudo[821]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:19 command-ctr-volumio sudo[821]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: NAK: from 192.168.1.250 Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: soliciting a DHCP lease Jan 06 04:30:20 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:20 command-ctr-volumio sudo[840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:20 command-ctr-volumio sudo[840]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: offered 192.168.1.128 from 192.168.1.250 Jan 06 04:30:20 command-ctr-volumio sudo[840]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: leased 192.168.1.128 for 60 seconds Jan 06 04:30:20 command-ctr-volumio avahi-daemon[501]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.128. Jan 06 04:30:20 command-ctr-volumio avahi-daemon[501]: New relevant interface wlan0.IPv4 for mDNS. Jan 06 04:30:20 command-ctr-volumio avahi-daemon[501]: Registering new address record for 192.168.1.128 on wlan0.IPv4. Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: adding host route to 192.168.1.128 via 127.0.0.1 Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: adding route to 192.168.1.0/24 Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: wlan0: adding default route via 192.168.1.250 Jan 06 04:30:20 command-ctr-volumio dhcpcd[738]: forked to background, child pid 869 Jan 06 04:30:20 command-ctr-volumio sudo[734]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:21 command-ctr-volumio wireless.js[572]: trying... Jan 06 04:30:21 command-ctr-volumio nmbd[714]: [2023/01/06 04:30:21.713328, 0] ../lib/util/become_daemon.c:124(daemon_ready) Jan 06 04:30:21 command-ctr-volumio sudo[874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 06 04:30:21 command-ctr-volumio nmbd[714]: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 06 04:30:21 command-ctr-volumio sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:21 command-ctr-volumio ntpd[557]: Listen normally on 3 wlan0 192.168.1.128 UDP 123 Jan 06 04:30:21 command-ctr-volumio ntpd[557]: peers refreshed Jan 06 04:30:21 command-ctr-volumio sudo[874]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:21 command-ctr-volumio wireless.js[572]: Connected to: ----NETGEAR_11N Jan 06 04:30:21 command-ctr-volumio wireless.js[572]: ---- Jan 06 04:30:21 command-ctr-volumio sudo[884]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 06 04:30:21 command-ctr-volumio sudo[884]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:30:21 command-ctr-volumio sudo[884]: pam_unix(sudo:session): session closed for user root Jan 06 04:30:22 command-ctr-volumio wireless.js[572]: ... joined AP, wlan0 IPv4 is 192.168.1.128, ipV6 is undefined Jan 06 04:30:22 command-ctr-volumio wireless.js[572]: It's done! AP Jan 06 04:30:22 command-ctr-volumio systemd[1]: Started Wireless Services. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Starting Volumio Backend Module... Jan 06 04:30:22 command-ctr-volumio systemd[1]: Started Volumio Backend Module. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Starting Volumio Streaming Daemon... Jan 06 04:30:22 command-ctr-volumio systemd[1]: Started Volumio Streaming Daemon. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Starting Multi-User System. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Reached target Multi-User System. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Starting Graphical Interface. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Reached target Graphical Interface. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 06 04:30:22 command-ctr-volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 06 04:30:22 command-ctr-volumio systemd[1]: Startup finished in 10.863s (kernel) + 1min 8.092s (userspace) = 1min 18.956s. Jan 06 04:30:22 command-ctr-volumio volumio-streaming-daemon[894]: ############################ Jan 06 04:30:22 command-ctr-volumio volumio-streaming-daemon[894]: # Volumio Streaming Daemon # Jan 06 04:30:22 command-ctr-volumio volumio-streaming-daemon[894]: # Running on port 7777 # Jan 06 04:30:22 command-ctr-volumio volumio-streaming-daemon[894]: ############################ Jan 06 04:30:23 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:23] [info] asio async_connect error: system:111 (Connection refused) Jan 06 04:30:23 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:23] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 06 04:30:23 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:23] [error] handle_connect error: Underlying Transport Error Jan 06 04:30:30 command-ctr-volumio ntpd_intres[626]: DNS 0.debian.pool.ntp.org -> 192.168.1.250 Jan 06 04:30:30 command-ctr-volumio ntpd_intres[626]: DNS 1.debian.pool.ntp.org -> 192.168.1.250 Jan 06 04:30:30 command-ctr-volumio ntpd_intres[626]: DNS 2.debian.pool.ntp.org -> 192.168.1.250 Jan 06 04:30:30 command-ctr-volumio ntpd_intres[626]: DNS 3.debian.pool.ntp.org -> 192.168.1.250 Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ----- Volumio2 ---- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ----- System startup ---- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: MYVOLUMIO Environment detected Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Plugin folders cleanup Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning into folder /volumio/app/plugins/ Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category audio_interface Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category miscellanea Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category music_service Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category plugins.json Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category system_controller Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category user_interface Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning into folder /data/plugins/ Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Scanning category music_service Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Plugin folders cleanup completed Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ----- Core plugins startup ---- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Loading plugins from folder /volumio/app/plugins/ Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Adding plugin upnp to MyMusic Plugins Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Loading plugins from folder /data/plugins/ Jan 06 04:30:31 command-ctr-volumio volumio[893]: info: Loading plugin "system"... Jan 06 04:30:32 command-ctr-volumio volumio[893]: { Error: ENOENT: no such file or directory, open '/sys/class/net/eth0/address' Jan 06 04:30:32 command-ctr-volumio volumio[893]: at Object.fs.openSync (fs.js:646:18) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at Object.fs.readFileSync (fs.js:551:33) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at ControllerSystem.callHome (/volumio/app/plugins/system_controller/system/index.js:578:20) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at ControllerSystem.onVolumioStart (/volumio/app/plugins/system_controller/system/index.js:51:7) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:169:35) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at /volumio/app/pluginmanager.js:261:30 Jan 06 04:30:32 command-ctr-volumio volumio[893]: at Array.forEach () Jan 06 04:30:32 command-ctr-volumio volumio[893]: at HashMap. (/volumio/app/pluginmanager.js:260:17) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:172:10) Jan 06 04:30:32 command-ctr-volumio volumio[893]: at HashMap.proto.(anonymous function) [as forEach] (/volumio/node_modules/hashmap/hashmap.js:184:7) Jan 06 04:30:32 command-ctr-volumio volumio[893]: errno: -2, Jan 06 04:30:32 command-ctr-volumio volumio[893]: code: 'ENOENT', Jan 06 04:30:32 command-ctr-volumio volumio[893]: syscall: 'open', Jan 06 04:30:32 command-ctr-volumio volumio[893]: path: '/sys/class/net/eth0/address' } Jan 06 04:30:32 command-ctr-volumio volumio[893]: info: Loading plugin "appearance"... Jan 06 04:30:33 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:33] [connect] Successful connection Jan 06 04:30:37 command-ctr-volumio volumio[893]: info: Loading plugin "network"... Jan 06 04:30:38 command-ctr-volumio volumio[893]: info: Loading plugin "services"... Jan 06 04:30:38 command-ctr-volumio volumio[893]: info: Loading plugin "alsa_controller"... Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: Loading plugin "wizard"... Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: Loading plugin "volumio_command_line_client"... Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: Loading plugin "upnp"... Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: [1672979439337] Starting Upmpd Daemon Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: Loading plugin "my_music"... Jan 06 04:30:39 command-ctr-volumio volumio[893]: info: Loading plugin "mpd"... Jan 06 04:30:41 command-ctr-volumio volumio[893]: info: Loading plugin "upnp_browser"... Jan 06 04:30:45 command-ctr-volumio volumio[893]: info: Loading plugin "networkfs"... Jan 06 04:30:46 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 06 04:30:46 command-ctr-volumio volumio[893]: info: Loading plugin "alarm-clock"... Jan 06 04:30:47 command-ctr-volumio volumio[893]: info: Loading plugin "airplay_emulation"... Jan 06 04:30:47 command-ctr-volumio volumio[893]: info: Starting Shairport Sync Jan 06 04:30:47 command-ctr-volumio volumio[893]: info: Loading plugin "last_100"... Jan 06 04:30:47 command-ctr-volumio volumio[893]: info: Loading plugin "webradio"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "i2s_dacs"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "volumiodiscovery"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** For more information see Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 06 04:30:48 command-ctr-volumio node[893]: *** WARNING *** For more information see Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** For more information see Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 06 04:30:48 command-ctr-volumio volumio[893]: *** WARNING *** For more information see Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 06 04:30:48 command-ctr-volumio volumio[893]: Discovery: StartAdv! undefined Jan 06 04:30:48 command-ctr-volumio volumio[893]: Discovery: Started advertising... command-ctr-Volumio - undefined Jan 06 04:30:48 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:30:48] [connect] Successful connection Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "outputs"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "albumart"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Plugin example_plugin is not enabled Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "inputs"... Jan 06 04:30:48 command-ctr-volumio volumio[893]: info: Loading plugin "updater_comm"... Jan 06 04:30:50 command-ctr-volumio volumio[893]: info: Plugin mpdemulation is not enabled Jan 06 04:30:50 command-ctr-volumio volumio[893]: info: Loading plugin "rest_api"... Jan 06 04:30:50 command-ctr-volumio volumio[893]: info: Loading plugin "websocket"... Jan 06 04:30:50 command-ctr-volumio volumio[893]: info: Loading plugin "spop"... Jan 06 04:30:51 command-ctr-volumio volumio[893]: Forking 1 albumart workers Jan 06 04:30:57 command-ctr-volumio volumio[893]: info: Loading plugin "volspotconnect2"... Jan 06 04:30:57 command-ctr-volumio volumio[893]: Starting albumart workers Jan 06 04:31:01 command-ctr-volumio volumio[893]: info: ___________ START PLUGINS ___________ Jan 06 04:31:01 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 06 04:31:01 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 06 04:31:01 command-ctr-volumio volumio[893]: info: [1672979461982] CoreMusicLibrary::Adding element Media Servers Jan 06 04:31:01 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: [1672979462308] CoreMusicLibrary::Adding element Last_100 Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: [1672979462329] CoreMusicLibrary::Adding element Webradio Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 06 04:31:02 command-ctr-volumio volumio[893]: [SpotifyConnect] Creating VLS config file Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:02 command-ctr-volumio volumio[893]: [SpotifyConnect] Starting metadata listener Jan 06 04:31:02 command-ctr-volumio sudo[943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start spop.service Jan 06 04:31:02 command-ctr-volumio sudo[943]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: ----- MyVolumio plugins startup ---- Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: ------------------------------------------- Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: Loading plugins from folder /myvolumio/plugins Jan 06 04:31:02 command-ctr-volumio systemd[1]: Configuration file /lib/systemd/system/spop.service is marked executable. Please remove executable permission bits. Proceeding anyway. Jan 06 04:31:02 command-ctr-volumio systemd[1]: Configuration file /lib/systemd/system/spop.service is marked world-writable. Please remove world writability permission bits. Proceeding anyway. Jan 06 04:31:02 command-ctr-volumio systemd[1]: Starting Spotify Daemon... Jan 06 04:31:02 command-ctr-volumio systemd[1]: Started Spotify Daemon. Jan 06 04:31:02 command-ctr-volumio sudo[943]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:02 command-ctr-volumio volumio[893]: info: Loading plugins from folder /data/myvolumio/plugins Jan 06 04:31:03 command-ctr-volumio sudo[949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Jan 06 04:31:03 command-ctr-volumio volumio[893]: info: Loading plugin "cd_controller"... Jan 06 04:31:03 command-ctr-volumio sudo[949]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:03 command-ctr-volumio systemd[1]: Starting Volspotconnect2 Daemon... Jan 06 04:31:03 command-ctr-volumio systemd[1]: Started Volspotconnect2 Daemon. Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.257 I [offline_authorizer.cpp:297] Unable to login offline: no such user Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.317 I [ap:1752] Connecting to AP ap.spotify.com:4070 Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.350 E [ap:1694] AP Socket Error: Connection refused (111) Jan 06 04:31:03 command-ctr-volumio sudo[949]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.366 E [ap:3953] Connection error: 101 Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.369 I [ap:1752] Connecting to AP ap.spotify.com:443 Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.389 E [ap:1694] AP Socket Error: Connection refused (111) Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.390 E [ap:3953] Connection error: 101 Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.400 I [ap:1752] Connecting to AP ap.spotify.com:80 Jan 06 04:31:03 command-ctr-volumio volumio[950]: 2023-01-06 04:31:03 [SPTF] 04:31:03.420 I [ap:1226] Connected to AP: 192.168.1.250:80 Jan 06 04:31:03 command-ctr-volumio volumio[893]: info: Loading plugin "streaming_services"... Jan 06 04:31:03 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:31:03] [connect] Successful connection Jan 06 04:31:03 command-ctr-volumio volumio[961]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Jan 06 04:31:03 command-ctr-volumio volumio[961]: Reading Config from "volspotify.toml" Jan 06 04:31:03 command-ctr-volumio volumio[961]: [Vollibrespot] : Using Alsa backend with device: plughw:1 Jan 06 04:31:04 command-ctr-volumio volumio[961]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.585 E [ap:1694] AP Socket Error: Software caused connection abort (103) Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.589 E [ap:3953] Connection error: 112 Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.591 I [ap:1752] Connecting to AP ap.spotify.com:4070 Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.605 E [ap:1694] AP Socket Error: Connection refused (111) Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.606 E [ap:3953] Connection error: 101 Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.610 I [ap:1752] Connecting to AP ap.spotify.com:443 Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.621 E [ap:1694] AP Socket Error: Connection refused (111) Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.622 E [ap:3953] Connection error: 101 Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.623 I [ap:1752] Connecting to AP ap.spotify.com:80 Jan 06 04:31:04 command-ctr-volumio volumio[893]: info: Loading plugin "my_volumio"... Jan 06 04:31:04 command-ctr-volumio volumio[950]: 2023-01-06 04:31:04 [SPTF] 04:31:04.663 I [ap:1226] Connected to AP: 192.168.1.250:80 Jan 06 04:31:05 command-ctr-volumio volumio[950]: 2023-01-06 04:31:05 [SPTF] 04:31:05.736 E [ap:1694] AP Socket Error: Software caused connection abort (103) Jan 06 04:31:05 command-ctr-volumio volumio[950]: 2023-01-06 04:31:05 [SPTF] 04:31:05.740 E [ap:3953] Connection error: 112 Jan 06 04:31:05 command-ctr-volumio volumio[950]: 2023-01-06 04:31:05 [WARN] Login failed: Cannot connect to Spotify Jan 06 04:31:05 command-ctr-volumio volumio[950]: 2023-01-06 04:31:05 [ERR ] Could not get the playlist container. Jan 06 04:31:05 command-ctr-volumio systemd[1]: spop.service: main process exited, code=killed, status=5/TRAP Jan 06 04:31:05 command-ctr-volumio systemd[1]: Unit spop.service entered failed state. Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Adding CD REST API Endpoints Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Adding detectCD REST Endpoint for plugin: music_service/cd_controller Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Adding cdRemove REST Endpoint for plugin: music_service/cd_controller Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Adding cdPostScan REST Endpoint for plugin: music_service/cd_controller Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Detecting CD presence Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Streaming services startup Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Starting Streaming Daemon Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Starting MyVolumio Remote Streaming Endpoints Jan 06 04:31:07 command-ctr-volumio sudo[968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 06 04:31:07 command-ctr-volumio sudo[968]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:07 command-ctr-volumio systemd[1]: Stopping Volumio Streaming Daemon... Jan 06 04:31:07 command-ctr-volumio systemd[1]: Starting Volumio Streaming Daemon... Jan 06 04:31:07 command-ctr-volumio systemd[1]: Started Volumio Streaming Daemon. Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: Loading i18n strings for locale en Jan 06 04:31:07 command-ctr-volumio sudo[968]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:07 command-ctr-volumio volumio[893]: Updating browse sources language Jan 06 04:31:07 command-ctr-volumio volumio[893]: Cannot find translation for sourceMedia Servers Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 06 04:31:07 command-ctr-volumio volumio-streaming-daemon[974]: ############################ Jan 06 04:31:07 command-ctr-volumio volumio-streaming-daemon[974]: # Volumio Streaming Daemon # Jan 06 04:31:07 command-ctr-volumio volumio-streaming-daemon[974]: # Running on port 7777 # Jan 06 04:31:07 command-ctr-volumio volumio-streaming-daemon[974]: ############################ Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 06 04:31:07 command-ctr-volumio volumio[893]: info: CoreCommandRouter::initPlayerControls Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: BOOT COMPLETED Jan 06 04:31:08 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: failed to renew DHCP, rebinding Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: NAK: from 192.168.1.1 Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: deleting host route to 192.168.1.128 via 127.0.0.1 Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: deleting route to 192.168.1.0/24 Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: deleting default route via 192.168.1.250 Jan 06 04:31:12 command-ctr-volumio avahi-daemon[501]: Withdrawing address record for 192.168.1.128 on wlan0. Jan 06 04:31:12 command-ctr-volumio avahi-daemon[501]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.128. Jan 06 04:31:12 command-ctr-volumio avahi-daemon[501]: Interface wlan0.IPv4 no longer relevant for mDNS. Jan 06 04:31:12 command-ctr-volumio dhcpcd[869]: wlan0: soliciting a DHCP lease Jan 06 04:31:13 command-ctr-volumio dhcpcd[869]: wlan0: offered 192.168.1.4 from 192.168.1.1 Jan 06 04:31:13 command-ctr-volumio dhcpcd[869]: wlan0: leased 192.168.1.4 for 86400 seconds Jan 06 04:31:13 command-ctr-volumio avahi-daemon[501]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.4. Jan 06 04:31:13 command-ctr-volumio avahi-daemon[501]: New relevant interface wlan0.IPv4 for mDNS. Jan 06 04:31:13 command-ctr-volumio avahi-daemon[501]: Registering new address record for 192.168.1.4 on wlan0.IPv4. Jan 06 04:31:13 command-ctr-volumio dhcpcd[869]: wlan0: adding host route to 192.168.1.4 via 127.0.0.1 Jan 06 04:31:13 command-ctr-volumio dhcpcd[869]: wlan0: adding route to 192.168.1.0/24 Jan 06 04:31:13 command-ctr-volumio dhcpcd[869]: wlan0: adding default route via 192.168.1.1 Jan 06 04:31:13 command-ctr-volumio volumio[893]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Jan 06 04:31:13 command-ctr-volumio volumio[893]: info: CoreCommandRouter::Close All Modals sent Jan 06 04:31:13 command-ctr-volumio volumio[893]: info: CoreCommandRouter::Close All Modals sent Jan 06 04:31:13 command-ctr-volumio volumio[893]: Express server listening on port 3000 Jan 06 04:31:13 command-ctr-volumio volumio[893]: Volumio Calling Home Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: MyVolumio not started Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: Initializing device activation check Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreStateMachine::resetVolumioState Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreStateMachine::getcurrentVolume Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioRetrievevolume Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 06 04:31:14 command-ctr-volumio sudo[1027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 06 04:31:14 command-ctr-volumio sudo[1027]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:14 command-ctr-volumio ntpd[557]: Listen normally on 4 wlan0 192.168.1.4 UDP 123 Jan 06 04:31:14 command-ctr-volumio ntpd[557]: Deleting interface #3 wlan0, 192.168.1.128#123, interface stats: received=0, sent=1, dropped=0, active_time=53 secs Jan 06 04:31:14 command-ctr-volumio ntpd[557]: 192.168.1.250 interface 192.168.1.128 -> (none) Jan 06 04:31:14 command-ctr-volumio ntpd[557]: peers refreshed Jan 06 04:31:14 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 06 04:31:14 command-ctr-volumio sudo[1027]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: Setting Device type: Raspberry PI Jan 06 04:31:16 command-ctr-volumio volumio[893]: [SpotifyConnect] Vollibrespot Daemon service started! Jan 06 04:31:16 command-ctr-volumio volumio[893]: SpotifyConnect: 13827.725ms Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: SpopD Daemon Started Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: MPD running with PID511 ,establishing connection Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: VolumeController:: Volume=32 Mute =true Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: CoreStateMachine::pushState Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: CoreStateMachine::getState Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: CorePlayQueue::getTrack 0 Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioPushState Jan 06 04:31:16 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 06 04:31:17 command-ctr-volumio volumio[893]: error: error Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: Reloading queue from file Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: message= [50@0] {} No such directory, stack=Error: [50@0] {} No such directory Jan 06 04:31:17 command-ctr-volumio volumio[893]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:14) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:10) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at emitOne (events.js:116:13) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at Socket.emit (events.js:211:7) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at addChunk (_stream_readable.js:263:12) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at readableAddChunk (_stream_readable.js:246:13) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at Socket.Readable.push (_stream_readable.js:208:10) Jan 06 04:31:17 command-ctr-volumio volumio[893]: at Pipe.onread (net.js:607:20) Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::setRepeat null single undefined Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::pushState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::getState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CorePlayQueue::getTrack 0 Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioPushState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::setRandom null Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::pushState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreStateMachine::getState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CorePlayQueue::getTrack 0 Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreCommandRouter::volumioPushState Jan 06 04:31:17 command-ctr-volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 06 04:31:18 command-ctr-volumio volumio[893]: info: mDNS: A device disapperared from network Jan 06 04:31:18 command-ctr-volumio volumio[893]: info: mDNS Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Jan 06 04:31:18 command-ctr-volumio sudo[1041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay Jan 06 04:31:18 command-ctr-volumio sudo[1041]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:18 command-ctr-volumio sudo[1043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay Jan 06 04:31:18 command-ctr-volumio volumio-remote-updater[467]: [2023-01-06 04:31:18] [connect] Successful connection Jan 06 04:31:18 command-ctr-volumio systemd[1]: Starting ShairportSync AirTunes receiver... Jan 06 04:31:18 command-ctr-volumio systemd[1]: Started ShairportSync AirTunes receiver. Jan 06 04:31:18 command-ctr-volumio sudo[1043]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:18 command-ctr-volumio sudo[1041]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:18 command-ctr-volumio sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 06 04:31:18 command-ctr-volumio sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 06 04:31:18 command-ctr-volumio systemd[1]: Stopping ShairportSync AirTunes receiver... Jan 06 04:31:18 command-ctr-volumio shairport-sync[1053]: Successful Startup Jan 06 04:31:18 command-ctr-volumio systemd[1]: Starting ShairportSync AirTunes receiver... Jan 06 04:31:18 command-ctr-volumio systemd[1]: Started ShairportSync AirTunes receiver. Jan 06 04:31:18 command-ctr-volumio volumio[893]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 06 04:31:18 command-ctr-volumio sudo[1043]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:19 command-ctr-volumio volumio[893]: { Error: addMembership ENODEV Jan 06 04:31:19 command-ctr-volumio volumio[893]: at _errnoException (util.js:1022:11) Jan 06 04:31:19 command-ctr-volumio volumio[893]: at Socket.addMembership (dgram.js:615:11) Jan 06 04:31:19 command-ctr-volumio volumio[893]: at Timeout.addMembership [as _onTimeout] (/volumio/node_modules/node-ssdp/lib/index.js:261:16) Jan 06 04:31:19 command-ctr-volumio volumio[893]: at ontimeout (timers.js:482:11) Jan 06 04:31:19 command-ctr-volumio volumio[893]: at tryOnTimeout (timers.js:317:5) Jan 06 04:31:19 command-ctr-volumio volumio[893]: at Timer.listOnTimeout (timers.js:277:5) code: 'ENODEV', errno: 'ENODEV', syscall: 'addMembership' } Jan 06 04:31:19 command-ctr-volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Jan 06 04:31:19 command-ctr-volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jan 06 04:31:19 command-ctr-volumio volumio[893]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 06 04:31:19 command-ctr-volumio sudo[1047]: pam_unix(sudo:session): session closed for user root Jan 06 04:31:19 command-ctr-volumio shairport-sync[1065]: Successful Startup Jan 06 04:31:22 command-ctr-volumio sudo[1083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-01-06 04:30 Jan 06 04:31:22 command-ctr-volumio sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="f1d44ae5428081b5b8ca49f419b134ef83e234df" VOLUMIO_FE_VERSION="021732c5252c1ad4fb85955339e1f032fe4ae9f0" VOLUMIO_BE_VERSION="caf6c0f9a8e3cd984391aa77621b50a9247127b8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Aug 2 17:17:17 CEST 2019" VOLUMIO_VERSION="2.599" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="c28fac21d698202aa4e6e014f85b1eaf"