-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Thu 2025-12-18 08:13:53 CST. -- Dec 18 08:12:02 volumio go-librespot[1272]: time="2025-12-18T08:12:02+08:00" level=trace msg="sent dealer ping" Dec 18 08:12:02 volumio go-librespot[1272]: time="2025-12-18T08:12:02+08:00" level=trace msg="received dealer pong" Dec 18 08:12:10 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:12:10 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Incoming message: 'noop' Dec 18 08:12:10 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Not handled: 'noop' Dec 18 08:12:10 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:12:10 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Incoming message: 'noop' Dec 18 08:12:10 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Not handled: 'noop' Dec 18 08:12:11 volumio volumio[985]: verbose: New Socket.io Connection to 192.168.1.142 from 192.168.1.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 18 08:12:11 volumio volumio[985]: verbose: New Socket.io Connection to 192.168.1.142 from 192.168.1.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 18 08:12:11 volumio volumio[985]: verbose: New Socket.io Connection to 192.168.1.142 from 192.168.1.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 18 08:12:11 volumio volumio[985]: verbose: New Socket.io Connection to 192.168.1.142 from 192.168.1.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:11 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetVisibleSources Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:11 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:11 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 18 08:12:11 volumio volumio[985]: info: Received Get System Info Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 18 08:12:11 volumio volumio[985]: info: Discovery: Getting this device information Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:11 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:11 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:11 volumio volumio[985]: info: Listing playlists Dec 18 08:12:11 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 18 08:12:16 volumio sudo[1878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 18 08:12:16 volumio sudo[1878]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 08:12:16 volumio sudo[1878]: pam_unix(sudo:session): session closed for user root Dec 18 08:12:16 volumio sudo[1881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 18 08:12:16 volumio sudo[1881]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 08:12:16 volumio sudo[1881]: pam_unix(sudo:session): session closed for user root Dec 18 08:12:16 volumio volumio[985]: verbose: New Socket.io Connection to 192.168.1.142 from 192.168.1.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::volumioGetVisibleSources Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:16 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 18 08:12:16 volumio volumio[985]: info: Loaded the previous config. Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 18 08:12:16 volumio volumio[985]: info: Received Get System Info Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 18 08:12:16 volumio volumio[985]: info: Discovery: Getting this device information Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:16 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:16 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:16 volumio volumio[985]: info: Listing playlists Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 18 08:12:16 volumio volumio[985]: info: ## populating UI... Dec 18 08:12:16 volumio volumio[985]: info: 1/1 settings loaded Dec 18 08:12:16 volumio volumio[985]: info: Populated config screen. Dec 18 08:12:16 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 18 08:12:18 volumio volumio[985]: info: Received Get System Info Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 18 08:12:18 volumio volumio[985]: info: Discovery: Getting this device information Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:18 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:18 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 18 08:12:19 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 18 08:12:19 volumio volumio[985]: info: Received Get System Info Dec 18 08:12:19 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 18 08:12:19 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 18 08:12:19 volumio volumio[985]: info: Discovery: Getting this device information Dec 18 08:12:19 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:19 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:19 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 18 08:12:27 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 18 08:12:32 volumio go-librespot[1272]: time="2025-12-18T08:12:32+08:00" level=trace msg="sent dealer ping" Dec 18 08:12:32 volumio go-librespot[1272]: time="2025-12-18T08:12:32+08:00" level=trace msg="received dealer pong" Dec 18 08:12:37 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:12:37 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Incoming message: 'noop' Dec 18 08:12:37 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Not handled: 'noop' Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 18 08:12:37 volumio volumio[985]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 18 08:12:37 volumio volumio[985]: info: Received Get System Version Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 08:12:37 volumio volumio[985]: info: Received Get System Info Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 18 08:12:37 volumio volumio[985]: info: Discovery: Getting this device information Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:12:37 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:12:37 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 18 08:12:37 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:12:37 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Incoming message: 'noop' Dec 18 08:12:37 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Not handled: 'noop' Dec 18 08:12:50 volumio volumio[985]: error: [yt-cast-receiver] RPC connection reader error: Dec 18 08:12:50 volumio volumio[985]: (Error) Premature close Dec 18 08:12:50 volumio volumio[985]: Error: Premature close Dec 18 08:12:50 volumio volumio[985]: at IncomingMessage. (/data/plugins/music_service/ytcr/node_modules/node-fetch/lib/index.js:1748:18) Dec 18 08:12:50 volumio volumio[985]: at Object.onceWrapper (events.js:421:28) Dec 18 08:12:50 volumio volumio[985]: at IncomingMessage.emit (events.js:315:20) Dec 18 08:12:50 volumio volumio[985]: at TLSSocket.socketCloseListener (_http_client.js:435:11) Dec 18 08:12:50 volumio volumio[985]: at TLSSocket.emit (events.js:327:22) Dec 18 08:12:50 volumio volumio[985]: at net.js:673:12 Dec 18 08:12:50 volumio volumio[985]: at TCP.done (_tls_wrap.js:563:7) Dec 18 08:12:50 volumio volumio[985]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting... Dec 18 08:12:50 volumio volumio[985]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=12&CI=0&RID=rpc&SID=AF0BAC60AFA2F7A&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=04k2cNw0VnEjN3WPg19hasYC-qppnSyH&id=7cd2e9df-1f19-4bfc-acbb-4386f392cea0&loungeIdToken=AGdO5p_0RyEVFfanHqNKyMR3rbLpJ-PdfjQbjbZCTbBJRdEFwWNmcmGvWsWSL5_ZZygGb7ssD7ZE-9dR2_Jp2XJ_DlWzHEkKHdFuZSGP38y205cC051Uzrg&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=m&v=2&zx=7651f621be08 Dec 18 08:12:50 volumio volumio[985]: verbose: [yt-cast-receiver] RPC connection established. Dec 18 08:12:50 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:12:50 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 13) (YouTube Music) Incoming message: 'noop' Dec 18 08:12:50 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 13) (YouTube Music) Not handled: 'noop' Dec 18 08:13:02 volumio go-librespot[1272]: time="2025-12-18T08:13:02+08:00" level=trace msg="received accesspoint ping" Dec 18 08:13:02 volumio go-librespot[1272]: time="2025-12-18T08:13:02+08:00" level=trace msg="received accesspoint pong ack" Dec 18 08:13:02 volumio go-librespot[1272]: time="2025-12-18T08:13:02+08:00" level=trace msg="sent dealer ping" Dec 18 08:13:02 volumio go-librespot[1272]: time="2025-12-18T08:13:02+08:00" level=trace msg="received dealer pong" Dec 18 08:13:03 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:13:03 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 13) (YouTube) Incoming message: 'noop' Dec 18 08:13:03 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 13) (YouTube) Not handled: 'noop' Dec 18 08:13:19 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:13:19 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 14) (YouTube Music) Incoming message: 'noop' Dec 18 08:13:19 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 14) (YouTube Music) Not handled: 'noop' Dec 18 08:13:29 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:13:29 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 14) (YouTube) Incoming message: 'noop' Dec 18 08:13:29 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 14) (YouTube) Not handled: 'noop' Dec 18 08:13:32 volumio go-librespot[1272]: time="2025-12-18T08:13:32+08:00" level=trace msg="sent dealer ping" Dec 18 08:13:32 volumio go-librespot[1272]: time="2025-12-18T08:13:32+08:00" level=trace msg="received dealer pong" Dec 18 08:13:42 volumio volumio[985]: info: CoreCommandRouter::volumioGetState Dec 18 08:13:42 volumio volumio[985]: info: CorePlayQueue::getTrack 0 Dec 18 08:13:45 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 18 08:13:45 volumio volumio[985]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 18 08:13:46 volumio volumio[985]: verbose: ----------------------------------- Dec 18 08:13:46 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 15) (YouTube Music) Incoming message: 'noop' Dec 18 08:13:46 volumio volumio[985]: verbose: [yt-cast-receiver] (AID: 15) (YouTube Music) Not handled: 'noop' Dec 18 08:13:51 volumio volumio[985]: info: Enabling plugin audiophonicsonoff Dec 18 08:13:51 volumio volumio[985]: info: Loading plugin "audiophonicsonoff"... Dec 18 08:13:51 volumio volumio[985]: info: Applying required configuration parameters for plugin audiophonicsonoff Dec 18 08:13:51 volumio volumio[985]: info: Audiophonics on/off initiated Dec 18 08:13:51 volumio volumio[985]: info: PLUGIN START: audiophonicsonoff Dec 18 08:13:51 volumio volumio[985]: info: Configuring GPIO pins Dec 18 08:13:51 volumio volumio[985]: info: Soft shutdown GPIO 540 binding... OK Dec 18 08:13:51 volumio volumio[985]: info: Hardware button GPIO 553 binding... OK Dec 18 08:13:51 volumio volumio[985]: info: Boot OK GPIO 558 binding... OK Dec 18 08:13:51 volumio volumio[985]: info: Done. Dec 18 08:13:51 volumio volumio[985]: info: ___________ PLUGINS: Run Shutdown Tasks ___________ Dec 18 08:13:51 volumio volumio[985]: info: PLUGIN onShutdown : networkfs Dec 18 08:13:51 volumio volumio[985]: info: PLUGIN onShutdown : audiophonicsonoff Dec 18 08:13:52 volumio volumio[985]: info: performing onStop action Dec 18 08:13:52 volumio volumio[985]: info: Disabling plugin audiophonicsonoff Dec 18 08:13:52 volumio volumio[985]: info: Done. Dec 18 08:13:52 volumio volumio[985]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 08:13:52 volumio volumio[985]: Error: EBADF: bad file descriptor, write Dec 18 08:13:52 volumio volumio[985]: at Object.writeSync (fs.js:711:3) Dec 18 08:13:52 volumio volumio[985]: at Gpio.writeSync (/data/plugins/system_hardware/audiophonicsonoff/node_modules/onoff/onoff.js:243:8) Dec 18 08:13:52 volumio volumio[985]: at Timeout._onTimeout (/data/plugins/system_hardware/audiophonicsonoff/index.js:50:31) Dec 18 08:13:52 volumio volumio[985]: at listOnTimeout (internal/timers.js:554:17) Dec 18 08:13:52 volumio volumio[985]: at processTimers (internal/timers.js:497:7) { Dec 18 08:13:52 volumio volumio[985]: errno: -9, Dec 18 08:13:52 volumio volumio[985]: syscall: 'write', Dec 18 08:13:52 volumio volumio[985]: code: 'EBADF' Dec 18 08:13:52 volumio volumio[985]: } Dec 18 08:13:52 volumio volumio[985]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 08:13:53 volumio sudo[2139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-18 08:12 Dec 18 08:13:53 volumio sudo[2139]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"