-- Logs begin at Thu 2019-02-14 04:11:59 CST, end at Fri 2025-06-06 16:00:17 CDT. -- Jun 06 15:59:02 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 06 15:59:02 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 06 15:59:02 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 06 15:59:02 volumio volumio-remote-updater[609]: No test mode Jun 06 15:59:02 volumio volumio-remote-updater[609]: No alpha test mode Jun 06 15:59:02 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 06 15:59:03 volumio volumio[963]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 06 15:59:03 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::volumioGetBrowseSources Jun 06 15:59:04 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 06 15:59:05 volumio go-librespot[1165]: time="2025-06-06T15:59:05-05:00" level=trace msg="sent dealer ping" Jun 06 15:59:05 volumio go-librespot[1165]: time="2025-06-06T15:59:05-05:00" level=trace msg="received dealer pong" Jun 06 15:59:05 volumio volumio[963]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 06 15:59:05 volumio volumio[963]: info: Completed starting MyVolumio Plugin Jun 06 15:59:05 volumio volumio[963]: [Metrics] CommandRouter: 43s 117.63ms Jun 06 15:59:05 volumio volumio[963]: info: CoreCommandRouter::volumiosetStartupVolume Jun 06 15:59:05 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 06 15:59:05 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 06 15:59:05 volumio volumio[963]: info: CoreCommandRouter::Close All Modals sent Jun 06 15:59:05 volumio volumio[963]: info: CoreCommandRouter::Close All Modals sent Jun 06 15:59:05 volumio volumio[963]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jun 06 15:59:05 volumio volumio[963]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Jun 06 15:59:05 volumio volumio[963]: aplay: main:828: audio open error: No such device Jun 06 15:59:06 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 06 15:59:06 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 06 15:59:06 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Jun 06 15:59:06 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 06 15:59:12 volumio volumio[963]: info: BOOT COMPLETED Jun 06 15:59:16 volumio ntpd[783]: Soliciting pool server 23.142.248.8 Jun 06 15:59:16 volumio volumio[1221]: .............................................................................................................................................................................................................................................................................................++++ Jun 06 15:59:16 volumio volumio[1221]: e is 65537 (0x010001) Jun 06 15:59:17 volumio volumio[1221]: writing RSA key Jun 06 15:59:17 volumio ntpd[783]: Soliciting pool server 23.141.40.124 Jun 06 15:59:17 volumio ntpd[783]: Soliciting pool server 198.137.202.56 Jun 06 15:59:17 volumio ntpd[783]: Soliciting pool server 163.237.218.18 Jun 06 15:59:18 volumio ntpd[783]: Soliciting pool server 208.113.130.146 Jun 06 15:59:18 volumio ntpd[783]: Soliciting pool server 178.156.168.134 Jun 06 15:59:18 volumio ntpd[783]: Soliciting pool server 15.204.246.57 Jun 06 15:59:19 volumio ntpd[783]: Soliciting pool server 50.205.57.38 Jun 06 15:59:19 volumio ntpd[783]: Soliciting pool server 104.131.155.175 Jun 06 15:59:19 volumio ntpd[783]: Soliciting pool server 64.6.144.6 Jun 06 15:59:20 volumio ntpd[783]: Soliciting pool server 23.95.49.216 Jun 06 15:59:20 volumio ntpd[783]: Soliciting pool server 44.190.5.123 Jun 06 15:59:21 volumio ntpd[783]: Soliciting pool server 12.205.28.193 Jun 06 15:59:21 volumio ntpd[783]: Soliciting pool server 2600:4040:e0da:f000::cbb9:201a Jun 06 15:59:22 volumio ntpd[783]: Soliciting pool server 23.186.168.126 Jun 06 15:59:23 volumio ntpd[783]: Soliciting pool server 45.77.126.122 Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad20372f does not match aorg 0000000000.00000000 from server@178.156.168.134 xmt 0xebedd52d.6ea67000 Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad1c1184 does not match aorg 0000000000.00000000 from server@23.95.49.216 xmt 0xebedd52d.6f684c0c Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad1ef054 does not match aorg 0000000000.00000000 from server@104.131.155.175 xmt 0xebedd52d.708b8d7d Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad153f6d does not match aorg 0000000000.00000000 from server@44.190.5.123 xmt 0xebedd52d.70983a72 Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad226dba does not match aorg 0000000000.00000000 from server@198.137.202.56 xmt 0xebedd52d.70fa75b0 Jun 06 15:59:25 volumio ntpd[783]: receive: Unexpected origin timestamp 0xebedd52c.ad1d6060 does not match aorg 0000000000.00000000 from server@50.205.57.38 xmt 0xebedd52d.70b7efe5 Jun 06 15:59:25 volumio ntpd[783]: Soliciting pool server 143.42.229.154 Jun 06 15:59:26 volumio ntpd[783]: Soliciting pool server 45.84.199.136 Jun 06 15:59:27 volumio ntpd[783]: Soliciting pool server 23.186.168.128 Jun 06 15:59:36 volumio go-librespot[1165]: time="2025-06-06T15:59:36-05:00" level=trace msg="sent dealer ping" Jun 06 15:59:36 volumio go-librespot[1165]: time="2025-06-06T15:59:36-05:00" level=trace msg="received dealer pong" Jun 06 15:59:56 volumio volumio[963]: verbose: New Socket.io Connection to 192.168.1.10 from 192.168.1.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::volumioGetVisibleSources Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Jun 06 15:59:56 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 06 15:59:56 volumio volumio[963]: info: Received Get System Info Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 06 15:59:56 volumio volumio[963]: info: Discovery: Getting this device information Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Jun 06 15:59:56 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Jun 06 15:59:56 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Jun 06 15:59:56 volumio volumio[963]: info: Listing playlists Jun 06 15:59:56 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 06 15:59:59 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 06 15:59:59 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 06 16:00:06 volumio go-librespot[1165]: time="2025-06-06T16:00:06-05:00" level=trace msg="sent dealer ping" Jun 06 16:00:06 volumio go-librespot[1165]: time="2025-06-06T16:00:06-05:00" level=trace msg="received dealer pong" Jun 06 16:00:07 volumio volumio[963]: info: Starting Uninstall of plugin system_hardware - gpio-buttons Jun 06 16:00:07 volumio volumio[963]: info: Uninstalling plugin gpio-buttons Jun 06 16:00:07 volumio volumio[963]: info: Disabling plugin gpio-buttons Jun 06 16:00:07 volumio volumio[963]: info: Checking if uninstall.sh is present Jun 06 16:00:07 volumio volumio[963]: info: Executing uninstall.sh Jun 06 16:00:07 volumio sudo[1521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_hardware/gpio-buttons/uninstall.sh Jun 06 16:00:07 volumio sudo[1521]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 06 16:00:07 volumio sudo[1521]: pam_unix(sudo:session): session closed for user root Jun 06 16:00:07 volumio volumio[963]: info: Uninstall script completed Jun 06 16:00:07 volumio volumio[963]: info: Removing plugin gpio-buttons from configuration Jun 06 16:00:07 volumio volumio[963]: info: Successfully removed gpio-buttons configuration files Jun 06 16:00:07 volumio volumio[963]: info: Plugin folders cleanup Jun 06 16:00:07 volumio volumio[963]: info: Scanning into folder /volumio/app/plugins/ Jun 06 16:00:07 volumio volumio[963]: info: Scanning category audio_interface Jun 06 16:00:07 volumio volumio[963]: info: Scanning category miscellanea Jun 06 16:00:07 volumio volumio[963]: info: Scanning category music_service Jun 06 16:00:07 volumio volumio[963]: info: Scanning category plugins.json Jun 06 16:00:07 volumio volumio[963]: info: Scanning category system_controller Jun 06 16:00:07 volumio volumio[963]: info: Scanning category user_interface Jun 06 16:00:07 volumio volumio[963]: info: Scanning into folder /data/plugins/ Jun 06 16:00:07 volumio volumio[963]: info: Scanning category music_service Jun 06 16:00:07 volumio volumio[963]: info: Scanning category system_controller Jun 06 16:00:07 volumio volumio[963]: info: Scanning category system_hardware Jun 06 16:00:07 volumio volumio[963]: info: Cleaning folder for gpio-buttons Jun 06 16:00:08 volumio volumio[963]: info: Plugin folders cleanup completed Jun 06 16:00:08 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 06 16:00:08 volumio volumio[963]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.4","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Amplifier Switch","name":"ampswitch","category":"system_controller","version":"0.2.1","icon":"fa-power-off","isManuallyInstalled":false,"enabled":true,"active":true}] Jun 06 16:00:08 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 06 16:00:14 volumio volumio[963]: info: [ASDebug] Port: 24 Jun 06 16:00:14 volumio volumio[963]: info: [ASDebug] Inverted: false Jun 06 16:00:14 volumio volumio[963]: info: [ASDebug] Delay: 720 Jun 06 16:00:16 volumio volumio[963]: info: Starting Uninstall of plugin system_controller - ampswitch Jun 06 16:00:16 volumio volumio[963]: info: Uninstalling plugin ampswitch Jun 06 16:00:16 volumio volumio[963]: info: [ASDebug] Port: 24 Jun 06 16:00:16 volumio volumio[963]: info: [ASDebug] Inverted: false Jun 06 16:00:16 volumio volumio[963]: info: [ASDebug] Delay: 720 Jun 06 16:00:16 volumio volumio[963]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 06 16:00:16 volumio volumio[963]: Error: EBADF: bad file descriptor, close Jun 06 16:00:16 volumio volumio[963]: at Object.closeSync (fs.js:439:3) Jun 06 16:00:16 volumio volumio[963]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Jun 06 16:00:16 volumio volumio[963]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Jun 06 16:00:16 volumio volumio[963]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Jun 06 16:00:16 volumio volumio[963]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Jun 06 16:00:16 volumio volumio[963]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Jun 06 16:00:16 volumio volumio[963]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jun 06 16:00:16 volumio volumio[963]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Jun 06 16:00:16 volumio volumio[963]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22) Jun 06 16:00:16 volumio volumio[963]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45) Jun 06 16:00:16 volumio volumio[963]: at Socket.emit (events.js:315:20) Jun 06 16:00:16 volumio volumio[963]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 06 16:00:16 volumio volumio[963]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jun 06 16:00:16 volumio volumio[963]: errno: -9, Jun 06 16:00:16 volumio volumio[963]: syscall: 'close', Jun 06 16:00:16 volumio volumio[963]: code: 'EBADF' Jun 06 16:00:16 volumio volumio[963]: } Jun 06 16:00:16 volumio volumio[963]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 06 16:00:17 volumio sudo[1605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-06 15:59 Jun 06 16:00:17 volumio sudo[1605]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"