-- Logs begin at Sun 2025-04-27 15:28:12 UTC, end at Mon 2025-05-05 05:30:16 UTC. -- May 05 05:29:12 volumio volumio[934]: info: CoreCommandRouter::volumioGetVisibleSources May 05 05:29:12 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 05 05:29:12 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 05 05:29:12 volumio volumio[934]: info: CoreCommandRouter::volumioGetState May 05 05:29:12 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:12 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:12 volumio volumio[934]: info: Listing playlists May 05 05:29:14 volumio volumio[934]: info: CoreCommandRouter::volumioPause May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::pause May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::stPlaybackTimer May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::servicePause May 05 05:29:14 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:14 volumio volumio[934]: info: CoreCommandRouter::servicePause May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::pause May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::sendMpdCommand pause May 05 05:29:14 volumio volumio[934]: info: sending command... May 05 05:29:14 volumio volumio[934]: info: May 05 05:29:14 volumio volumio[934]: ---------------------------- MPD announces state update: player May 05 05:29:14 volumio volumio[934]: info: parsing response... May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::getState May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::sendMpdCommand status May 05 05:29:14 volumio volumio[934]: info: sending command... May 05 05:29:14 volumio volumio[934]: info: parsing response... May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::parseState May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::sendMpdCommand playlistinfo May 05 05:29:14 volumio volumio[934]: info: sending command... May 05 05:29:14 volumio volumio[934]: info: parsing response... May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::parseTrackInfo May 05 05:29:14 volumio volumio[934]: info: ControllerMpd::pushState May 05 05:29:14 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:14 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:14 volumio volumio[934]: info: STATE SERVICE {"status":"pause","position":0,"seek":233105,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"990 Kbps","isStreaming":false,"title":"闪亮的星","artist":"梁静茹","album":"闪亮的星","uri":"NAS/SharedMusics/梁静茹/闪亮的星/02 闪亮的星.flac","trackType":"flac"} May 05 05:29:14 volumio volumio[934]: info: CURRENT POSITION 1 May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::syncState stateService pause May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::syncState currentStatus pause May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:14 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:14 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:14 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:14 volumio volumio[934]: info: CoreStateMachine::stPlaybackTimer May 05 05:29:14 volumio volumio[934]: info: ------------------------------ 178ms May 05 05:29:30 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:30 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:30 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:31 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:31 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:31 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:31 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:31 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:31 volumio shairport-sync[1126]: Failed to create secure directory (/home/shairport-sync/.config/pulse): No such file or directory May 05 05:29:32 volumio kernel: bcm2835-i2s 20203000.i2s: I2S SYNC error! May 05 05:29:32 volumio volumio[934]: info: Airplay started streaming, receiving metadatas May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::volumioStop May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::stop May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:32 volumio volumio[934]: UNSET VOLATILE May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::updateTrackBlock May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrackBlock May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::stPlaybackTimer May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::serviceStop May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::serviceStop May 05 05:29:32 volumio volumio[934]: info: ControllerMpd::stop May 05 05:29:32 volumio volumio[934]: info: ControllerMpd::sendMpdCommand stop May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:32 volumio volumio[934]: info: Airplay started streaming, receiving metadatas May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::volumioStop May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::stop May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:32 volumio volumio[934]: UNSET VOLATILE May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:32 volumio volumio[934]: info: sending command... May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio shairport-sync[1126]: % Total % Received % Xferd Average Speed Time Time Time Current May 05 05:29:32 volumio shairport-sync[1126]: Dload Upload Total Spent Left Speed May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio shairport-sync[1126]: 0 0 0 0 0 0 % Total % Received % Xferd 0 0 --:--:-- --:--:-- --:--:-- 0 Average Speed Time Time Time Current May 05 05:29:32 volumio shairport-sync[1126]: Dload Upload Total Spent Left Speed May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:32 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:32 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:32 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:32 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received airplay_emulation May 05 05:29:33 volumio volumio[934]: info: May 05 05:29:33 volumio volumio[934]: ---------------------------- MPD announces state update: player May 05 05:29:33 volumio volumio[934]: info: parsing response... May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::getState May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::sendMpdCommand status May 05 05:29:33 volumio volumio[934]: info: sending command... May 05 05:29:33 volumio volumio[934]: info: parsing response... May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::parseState May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::sendMpdCommand playlistinfo May 05 05:29:33 volumio volumio[934]: info: sending command... May 05 05:29:33 volumio volumio[934]: info: parsing response... May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::parseTrackInfo May 05 05:29:33 volumio volumio[934]: info: ControllerMpd::pushState May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"闪亮的星","artist":"梁静茹","album":"闪亮的星","uri":"NAS/SharedMusics/梁静茹/闪亮的星/02 闪亮的星.flac","trackType":"flac"} May 05 05:29:33 volumio volumio[934]: info: CURRENT POSITION 1 May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState stateService stop May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState currentStatus stop May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:33 volumio volumio[934]: info: No code May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:33 volumio volumio[934]: info: ------------------------------ 749ms May 05 05:29:33 volumio volumio[934]: info: May 05 05:29:33 volumio volumio[934]: ---------------------------- Client requests Start Airplay PlaybackRoutine May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback May 05 05:29:33 volumio volumio[934]: info: Airplay playback start May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:33 volumio volumio[934]: info: CorePlayQueue::getTrack 1 May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::volumioStop May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::stop May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:33 volumio volumio[934]: UNSET VOLATILE May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 05:29:33 volumio shairport-sync[1126]: [392B blob data] May 05 05:29:33 volumio volumio[934]: info: May 05 05:29:33 volumio volumio[934]: ---------------------------- Client requests AirplayActive May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive May 05 05:29:33 volumio shairport-sync[1126]: [222B blob data] May 05 05:29:33 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:33 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::servicePushState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::syncState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::pushState May 05 05:29:34 volumio volumio[934]: info: CoreStateMachine::getState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::volumioPushState May 05 05:29:34 volumio volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 05:30:08 volumio volumio[934]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 05:30:08 volumio volumio[934]: { Error: connect ETIMEDOUT 23.101.24.70:443 May 05 05:30:08 volumio volumio[934]: at Object._errnoException (util.js:1022:11) May 05 05:30:08 volumio volumio[934]: at _exceptionWithHostPort (util.js:1044:20) May 05 05:30:08 volumio volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) May 05 05:30:08 volumio volumio[934]: code: 'ETIMEDOUT', May 05 05:30:08 volumio volumio[934]: errno: 'ETIMEDOUT', May 05 05:30:08 volumio volumio[934]: syscall: 'connect', May 05 05:30:08 volumio volumio[934]: address: '23.101.24.70', May 05 05:30:08 volumio volumio[934]: port: 443 } May 05 05:30:08 volumio volumio[934]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 05:30:16 volumio sudo[4134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-05 05:29 May 05 05:30:16 volumio sudo[4134]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="ac2a0afddd424ea15d982b8c75eeec3a8648a313" VOLUMIO_FE_VERSION="700492006632ef61a5a17e6a3be4f37c790f883c" VOLUMIO_BE_VERSION="b2e85b2e8facd2d741f2fc40be426a34804b56fc" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue May 5 18:38:33 CEST 2020" VOLUMIO_VERSION="2.773" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="9e13d1d50d1f834c8c0294a226468074"