-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2025-10-25 17:20:36 CEST. -- Oct 25 17:19:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 25 17:19:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 25 17:19:09 volumio-1 volumio[1089]: info: Discovery: Getting this device information Oct 25 17:19:09 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 25 17:19:09 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 12 Oct 25 17:19:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 25 17:19:26 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 12 Oct 25 17:19:26 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:26 volumio-1 volumio[1089]: info: Prefetching next song Oct 25 17:19:26 volumio-1 volumio[1089]: info: DOING PREFETCH IN MPD Oct 25 17:19:26 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand add "USB/512GB-Flac/Schiller/Greatest Hits/14. Sommernacht.flac" Oct 25 17:19:26 volumio-1 volumio[1089]: info: Oct 25 17:19:26 volumio-1 volumio[1089]: ---------------------------- MPD announces system playlist update Oct 25 17:19:26 volumio-1 volumio[1089]: info: Ignoring MPD Status Update Oct 25 17:19:26 volumio-1 volumio[1089]: info: sendMpdCommand add "USB/512GB-Flac/Schiller/Greatest Hits/14. Sommernacht.flac" took 1 milliseconds Oct 25 17:19:26 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 25 17:19:26 volumio-1 volumio[1089]: info: ------------------------------ 1ms Oct 25 17:19:26 volumio-1 volumio[1089]: info: sendMpdCommand consume 1 took 1 milliseconds Oct 25 17:19:29 volumio-1 kernel: hwmon hwmon3: Undervoltage detected! Oct 25 17:19:30 volumio-1 volumio[1089]: info: CoreStateMachine::startPlaybackTimer Oct 25 17:19:30 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: Oct 25 17:19:31 volumio-1 volumio[1089]: ---------------------------- MPD announces system playlist update Oct 25 17:19:31 volumio-1 volumio[1089]: info: Ignoring MPD Status Update Oct 25 17:19:31 volumio-1 volumio[1089]: info: Oct 25 17:19:31 volumio-1 volumio[1089]: ---------------------------- MPD announces state update: player Oct 25 17:19:31 volumio-1 volumio[1089]: info: ControllerMpd::getState Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand status Oct 25 17:19:31 volumio-1 volumio[1089]: info: Oct 25 17:19:31 volumio-1 volumio[1089]: ---------------------------- MPD announces state update: player Oct 25 17:19:31 volumio-1 volumio[1089]: info: ControllerMpd::getState Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand status Oct 25 17:19:31 volumio-1 volumio[1089]: info: ------------------------------ 2ms Oct 25 17:19:31 volumio-1 volumio[1089]: info: sendMpdCommand status took 2 milliseconds Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::parseState Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 17:19:31 volumio-1 volumio[1089]: info: sendMpdCommand status took 2 milliseconds Oct 25 17:19:31 volumio-1 volumio[1089]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::parseState Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::parseTrackInfo Oct 25 17:19:31 volumio-1 volumio[1089]: info: ControllerMpd::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":285,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"371 Kbps","isStreaming":false,"title":"Sommernacht","artist":"Schiller","album":"Greatest Hits","uri":"USB/512GB-Flac/Schiller/Greatest Hits/14. Sommernacht.flac","trackType":"flac"} Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: CURRENT POSITION 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::syncState stateService play Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::syncState currentStatus play Oct 25 17:19:31 volumio-1 volumio[1089]: info: Received an update from plugin. extracting info from payload Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output Oct 25 17:19:31 volumio-1 volumio[1089]: info: ------------------------------ 38ms Oct 25 17:19:31 volumio-1 volumio[1089]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: ControllerMpd::parseTrackInfo Oct 25 17:19:31 volumio-1 volumio[1089]: info: ControllerMpd::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":285,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"371 Kbps","isStreaming":false,"title":"Sommernacht","artist":"Schiller","album":"Greatest Hits","uri":"USB/512GB-Flac/Schiller/Greatest Hits/14. Sommernacht.flac","trackType":"flac"} Oct 25 17:19:31 volumio-1 volumio[1089]: verbose: CURRENT POSITION 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::syncState stateService play Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::syncState currentStatus play Oct 25 17:19:31 volumio-1 volumio[1089]: info: Received an update from plugin. extracting info from payload Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output Oct 25 17:19:31 volumio-1 volumio[1089]: info: ------------------------------ 61ms Oct 25 17:19:31 volumio-1 volumio[1089]: info: [ASDebug] CurState: play PrevState: play Oct 25 17:19:31 volumio-1 volumio[1089]: info: [ASDebug] CurState: play PrevState: play Oct 25 17:19:31 volumio-1 volumio[1089]: info: [ASDebug] CurState: play PrevState: play Oct 25 17:19:31 volumio-1 volumio[1089]: info: [ASDebug] CurState: play PrevState: play Oct 25 17:19:31 volumio-1 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 25 17:19:31 volumio-1 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 25 17:19:31 volumio-1 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 25 17:19:31 volumio-1 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreStateMachine::pushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 17:19:31 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Oct 25 17:19:31 volumio-1 volumio[1089]: info: MRS: Pushing multiroomSync output Oct 25 17:19:31 volumio-1 volumio[1089]: info: [ASDebug] CurState: play PrevState: play Oct 25 17:19:31 volumio-1 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 25 17:19:33 volumio-1 volumio[1089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 14 Oct 25 17:19:33 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 25 17:19:33 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:35 volumio-1 kernel: hwmon hwmon3: Voltage normalised Oct 25 17:19:39 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 25 17:19:39 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 25 17:19:39 volumio-1 volumio[1089]: info: Discovery: Getting this device information Oct 25 17:19:39 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 25 17:19:39 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:19:39 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 25 17:20:03 volumio-1 kernel: hwmon hwmon3: Undervoltage detected! Oct 25 17:20:06 volumio-1 kernel: hwmon hwmon3: Voltage normalised Oct 25 17:20:07 volumio-1 volumio[1089]: info: MRS: Updating multiroomSync output Oct 25 17:20:08 volumio-1 volumio[1089]: info: MRS: Updating multiroomSync output Oct 25 17:20:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 25 17:20:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 25 17:20:09 volumio-1 volumio[1089]: info: Discovery: Getting this device information Oct 25 17:20:09 volumio-1 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 25 17:20:09 volumio-1 volumio[1089]: info: CorePlayQueue::getTrack 13 Oct 25 17:20:09 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 25 17:20:13 volumio-1 volumio[1089]: info: Starting Uninstall of plugin system_controller - ampswitch Oct 25 17:20:13 volumio-1 volumio[1089]: info: Uninstalling plugin ampswitch Oct 25 17:20:13 volumio-1 volumio[1089]: info: [ASDebug] Port: 24 Oct 25 17:20:13 volumio-1 volumio[1089]: info: [ASDebug] Inverted: false Oct 25 17:20:13 volumio-1 volumio[1089]: info: [ASDebug] Delay: 720 Oct 25 17:20:22 volumio-1 kernel: hwmon hwmon3: Undervoltage detected! Oct 25 17:20:24 volumio-1 kernel: hwmon hwmon3: Voltage normalised Oct 25 17:20:25 volumio-1 volumio[1089]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] Setting UI defaults Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] Port: 24 Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] Inverted: false Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] Latched: false Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] On pulse width: 500 Oct 25 17:20:25 volumio-1 volumio[1089]: info: [ASDebug] Off pulse width: 500 Oct 25 17:20:30 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 25 17:20:30 volumio-1 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 25 17:20:36 volumio-1 volumio[1089]: info: Starting Uninstall of plugin system_controller - ampswitch Oct 25 17:20:36 volumio-1 volumio[1089]: info: Uninstalling plugin ampswitch Oct 25 17:20:36 volumio-1 volumio[1089]: info: [ASDebug] Port: 24 Oct 25 17:20:36 volumio-1 volumio[1089]: info: [ASDebug] Inverted: false Oct 25 17:20:36 volumio-1 volumio[1089]: info: [ASDebug] Delay: 720 Oct 25 17:20:36 volumio-1 volumio[1089]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 17:20:36 volumio-1 volumio[1089]: Error: EBADF: bad file descriptor, close Oct 25 17:20:36 volumio-1 volumio[1089]: at Object.closeSync (fs.js:439:3) Oct 25 17:20:36 volumio-1 volumio[1089]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Oct 25 17:20:36 volumio-1 volumio[1089]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Oct 25 17:20:36 volumio-1 volumio[1089]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Oct 25 17:20:36 volumio-1 volumio[1089]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Oct 25 17:20:36 volumio-1 volumio[1089]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Oct 25 17:20:36 volumio-1 volumio[1089]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Oct 25 17:20:36 volumio-1 volumio[1089]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Oct 25 17:20:36 volumio-1 volumio[1089]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1465:22) Oct 25 17:20:36 volumio-1 volumio[1089]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1242:45) Oct 25 17:20:36 volumio-1 volumio[1089]: at Socket.emit (events.js:315:20) Oct 25 17:20:36 volumio-1 volumio[1089]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 25 17:20:36 volumio-1 volumio[1089]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Oct 25 17:20:36 volumio-1 volumio[1089]: errno: -9, Oct 25 17:20:36 volumio-1 volumio[1089]: syscall: 'close', Oct 25 17:20:36 volumio-1 volumio[1089]: code: 'EBADF' Oct 25 17:20:36 volumio-1 volumio[1089]: } Oct 25 17:20:36 volumio-1 volumio[1089]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 17:20:36 volumio-1 sudo[5002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-25 17:19 Oct 25 17:20:36 volumio-1 sudo[5002]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="905ee02fb5387537cfa16b84ebd7f14b7640848e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 04 Jul 2024 02:29:26 AM CEST" VOLUMIO_VERSION="3.735" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="c3549df9b4fb845b268fd7accf565d01"