-- Logs begin at Wed 2025-09-17 15:34:31 UTC, end at Wed 2025-09-17 17:28:44 UTC. -- Sep 17 17:27:34 volumio kernel: usb 1-1-port5: disabled by hub (EMI?), re-enabling... Sep 17 17:27:34 volumio kernel: usb 1-1.5: USB disconnect, device number 9 Sep 17 17:27:34 volumio wpa_supplicant[2073]: Could not read interface wlan0 flags: No such device Sep 17 17:27:34 volumio avahi-daemon[603]: Withdrawing workstation service for wlan0. Sep 17 17:27:34 volumio dhcpcd[2220]: wlan0: removing interface Sep 17 17:27:34 volumio systemd[1]: Stopping ifup for wlan0... Sep 17 17:27:35 volumio systemd[1]: Stopped ifup for wlan0. Sep 17 17:27:35 volumio kernel: usb 1-1.5: new high-speed USB device number 10 using dwc_otg Sep 17 17:27:35 volumio kernel: usb 1-1.5: device descriptor read/all, error -71 Sep 17 17:27:35 volumio kernel: usb 1-1.5: new high-speed USB device number 11 using dwc_otg Sep 17 17:27:36 volumio kernel: usb 1-1.5: New USB device found, idVendor=0bda, idProduct=8187, bcdDevice= 1.00 Sep 17 17:27:36 volumio kernel: usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 17 17:27:36 volumio kernel: usb 1-1.5: Product: RTL8187_Wireless Sep 17 17:27:36 volumio kernel: usb 1-1.5: Manufacturer: Manufacturer_Realtek_RTL8187_ Sep 17 17:27:36 volumio kernel: usb 1-1.5: SerialNumber: 00E04C819623 Sep 17 17:27:36 volumio kernel: ieee80211 phy2: Selected rate control algorithm 'minstrel_ht' Sep 17 17:27:36 volumio kernel: ieee80211 phy2: hwaddr 00:e0:4c:81:96:23, RTL8187vB (default) V1 + rtl8225z2, rfkill mask 2 Sep 17 17:27:36 volumio kernel: rtl8187: Customer ID is 0x00 Sep 17 17:27:36 volumio kernel: rtl8187: wireless switch is on Sep 17 17:27:36 volumio systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill2... Sep 17 17:27:36 volumio systemd[1]: Started Load/Save RF Kill Switch Status of rfkill2. Sep 17 17:27:38 volumio systemd[1]: Starting ifup for wlan0... Sep 17 17:27:38 volumio dhcpcd[2220]: wlan0: waiting for carrier Sep 17 17:27:38 volumio dhcpcd[2220]: wlan0: carrier acquired Sep 17 17:27:38 volumio systemd[1]: Started ifup for wlan0. Sep 17 17:27:38 volumio dhcpcd[2220]: wlan0: carrier lost Sep 17 17:27:38 volumio dhcpcd[2220]: wlan0: waiting for carrier Sep 17 17:27:41 volumio wpa_supplicant[2073]: wlan0: SME: Trying to authenticate with 34:47:d4:47:93:73 (SSID='Ray' freq=2462 MHz) Sep 17 17:27:41 volumio kernel: wlan0: authenticate with 34:47:d4:47:93:73 Sep 17 17:27:41 volumio wpa_supplicant[2073]: wlan0: Trying to associate with 34:47:d4:47:93:73 (SSID='Ray' freq=2462 MHz) Sep 17 17:27:41 volumio kernel: wlan0: send auth to 34:47:d4:47:93:73 (try 1/3) Sep 17 17:27:41 volumio kernel: wlan0: authenticated Sep 17 17:27:41 volumio kernel: wlan0: associate with 34:47:d4:47:93:73 (try 1/3) Sep 17 17:27:41 volumio wpa_supplicant[2073]: wlan0: Associated with 34:47:d4:47:93:73 Sep 17 17:27:41 volumio kernel: wlan0: RX AssocResp from 34:47:d4:47:93:73 (capab=0x1831 status=0 aid=24) Sep 17 17:27:41 volumio kernel: wlan0: associated Sep 17 17:27:42 volumio wpa_supplicant[2073]: wlan0: WPA: Key negotiation completed with 34:47:d4:47:93:73 [PTK=CCMP GTK=CCMP] Sep 17 17:27:42 volumio wpa_supplicant[2073]: wlan0: CTRL-EVENT-CONNECTED - Connection to 34:47:d4:47:93:73 completed [id=0 id_str=] Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: carrier acquired Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: soliciting an IPv6 router Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: rebinding lease of 192.168.2.248 Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: NAK: address in use from 192.168.2.1 Sep 17 17:27:42 volumio kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 34:47:d4:47:93:73 Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: soliciting an IPv6 router Sep 17 17:27:42 volumio dhcpcd[2220]: wlan0: soliciting a DHCP lease Sep 17 17:27:45 volumio dhcpcd[2220]: wlan0: offered 192.168.2.249 from 192.168.2.1 Sep 17 17:27:50 volumio dhcpcd[2220]: wlan0: leased 192.168.2.249 for 86400 seconds Sep 17 17:27:50 volumio dhcpcd[2220]: wlan0: adding host route to 192.168.2.249 via 127.0.0.1 Sep 17 17:27:50 volumio dhcpcd[2220]: wlan0: adding route to 192.168.2.0/24 Sep 17 17:27:50 volumio dhcpcd[2220]: wlan0: adding default route via 192.168.2.1 Sep 17 17:27:50 volumio avahi-daemon[603]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.249. Sep 17 17:27:50 volumio avahi-daemon[603]: New relevant interface wlan0.IPv4 for mDNS. Sep 17 17:27:50 volumio avahi-daemon[603]: Registering new address record for 192.168.2.249 on wlan0.IPv4. Sep 17 17:27:51 volumio volumio[3749]: Discovery: adding 5511b364-fada-4408-82b7-913bee39482d Sep 17 17:27:51 volumio volumio[3749]: info: mDNS: Found device Volumio Sep 17 17:27:51 volumio volumio[3749]: info: CoreCommandRouter::volumioGetState Sep 17 17:27:51 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:27:52 volumio ntpd[688]: Listen normally on 5 wlan0 192.168.2.249 UDP 123 Sep 17 17:27:52 volumio ntpd[688]: peers refreshed Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 17 17:28:04 volumio volumio[3749]: info: Discovery: Getting this device information Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::volumioGetState Sep 17 17:28:04 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: network , getCachedPAddresses Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getConf Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getConf Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::volumioGetState Sep 17 17:28:04 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 17 17:28:04 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 17 17:28:08 volumio volumio[3749]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%3F%3F/29c1e05d-dafe-42f7-ac21-0d59ff8b9980.jpg' Sep 17 17:28:12 volumio sudo[17249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 17 17:28:12 volumio sudo[17247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 17 17:28:12 volumio sudo[17247]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 17:28:12 volumio sudo[17249]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 17:28:12 volumio sudo[17249]: pam_unix(sudo:session): session closed for user root Sep 17 17:28:12 volumio sudo[17247]: pam_unix(sudo:session): session closed for user root Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::volumioGetState Sep 17 17:28:13 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 17 17:28:13 volumio volumio[3749]: info: Listing playlists Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 17 17:28:13 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 17 17:28:14 volumio volumio[3749]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%3F%3F/29c1e05d-dafe-42f7-ac21-0d59ff8b9980.jpg' Sep 17 17:28:24 volumio volumio[3749]: info: CoreCommandRouter::volumioGetQueue Sep 17 17:28:24 volumio volumio[3749]: info: CoreStateMachine::getQueue Sep 17 17:28:24 volumio volumio[3749]: info: CorePlayQueue::getQueue Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::volumioPlay Sep 17 17:28:28 volumio volumio[3749]: UNSET VOLATILE Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::play index 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::stop Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 17:28:28 volumio volumio[3749]: UNSET VOLATILE Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::stPlaybackTimer Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::updateTrackBlock Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrackBlock Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::volumioPushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::serviceStop Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 1 Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::serviceStop Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::stop Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand stop Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::play index undefined Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::startPlaybackTimer Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::clearAddPlayTracks USB/RAY_UKEY/王闻-男人四十/DSD-星-王闻.wav Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand stop Sep 17 17:28:28 volumio volumio[3749]: info: Sep 17 17:28:28 volumio volumio[3749]: ---------------------------- MPD announces state update: player Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::getState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand status Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand clear Sep 17 17:28:28 volumio volumio[3749]: info: Sep 17 17:28:28 volumio volumio[3749]: ---------------------------- MPD announces system playlist update Sep 17 17:28:28 volumio volumio[3749]: info: Ignoring MPD Status Update Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand add "USB/RAY_UKEY/王闻-男人四十/DSD-星-王闻.wav" Sep 17 17:28:28 volumio volumio[3749]: error: updateQueue error: null Sep 17 17:28:28 volumio volumio[3749]: info: Sep 17 17:28:28 volumio volumio[3749]: ---------------------------- MPD announces system playlist update Sep 17 17:28:28 volumio volumio[3749]: info: Ignoring MPD Status Update Sep 17 17:28:28 volumio volumio[3749]: info: ------------------------------ 8ms Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseTrackInfo Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand play Sep 17 17:28:28 volumio volumio[3749]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 17 17:28:28 volumio volumio[3749]: info: ------------------------------ 20ms Sep 17 17:28:28 volumio volumio[3749]: info: ------------------------------ 10ms Sep 17 17:28:28 volumio volumio[3749]: info: Sep 17 17:28:28 volumio volumio[3749]: ---------------------------- MPD announces state update: player Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::getState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand status Sep 17 17:28:28 volumio volumio[3749]: info: Sep 17 17:28:28 volumio volumio[3749]: ---------------------------- MPD announces state update: player Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::getState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand status Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseState Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseTrackInfo Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::servicePushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: verbose: STATE SERVICE {"status":"play","position":0,"seek":162,"duration":326,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"??","artist":null,"album":null,"uri":"USB/RAY_UKEY/王闻-男人四十/DSD-星-王闻.wav","trackType":"wav"} Sep 17 17:28:28 volumio volumio[3749]: verbose: CURRENT POSITION 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::syncState stateService play Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::syncState currentStatus stop Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::volumioPushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 17:28:28 volumio volumio[3749]: info: ------------------------------ 60ms Sep 17 17:28:28 volumio volumio[3749]: verbose: ControllerMpd::parseTrackInfo Sep 17 17:28:28 volumio volumio[3749]: info: ControllerMpd::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::servicePushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":326,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"??","artist":null,"album":null,"uri":"USB/RAY_UKEY/王闻-男人四十/DSD-星-王闻.wav","trackType":"wav"} Sep 17 17:28:28 volumio volumio[3749]: verbose: CURRENT POSITION 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::syncState stateService play Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::syncState currentStatus play Sep 17 17:28:28 volumio volumio[3749]: info: Received an update from plugin. extracting info from payload Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::volumioPushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 17:28:28 volumio volumio[3749]: info: CoreStateMachine::pushState Sep 17 17:28:28 volumio volumio[3749]: info: CorePlayQueue::getTrack 0 Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::volumioPushState Sep 17 17:28:28 volumio volumio[3749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 17:28:28 volumio volumio[3749]: info: ------------------------------ 93ms Sep 17 17:28:43 volumio volumio[3749]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 17:28:43 volumio volumio[3749]: { Error: connect ETIMEDOUT 202.160.129.6:80 Sep 17 17:28:43 volumio volumio[3749]: at Object._errnoException (util.js:1022:11) Sep 17 17:28:43 volumio volumio[3749]: at _exceptionWithHostPort (util.js:1044:20) Sep 17 17:28:43 volumio volumio[3749]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Sep 17 17:28:43 volumio volumio[3749]: code: 'ETIMEDOUT', Sep 17 17:28:43 volumio volumio[3749]: errno: 'ETIMEDOUT', Sep 17 17:28:43 volumio volumio[3749]: syscall: 'connect', Sep 17 17:28:43 volumio volumio[3749]: address: '202.160.129.6', Sep 17 17:28:43 volumio volumio[3749]: port: 80 } Sep 17 17:28:43 volumio volumio[3749]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 17:28:44 volumio sudo[17358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-17 17:27 Sep 17 17:28:44 volumio sudo[17358]: 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="74e4cc9de715c64d553d35948d017f973a622b6d" VOLUMIO_FE_VERSION="2be6c28eb9de74ec1f9662ca333f7bd51a232c33" VOLUMIO_BE_VERSION="259a7f2894e1376413ffac331be84e0e9a6173dd" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Sep 24 22:42:43 CEST 2020" VOLUMIO_VERSION="2.834" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="e41ef0f29aa50c1af109d3064a380c69"