-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Thu 2025-04-24 13:07:39 CST. -- Apr 24 13:06:01 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 24 13:06:01 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 24 13:06:01 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 13:06:02 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 24 13:06:03 primo volumio[16863]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 24 13:06:03 primo volumio[16863]: info: Completed starting MyVolumio Plugin Apr 24 13:06:03 primo volumio[16863]: [Metrics] CommandRouter: 36s 616.36ms Apr 24 13:06:03 primo volumio[16863]: info: CoreCommandRouter::volumiosetStartupVolume Apr 24 13:06:03 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 24 13:06:03 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 24 13:06:03 primo volumio[16863]: info: CoreCommandRouter::Close All Modals sent Apr 24 13:06:03 primo volumio[16863]: info: CoreCommandRouter::Close All Modals sent Apr 24 13:06:03 primo volumio[16863]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Apr 24 13:06:03 primo volumio[16863]: aplay: main:828: audio open error: Device or resource busy Apr 24 13:06:04 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 24 13:06:04 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 24 13:06:04 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 24 13:06:10 primo volumio[16863]: info: BOOT COMPLETED Apr 24 13:06:14 primo volumio-remote-updater[583]: No test mode Apr 24 13:06:14 primo volumio-remote-updater[583]: No alpha test mode Apr 24 13:06:14 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 24 13:06:15 primo volumio[16863]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 24 13:06:15 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 24 13:07:23 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:23 primo volumio[16863]: info: CorePlayQueue::getTrack 1 Apr 24 13:07:29 primo volumio[16863]: info: Apr 24 13:07:29 primo volumio[16863]: ---------------------------- MPD announces state update: player Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::getState Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::sendMpdCommand status Apr 24 13:07:29 primo volumio[16863]: info: sendMpdCommand status took 1 milliseconds Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::parseState Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::pushState Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::servicePushState Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: 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} Apr 24 13:07:29 primo volumio[16863]: verbose: CURRENT POSITION 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState stateService stop Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::stPlaybackTimer Apr 24 13:07:29 primo volumio[16863]: info: ------------------------------ 21ms Apr 24 13:07:29 primo volumio[16863]: info: Apr 24 13:07:29 primo volumio[16863]: ---------------------------- MPD announces state update: player Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::getState Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::sendMpdCommand status Apr 24 13:07:29 primo volumio[16863]: info: Apr 24 13:07:29 primo volumio[16863]: ---------------------------- MPD announces state update: player Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::getState Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::sendMpdCommand status Apr 24 13:07:29 primo volumio[16863]: info: sendMpdCommand status took 3 milliseconds Apr 24 13:07:29 primo volumio[16863]: info: sendMpdCommand status took 1 milliseconds Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::parseState Apr 24 13:07:29 primo volumio[16863]: verbose: ControllerMpd::parseState Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::pushState Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::servicePushState Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: 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} Apr 24 13:07:29 primo volumio[16863]: verbose: CURRENT POSITION 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState stateService stop Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState currentStatus stop Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: No code Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: ControllerMpd::pushState Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::servicePushState Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: 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} Apr 24 13:07:29 primo volumio[16863]: verbose: CURRENT POSITION 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState stateService stop Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::syncState currentStatus stop Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: No code Apr 24 13:07:29 primo volumio[16863]: info: CoreStateMachine::pushState Apr 24 13:07:29 primo volumio[16863]: info: CorePlayQueue::getTrack 0 Apr 24 13:07:29 primo volumio[16863]: info: CoreCommandRouter::volumioPushState Apr 24 13:07:29 primo volumio[16863]: info: ------------------------------ 60ms Apr 24 13:07:29 primo volumio[16863]: info: ------------------------------ 59ms Apr 24 13:07:39 primo volumio[16863]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 13:07:39 primo volumio[16863]: Error: connect ETIMEDOUT 69.171.229.73:443 Apr 24 13:07:39 primo volumio[16863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Apr 24 13:07:39 primo volumio[16863]: errno: -110, Apr 24 13:07:39 primo volumio[16863]: code: 'ETIMEDOUT', Apr 24 13:07:39 primo volumio[16863]: syscall: 'connect', Apr 24 13:07:39 primo volumio[16863]: address: '69.171.229.73', Apr 24 13:07:39 primo volumio[16863]: port: 443 Apr 24 13:07:39 primo volumio[16863]: } Apr 24 13:07:39 primo volumio[16863]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 13:07:39 primo sudo[17493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-24 13:06 Apr 24 13:07:39 primo sudo[17493]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:14:40 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="a9bbde8819c9c7e405795a261e2a2f93"