-- Logs begin at Thu 2019-02-14 17:11:58 +07, end at Mon 2025-02-24 09:46:26 +07. -- Feb 24 09:45:01 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:01 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 113. Feb 24 09:45:01 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:01 volumio dnsmasq[5024]: exiting on receipt of SIGTERM Feb 24 09:45:01 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:01 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:01 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:01 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:01 volumio hostapd[5052]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:02 volumio hostapd[5052]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:02 volumio hostapd[5052]: nl80211: Could not configure driver mode Feb 24 09:45:02 volumio hostapd[5052]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:02 volumio hostapd[5052]: nl80211 driver initialization failed. Feb 24 09:45:02 volumio hostapd[5052]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:02 volumio hostapd[5052]: wlan0: AP-DISABLED Feb 24 09:45:02 volumio hostapd[5052]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:02 volumio hostapd[5052]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:02 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:02 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:02 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:02 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:02 volumio dnsmasq[5058]: dnsmasq: syntax check OK. Feb 24 09:45:02 volumio dnsmasq[5064]: started, version 2.80 cachesize 150 Feb 24 09:45:02 volumio dnsmasq[5064]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:02 volumio dnsmasq-dhcp[5064]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:02 volumio dnsmasq[5064]: reading /etc/resolv.conf Feb 24 09:45:02 volumio dnsmasq[5064]: using nameserver 192.168.1.1#53 Feb 24 09:45:02 volumio dnsmasq[5064]: using nameserver 208.67.222.222#53 Feb 24 09:45:02 volumio dnsmasq[5064]: using nameserver 208.67.222.222#53 Feb 24 09:45:02 volumio dnsmasq[5064]: using nameserver 208.67.220.220#53 Feb 24 09:45:02 volumio dnsmasq[5064]: read /etc/hosts - 5 addresses Feb 24 09:45:02 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:04 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:04 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 114. Feb 24 09:45:04 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:04 volumio dnsmasq[5064]: exiting on receipt of SIGTERM Feb 24 09:45:04 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:04 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:04 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:04 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:04 volumio hostapd[5078]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:05 volumio hostapd[5078]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:05 volumio hostapd[5078]: nl80211: Could not configure driver mode Feb 24 09:45:05 volumio hostapd[5078]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:05 volumio hostapd[5078]: nl80211 driver initialization failed. Feb 24 09:45:05 volumio hostapd[5078]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:05 volumio hostapd[5078]: wlan0: AP-DISABLED Feb 24 09:45:05 volumio hostapd[5078]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:05 volumio hostapd[5078]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:05 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:05 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:05 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:05 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:05 volumio dnsmasq[5081]: dnsmasq: syntax check OK. Feb 24 09:45:05 volumio dnsmasq[5087]: started, version 2.80 cachesize 150 Feb 24 09:45:05 volumio dnsmasq[5087]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:05 volumio dnsmasq-dhcp[5087]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:05 volumio dnsmasq[5087]: reading /etc/resolv.conf Feb 24 09:45:05 volumio dnsmasq[5087]: using nameserver 192.168.1.1#53 Feb 24 09:45:05 volumio dnsmasq[5087]: using nameserver 208.67.222.222#53 Feb 24 09:45:05 volumio dnsmasq[5087]: using nameserver 208.67.222.222#53 Feb 24 09:45:05 volumio dnsmasq[5087]: using nameserver 208.67.220.220#53 Feb 24 09:45:05 volumio dnsmasq[5087]: read /etc/hosts - 5 addresses Feb 24 09:45:05 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::volumioPause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::servicePause Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::servicePause Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::pause Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand pause Feb 24 09:45:06 volumio volumio[914]: info: Feb 24 09:45:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand pause took 2 milliseconds Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:06 volumio volumio[914]: info: Feb 24 09:45:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:06 volumio volumio[914]: info: Feb 24 09:45:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand status took 2 milliseconds Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 24 09:45:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":217449,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Mot Minh","artist":"M? Linh","album":"Tinh Khuc Thanh Tung - Vol. 2 - Mot Minh","uri":"NAS/Volumio/CD Trong nuoc/Thanh Tung Vol 2-Mot Minh [WAV]/04-Mot Minh-Mỹ Linh.wav","trackType":"wav"} Feb 24 09:45:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":217449,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Mot Minh","artist":"M? Linh","album":"Tinh Khuc Thanh Tung - Vol. 2 - Mot Minh","uri":"NAS/Volumio/CD Trong nuoc/Thanh Tung Vol 2-Mot Minh [WAV]/04-Mot Minh-Mỹ Linh.wav","trackType":"wav"} Feb 24 09:45:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:45:06 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":217449,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Mot Minh","artist":"M? Linh","album":"Tinh Khuc Thanh Tung - Vol. 2 - Mot Minh","uri":"NAS/Volumio/CD Trong nuoc/Thanh Tung Vol 2-Mot Minh [WAV]/04-Mot Minh-Mỹ Linh.wav","trackType":"wav"} Feb 24 09:45:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:06 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:45:06 volumio volumio[914]: info: ------------------------------ 40ms Feb 24 09:45:06 volumio volumio[914]: info: ------------------------------ 38ms Feb 24 09:45:06 volumio volumio[914]: info: ------------------------------ 38ms Feb 24 09:45:06 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:06 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:06 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:07 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:07 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 115. Feb 24 09:45:07 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:07 volumio dnsmasq[5087]: exiting on receipt of SIGTERM Feb 24 09:45:07 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:07 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:07 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:07 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:07 volumio hostapd[5101]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:08 volumio hostapd[5101]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:08 volumio hostapd[5101]: nl80211: Could not configure driver mode Feb 24 09:45:08 volumio hostapd[5101]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:08 volumio hostapd[5101]: nl80211 driver initialization failed. Feb 24 09:45:08 volumio hostapd[5101]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:08 volumio hostapd[5101]: wlan0: AP-DISABLED Feb 24 09:45:08 volumio hostapd[5101]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:08 volumio hostapd[5101]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:08 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:08 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:08 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:08 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:08 volumio dnsmasq[5102]: dnsmasq: syntax check OK. Feb 24 09:45:08 volumio dnsmasq[5108]: started, version 2.80 cachesize 150 Feb 24 09:45:08 volumio dnsmasq[5108]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:08 volumio dnsmasq-dhcp[5108]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:08 volumio dnsmasq[5108]: reading /etc/resolv.conf Feb 24 09:45:08 volumio dnsmasq[5108]: using nameserver 192.168.1.1#53 Feb 24 09:45:08 volumio dnsmasq[5108]: using nameserver 208.67.222.222#53 Feb 24 09:45:08 volumio dnsmasq[5108]: using nameserver 208.67.222.222#53 Feb 24 09:45:08 volumio dnsmasq[5108]: using nameserver 208.67.220.220#53 Feb 24 09:45:08 volumio dnsmasq[5108]: read /etc/hosts - 5 addresses Feb 24 09:45:08 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:09 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:45:09 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:45:09 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:45:09 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:09 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:09 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:45:10 volumio go-librespot[2781]: time="2025-02-24T09:45:10+07:00" level=error msg="did not receive last pong ack from accesspoint, 120s passed" Feb 24 09:45:10 volumio go-librespot[2781]: time="2025-02-24T09:45:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.11:44728->104.199.241.202:4070: use of closed network connection" Feb 24 09:45:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:10 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Error: socket hang up Feb 24 09:45:10 volumio volumio[914]: at connResetException (internal/errors.js:639:14) Feb 24 09:45:10 volumio volumio[914]: at Socket.socketOnEnd (_http_client.js:499:23) Feb 24 09:45:10 volumio volumio[914]: at Socket.emit (events.js:412:35) Feb 24 09:45:10 volumio volumio[914]: at endReadableNT (internal/streams/readable.js:1333:12) Feb 24 09:45:10 volumio volumio[914]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Feb 24 09:45:10 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 12) Feb 24 09:45:10 volumio volumio[914]: info: Connection to go-librespot Websocket closed Feb 24 09:45:10 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:10 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 116. Feb 24 09:45:10 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:10 volumio dnsmasq[5108]: exiting on receipt of SIGTERM Feb 24 09:45:10 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:10 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:10 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:10 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:10 volumio hostapd[5132]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:11 volumio hostapd[5132]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:11 volumio hostapd[5132]: nl80211: Could not configure driver mode Feb 24 09:45:11 volumio hostapd[5132]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:11 volumio hostapd[5132]: nl80211 driver initialization failed. Feb 24 09:45:11 volumio hostapd[5132]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:11 volumio hostapd[5132]: wlan0: AP-DISABLED Feb 24 09:45:11 volumio hostapd[5132]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:11 volumio hostapd[5132]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:11 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:11 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:11 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:11 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:11 volumio dnsmasq[5133]: dnsmasq: syntax check OK. Feb 24 09:45:11 volumio dnsmasq[5139]: started, version 2.80 cachesize 150 Feb 24 09:45:11 volumio dnsmasq[5139]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:11 volumio dnsmasq-dhcp[5139]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:11 volumio dnsmasq[5139]: reading /etc/resolv.conf Feb 24 09:45:11 volumio dnsmasq[5139]: using nameserver 192.168.1.1#53 Feb 24 09:45:11 volumio dnsmasq[5139]: using nameserver 208.67.222.222#53 Feb 24 09:45:11 volumio dnsmasq[5139]: using nameserver 208.67.222.222#53 Feb 24 09:45:11 volumio dnsmasq[5139]: using nameserver 208.67.220.220#53 Feb 24 09:45:11 volumio dnsmasq[5139]: read /etc/hosts - 5 addresses Feb 24 09:45:11 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:13 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:13 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 24 09:45:13 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:13 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:13 volumio go-librespot[5148]: Librespot-go daemon starting... Feb 24 09:45:13 volumio go-librespot[5148]: time="2025-02-24T09:45:13+07:00" level=info msg="generated new device id: 65c6f5a865c6231a685571c691ac731f976da1e8" Feb 24 09:45:13 volumio go-librespot[5148]: time="2025-02-24T09:45:13+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:13 volumio go-librespot[5148]: time="2025-02-24T09:45:13+07:00" level=debug msg="obtained new client token: AAA0BAi6ijPrAdFJF+AeNnlBCUaM7vF21dXXMCxKT9tvYYAOWyU7VQlOIfTF+JYCw/mSZ27SQOT1w7QOy6JMlBMSO3manog5jJi9ooqd6aG56xQ992XK0IFPg85GJEezZkJi+cElZzt7Z+IxsNZPesHYCHt9z8bB7Nz+h7c6ai75uVGToHk4xgLbsckT/EsSe9t5nozMeQlQ12+QF0VjZK1Nq10UAKSl4t1Qg+M19LmvmEGMJNtym9d9nSxeoVc=" Feb 24 09:45:13 volumio go-librespot[5148]: time="2025-02-24T09:45:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:14 volumio go-librespot[5148]: time="2025-02-24T09:45:14+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:14 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:14 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 117. Feb 24 09:45:14 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:14 volumio dnsmasq[5139]: exiting on receipt of SIGTERM Feb 24 09:45:14 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:14 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:14 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:14 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:14 volumio hostapd[5160]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:14 volumio go-librespot[5148]: time="2025-02-24T09:45:14+07:00" level=debug msg="completed challenge" Feb 24 09:45:14 volumio go-librespot[5148]: time="2025-02-24T09:45:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:15 volumio hostapd[5160]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:15 volumio hostapd[5160]: nl80211: Could not configure driver mode Feb 24 09:45:15 volumio hostapd[5160]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:15 volumio hostapd[5160]: nl80211 driver initialization failed. Feb 24 09:45:15 volumio hostapd[5160]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:15 volumio hostapd[5160]: wlan0: AP-DISABLED Feb 24 09:45:15 volumio hostapd[5160]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:15 volumio hostapd[5160]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:15 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:15 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:15 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:15 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:15 volumio dnsmasq[5161]: dnsmasq: syntax check OK. Feb 24 09:45:15 volumio dnsmasq[5167]: started, version 2.80 cachesize 150 Feb 24 09:45:15 volumio dnsmasq[5167]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:15 volumio dnsmasq-dhcp[5167]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:15 volumio dnsmasq[5167]: reading /etc/resolv.conf Feb 24 09:45:15 volumio dnsmasq[5167]: using nameserver 192.168.1.1#53 Feb 24 09:45:15 volumio dnsmasq[5167]: using nameserver 208.67.222.222#53 Feb 24 09:45:15 volumio dnsmasq[5167]: using nameserver 208.67.222.222#53 Feb 24 09:45:15 volumio dnsmasq[5167]: using nameserver 208.67.220.220#53 Feb 24 09:45:15 volumio dnsmasq[5167]: read /etc/hosts - 5 addresses Feb 24 09:45:15 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:16 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:16 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:17 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:17 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 118. Feb 24 09:45:17 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:17 volumio dnsmasq[5167]: exiting on receipt of SIGTERM Feb 24 09:45:17 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:17 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:17 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:17 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:17 volumio hostapd[5178]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 24 09:45:17 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:17 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:17 volumio go-librespot[5179]: Librespot-go daemon starting... Feb 24 09:45:17 volumio go-librespot[5179]: time="2025-02-24T09:45:17+07:00" level=info msg="generated new device id: 259a49e44d29d9b5f3028e78c152e1712a4ced56" Feb 24 09:45:17 volumio go-librespot[5179]: time="2025-02-24T09:45:17+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:18 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 09:45:18 volumio volumio[914]: info: CURURI: albums://Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi Feb 24 09:45:18 volumio go-librespot[5179]: time="2025-02-24T09:45:18+07:00" level=debug msg="obtained new client token: AABij9pxk3jgf/+CkEkbJw0Cc82vJ8FpukUMfMxNbEE0YsfUNdOTFLlF33udCk5zioIs8nE7wGzwmTAICBuXstKzGUFW9/HCrAIN4Wk0LkxVAEvEn+BCpmsEwnw6DahMbCA64nuqRsURHFZ5Vy5uKm/lnIzjJYTDG82eRamrmOSpyHMByHTfQb8j8bcD9lsoEtHx/5wdVeKsEL1BSsX0HBmaYf3PD7wrWMbH5yMbsHnGeXYp0sqS4MMND4TzNC1q9g==" Feb 24 09:45:18 volumio volumio[914]: info: Preload queue cleared Feb 24 09:45:18 volumio volumio[914]: info: Preloading song: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: Preloading song: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/04-Duyên tình-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: Preloading song: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/06-Mùa đông của anh-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: Preloading song: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/08-Ngày đá đơm bông-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: Preloading song: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/10-Sao em vô tình-Tuấn Vũ.wav Feb 24 09:45:18 volumio hostapd[5178]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:18 volumio hostapd[5178]: nl80211: Could not configure driver mode Feb 24 09:45:18 volumio hostapd[5178]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:18 volumio hostapd[5178]: nl80211 driver initialization failed. Feb 24 09:45:18 volumio hostapd[5178]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:18 volumio hostapd[5178]: wlan0: AP-DISABLED Feb 24 09:45:18 volumio hostapd[5178]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:18 volumio hostapd[5178]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:18 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:18 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:18 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:18 volumio volumio[914]: info: Exploding uri music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav in service mpd Feb 24 09:45:18 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:18 volumio dnsmasq[5187]: dnsmasq: syntax check OK. Feb 24 09:45:18 volumio volumio[914]: info: ALBUMART /albumart?cacheid=416&web=Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi/extralarge&path=%2Fmnt%2FNAS%2FVolumio%2FCD%20Trong%20nuoc%2FLac%20Vu-Tuan%20Vu%20Phi%20Nhung-Tinh%20%20Xua%20Vung%20Dai%20%5BWAV%5D%2F02-Anh%20cho%20em%20m%C3%B9a%20xu%C3%A2n-Tu%E1%BA%A5n%20V%C5%A9.wav&metadata=false Feb 24 09:45:18 volumio volumio[914]: info: URI /mnt/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:45:18 volumio dnsmasq[5193]: started, version 2.80 cachesize 150 Feb 24 09:45:18 volumio dnsmasq[5193]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:18 volumio dnsmasq-dhcp[5193]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:18 volumio dnsmasq[5193]: reading /etc/resolv.conf Feb 24 09:45:18 volumio dnsmasq[5193]: using nameserver 192.168.1.1#53 Feb 24 09:45:18 volumio dnsmasq[5193]: using nameserver 208.67.222.222#53 Feb 24 09:45:18 volumio dnsmasq[5193]: using nameserver 208.67.222.222#53 Feb 24 09:45:18 volumio dnsmasq[5193]: using nameserver 208.67.220.220#53 Feb 24 09:45:18 volumio dnsmasq[5193]: read /etc/hosts - 5 addresses Feb 24 09:45:18 volumio volumio[914]: info: Exploding uri music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/04-Duyên tình-Tuấn Vũ.wav in service mpd Feb 24 09:45:18 volumio volumio[914]: info: ALBUMART /albumart?cacheid=416&web=Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi/extralarge&path=%2Fmnt%2FNAS%2FVolumio%2FCD%20Trong%20nuoc%2FLac%20Vu-Tuan%20Vu%20Phi%20Nhung-Tinh%20%20Xua%20Vung%20Dai%20%5BWAV%5D%2F04-Duy%C3%AAn%20t%C3%ACnh-Tu%E1%BA%A5n%20V%C5%A9.wav&metadata=false Feb 24 09:45:18 volumio volumio[914]: info: URI /mnt/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/04-Duyên tình-Tuấn Vũ.wav Feb 24 09:45:18 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:18 volumio volumio[914]: info: Exploding uri music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/06-Mùa đông của anh-Tuấn Vũ.wav in service mpd Feb 24 09:45:18 volumio volumio[914]: info: ALBUMART /albumart?cacheid=416&web=Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi/extralarge&path=%2Fmnt%2FNAS%2FVolumio%2FCD%20Trong%20nuoc%2FLac%20Vu-Tuan%20Vu%20Phi%20Nhung-Tinh%20%20Xua%20Vung%20Dai%20%5BWAV%5D%2F06-M%C3%B9a%20%C4%91%C3%B4ng%20c%E1%BB%A7a%20anh-Tu%E1%BA%A5n%20V%C5%A9.wav&metadata=false Feb 24 09:45:18 volumio volumio[914]: info: URI /mnt/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/06-Mùa đông của anh-Tuấn Vũ.wav Feb 24 09:45:18 volumio go-librespot[5179]: time="2025-02-24T09:45:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:18 volumio volumio[914]: info: Exploding uri music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/08-Ngày đá đơm bông-Tuấn Vũ.wav in service mpd Feb 24 09:45:18 volumio volumio[914]: info: ALBUMART /albumart?cacheid=416&web=Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi/extralarge&path=%2Fmnt%2FNAS%2FVolumio%2FCD%20Trong%20nuoc%2FLac%20Vu-Tuan%20Vu%20Phi%20Nhung-Tinh%20%20Xua%20Vung%20Dai%20%5BWAV%5D%2F08-Ng%C3%A0y%20%C4%91%C3%A1%20%C4%91%C6%A1m%20b%C3%B4ng-Tu%E1%BA%A5n%20V%C5%A9.wav&metadata=false Feb 24 09:45:18 volumio volumio[914]: info: URI /mnt/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/08-Ngày đá đơm bông-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: Exploding uri music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/10-Sao em vô tình-Tuấn Vũ.wav in service mpd Feb 24 09:45:18 volumio volumio[914]: info: ALBUMART /albumart?cacheid=416&web=Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi/extralarge&path=%2Fmnt%2FNAS%2FVolumio%2FCD%20Trong%20nuoc%2FLac%20Vu-Tuan%20Vu%20Phi%20Nhung-Tinh%20%20Xua%20Vung%20Dai%20%5BWAV%5D%2F10-Sao%20em%20v%C3%B4%20t%C3%ACnh-Tu%E1%BA%A5n%20V%C5%A9.wav&metadata=false Feb 24 09:45:18 volumio volumio[914]: info: URI /mnt/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/10-Sao em vô tình-Tuấn Vũ.wav Feb 24 09:45:18 volumio volumio[914]: info: No valid Plugin REST Endpoint Feb 24 09:45:18 volumio volumio[914]: info: No valid Plugin REST Endpoint Feb 24 09:45:18 volumio volumio[914]: info: No valid Plugin REST Endpoint Feb 24 09:45:18 volumio go-librespot[5179]: time="2025-02-24T09:45:18+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:19 volumio go-librespot[5179]: time="2025-02-24T09:45:19+07:00" level=debug msg="completed challenge" Feb 24 09:45:19 volumio go-librespot[5179]: time="2025-02-24T09:45:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:19 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:19 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:20 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:20 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 119. Feb 24 09:45:20 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:20 volumio dnsmasq[5193]: exiting on receipt of SIGTERM Feb 24 09:45:20 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:20 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:20 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:20 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:20 volumio hostapd[5203]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:21 volumio hostapd[5203]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:21 volumio hostapd[5203]: nl80211: Could not configure driver mode Feb 24 09:45:21 volumio hostapd[5203]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:21 volumio hostapd[5203]: nl80211 driver initialization failed. Feb 24 09:45:21 volumio hostapd[5203]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:21 volumio hostapd[5203]: wlan0: AP-DISABLED Feb 24 09:45:21 volumio hostapd[5203]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:21 volumio hostapd[5203]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:21 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:21 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:21 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:21 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:21 volumio dnsmasq[5212]: dnsmasq: syntax check OK. Feb 24 09:45:21 volumio dnsmasq[5224]: started, version 2.80 cachesize 150 Feb 24 09:45:21 volumio dnsmasq[5224]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:21 volumio dnsmasq-dhcp[5224]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:21 volumio dnsmasq[5224]: reading /etc/resolv.conf Feb 24 09:45:21 volumio dnsmasq[5224]: using nameserver 192.168.1.1#53 Feb 24 09:45:21 volumio dnsmasq[5224]: using nameserver 208.67.222.222#53 Feb 24 09:45:21 volumio dnsmasq[5224]: using nameserver 208.67.222.222#53 Feb 24 09:45:21 volumio dnsmasq[5224]: using nameserver 208.67.220.220#53 Feb 24 09:45:21 volumio dnsmasq[5224]: read /etc/hosts - 5 addresses Feb 24 09:45:21 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:22 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:22 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 24 09:45:22 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:22 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:22 volumio go-librespot[5230]: Librespot-go daemon starting... Feb 24 09:45:22 volumio go-librespot[5230]: time="2025-02-24T09:45:22+07:00" level=info msg="generated new device id: a5f8bf906011255eb97f4cb746c615aa2c17277c" Feb 24 09:45:22 volumio go-librespot[5230]: time="2025-02-24T09:45:22+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:22 volumio go-librespot[5230]: time="2025-02-24T09:45:22+07:00" level=debug msg="obtained new client token: AAAS18bCdGZmx4ocMTF5IjqJfHqMWxU5jb0hZx9p2liYag+jPTQPRLFCexoHNxRHbHLSsOx5Nd+J1xoBBY1la75z8MueyRfY6mTuAfGu3Ttj7xa1ZR3Swf0yPJF9FkyGaqRPiokZ1MRehfH0yI3+F5ZNZZliuoMljR3tE6Alz64riQsDg4rK1rS1zGw5OW6wachwbjEYGaV2dvvbmFI85dQRtcen6pGIzAk9/dQv1/MBbpdTz2k3JOABgHhTN9Q=" Feb 24 09:45:22 volumio go-librespot[5230]: time="2025-02-24T09:45:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:23 volumio go-librespot[5230]: time="2025-02-24T09:45:23+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:23 volumio go-librespot[5230]: time="2025-02-24T09:45:23+07:00" level=debug msg="completed challenge" Feb 24 09:45:23 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:23 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 120. Feb 24 09:45:23 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:23 volumio go-librespot[5230]: time="2025-02-24T09:45:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:23 volumio dnsmasq[5224]: exiting on receipt of SIGTERM Feb 24 09:45:23 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:23 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:23 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:23 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:23 volumio hostapd[5245]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:24 volumio hostapd[5245]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:24 volumio hostapd[5245]: nl80211: Could not configure driver mode Feb 24 09:45:24 volumio hostapd[5245]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:24 volumio hostapd[5245]: nl80211 driver initialization failed. Feb 24 09:45:24 volumio hostapd[5245]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:24 volumio hostapd[5245]: wlan0: AP-DISABLED Feb 24 09:45:24 volumio hostapd[5245]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:24 volumio hostapd[5245]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:24 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:24 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:24 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:24 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:24 volumio dnsmasq[5246]: dnsmasq: syntax check OK. Feb 24 09:45:24 volumio dnsmasq[5252]: started, version 2.80 cachesize 150 Feb 24 09:45:24 volumio dnsmasq[5252]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:24 volumio dnsmasq-dhcp[5252]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:24 volumio dnsmasq[5252]: reading /etc/resolv.conf Feb 24 09:45:24 volumio dnsmasq[5252]: using nameserver 192.168.1.1#53 Feb 24 09:45:24 volumio dnsmasq[5252]: using nameserver 208.67.222.222#53 Feb 24 09:45:24 volumio dnsmasq[5252]: using nameserver 208.67.222.222#53 Feb 24 09:45:24 volumio dnsmasq[5252]: using nameserver 208.67.220.220#53 Feb 24 09:45:24 volumio dnsmasq[5252]: read /etc/hosts - 5 addresses Feb 24 09:45:24 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:25 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:25 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:26 volumio volumio[914]: info: Preload queue cleared Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::ClearQueue Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::serviceStop Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::serviceStop Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::stop Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::saveQueue Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::addQueueItems Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::addQueueItems Feb 24 09:45:26 volumio volumio[914]: info: Preload queue cleared Feb 24 09:45:26 volumio volumio[914]: info: Adding Item to queue: albums://Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi Feb 24 09:45:26 volumio volumio[914]: info: Exploding uri albums://Tu%3Fn%20Vu/T%3Fnh%20Xua%20V%3Fng%20D%3Fi in service mpd Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand stop took 15 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::saveQueue Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::play index 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::play index undefined Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::clearAddPlayTracks NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand status took 14 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand stop took 2 milliseconds Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand clear took 4 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand status took 2 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand status took 1 milliseconds Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav" Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Mot Minh","artist":"M? Linh","album":"Tinh Khuc Thanh Tung - Vol. 2 - Mot Minh","uri":"NAS/Volumio/CD Trong nuoc/Thanh Tung Vol 2-Mot Minh [WAV]/04-Mot Minh-Mỹ Linh.wav","trackType":"wav"} Feb 24 09:45:26 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: No code Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 09:45:26 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: No code Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 09:45:26 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: No code Feb 24 09:45:26 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:26 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 88ms Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 71ms Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 71ms Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: error: updateQueue error: null Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 76ms Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand add "NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav" took 63 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 5ms Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 4ms Feb 24 09:45:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: info: Feb 24 09:45:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:45:26 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 17ms Feb 24 09:45:26 volumio volumio[914]: info: sendMpdCommand play took 15 milliseconds Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 15ms Feb 24 09:45:26 volumio volumio[914]: info: ------------------------------ 14ms Feb 24 09:45:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 24 09:45:26 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:26 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 121. Feb 24 09:45:26 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:26 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:26 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:26 volumio go-librespot[5261]: Librespot-go daemon starting... Feb 24 09:45:26 volumio go-librespot[5261]: time="2025-02-24T09:45:26+07:00" level=info msg="generated new device id: 68a6a0779be5b73be189d8d6dd90d40d8d83d76a" Feb 24 09:45:26 volumio go-librespot[5261]: time="2025-02-24T09:45:26+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:26 volumio dnsmasq[5252]: exiting on receipt of SIGTERM Feb 24 09:45:26 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:26 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:26 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:26 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:26 volumio hostapd[5272]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio volumio[914]: info: sendMpdCommand status took 7 milliseconds Feb 24 09:45:27 volumio volumio[914]: info: sendMpdCommand status took 7 milliseconds Feb 24 09:45:27 volumio volumio[914]: info: sendMpdCommand status took 7 milliseconds Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio volumio[914]: info: Feb 24 09:45:27 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:45:27 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:45:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:45:27 volumio go-librespot[5261]: time="2025-02-24T09:45:27+07:00" level=debug msg="obtained new client token: AABJS+dtmCTH6sel0VE2LRW7gwY3sEkqU934/qzV7pihYrfD9EMcrfwrWxKdanyNx5xp9vGfgLGjPn6P/1R13xQTLLeEDxDVshz4upZjPz7Ewyb9etkjBc73WU3+B+n+MHM2RqpQvyqLyi92aNO9uKKRqY8gNP2CJWda3D8c2owrHn6L/unU6Ec5oJI+7sOZuWyprgxT1C7wmtCRqOBbEvxoBdL758NSqXTzeMnx7t3ovsEz/e0WX1OsDTrv/ZY=" Feb 24 09:45:27 volumio go-librespot[5261]: time="2025-02-24T09:45:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:27 volumio hostapd[5272]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:27 volumio hostapd[5272]: nl80211: Could not configure driver mode Feb 24 09:45:27 volumio hostapd[5272]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:27 volumio hostapd[5272]: nl80211 driver initialization failed. Feb 24 09:45:27 volumio hostapd[5272]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:27 volumio hostapd[5272]: wlan0: AP-DISABLED Feb 24 09:45:27 volumio hostapd[5272]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:27 volumio hostapd[5272]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:27 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:27 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:27 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:27 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:27 volumio dnsmasq[5273]: dnsmasq: syntax check OK. Feb 24 09:45:27 volumio go-librespot[5261]: time="2025-02-24T09:45:27+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:27 volumio dnsmasq[5279]: started, version 2.80 cachesize 150 Feb 24 09:45:27 volumio dnsmasq[5279]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:27 volumio dnsmasq-dhcp[5279]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:27 volumio dnsmasq[5279]: reading /etc/resolv.conf Feb 24 09:45:27 volumio dnsmasq[5279]: using nameserver 192.168.1.1#53 Feb 24 09:45:27 volumio dnsmasq[5279]: using nameserver 208.67.222.222#53 Feb 24 09:45:27 volumio dnsmasq[5279]: using nameserver 208.67.222.222#53 Feb 24 09:45:27 volumio dnsmasq[5279]: using nameserver 208.67.220.220#53 Feb 24 09:45:27 volumio dnsmasq[5279]: read /etc/hosts - 5 addresses Feb 24 09:45:27 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:28 volumio go-librespot[5261]: time="2025-02-24T09:45:28+07:00" level=debug msg="completed challenge" Feb 24 09:45:28 volumio go-librespot[5261]: time="2025-02-24T09:45:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:28 volumio ntpd[812]: Soliciting pool server 103.70.115.65 Feb 24 09:45:29 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:29 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 122. Feb 24 09:45:29 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:29 volumio dnsmasq[5279]: exiting on receipt of SIGTERM Feb 24 09:45:29 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:29 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:29 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:29 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:29 volumio hostapd[5289]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:30 volumio hostapd[5289]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:30 volumio hostapd[5289]: nl80211: Could not configure driver mode Feb 24 09:45:30 volumio hostapd[5289]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:30 volumio hostapd[5289]: nl80211 driver initialization failed. Feb 24 09:45:30 volumio hostapd[5289]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:30 volumio hostapd[5289]: wlan0: AP-DISABLED Feb 24 09:45:30 volumio hostapd[5289]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:30 volumio hostapd[5289]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:30 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:30 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:30 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:30 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:30 volumio dnsmasq[5290]: dnsmasq: syntax check OK. Feb 24 09:45:30 volumio dnsmasq[5296]: started, version 2.80 cachesize 150 Feb 24 09:45:30 volumio dnsmasq[5296]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:30 volumio dnsmasq-dhcp[5296]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:30 volumio dnsmasq[5296]: reading /etc/resolv.conf Feb 24 09:45:30 volumio dnsmasq[5296]: using nameserver 192.168.1.1#53 Feb 24 09:45:30 volumio dnsmasq[5296]: using nameserver 208.67.222.222#53 Feb 24 09:45:30 volumio dnsmasq[5296]: using nameserver 208.67.222.222#53 Feb 24 09:45:30 volumio dnsmasq[5296]: using nameserver 208.67.220.220#53 Feb 24 09:45:30 volumio dnsmasq[5296]: read /etc/hosts - 5 addresses Feb 24 09:45:30 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 24 09:45:31 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:31 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:31 volumio go-librespot[5316]: Librespot-go daemon starting... Feb 24 09:45:31 volumio go-librespot[5316]: time="2025-02-24T09:45:31+07:00" level=info msg="generated new device id: d00013372161d0354c4fb538aedd6295a33da611" Feb 24 09:45:31 volumio go-librespot[5316]: time="2025-02-24T09:45:31+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:31 volumio go-librespot[5316]: time="2025-02-24T09:45:31+07:00" level=debug msg="obtained new client token: AABU0SXxDVFac2i0sOP0Pxbmm5yUvdzPnyeGpiWl/yr4QeGgxrabPcihyx5xTR9Vw+8WEMP4BAE0lmHdWi/d2WJ2O2dRsHXm6qeKaziK0oXNeDTQO/7baMuaarxzQ5yrkO2n3j42rsmwm318q8JN8BJxPZ0KQnFnuf/4OJ2gOUC4rpW4zPPQ/wNL9zEhs9W1wkkHBIKs4RuwDtuV3zgPM0G3vi+5tZAppARVuO09fJ0cpsDNlotbzzUdzyWzoKl5KA==" Feb 24 09:45:32 volumio go-librespot[5316]: time="2025-02-24T09:45:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:32 volumio go-librespot[5316]: time="2025-02-24T09:45:32+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:32 volumio ntpd[812]: Soliciting pool server 2401:5f80:5001:1f::31f Feb 24 09:45:32 volumio go-librespot[5316]: time="2025-02-24T09:45:32+07:00" level=debug msg="completed challenge" Feb 24 09:45:32 volumio go-librespot[5316]: time="2025-02-24T09:45:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:33 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:33 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 123. Feb 24 09:45:33 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:33 volumio dnsmasq[5296]: exiting on receipt of SIGTERM Feb 24 09:45:33 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:33 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:33 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:33 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:33 volumio hostapd[5331]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:34 volumio hostapd[5331]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:34 volumio hostapd[5331]: nl80211: Could not configure driver mode Feb 24 09:45:34 volumio hostapd[5331]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:34 volumio hostapd[5331]: nl80211 driver initialization failed. Feb 24 09:45:34 volumio hostapd[5331]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:34 volumio hostapd[5331]: wlan0: AP-DISABLED Feb 24 09:45:34 volumio hostapd[5331]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:34 volumio hostapd[5331]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:34 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:34 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:34 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:34 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:34 volumio dnsmasq[5332]: dnsmasq: syntax check OK. Feb 24 09:45:34 volumio dnsmasq[5338]: started, version 2.80 cachesize 150 Feb 24 09:45:34 volumio dnsmasq[5338]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:34 volumio dnsmasq-dhcp[5338]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:34 volumio dnsmasq[5338]: reading /etc/resolv.conf Feb 24 09:45:34 volumio dnsmasq[5338]: using nameserver 192.168.1.1#53 Feb 24 09:45:34 volumio dnsmasq[5338]: using nameserver 208.67.222.222#53 Feb 24 09:45:34 volumio dnsmasq[5338]: using nameserver 208.67.222.222#53 Feb 24 09:45:34 volumio dnsmasq[5338]: using nameserver 208.67.220.220#53 Feb 24 09:45:34 volumio dnsmasq[5338]: read /etc/hosts - 5 addresses Feb 24 09:45:34 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:35 volumio volumio-remote-updater[574]: [2025-02-24 09:45:35] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Feb 24 09:45:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 24 09:45:36 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:36 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:36 volumio go-librespot[5344]: Librespot-go daemon starting... Feb 24 09:45:36 volumio go-librespot[5344]: time="2025-02-24T09:45:36+07:00" level=info msg="generated new device id: 4ade809b0a45532d36f74f7e225629c2193cc05e" Feb 24 09:45:36 volumio go-librespot[5344]: time="2025-02-24T09:45:36+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:36 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:36 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 124. Feb 24 09:45:36 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:36 volumio dnsmasq[5338]: exiting on receipt of SIGTERM Feb 24 09:45:36 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:36 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:36 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:36 volumio go-librespot[5344]: time="2025-02-24T09:45:36+07:00" level=debug msg="obtained new client token: AAC0R2xLhO03HG1pZ/e8iXHCEHGqZuxdjWlP5QC957CVQzbt0XEzipMWnSkdwoKqx4Xfg3O9U+MNhqO1UVaF4aJD1nn+U2JWa04GUeM0e9Ox735wqXlYvWLs2Dwd44qRM4Pn7rAGFvNeFAy0NZwIzp1AGYkk+Ka26AP1zjxT8srECjoXgJlZP9jB7K4kEYDmcf1WqWhStCOaUT/v/bzQfuCRD+PV7wlOhg7f94NCImwELhy6fHhNPKcgwJW6IsJBNg==" Feb 24 09:45:36 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:36 volumio hostapd[5356]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:36 volumio ntpd[812]: Soliciting pool server 103.70.115.65 Feb 24 09:45:36 volumio go-librespot[5344]: time="2025-02-24T09:45:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 24 09:45:37 volumio go-librespot[5344]: time="2025-02-24T09:45:37+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:37 volumio hostapd[5356]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:37 volumio hostapd[5356]: nl80211: Could not configure driver mode Feb 24 09:45:37 volumio hostapd[5356]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:37 volumio hostapd[5356]: nl80211 driver initialization failed. Feb 24 09:45:37 volumio hostapd[5356]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:37 volumio hostapd[5356]: wlan0: AP-DISABLED Feb 24 09:45:37 volumio hostapd[5356]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:37 volumio hostapd[5356]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:37 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:37 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:37 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:37 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:37 volumio dnsmasq[5358]: dnsmasq: syntax check OK. Feb 24 09:45:37 volumio dnsmasq[5364]: started, version 2.80 cachesize 150 Feb 24 09:45:37 volumio dnsmasq[5364]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:37 volumio dnsmasq-dhcp[5364]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:37 volumio dnsmasq[5364]: reading /etc/resolv.conf Feb 24 09:45:37 volumio dnsmasq[5364]: using nameserver 192.168.1.1#53 Feb 24 09:45:37 volumio dnsmasq[5364]: using nameserver 208.67.222.222#53 Feb 24 09:45:37 volumio dnsmasq[5364]: using nameserver 208.67.222.222#53 Feb 24 09:45:37 volumio dnsmasq[5364]: using nameserver 208.67.220.220#53 Feb 24 09:45:37 volumio dnsmasq[5364]: read /etc/hosts - 5 addresses Feb 24 09:45:37 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:37 volumio go-librespot[5344]: time="2025-02-24T09:45:37+07:00" level=debug msg="completed challenge" Feb 24 09:45:37 volumio go-librespot[5344]: time="2025-02-24T09:45:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:39 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:39 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 125. Feb 24 09:45:39 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:39 volumio dnsmasq[5364]: exiting on receipt of SIGTERM Feb 24 09:45:39 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:39 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:39 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:39 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:39 volumio hostapd[5374]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:39 volumio ntpd[812]: Soliciting pool server 27.71.27.209 Feb 24 09:45:40 volumio volumio-remote-updater[574]: [2025-02-24 09:45:40] [connect] Successful connection Feb 24 09:45:40 volumio hostapd[5374]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:40 volumio hostapd[5374]: nl80211: Could not configure driver mode Feb 24 09:45:40 volumio hostapd[5374]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:40 volumio hostapd[5374]: nl80211 driver initialization failed. Feb 24 09:45:40 volumio hostapd[5374]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:40 volumio hostapd[5374]: wlan0: AP-DISABLED Feb 24 09:45:40 volumio hostapd[5374]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:40 volumio hostapd[5374]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:40 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:40 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:40 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:40 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:40 volumio dnsmasq[5375]: dnsmasq: syntax check OK. Feb 24 09:45:40 volumio dnsmasq[5381]: started, version 2.80 cachesize 150 Feb 24 09:45:40 volumio dnsmasq[5381]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:40 volumio dnsmasq-dhcp[5381]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:40 volumio dnsmasq[5381]: reading /etc/resolv.conf Feb 24 09:45:40 volumio dnsmasq[5381]: using nameserver 192.168.1.1#53 Feb 24 09:45:40 volumio dnsmasq[5381]: using nameserver 208.67.222.222#53 Feb 24 09:45:40 volumio dnsmasq[5381]: using nameserver 208.67.222.222#53 Feb 24 09:45:40 volumio dnsmasq[5381]: using nameserver 208.67.220.220#53 Feb 24 09:45:40 volumio dnsmasq[5381]: read /etc/hosts - 5 addresses Feb 24 09:45:40 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 24 09:45:40 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:40 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:40 volumio go-librespot[5387]: Librespot-go daemon starting... Feb 24 09:45:40 volumio go-librespot[5387]: time="2025-02-24T09:45:40+07:00" level=info msg="generated new device id: 7b03327e0aa1600acc3f3ef91a5c117d262ec424" Feb 24 09:45:40 volumio go-librespot[5387]: time="2025-02-24T09:45:40+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:41 volumio go-librespot[5387]: time="2025-02-24T09:45:41+07:00" level=debug msg="obtained new client token: AABEf55azzoH2M8SkOkVMkkKuqrbrc7AiaNgVgKjwK7ulS934QCV9xKJpEhL1kpe972JxhM5Hm43HKs+RPaGY5a1jgPjJediVsI3ABBVxHZhZPOxbWBRY7GkheVJhyWbY98hK/9vtnTDxYd/y5UKG095i6CwujYFvRlkmjxotoN5Azd2aR9OStu1GaLaqfIpT0KIwS4c6Rtryy4Po7Ex1/klCCfAeFlH2SNWgWENcwq24d7r3gzN4gbfXDWFkmGicQ==" Feb 24 09:45:41 volumio go-librespot[5387]: time="2025-02-24T09:45:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 24 09:45:41 volumio go-librespot[5387]: time="2025-02-24T09:45:41+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:42 volumio go-librespot[5387]: time="2025-02-24T09:45:42+07:00" level=debug msg="completed challenge" Feb 24 09:45:42 volumio go-librespot[5387]: time="2025-02-24T09:45:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:42 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:42 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 126. Feb 24 09:45:42 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:42 volumio dnsmasq[5381]: exiting on receipt of SIGTERM Feb 24 09:45:42 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:42 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:42 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:42 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:42 volumio hostapd[5416]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:43 volumio hostapd[5416]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:43 volumio hostapd[5416]: nl80211: Could not configure driver mode Feb 24 09:45:43 volumio hostapd[5416]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:43 volumio hostapd[5416]: nl80211 driver initialization failed. Feb 24 09:45:43 volumio hostapd[5416]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:43 volumio hostapd[5416]: wlan0: AP-DISABLED Feb 24 09:45:43 volumio hostapd[5416]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:43 volumio hostapd[5416]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:43 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:43 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:43 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:43 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:43 volumio dnsmasq[5417]: dnsmasq: syntax check OK. Feb 24 09:45:43 volumio dnsmasq[5423]: started, version 2.80 cachesize 150 Feb 24 09:45:43 volumio dnsmasq[5423]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:43 volumio dnsmasq-dhcp[5423]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:43 volumio dnsmasq[5423]: reading /etc/resolv.conf Feb 24 09:45:43 volumio dnsmasq[5423]: using nameserver 192.168.1.1#53 Feb 24 09:45:43 volumio dnsmasq[5423]: using nameserver 208.67.222.222#53 Feb 24 09:45:43 volumio dnsmasq[5423]: using nameserver 208.67.222.222#53 Feb 24 09:45:43 volumio dnsmasq[5423]: using nameserver 208.67.220.220#53 Feb 24 09:45:43 volumio dnsmasq[5423]: read /etc/hosts - 5 addresses Feb 24 09:45:43 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 24 09:45:45 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:45 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:45 volumio go-librespot[5429]: Librespot-go daemon starting... Feb 24 09:45:45 volumio go-librespot[5429]: time="2025-02-24T09:45:45+07:00" level=info msg="generated new device id: b53a8751f5c618c9c8182a7d8e0d3323454de537" Feb 24 09:45:45 volumio go-librespot[5429]: time="2025-02-24T09:45:45+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:45 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand status took 18360 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 18360 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 18359 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 18360 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand status took 18359 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand status took 18356 milliseconds Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:45:45 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:45:45 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18390ms Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18401ms Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18400ms Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 51 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 49 milliseconds Feb 24 09:45:45 volumio volumio[914]: info: sendMpdCommand playlistinfo took 49 milliseconds Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:45:45 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:45:45 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:45:45 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:45:45 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:45:45 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:45 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18441ms Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18439ms Feb 24 09:45:45 volumio volumio[914]: info: ------------------------------ 18436ms Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:45 volumio go-librespot[5429]: time="2025-02-24T09:45:45+07:00" level=debug msg="new websocket client" Feb 24 09:45:45 volumio volumio[914]: info: Connection to go-librespot Websocket established Feb 24 09:45:45 volumio volumio[914]: Upnp client error: Error: This socket has been ended by the other party Feb 24 09:45:45 volumio go-librespot[5429]: time="2025-02-24T09:45:45+07:00" level=debug msg="obtained new client token: AADh5Ygw63tN5RAITQTNF8R0nPe8mthGowUunzwj+j5sqdNTpHP19K56IzIjxDYBA/CRWLO9gTD/8aT47AIUWH5EWavHNBX1X5t/KKnAmkvNdh1YwZ21dNIRvD1C5MdsWwtNanx/Vz5z5JS6ArhbtlQGKT1BaTMiggH7cTFK+6+dYg+XJOb4zsTtsKXZLpvLX7vfgaY6QRUF+z/Qgi9svxwBqlPE721EQfgYKhoFPDqH82UFoeVtwEZ37rG0FjTVUA==" Feb 24 09:45:45 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:45 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 127. Feb 24 09:45:45 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:45 volumio go-librespot[5429]: time="2025-02-24T09:45:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:45 volumio dnsmasq[5423]: exiting on receipt of SIGTERM Feb 24 09:45:45 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:45 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:45 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:45 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:45 volumio hostapd[5446]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:46 volumio go-librespot[5429]: time="2025-02-24T09:45:46+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:46 volumio go-librespot[5429]: time="2025-02-24T09:45:46+07:00" level=debug msg="completed challenge" Feb 24 09:45:46 volumio go-librespot[5429]: time="2025-02-24T09:45:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:46 volumio volumio[914]: info: Connection to go-librespot Websocket closed Feb 24 09:45:46 volumio hostapd[5446]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:46 volumio hostapd[5446]: nl80211: Could not configure driver mode Feb 24 09:45:46 volumio hostapd[5446]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:46 volumio hostapd[5446]: nl80211 driver initialization failed. Feb 24 09:45:46 volumio hostapd[5446]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:46 volumio hostapd[5446]: wlan0: AP-DISABLED Feb 24 09:45:46 volumio hostapd[5446]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:46 volumio hostapd[5446]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:46 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:46 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:46 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:46 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:46 volumio dnsmasq[5449]: dnsmasq: syntax check OK. Feb 24 09:45:46 volumio dnsmasq[5455]: started, version 2.80 cachesize 150 Feb 24 09:45:46 volumio dnsmasq[5455]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:46 volumio dnsmasq-dhcp[5455]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:46 volumio dnsmasq[5455]: reading /etc/resolv.conf Feb 24 09:45:46 volumio dnsmasq[5455]: using nameserver 192.168.1.1#53 Feb 24 09:45:46 volumio dnsmasq[5455]: using nameserver 208.67.222.222#53 Feb 24 09:45:46 volumio dnsmasq[5455]: using nameserver 208.67.222.222#53 Feb 24 09:45:46 volumio dnsmasq[5455]: using nameserver 208.67.220.220#53 Feb 24 09:45:46 volumio dnsmasq[5455]: read /etc/hosts - 5 addresses Feb 24 09:45:46 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:46 volumio volumio[914]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 24 09:45:46 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:46 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:45:48 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:48 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:45:48 volumio volumio[914]: verbose: New Socket.io Connection to 192.168.1.11:3000 from 192.168.1.71 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:48 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 09:45:48 volumio volumio[914]: info: Getting Spotify volume Feb 24 09:45:48 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:48 volumio volumio[914]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 24 09:45:48 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 13) Feb 24 09:45:48 volumio volumio[914]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 24 09:45:48 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:48 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:48 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:45:49 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:49 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 128. Feb 24 09:45:49 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:49 volumio dnsmasq[5455]: exiting on receipt of SIGTERM Feb 24 09:45:49 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:49 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:49 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:49 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:49 volumio hostapd[5469]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:49 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:49 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 24 09:45:49 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:49 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:49 volumio go-librespot[5472]: Librespot-go daemon starting... Feb 24 09:45:49 volumio go-librespot[5472]: time="2025-02-24T09:45:49+07:00" level=info msg="generated new device id: 7398732d4992b93448aabc36c3e04d460ada6ae9" Feb 24 09:45:49 volumio go-librespot[5472]: time="2025-02-24T09:45:49+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:50 volumio hostapd[5469]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:50 volumio hostapd[5469]: nl80211: Could not configure driver mode Feb 24 09:45:50 volumio hostapd[5469]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:50 volumio hostapd[5469]: nl80211 driver initialization failed. Feb 24 09:45:50 volumio hostapd[5469]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:50 volumio hostapd[5469]: wlan0: AP-DISABLED Feb 24 09:45:50 volumio hostapd[5469]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:50 volumio hostapd[5469]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:50 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:50 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:50 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:50 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:50 volumio dnsmasq[5479]: dnsmasq: syntax check OK. Feb 24 09:45:50 volumio dnsmasq[5485]: started, version 2.80 cachesize 150 Feb 24 09:45:50 volumio dnsmasq[5485]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:50 volumio dnsmasq-dhcp[5485]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:50 volumio dnsmasq[5485]: reading /etc/resolv.conf Feb 24 09:45:50 volumio dnsmasq[5485]: using nameserver 192.168.1.1#53 Feb 24 09:45:50 volumio dnsmasq[5485]: using nameserver 208.67.222.222#53 Feb 24 09:45:50 volumio dnsmasq[5485]: using nameserver 208.67.222.222#53 Feb 24 09:45:50 volumio dnsmasq[5485]: using nameserver 208.67.220.220#53 Feb 24 09:45:50 volumio dnsmasq[5485]: read /etc/hosts - 5 addresses Feb 24 09:45:50 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:50 volumio go-librespot[5472]: time="2025-02-24T09:45:50+07:00" level=debug msg="obtained new client token: AAAtkF1DJ/LJHO+lulBovgyQYE0AoJrsXIk9PUc0VCvLKED9UUW2OSIk9muqr9rxgALbDrTMAIZs7Th0gGDbCs2neKAREKiQKYxQUbZwhqZ/DneV35mXNHkLOc3XsAammUJe8OYhAXBMoLXIKGHo/iq5ilP3jjh97AZhxODAVZNdcBNe2BDS5/qcP4fUZzQKRAG/9u3n8bWM7f07+9xOyKftec1doeOpFKPXZQycYEaDkUffHYtPFkl8Cg9YpryAVQ==" Feb 24 09:45:50 volumio go-librespot[5472]: time="2025-02-24T09:45:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:50 volumio go-librespot[5472]: time="2025-02-24T09:45:50+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:51 volumio go-librespot[5472]: time="2025-02-24T09:45:51+07:00" level=debug msg="completed challenge" Feb 24 09:45:51 volumio go-librespot[5472]: time="2025-02-24T09:45:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:52 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:52 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 129. Feb 24 09:45:52 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:52 volumio dnsmasq[5485]: exiting on receipt of SIGTERM Feb 24 09:45:52 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:52 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:52 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:52 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:52 volumio hostapd[5514]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:52 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:53 volumio volumio-remote-updater[574]: [2025-02-24 09:45:53] [connect] Successful connection Feb 24 09:45:53 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:53 volumio volumio-remote-updater[574]: [2025-02-24 09:45:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740365152 101 Feb 24 09:45:53 volumio volumio[914]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5 Feb 24 09:45:53 volumio hostapd[5514]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:53 volumio hostapd[5514]: nl80211: Could not configure driver mode Feb 24 09:45:53 volumio hostapd[5514]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:53 volumio hostapd[5514]: nl80211 driver initialization failed. Feb 24 09:45:53 volumio hostapd[5514]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:53 volumio hostapd[5514]: wlan0: AP-DISABLED Feb 24 09:45:53 volumio hostapd[5514]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:53 volumio hostapd[5514]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:53 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:53 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:53 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:53 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:53 volumio dnsmasq[5520]: dnsmasq: syntax check OK. Feb 24 09:45:53 volumio dnsmasq[5526]: started, version 2.80 cachesize 150 Feb 24 09:45:53 volumio dnsmasq[5526]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:53 volumio dnsmasq-dhcp[5526]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:53 volumio dnsmasq[5526]: reading /etc/resolv.conf Feb 24 09:45:53 volumio dnsmasq[5526]: using nameserver 192.168.1.1#53 Feb 24 09:45:53 volumio dnsmasq[5526]: using nameserver 208.67.222.222#53 Feb 24 09:45:53 volumio dnsmasq[5526]: using nameserver 208.67.222.222#53 Feb 24 09:45:53 volumio dnsmasq[5526]: using nameserver 208.67.220.220#53 Feb 24 09:45:53 volumio dnsmasq[5526]: read /etc/hosts - 5 addresses Feb 24 09:45:53 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:54 volumio sudo[5535]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 09:45:54 volumio sudo[5535]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 09:45:54 volumio sudo[5538]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 09:45:54 volumio sudo[5535]: pam_unix(sudo:session): session closed for user root Feb 24 09:45:54 volumio sudo[5538]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 09:45:54 volumio sudo[5538]: pam_unix(sudo:session): session closed for user root Feb 24 09:45:54 volumio volumio[914]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.71 UA: Mozilla/5.0 (Linux; Android 13; SM-A325F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/132.0.6834.166 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 24 09:45:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 24 09:45:55 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:55 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:55 volumio go-librespot[5557]: Librespot-go daemon starting... Feb 24 09:45:55 volumio go-librespot[5557]: time="2025-02-24T09:45:55+07:00" level=info msg="generated new device id: 0eb18390e4b122b47c63f8c164da40f11037dae6" Feb 24 09:45:55 volumio go-librespot[5557]: time="2025-02-24T09:45:55+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:55 volumio go-librespot[5557]: time="2025-02-24T09:45:55+07:00" level=debug msg="obtained new client token: AACJRrqn7X6BSj/O72qeX7WUSRcCMnVj4vfsF1eVLYvm58tiNIwMt6jpSXEq0FdD83PYYg01jhTFYMatxqpRM1le75CGr+aBGwRfwg6ahtQYnLyKYCxl2gznQnKRRlgWrt9440Z5JnF8C4fCCB0YY0fS3XEyxpsslA7TNIJD9WHHTgfogj6bLFRsfbmGNkf8OZQ3aZvmhOm8pyHwt9RXPA3RIwExwUJTY8YMxRwUXk7Wf4rAQopKaRZbof3bLcQ=" Feb 24 09:45:55 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:55 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 130. Feb 24 09:45:55 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:55 volumio go-librespot[5557]: time="2025-02-24T09:45:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:45:55 volumio dnsmasq[5526]: exiting on receipt of SIGTERM Feb 24 09:45:55 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:55 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:55 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:55 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:55 volumio hostapd[5569]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:55 volumio go-librespot[5557]: time="2025-02-24T09:45:55+07:00" level=debug msg="completed keyexchange" Feb 24 09:45:56 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:56 volumio go-librespot[5557]: time="2025-02-24T09:45:56+07:00" level=debug msg="completed challenge" Feb 24 09:45:56 volumio sudo[5573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 09:45:56 volumio sudo[5573]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 09:45:56 volumio go-librespot[5557]: time="2025-02-24T09:45:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:45:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:45:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:45:56 volumio hostapd[5569]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:56 volumio hostapd[5569]: nl80211: Could not configure driver mode Feb 24 09:45:56 volumio hostapd[5569]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:56 volumio hostapd[5569]: nl80211 driver initialization failed. Feb 24 09:45:56 volumio sudo[5573]: pam_unix(sudo:session): session closed for user root Feb 24 09:45:56 volumio hostapd[5569]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:56 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:45:56 volumio hostapd[5569]: wlan0: AP-DISABLED Feb 24 09:45:56 volumio hostapd[5569]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:56 volumio hostapd[5569]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:56 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:56 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:56 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:56 volumio sudo[5575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 09:45:56 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:56 volumio sudo[5575]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 09:45:56 volumio dnsmasq[5584]: dnsmasq: syntax check OK. Feb 24 09:45:56 volumio sudo[5575]: pam_unix(sudo:session): session closed for user root Feb 24 09:45:56 volumio dnsmasq[5598]: started, version 2.80 cachesize 150 Feb 24 09:45:56 volumio dnsmasq[5598]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:56 volumio dnsmasq-dhcp[5598]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:56 volumio dnsmasq[5598]: reading /etc/resolv.conf Feb 24 09:45:56 volumio dnsmasq[5598]: using nameserver 192.168.1.1#53 Feb 24 09:45:56 volumio dnsmasq[5598]: using nameserver 208.67.222.222#53 Feb 24 09:45:56 volumio dnsmasq[5598]: using nameserver 208.67.222.222#53 Feb 24 09:45:56 volumio dnsmasq[5598]: using nameserver 208.67.220.220#53 Feb 24 09:45:56 volumio dnsmasq[5598]: read /etc/hosts - 5 addresses Feb 24 09:45:56 volumio volumio[914]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.71 UA: Mozilla/5.0 (Linux; Android 13; SM-A325F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/132.0.6834.166 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Feb 24 09:45:56 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:57 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetQueue Feb 24 09:45:57 volumio volumio[914]: info: CoreStateMachine::getQueue Feb 24 09:45:57 volumio volumio[914]: info: CorePlayQueue::getQueue Feb 24 09:45:57 volumio volumio[914]: info: Listing playlists Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 09:45:57 volumio volumio[914]: info: Received Get System Info Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:45:57 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:57 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:57 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 09:45:57 volumio volumio[914]: info: Received Get System Info Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:45:57 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:45:57 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:45:57 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:45:58 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 24 09:45:58 volumio volumio[914]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 24 09:45:58 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:45:58 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 131. Feb 24 09:45:58 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:58 volumio dnsmasq[5598]: exiting on receipt of SIGTERM Feb 24 09:45:58 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:45:58 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:58 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:58 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:45:58 volumio hostapd[5653]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:45:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:45:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 24 09:45:59 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:45:59 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:45:59 volumio go-librespot[5654]: Librespot-go daemon starting... Feb 24 09:45:59 volumio go-librespot[5654]: time="2025-02-24T09:45:59+07:00" level=info msg="generated new device id: aad1790a79ff5b4365ef6a4aff7a3c89727828e8" Feb 24 09:45:59 volumio go-librespot[5654]: time="2025-02-24T09:45:59+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:45:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 24 09:45:59 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:45:59 volumio go-librespot[5654]: time="2025-02-24T09:45:59+07:00" level=debug msg="obtained new client token: AAApy6R22h7bIrQ/PAF5/oSL6Q9jcS5RjC43PzO/1DKhlgiZtx8gbSedQRvP1tYrYB1cYvTNPsPFQcjx9HGz30P0xD6J/O9I6HYfQ6GJogJ4vb7T3N2A3qHyte1NoDfyli+2VyOF9pKU1/uPPuQxDPQhakHoZwbbPrTwivsWGlAXwHz9CMrEE6mJmVlCddS06KwSZdnypB6hOEVfXbMFgZRtRbRI1nWH5usS7BJfJsMCSuXK8yQAuMx3FqPriJ+O+Q==" Feb 24 09:45:59 volumio hostapd[5653]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:45:59 volumio hostapd[5653]: nl80211: Could not configure driver mode Feb 24 09:45:59 volumio hostapd[5653]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:45:59 volumio hostapd[5653]: nl80211 driver initialization failed. Feb 24 09:45:59 volumio hostapd[5653]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:45:59 volumio hostapd[5653]: wlan0: AP-DISABLED Feb 24 09:45:59 volumio hostapd[5653]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:45:59 volumio hostapd[5653]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:45:59 volumio go-librespot[5654]: time="2025-02-24T09:45:59+07:00" level=debug msg="new websocket client" Feb 24 09:45:59 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:45:59 volumio volumio[914]: info: Connection to go-librespot Websocket established Feb 24 09:45:59 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:45:59 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:45:59 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:45:59 volumio dnsmasq[5664]: dnsmasq: syntax check OK. Feb 24 09:45:59 volumio dnsmasq[5670]: started, version 2.80 cachesize 150 Feb 24 09:45:59 volumio dnsmasq[5670]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:45:59 volumio dnsmasq-dhcp[5670]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:45:59 volumio dnsmasq[5670]: reading /etc/resolv.conf Feb 24 09:45:59 volumio dnsmasq[5670]: using nameserver 192.168.1.1#53 Feb 24 09:45:59 volumio dnsmasq[5670]: using nameserver 208.67.222.222#53 Feb 24 09:45:59 volumio dnsmasq[5670]: using nameserver 208.67.222.222#53 Feb 24 09:45:59 volumio dnsmasq[5670]: using nameserver 208.67.220.220#53 Feb 24 09:45:59 volumio dnsmasq[5670]: read /etc/hosts - 5 addresses Feb 24 09:45:59 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:45:59 volumio go-librespot[5654]: time="2025-02-24T09:45:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:00 volumio go-librespot[5654]: time="2025-02-24T09:46:00+07:00" level=debug msg="completed keyexchange" Feb 24 09:46:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 09:46:00 volumio volumio[914]: info: Received Get System Info Feb 24 09:46:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:46:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:46:00 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:46:00 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:00 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:46:00 volumio go-librespot[5654]: time="2025-02-24T09:46:00+07:00" level=debug msg="completed challenge" Feb 24 09:46:00 volumio go-librespot[5654]: time="2025-02-24T09:46:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:46:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:00 volumio volumio[914]: info: Connection to go-librespot Websocket closed Feb 24 09:46:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 09:46:01 volumio volumio[914]: info: Received Get System Info Feb 24 09:46:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:46:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:46:01 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:46:01 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:01 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:46:01 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:01 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 132. Feb 24 09:46:01 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:01 volumio dnsmasq[5670]: exiting on receipt of SIGTERM Feb 24 09:46:01 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:01 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:01 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:01 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:01 volumio hostapd[5698]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 09:46:02 volumio volumio[914]: info: Received Get System Info Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:46:02 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:02 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:46:02 volumio hostapd[5698]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:02 volumio hostapd[5698]: nl80211: Could not configure driver mode Feb 24 09:46:02 volumio hostapd[5698]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:02 volumio hostapd[5698]: nl80211 driver initialization failed. Feb 24 09:46:02 volumio hostapd[5698]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:02 volumio hostapd[5698]: wlan0: AP-DISABLED Feb 24 09:46:02 volumio hostapd[5698]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:02 volumio hostapd[5698]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:02 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:02 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:02 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:02 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:02 volumio dnsmasq[5704]: dnsmasq: syntax check OK. Feb 24 09:46:02 volumio volumio[914]: info: Getting Spotify volume Feb 24 09:46:02 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:02 volumio volumio[914]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 24 09:46:02 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14) Feb 24 09:46:02 volumio volumio[914]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 24 09:46:02 volumio dnsmasq[5710]: started, version 2.80 cachesize 150 Feb 24 09:46:02 volumio dnsmasq[5710]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:02 volumio dnsmasq-dhcp[5710]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:02 volumio dnsmasq[5710]: reading /etc/resolv.conf Feb 24 09:46:02 volumio dnsmasq[5710]: using nameserver 192.168.1.1#53 Feb 24 09:46:02 volumio dnsmasq[5710]: using nameserver 208.67.222.222#53 Feb 24 09:46:02 volumio dnsmasq[5710]: using nameserver 208.67.222.222#53 Feb 24 09:46:02 volumio dnsmasq[5710]: using nameserver 208.67.220.220#53 Feb 24 09:46:02 volumio dnsmasq[5710]: read /etc/hosts - 5 addresses Feb 24 09:46:02 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:02 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:02 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:02 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:03 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:03 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 24 09:46:03 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:03 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:03 volumio go-librespot[5718]: Librespot-go daemon starting... Feb 24 09:46:03 volumio go-librespot[5718]: time="2025-02-24T09:46:03+07:00" level=info msg="generated new device id: 9972ddf4923a5d3065fb2925d14fbbbc722c8d02" Feb 24 09:46:03 volumio go-librespot[5718]: time="2025-02-24T09:46:03+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:04 volumio go-librespot[5718]: time="2025-02-24T09:46:04+07:00" level=debug msg="obtained new client token: AAC7tVz+Iqj9nHcpvTYurLSICo4ViHWaU2uYRgK4WUaGbqG4cIgXyiaBDh3DR7OOCqwdAnK0Ikb8YH/G1YMrY2Su0A8UjPVmzD8YJ4Xqs0KvuHzyx0F+4/2TVrPTR1yI0UgYbQBr+do/hlk+b5v7ssWjd+KZiSfW6ESQS4IcZjkrMHvf5dT6P0aVg6R54DkWv27nKfXTeqFW0XQxpFm7eXkNGFmrfg26hJ9ul/9pKWQAGuO1WMG4rpxfQYIDD4yjDA==" Feb 24 09:46:04 volumio go-librespot[5718]: time="2025-02-24T09:46:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:04 volumio go-librespot[5718]: time="2025-02-24T09:46:04+07:00" level=debug msg="completed keyexchange" Feb 24 09:46:04 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:04 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 133. Feb 24 09:46:04 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:04 volumio dnsmasq[5710]: exiting on receipt of SIGTERM Feb 24 09:46:04 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:04 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:04 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:04 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:04 volumio hostapd[5732]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:05 volumio go-librespot[5718]: time="2025-02-24T09:46:05+07:00" level=debug msg="completed challenge" Feb 24 09:46:05 volumio go-librespot[5718]: time="2025-02-24T09:46:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:46:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:05 volumio hostapd[5732]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:05 volumio hostapd[5732]: nl80211: Could not configure driver mode Feb 24 09:46:05 volumio hostapd[5732]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:05 volumio hostapd[5732]: nl80211 driver initialization failed. Feb 24 09:46:05 volumio hostapd[5732]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:05 volumio hostapd[5732]: wlan0: AP-DISABLED Feb 24 09:46:05 volumio hostapd[5732]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:05 volumio hostapd[5732]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:05 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:05 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:05 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:05 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:05 volumio dnsmasq[5735]: dnsmasq: syntax check OK. Feb 24 09:46:05 volumio dnsmasq[5741]: started, version 2.80 cachesize 150 Feb 24 09:46:05 volumio dnsmasq[5741]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:05 volumio dnsmasq-dhcp[5741]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:05 volumio dnsmasq[5741]: reading /etc/resolv.conf Feb 24 09:46:05 volumio dnsmasq[5741]: using nameserver 192.168.1.1#53 Feb 24 09:46:05 volumio dnsmasq[5741]: using nameserver 208.67.222.222#53 Feb 24 09:46:05 volumio dnsmasq[5741]: using nameserver 208.67.222.222#53 Feb 24 09:46:05 volumio dnsmasq[5741]: using nameserver 208.67.220.220#53 Feb 24 09:46:05 volumio dnsmasq[5741]: read /etc/hosts - 5 addresses Feb 24 09:46:05 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 24 09:46:06 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:06 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::volumioPause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::servicePause Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::servicePause Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::pause Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand pause Feb 24 09:46:07 volumio volumio[914]: info: Feb 24 09:46:07 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand pause took 1 milliseconds Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:07 volumio volumio[914]: info: Feb 24 09:46:07 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:07 volumio volumio[914]: info: Feb 24 09:46:07 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand status took 2 milliseconds Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand status took 1 milliseconds Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 24 09:46:07 volumio volumio[914]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:07 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":37156,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:07 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":37156,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:07 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:46:07 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":37156,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:07 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState stateService pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus pause Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:07 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:07 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:07 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:46:07 volumio volumio[914]: info: ------------------------------ 36ms Feb 24 09:46:07 volumio volumio[914]: info: ------------------------------ 35ms Feb 24 09:46:07 volumio volumio[914]: info: ------------------------------ 34ms Feb 24 09:46:07 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:07 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:07 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:08 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:08 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 134. Feb 24 09:46:08 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:08 volumio dnsmasq[5741]: exiting on receipt of SIGTERM Feb 24 09:46:08 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:08 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:08 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:08 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:08 volumio hostapd[5758]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 24 09:46:08 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:08 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:08 volumio go-librespot[5759]: Librespot-go daemon starting... Feb 24 09:46:08 volumio go-librespot[5759]: time="2025-02-24T09:46:08+07:00" level=info msg="generated new device id: c3d64c0b14d4bd65d84b26cfe71dd04b09bd2d9b" Feb 24 09:46:08 volumio go-librespot[5759]: time="2025-02-24T09:46:08+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:08 volumio go-librespot[5759]: time="2025-02-24T09:46:08+07:00" level=debug msg="obtained new client token: AADSmU7AQ/rDSdkYlmvsSonwP4i9qq3kMaIbcyXQGPw7JSzI3aRocqCTNSfQlbdB/2nHiIv9RgRJ8n4wXB1rxTy3F/1xcSPyOQQ50UwYBkhxPYSwjdNv/7Pp//sdxKoKuIr2hLcQPmPAC9a0tSYNBP7BcO4lOalYzLO+jmkme9v6Jqk7HGEpRXGwJgNop5vckTxGUkQu8p2D8TMngvMbbF2JKN39A7ktbcYwEpoeg40StzLyDqUzbMAjqDgV4gc=" Feb 24 09:46:08 volumio go-librespot[5759]: time="2025-02-24T09:46:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 24 09:46:09 volumio hostapd[5758]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:09 volumio hostapd[5758]: nl80211: Could not configure driver mode Feb 24 09:46:09 volumio hostapd[5758]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:09 volumio hostapd[5758]: nl80211 driver initialization failed. Feb 24 09:46:09 volumio hostapd[5758]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:09 volumio hostapd[5758]: wlan0: AP-DISABLED Feb 24 09:46:09 volumio hostapd[5758]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:09 volumio hostapd[5758]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:09 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:09 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:09 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:09 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:09 volumio dnsmasq[5767]: dnsmasq: syntax check OK. Feb 24 09:46:09 volumio go-librespot[5759]: time="2025-02-24T09:46:09+07:00" level=debug msg="completed keyexchange" Feb 24 09:46:09 volumio dnsmasq[5773]: started, version 2.80 cachesize 150 Feb 24 09:46:09 volumio dnsmasq[5773]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:09 volumio dnsmasq-dhcp[5773]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:09 volumio dnsmasq[5773]: reading /etc/resolv.conf Feb 24 09:46:09 volumio dnsmasq[5773]: using nameserver 192.168.1.1#53 Feb 24 09:46:09 volumio dnsmasq[5773]: using nameserver 208.67.222.222#53 Feb 24 09:46:09 volumio dnsmasq[5773]: using nameserver 208.67.222.222#53 Feb 24 09:46:09 volumio dnsmasq[5773]: using nameserver 208.67.220.220#53 Feb 24 09:46:09 volumio dnsmasq[5773]: read /etc/hosts - 5 addresses Feb 24 09:46:09 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:09 volumio go-librespot[5759]: time="2025-02-24T09:46:09+07:00" level=debug msg="completed challenge" Feb 24 09:46:09 volumio go-librespot[5759]: time="2025-02-24T09:46:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:46:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:09 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:09 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:11 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:11 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 135. Feb 24 09:46:11 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:11 volumio dnsmasq[5773]: exiting on receipt of SIGTERM Feb 24 09:46:11 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:11 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:11 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:11 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:11 volumio hostapd[5783]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:12 volumio hostapd[5783]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:12 volumio hostapd[5783]: nl80211: Could not configure driver mode Feb 24 09:46:12 volumio hostapd[5783]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:12 volumio hostapd[5783]: nl80211 driver initialization failed. Feb 24 09:46:12 volumio hostapd[5783]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:12 volumio hostapd[5783]: wlan0: AP-DISABLED Feb 24 09:46:12 volumio hostapd[5783]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:12 volumio hostapd[5783]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:12 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:12 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:12 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:12 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:12 volumio dnsmasq[5792]: dnsmasq: syntax check OK. Feb 24 09:46:12 volumio dnsmasq[5804]: started, version 2.80 cachesize 150 Feb 24 09:46:12 volumio dnsmasq[5804]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:12 volumio dnsmasq-dhcp[5804]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:12 volumio dnsmasq[5804]: reading /etc/resolv.conf Feb 24 09:46:12 volumio dnsmasq[5804]: using nameserver 192.168.1.1#53 Feb 24 09:46:12 volumio dnsmasq[5804]: using nameserver 208.67.222.222#53 Feb 24 09:46:12 volumio dnsmasq[5804]: using nameserver 208.67.222.222#53 Feb 24 09:46:12 volumio dnsmasq[5804]: using nameserver 208.67.220.220#53 Feb 24 09:46:12 volumio dnsmasq[5804]: read /etc/hosts - 5 addresses Feb 24 09:46:12 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:12 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:12 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 24 09:46:12 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:12 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:12 volumio go-librespot[5813]: Librespot-go daemon starting... Feb 24 09:46:12 volumio go-librespot[5813]: time="2025-02-24T09:46:12+07:00" level=info msg="generated new device id: 1a08fa32b2b383fd0037d6b173af303c2be68775" Feb 24 09:46:12 volumio go-librespot[5813]: time="2025-02-24T09:46:12+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:13 volumio go-librespot[5813]: time="2025-02-24T09:46:13+07:00" level=debug msg="obtained new client token: AABiRU6QY1J6lM2TNM2Sk+N+Cf+C4SOQZ5GiW/z7PmQer8d3T2KuoJD4zFPcW28RTEOU6GYPhGyMNzzHy1OpJBm8fCGFDOtlGsWdJoqzHe8iYLwTjRYjv75STqDkbwC1HI6P1GxYVa5Y1kFzuxyf72mDaPNmCnmeP9qoKG/gws/DnCnaqMVKy6hJJpiptIOapmxkC/6Mb2yeFfD7p8mGmojQJOGFqufg0DsPXznMERYVUI5kMCGvYlEsdckO5Gcj8Q==" Feb 24 09:46:13 volumio go-librespot[5813]: time="2025-02-24T09:46:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:13 volumio go-librespot[5813]: time="2025-02-24T09:46:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Feb 24 09:46:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:14 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:14 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 136. Feb 24 09:46:14 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:14 volumio dnsmasq[5804]: exiting on receipt of SIGTERM Feb 24 09:46:14 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:14 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:14 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:14 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:14 volumio hostapd[5825]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 09:46:14 volumio volumio[914]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 24 09:46:14 volumio volumio[914]: info: Received Get System Version Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 09:46:14 volumio volumio[914]: info: Received Get System Info Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:46:14 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:14 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:46:15 volumio hostapd[5825]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:15 volumio hostapd[5825]: nl80211: Could not configure driver mode Feb 24 09:46:15 volumio hostapd[5825]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:15 volumio hostapd[5825]: nl80211 driver initialization failed. Feb 24 09:46:15 volumio hostapd[5825]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:15 volumio hostapd[5825]: wlan0: AP-DISABLED Feb 24 09:46:15 volumio hostapd[5825]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:15 volumio hostapd[5825]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:15 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:15 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:15 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:15 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:15 volumio dnsmasq[5826]: dnsmasq: syntax check OK. Feb 24 09:46:15 volumio dnsmasq[5832]: started, version 2.80 cachesize 150 Feb 24 09:46:15 volumio dnsmasq[5832]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:15 volumio dnsmasq-dhcp[5832]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:15 volumio dnsmasq[5832]: reading /etc/resolv.conf Feb 24 09:46:15 volumio dnsmasq[5832]: using nameserver 192.168.1.1#53 Feb 24 09:46:15 volumio dnsmasq[5832]: using nameserver 208.67.222.222#53 Feb 24 09:46:15 volumio dnsmasq[5832]: using nameserver 208.67.222.222#53 Feb 24 09:46:15 volumio dnsmasq[5832]: using nameserver 208.67.220.220#53 Feb 24 09:46:15 volumio dnsmasq[5832]: read /etc/hosts - 5 addresses Feb 24 09:46:15 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:15 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:15 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Feb 24 09:46:16 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:16 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:16 volumio go-librespot[5838]: Librespot-go daemon starting... Feb 24 09:46:16 volumio go-librespot[5838]: time="2025-02-24T09:46:16+07:00" level=info msg="generated new device id: 793b103b957981b6784a21713e2221049d35eacd" Feb 24 09:46:16 volumio go-librespot[5838]: time="2025-02-24T09:46:16+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:16 volumio go-librespot[5838]: time="2025-02-24T09:46:16+07:00" level=debug msg="obtained new client token: AABvcEmDuPSoJyM8IsxbGSluAD92PxYgANfdq4Ymg322SvWncUHZ+UynKQF/HqYhxXnBGuNXMZ9kv5Hja2MS61GODEObILls4SbT4GMw/s942tVJEei93muIli3SLnXBzOIYRGQUpaAJEo7LilgaKaj9M2n02KG9K5dAbJReB3q9GOH/lxKe8R3WqsQmouqErohUcACyZY2pLsu3lsseVxbMcwAPub5S+JEw3ZeRUhPDKtCduV1jUpAmdhQpl1tJqg==" Feb 24 09:46:17 volumio go-librespot[5838]: time="2025-02-24T09:46:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:17 volumio go-librespot[5838]: time="2025-02-24T09:46:17+07:00" level=debug msg="completed keyexchange" Feb 24 09:46:17 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:17 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 137. Feb 24 09:46:17 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:17 volumio dnsmasq[5832]: exiting on receipt of SIGTERM Feb 24 09:46:17 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:17 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:17 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:17 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:17 volumio hostapd[5851]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:17 volumio go-librespot[5838]: time="2025-02-24T09:46:17+07:00" level=debug msg="completed challenge" Feb 24 09:46:17 volumio go-librespot[5838]: time="2025-02-24T09:46:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:46:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:18 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 09:46:18 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 09:46:18 volumio volumio[914]: info: Discovery: Getting this device information Feb 24 09:46:18 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:18 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:18 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 09:46:18 volumio hostapd[5851]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:18 volumio hostapd[5851]: nl80211: Could not configure driver mode Feb 24 09:46:18 volumio hostapd[5851]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:18 volumio hostapd[5851]: nl80211 driver initialization failed. Feb 24 09:46:18 volumio hostapd[5851]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:18 volumio hostapd[5851]: wlan0: AP-DISABLED Feb 24 09:46:18 volumio hostapd[5851]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:18 volumio hostapd[5851]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:18 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:18 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:18 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:18 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:18 volumio dnsmasq[5852]: dnsmasq: syntax check OK. Feb 24 09:46:18 volumio dnsmasq[5858]: started, version 2.80 cachesize 150 Feb 24 09:46:18 volumio dnsmasq[5858]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:18 volumio dnsmasq-dhcp[5858]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:18 volumio dnsmasq[5858]: reading /etc/resolv.conf Feb 24 09:46:18 volumio dnsmasq[5858]: using nameserver 192.168.1.1#53 Feb 24 09:46:18 volumio dnsmasq[5858]: using nameserver 208.67.222.222#53 Feb 24 09:46:18 volumio dnsmasq[5858]: using nameserver 208.67.222.222#53 Feb 24 09:46:18 volumio dnsmasq[5858]: using nameserver 208.67.220.220#53 Feb 24 09:46:18 volumio dnsmasq[5858]: read /etc/hosts - 5 addresses Feb 24 09:46:18 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:18 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:18 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:20 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:20 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 138. Feb 24 09:46:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Feb 24 09:46:20 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:20 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:20 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:20 volumio go-librespot[5864]: Librespot-go daemon starting... Feb 24 09:46:20 volumio go-librespot[5864]: time="2025-02-24T09:46:20+07:00" level=info msg="generated new device id: f47dcc890e4d4fb9eb637c2c7919946e98a30abc" Feb 24 09:46:20 volumio go-librespot[5864]: time="2025-02-24T09:46:20+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:20 volumio dnsmasq[5858]: exiting on receipt of SIGTERM Feb 24 09:46:20 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:20 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:20 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:20 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:20 volumio hostapd[5875]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:21 volumio go-librespot[5864]: time="2025-02-24T09:46:21+07:00" level=debug msg="obtained new client token: AADixB2jK7Df154iDbpr7ByfTlykvhiliOzdbXa00hOTetsCsbfm3EnoEgHNVNRJqQTkVJnmXGCLmRMsIN2is14qVuByZ2mP1CikARrXF2JEWrs/0B96t3Bb6hn19uNzw9O0MY3zjdL5koTZrZPFb+LO5jENLJUFhXvEwD0OYctdWiyUBke1roGiWe0esEh7+AKM0cUaiz5SJ7coJFCMBZVyx/wNeHjh9hjuq57cQ3bbQfG04RFXpt7RHPAH728=" Feb 24 09:46:21 volumio go-librespot[5864]: time="2025-02-24T09:46:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:21 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:21 volumio hostapd[5875]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:21 volumio hostapd[5875]: nl80211: Could not configure driver mode Feb 24 09:46:21 volumio hostapd[5875]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:21 volumio hostapd[5875]: nl80211 driver initialization failed. Feb 24 09:46:21 volumio hostapd[5875]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:21 volumio hostapd[5875]: wlan0: AP-DISABLED Feb 24 09:46:21 volumio hostapd[5875]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:21 volumio hostapd[5875]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:21 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:21 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:21 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:21 volumio volumio[914]: info: Connection to go-librespot Websocket established Feb 24 09:46:21 volumio go-librespot[5864]: time="2025-02-24T09:46:21+07:00" level=debug msg="new websocket client" Feb 24 09:46:21 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:21 volumio go-librespot[5864]: time="2025-02-24T09:46:21+07:00" level=debug msg="completed keyexchange" Feb 24 09:46:21 volumio dnsmasq[5877]: dnsmasq: syntax check OK. Feb 24 09:46:21 volumio dnsmasq[5883]: started, version 2.80 cachesize 150 Feb 24 09:46:21 volumio dnsmasq[5883]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:21 volumio dnsmasq-dhcp[5883]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:21 volumio dnsmasq[5883]: reading /etc/resolv.conf Feb 24 09:46:21 volumio dnsmasq[5883]: using nameserver 192.168.1.1#53 Feb 24 09:46:21 volumio dnsmasq[5883]: using nameserver 208.67.222.222#53 Feb 24 09:46:21 volumio dnsmasq[5883]: using nameserver 208.67.222.222#53 Feb 24 09:46:21 volumio dnsmasq[5883]: using nameserver 208.67.220.220#53 Feb 24 09:46:21 volumio dnsmasq[5883]: read /etc/hosts - 5 addresses Feb 24 09:46:21 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:22 volumio go-librespot[5864]: time="2025-02-24T09:46:22+07:00" level=debug msg="completed challenge" Feb 24 09:46:22 volumio go-librespot[5864]: time="2025-02-24T09:46:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 24 09:46:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 09:46:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 09:46:22 volumio volumio[914]: info: Connection to go-librespot Websocket closed Feb 24 09:46:24 volumio systemd[1]: hostapd.service: Service RestartSec=2s expired, scheduling restart. Feb 24 09:46:24 volumio systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 139. Feb 24 09:46:24 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:24 volumio dnsmasq[5883]: exiting on receipt of SIGTERM Feb 24 09:46:24 volumio systemd[1]: dnsmasq.service: Succeeded. Feb 24 09:46:24 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:24 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:24 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Feb 24 09:46:24 volumio hostapd[5910]: Configuration file: /etc/hostapd/hostapd.conf Feb 24 09:46:24 volumio volumio[914]: info: Getting Spotify volume Feb 24 09:46:24 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 24 09:46:24 volumio volumio[914]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 24 09:46:24 volumio volumio[914]: (node:914) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 15) Feb 24 09:46:25 volumio hostapd[5910]: Could not set interface wlan0 flags (UP): Operation not permitted Feb 24 09:46:25 volumio hostapd[5910]: nl80211: Could not configure driver mode Feb 24 09:46:25 volumio hostapd[5910]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 24 09:46:25 volumio hostapd[5910]: nl80211 driver initialization failed. Feb 24 09:46:25 volumio hostapd[5910]: wlan0: interface state UNINITIALIZED->DISABLED Feb 24 09:46:25 volumio hostapd[5910]: wlan0: AP-DISABLED Feb 24 09:46:25 volumio hostapd[5910]: wlan0: CTRL-EVENT-TERMINATING Feb 24 09:46:25 volumio hostapd[5910]: hostapd_free_hapd_data: Interface wlan0 wasn't started Feb 24 09:46:25 volumio systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Feb 24 09:46:25 volumio systemd[1]: hostapd.service: Failed with result 'exit-code'. Feb 24 09:46:25 volumio systemd[1]: Failed to start Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Feb 24 09:46:25 volumio volumio[914]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 24 09:46:25 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio dnsmasq[5911]: dnsmasq: syntax check OK. Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio dnsmasq[5917]: started, version 2.80 cachesize 150 Feb 24 09:46:25 volumio dnsmasq[5917]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Feb 24 09:46:25 volumio dnsmasq-dhcp[5917]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 24 09:46:25 volumio dnsmasq[5917]: reading /etc/resolv.conf Feb 24 09:46:25 volumio dnsmasq[5917]: using nameserver 192.168.1.1#53 Feb 24 09:46:25 volumio dnsmasq[5917]: using nameserver 208.67.222.222#53 Feb 24 09:46:25 volumio dnsmasq[5917]: using nameserver 208.67.222.222#53 Feb 24 09:46:25 volumio dnsmasq[5917]: using nameserver 208.67.220.220#53 Feb 24 09:46:25 volumio dnsmasq[5917]: read /etc/hosts - 5 addresses Feb 24 09:46:25 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Feb 24 09:46:25 volumio volumio[914]: info: Preload queue cleared Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::ClearQueue Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::serviceStop Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::serviceStop Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::stop Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::saveQueue Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::addQueueItems Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::addQueueItems Feb 24 09:46:25 volumio volumio[914]: info: Preload queue cleared Feb 24 09:46:25 volumio volumio[914]: info: Adding Item to queue: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Using cached record of: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::saveQueue Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::play index 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::addQueueItems Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::addQueueItems Feb 24 09:46:25 volumio volumio[914]: info: Preload queue cleared Feb 24 09:46:25 volumio volumio[914]: info: Adding Item to queue: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/04-Duyên tình-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Using cached record of: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/04-Duyên tình-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Adding Item to queue: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/06-Mùa đông của anh-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Using cached record of: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/06-Mùa đông của anh-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Adding Item to queue: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/08-Ngày đá đơm bông-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Using cached record of: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/08-Ngày đá đơm bông-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Adding Item to queue: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/10-Sao em vô tình-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: Using cached record of: music-library/NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/10-Sao em vô tình-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::saveQueue Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::play index undefined Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::clearAddPlayTracks NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand stop took 27 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand stop took 5 milliseconds Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 4 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand clear took 4 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 2 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 2 milliseconds Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav" Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: No code Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: No code Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 48ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 48ms Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: error: updateQueue error: null Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 51ms Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 51 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand add "NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav" took 51 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 5ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 4ms Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Feb 24 09:46:25 volumio volumio[914]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 59ms Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces system playlist update Feb 24 09:46:25 volumio volumio[914]: info: Ignoring MPD Status Update Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 15ms Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand play took 14 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 12ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 12ms Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 09:46:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Feb 24 09:46:25 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 09:46:25 volumio systemd[1]: Started go-librespot Daemon. Feb 24 09:46:25 volumio go-librespot[5925]: Librespot-go daemon starting... Feb 24 09:46:25 volumio volumio[914]: info: Initializing connection to go-librespot Websocket Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 231 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 230 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 228 milliseconds Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio go-librespot[5925]: time="2025-02-24T09:46:25+07:00" level=info msg="generated new device id: 07440ec95fdcce7ba26d1225edfa836ce97d0fd9" Feb 24 09:46:25 volumio go-librespot[5925]: time="2025-02-24T09:46:25+07:00" level=debug msg="stored credentials found for 31swqmdkui2gaodqllbj35b5fugm" Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: Feb 24 09:46:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::getState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 8 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 5 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseState Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":594,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:46:25 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":594,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:46:25 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 261ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 276ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 275ms Feb 24 09:46:25 volumio go-librespot[5925]: time="2025-02-24T09:46:25+07:00" level=debug msg="new websocket client" Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 40 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 39 milliseconds Feb 24 09:46:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 39 milliseconds Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:46:25 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:46:25 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ControllerMpd::pushState Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Anh cho em m?a xu?n","artist":"Tu?n Vu","album":"T?nh Xua V?ng D?i","uri":"NAS/Volumio/CD Trong nuoc/Lac Vu-Tuan Vu Phi Nhung-Tinh Xua Vung Dai [WAV]/02-Anh cho em mùa xuân-Tuấn Vũ.wav","trackType":"wav"} Feb 24 09:46:25 volumio volumio[914]: verbose: CURRENT POSITION 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Feb 24 09:46:25 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: CoreStateMachine::pushState Feb 24 09:46:25 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Feb 24 09:46:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 88ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 84ms Feb 24 09:46:25 volumio volumio[914]: info: ------------------------------ 82ms Feb 24 09:46:25 volumio volumio[914]: info: Connection to go-librespot Websocket established Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 24 09:46:25 volumio volumio[914]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 09:46:25 volumio volumio[914]: Error: connect ETIMEDOUT 151.101.194.79:80 Feb 24 09:46:25 volumio volumio[914]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Feb 24 09:46:25 volumio volumio[914]: errno: -110, Feb 24 09:46:25 volumio volumio[914]: code: 'ETIMEDOUT', Feb 24 09:46:25 volumio volumio[914]: syscall: 'connect', Feb 24 09:46:25 volumio volumio[914]: address: '151.101.194.79', Feb 24 09:46:25 volumio volumio[914]: port: 80 Feb 24 09:46:25 volumio volumio[914]: } Feb 24 09:46:25 volumio volumio[914]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 09:46:25 volumio go-librespot[5925]: time="2025-02-24T09:46:25+07:00" level=debug msg="obtained new client token: AAA0SK4XNA5JnOeIbbWQEMFDZ+pg+tzYe7S170RgMT9LxmzL5+Ooe08u1FMnrAopWlsaIx7AFeKDOks3Em2gOImUuzW0n+Cy41KO+ckimnIFFCPGfUfnw/YFm5truR5cfuu5Qcrf1gIdkAFjtzigCVL5DNMU22PEiikwMILg7KOaQSl+i8ZM6UwraH+kZeBXHCTIUvjnvvjUXgMhXbFxK7gaxuWfNmLXZV7kI16sf3xPnIkYSOnsPI7zMy+AV2F/ng==" Feb 24 09:46:26 volumio go-librespot[5925]: time="2025-02-24T09:46:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 24 09:46:26 volumio sudo[5942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-24 09:45 Feb 24 09:46:26 volumio sudo[5942]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"