-- 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"