-- Logs begin at Mon 2025-09-15 02:15:30 HKT, end at Tue 2025-09-16 16:13:08 HKT. -- Sep 16 16:12:01 volumiosisa volumio[710]: info: MyVolumio login type: Token Sep 16 16:12:05 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:15 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:15 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:12:15 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::ClearQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::stop Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::stPlaybackTimer Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::updateTrackBlock Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrackBlock Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::pushState Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushState Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::serviceStop Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::serviceStop Sep 16 16:12:21 volumiosisa volumio[710]: info: [1758010341441] ControllerWebradio::stop Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand stop Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::clearPlayQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::saveQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::addQueueItems Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::addQueueItems Sep 16 16:12:21 volumiosisa volumio[710]: info: Preload queue cleared Sep 16 16:12:21 volumiosisa volumio[710]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1871329 Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::saveQueue Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::updateTrackBlock Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrackBlock Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPlay Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::play index 0 Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::stop Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::play index undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::startPlaybackTimer Sep 16 16:12:21 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:21 volumiosisa volumio[710]: info: [1758010341525] ControllerWebradio::clearAddPlayTrack Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand stop Sep 16 16:12:21 volumiosisa volumio[710]: info: Sep 16 16:12:21 volumiosisa volumio[710]: ---------------------------- MPD announces state update: player Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand stop took 109 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: info: ControllerMpd::getState Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand status Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand stop took 32 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand clear Sep 16 16:12:21 volumiosisa volumio[710]: info: Sep 16 16:12:21 volumiosisa volumio[710]: ---------------------------- MPD announces system playlist update Sep 16 16:12:21 volumiosisa volumio[710]: info: Ignoring MPD Status Update Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand status took 20 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand clear took 16 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::parseState Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1871329" Sep 16 16:12:21 volumiosisa volumio[710]: error: updateQueue error: null Sep 16 16:12:21 volumiosisa volumio[710]: info: ------------------------------ 29ms Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand playlistinfo took 17 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::parseTrackInfo Sep 16 16:12:21 volumiosisa volumio[710]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 16 16:12:21 volumiosisa volumio[710]: info: ------------------------------ 67ms Sep 16 16:12:21 volumiosisa volumio[710]: info: Sep 16 16:12:21 volumiosisa volumio[710]: ---------------------------- MPD announces system playlist update Sep 16 16:12:21 volumiosisa volumio[710]: info: Ignoring MPD Status Update Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1871329" took 295 milliseconds Sep 16 16:12:21 volumiosisa volumio[710]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 16 16:12:21 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand play Sep 16 16:12:21 volumiosisa volumio[710]: info: ------------------------------ 28ms Sep 16 16:12:21 volumiosisa volumio[710]: info: sendMpdCommand play took 21 milliseconds Sep 16 16:12:22 volumiosisa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Sep 16 16:12:22 volumiosisa volumio[710]: info: Sep 16 16:12:22 volumiosisa volumio[710]: ---------------------------- MPD announces state update: player Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::getState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand status Sep 16 16:12:22 volumiosisa volumio[710]: info: Sep 16 16:12:22 volumiosisa volumio[710]: ---------------------------- MPD announces state update: player Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand status took 22 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::getState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand status Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand status took 17 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand playlistinfo took 19 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseTrackInfo Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::servicePushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:22 volumiosisa volumio[710]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3.223.187.189:8005","artist":"(#1 - 2/1000) Radio Amadeus en Vivo","album":null,"uri":"http://3.223.187.189:8005","trackType":"189:8005"} Sep 16 16:12:22 volumiosisa volumio[710]: verbose: CURRENT POSITION 0 Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState stateService play Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState currentStatus stop Sep 16 16:12:22 volumiosisa volumio[710]: info: ------------------------------ 89ms Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand playlistinfo took 37 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseTrackInfo Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::servicePushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:22 volumiosisa volumio[710]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3.223.187.189:8005","artist":"(#1 - 2/1000) Radio Amadeus en Vivo","album":null,"uri":"http://3.223.187.189:8005","trackType":"189:8005"} Sep 16 16:12:22 volumiosisa volumio[710]: verbose: CURRENT POSITION 0 Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState stateService play Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState currentStatus play Sep 16 16:12:22 volumiosisa volumio[710]: info: Received an update from plugin. extracting info from payload Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushState Sep 16 16:12:22 volumiosisa volumio[710]: info: ------------------------------ 181ms Sep 16 16:12:22 volumiosisa volumio[710]: info: Sep 16 16:12:22 volumiosisa volumio[710]: ---------------------------- MPD announces system playlist update Sep 16 16:12:22 volumiosisa volumio[710]: info: Ignoring MPD Status Update Sep 16 16:12:22 volumiosisa volumio[710]: info: Sep 16 16:12:22 volumiosisa volumio[710]: ---------------------------- MPD announces state update: player Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::getState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand status Sep 16 16:12:22 volumiosisa volumio[710]: info: ------------------------------ 33ms Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand status took 8 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseState Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 16 16:12:22 volumiosisa volumio[710]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 16 16:12:22 volumiosisa volumio[710]: verbose: ControllerMpd::parseTrackInfo Sep 16 16:12:22 volumiosisa volumio[710]: info: ControllerMpd::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::servicePushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:22 volumiosisa volumio[710]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"40 Kbps","isStreaming":false,"title":"3.223.187.189:8005","artist":"Radio Amadeus en Vivo","album":null,"uri":"http://3.223.187.189:8005","trackType":"189:8005"} Sep 16 16:12:22 volumiosisa volumio[710]: verbose: CURRENT POSITION 0 Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState stateService play Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::syncState currentStatus play Sep 16 16:12:22 volumiosisa volumio[710]: info: Received an update from plugin. extracting info from payload Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CorePlayQueue::getTrack 0 Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreStateMachine::pushState Sep 16 16:12:22 volumiosisa volumio[710]: info: CoreCommandRouter::volumioPushState Sep 16 16:12:22 volumiosisa volumio[710]: info: ------------------------------ 111ms Sep 16 16:12:25 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:31 volumiosisa volumio[710]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Sep 16 16:12:32 volumiosisa volumio[710]: info: Retrying Login Due to Network Error Sep 16 16:12:35 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:35 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:12:35 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:12:42 volumiosisa volumio[710]: info: MyVolumio login type: Token Sep 16 16:12:45 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:47 volumiosisa irexec[1049]: [47.9K blob data] Sep 16 16:12:55 volumiosisa volumio[710]: info: CoreCommandRouter::volumioGetState Sep 16 16:12:55 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:12:55 volumiosisa volumio[710]: info: Listing playlists Sep 16 16:13:05 volumiosisa volumio[710]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 16 16:13:05 volumiosisa volumio[710]: Error: connect ETIMEDOUT 157.240.17.14:80 Sep 16 16:13:05 volumiosisa volumio[710]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Sep 16 16:13:05 volumiosisa volumio[710]: errno: -110, Sep 16 16:13:05 volumiosisa volumio[710]: code: 'ETIMEDOUT', Sep 16 16:13:05 volumiosisa volumio[710]: syscall: 'connect', Sep 16 16:13:05 volumiosisa volumio[710]: address: '157.240.17.14', Sep 16 16:13:05 volumiosisa volumio[710]: port: 80 Sep 16 16:13:05 volumiosisa volumio[710]: } Sep 16 16:13:05 volumiosisa volumio[710]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 16 16:13:08 volumiosisa sudo[18335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-16 16:12 Sep 16 16:13:08 volumiosisa sudo[18335]: 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="b1c3cf61c2a0027c66bab1eb0a3795f80c1f2e95" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e3eb3ee5b16063502f3a1735e11a28cfe54a0f46" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 25 Jun 2023 07:20:58 PM CEST" VOLUMIO_VERSION="3.512" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="946a42b62509f37b5e7e2d86a2932a62"