-- Logs begin at Sun 2024-07-14 01:01:25 +09, end at Sun 2024-07-14 01:03:37 +09. --
Jul 14 01:02:01 volumio systemd[1]: systemd-hostnamed.service: Succeeded.
Jul 14 01:02:04 volumio sshd[970]: Accepted password for volumio from 192.168.0.12 port 60676 ssh2
Jul 14 01:02:04 volumio sshd[970]: pam_unix(sshd:session): session opened for user volumio by (uid=0)
Jul 14 01:02:04 volumio systemd[1]: Created slice User Slice of UID 1000.
Jul 14 01:02:04 volumio systemd[1]: Starting User Runtime Directory /run/user/1000...
Jul 14 01:02:04 volumio systemd-logind[664]: New session 1 of user volumio.
Jul 14 01:02:04 volumio systemd[1]: Started User Runtime Directory /run/user/1000.
Jul 14 01:02:04 volumio systemd[1]: Starting User Manager for UID 1000...
Jul 14 01:02:04 volumio systemd[1220]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0)
Jul 14 01:02:05 volumio systemd[1220]: Reached target Timers.
Jul 14 01:02:05 volumio systemd[1220]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Jul 14 01:02:05 volumio systemd[1220]: Listening on GnuPG cryptographic agent and passphrase cache.
Jul 14 01:02:05 volumio systemd[1220]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Jul 14 01:02:05 volumio systemd[1220]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Jul 14 01:02:05 volumio systemd[1220]: Listening on GnuPG network certificate management daemon.
Jul 14 01:02:05 volumio systemd[1220]: Listening on Sound System.
Jul 14 01:02:05 volumio systemd[1220]: Reached target Paths.
Jul 14 01:02:05 volumio systemd[1220]: Starting D-Bus User Message Bus Socket.
Jul 14 01:02:05 volumio systemd[1220]: Listening on D-Bus User Message Bus Socket.
Jul 14 01:02:05 volumio systemd[1220]: Reached target Sockets.
Jul 14 01:02:05 volumio systemd[1220]: Reached target Basic System.
Jul 14 01:02:05 volumio systemd[1]: Started User Manager for UID 1000.
Jul 14 01:02:05 volumio systemd[1220]: Starting Music Player Daemon...
Jul 14 01:02:05 volumio systemd[1]: Started Session 1 of user volumio.
Jul 14 01:02:05 volumio mpd[1231]: exception: failed to open log file "/var/log/mpd.log" (config line 7): Permission denied
Jul 14 01:02:05 volumio systemd[1220]: mpd.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 01:02:05 volumio systemd[1220]: mpd.service: Failed with result 'exit-code'.
Jul 14 01:02:05 volumio systemd[1220]: Failed to start Music Player Daemon.
Jul 14 01:02:05 volumio systemd[1220]: Reached target Default.
Jul 14 01:02:05 volumio systemd[1220]: Startup finished in 868ms.
Jul 14 01:02:06 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Jul 14 01:02:06 volumio volumio[901]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13
Jul 14 01:02:06 volumio volumio[901]: info: CoreCommandRouter::volumioGetState
Jul 14 01:02:06 volumio volumio[901]: info: CorePlayQueue::getTrack 0
Jul 14 01:02:08 volumio sudo[1243]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/sbin/ifconfig
Jul 14 01:02:08 volumio sudo[1243]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Jul 14 01:02:08 volumio sudo[1243]: pam_unix(sudo:session): session closed for user root
Jul 14 01:02:09 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 14 01:02:09 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 14 01:02:09 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Jul 14 01:02:09 volumio volumio-remote-updater[648]: No test mode
Jul 14 01:02:09 volumio volumio-remote-updater[648]: No alpha test mode
Jul 14 01:02:09 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Jul 14 01:02:10 volumio volumio[901]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Jul 14 01:02:10 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::volumioGetBrowseSources
Jul 14 01:02:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 14 01:02:12 volumio volumio[901]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Jul 14 01:02:12 volumio volumio[901]: info: Completed starting MyVolumio Plugin
Jul 14 01:02:12 volumio volumio[901]: info: BOOT COMPLETED
Jul 14 01:02:12 volumio volumio[901]: [Metrics] CommandRouter: 36s 591.58ms
Jul 14 01:02:12 volumio volumio[901]: info: CoreCommandRouter::volumiosetStartupVolume
Jul 14 01:02:12 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 14 01:02:12 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 14 01:02:12 volumio volumio[901]: info: CoreCommandRouter::Close All Modals sent
Jul 14 01:02:12 volumio volumio[901]: info: CoreCommandRouter::Close All Modals sent
Jul 14 01:02:12 volumio volumio[901]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
Jul 14 01:02:12 volumio volumio[901]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card
Jul 14 01:02:12 volumio volumio[901]: aplay: main:828: audio open error: No such device
Jul 14 01:02:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Jul 14 01:02:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Jul 14 01:02:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Jul 14 01:02:24 volumio sudo[1250]: pam_unix(sudo:auth): authentication failure; logname=volumio uid=1000 euid=0 tty=/dev/pts/0 ruser=volumio rhost= user=volumio
Jul 14 01:02:34 volumio sudo[1250]: volumio : 3 incorrect password attempts ; TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=systemclt start dhcpcd
Jul 14 01:02:36 volumio ntpd[830]: Soliciting pool server 202.182.111.234
Jul 14 01:02:37 volumio ntpd[830]: Soliciting pool server 150.249.188.191
Jul 14 01:02:38 volumio ntpd[830]: Soliciting pool server 162.159.200.123
Jul 14 01:02:39 volumio ntpd[830]: Soliciting pool server 172.105.204.105
Jul 14 01:02:39 volumio ntpd[830]: Soliciting pool server 133.243.238.243
Jul 14 01:02:39 volumio ntpd[830]: Soliciting pool server 133.243.238.163
Jul 14 01:02:40 volumio ntpd[830]: Soliciting pool server 160.16.113.133
Jul 14 01:02:40 volumio ntpd[830]: Soliciting pool server 18.180.64.47
Jul 14 01:02:40 volumio ntpd[830]: Soliciting pool server 202.181.103.212
Jul 14 01:02:41 volumio ntpd[830]: Soliciting pool server 162.159.200.1
Jul 14 01:02:41 volumio ntpd[830]: Soliciting pool server 108.160.132.224
Jul 14 01:02:41 volumio ntpd[830]: Soliciting pool server 162.159.200.1
Jul 14 01:02:41 volumio ntpd[830]: Soliciting pool server 133.130.121.141
Jul 14 01:02:42 volumio ntpd[830]: Soliciting pool server 129.250.35.251
Jul 14 01:02:42 volumio ntpd[830]: Soliciting pool server 45.76.221.157
Jul 14 01:02:42 volumio ntpd[830]: Soliciting pool server 129.250.35.250
Jul 14 01:02:43 volumio ntpd[830]: Soliciting pool server 2400:8902:e001:347:0:a789:b456:c123
Jul 14 01:02:43 volumio ntpd[830]: Soliciting pool server 167.179.119.205
Jul 14 01:03:12 volumio ntpd[830]: receive: Unexpected origin timestamp 0xea3d23a3.4bc848fb does not match aorg 0000000000.00000000 from server@133.243.238.163 xmt 0xea3d23c0.4c948497
Jul 14 01:03:13 volumio ntpd[830]: Soliciting pool server 45.77.20.103
Jul 14 01:03:21 volumio sudo[1290]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl start dhcpcd
Jul 14 01:03:21 volumio sudo[1290]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Jul 14 01:03:21 volumio sudo[1290]: pam_unix(sudo:session): session closed for user root
Jul 14 01:03:30 volumio sudo[1294]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl start hostapd
Jul 14 01:03:30 volumio sudo[1294]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Jul 14 01:03:30 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator...
Jul 14 01:03:30 volumio hostapd[1297]: Configuration file: /etc/hostapd/hostapd.conf
Jul 14 01:03:30 volumio hostapd[1297]: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Jul 14 01:03:30 volumio hostapd[1297]: wlan0: Could not connect to kernel driver
Jul 14 01:03:30 volumio hostapd[1297]: Using interface wlan0 with hwaddr e4:5f:01:ef:09:c8 and ssid "music_play"
Jul 14 01:03:30 volumio dhcpcd[712]: wlan0: carrier acquired
Jul 14 01:03:30 volumio hostapd[1297]: wlan0: interface state COUNTRY_UPDATE->ENABLED
Jul 14 01:03:30 volumio hostapd[1297]: wlan0: AP-ENABLED
Jul 14 01:03:30 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator.
Jul 14 01:03:30 volumio dhcpcd[712]: wlan0: IAID 01:ef:09:c8
Jul 14 01:03:30 volumio dhcpcd[712]: wlan0: probing address 10.0.0.1/24
Jul 14 01:03:30 volumio sudo[1294]: pam_unix(sudo:session): session closed for user root
Jul 14 01:03:31 volumio dhcpcd[712]: wlan0: soliciting an IPv6 router
Jul 14 01:03:35 volumio dhcpcd[712]: wlan0: using static address 10.0.0.1/24
Jul 14 01:03:35 volumio avahi-daemon[660]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.0.0.1.
Jul 14 01:03:35 volumio dhcpcd[712]: wlan0: adding route to 10.0.0.0/24
Jul 14 01:03:35 volumio avahi-daemon[660]: New relevant interface wlan0.IPv4 for mDNS.
Jul 14 01:03:35 volumio avahi-daemon[660]: Registering new address record for 10.0.0.1 on wlan0.IPv4.
Jul 14 01:03:36 volumio volumio[901]: info: Discovery: this is already registered, 94d7b86c-0867-4fca-be30-93c1554a4c70
Jul 14 01:03:36 volumio volumio[901]: info: Discovery: Found device Volumio
Jul 14 01:03:36 volumio volumio[901]: info: CoreCommandRouter::volumioGetState
Jul 14 01:03:36 volumio volumio[901]: info: CorePlayQueue::getTrack 0
Jul 14 01:03:36 volumio volumio[901]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 14 01:03:36 volumio volumio[901]: Error: The value NaN is not a number
Jul 14 01:03:36 volumio volumio[901]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20)
Jul 14 01:03:36 volumio volumio[901]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25)
Jul 14 01:03:36 volumio volumio[901]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25)
Jul 14 01:03:36 volumio volumio[901]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10)
Jul 14 01:03:36 volumio volumio[901]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12)
Jul 14 01:03:36 volumio volumio[901]: at Browser.emit (events.js:315:20)
Jul 14 01:03:36 volumio volumio[901]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14)
Jul 14 01:03:36 volumio volumio[901]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7)
Jul 14 01:03:36 volumio volumio[901]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5)
Jul 14 01:03:36 volumio volumio[901]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21)
Jul 14 01:03:36 volumio volumio[901]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11
Jul 14 01:03:36 volumio volumio[901]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7)
Jul 14 01:03:36 volumio volumio[901]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9)
Jul 14 01:03:36 volumio volumio[901]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 14 01:03:37 volumio sudo[1329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-14 01:02
Jul 14 01:03:37 volumio sudo[1329]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST"
VOLUMIO_VERSION="3.703"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"