Oct 03 12:17:33 volumiopi4 volumio[1296]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.21 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/27.0 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioGetState Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 03 12:17:33 volumiopi4 volumio[1296]: info: Listing playlists Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioGetVisibleSources Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioGetQueue Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CoreStateMachine::getQueue Oct 03 12:17:33 volumiopi4 volumio[1296]: info: CorePlayQueue::getQueue Oct 03 12:17:47 volumiopi4 shairport-sync[7064]: Oct 03 12:17:47 volumiopi4 shairport-sync[7063]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:17:47 volumiopi4 shairport-sync[7063]: Dload Upload Total Spent Left Speed Oct 03 12:17:47 volumiopi4 shairport-sync[7063]: [79B blob data] Oct 03 12:17:47 volumiopi4 shairport-sync[7064]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:17:47 volumiopi4 shairport-sync[7064]: Dload Upload Total Spent Left Speed Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Oct 03 12:17:47 volumiopi4 volumio[1296]: ---------------------------- Client requests AirplayActive Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:17:47 volumiopi4 shairport-sync[7064]: [79B blob data] Oct 03 12:17:47 volumiopi4 shairport-sync[7063]: [79B blob data] Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::stPlaybackTimer Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::updateTrackBlock Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrackBlock Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::serviceStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::serviceStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::stop Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Oct 03 12:17:47 volumiopi4 volumio[1296]: ---------------------------- MPD announces state update: player Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand stop took 13 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::getState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music41/v4/ab/4a/f5/ab4af555-0198-f465-6674-e2b33e42d7a8/source/600x600bb.jpg","name":"David Bowie - Seven Years in Tibet","title":"Seven Years in Tibet","artist":"80s80s David Bowie","album":"","streaming":true,"disableUiControls":true,"duration":"360","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: CURRENT POSITION 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::syncState stateService stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::syncState currentStatus stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: No code Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Oct 03 12:17:47 volumiopi4 volumio[1296]: ---------------------------- MPD announces state update: player Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::getState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Oct 03 12:17:47 volumiopi4 volumio[1296]: ---------------------------- MPD announces state update: player Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::getState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Oct 03 12:17:47 volumiopi4 volumio[1296]: ---------------------------- Client requests Start Airplay PlaybackRoutine Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Airplay playback start Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioStop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::stop Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 12:17:47 volumiopi4 shairport-sync[7063]: {"time":1790997467803,"response":"airplayActive Success"} Oct 03 12:17:47 volumiopi4 shairport-sync[7064]: [79B blob data] Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand status took 34 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand status took 16 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand status took 15 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseState Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseTrackInfo Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseTrackInfo Oct 03 12:17:47 volumiopi4 volumio[1296]: verbose: ControllerMpd::parseTrackInfo Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ControllerMpd::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ------------------------------ 59ms Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ------------------------------ 42ms Oct 03 12:17:47 volumiopi4 volumio[1296]: info: ------------------------------ 41ms Oct 03 12:17:47 volumiopi4 volumio[1296]: info: Updating volume from AirPlay: -20; 33% Oct 03 12:17:47 volumiopi4 volumio[1296]: info: VolumeController::SetAlsaVolume33 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrack 0 Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:47 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:48 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:49 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:51 volumiopi4 shairport-sync[7064]: {"time":1790997467858,"response":"startAirplayPlayback Success"} Oct 03 12:17:51 volumiopi4 shairport-sync[7075]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:17:51 volumiopi4 shairport-sync[7075]: Dload Upload Total Spent Left Speed Oct 03 12:17:51 volumiopi4 volumio[1296]: info: Oct 03 12:17:51 volumiopi4 volumio[1296]: ---------------------------- Client requests Stop Airplay Playback Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Oct 03 12:17:51 volumiopi4 volumio[1296]: info: Airplay playback stop Oct 03 12:17:51 volumiopi4 volumio[1296]: info: Airplay Playback Stopped, clearing state Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::resetVolumioState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::getcurrentVolume Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 12:17:51 volumiopi4 shairport-sync[7075]: [158B blob data] Oct 03 12:17:51 volumiopi4 volumio[1296]: info: VolumeController:: Volume=33 Mute =false Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::updateTrackBlock Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrackBlock Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 12:17:51 volumiopi4 volumio[1296]: info: VolumeController:: Volume=33 Mute =false Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:17:51 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:01 volumiopi4 shairport-sync[7075]: {"time":1790997471253,"response":"stopAirplayPlayback Success"} Oct 03 12:18:01 volumiopi4 shairport-sync[7097]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:18:01 volumiopi4 shairport-sync[7097]: Dload Upload Total Spent Left Speed Oct 03 12:18:01 volumiopi4 volumio[1296]: info: Oct 03 12:18:01 volumiopi4 volumio[1296]: ---------------------------- Client requests AirplayInactive Oct 03 12:18:01 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayInctive Oct 03 12:18:01 volumiopi4 shairport-sync[7097]: [158B blob data] Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:07 volumiopi4 shairport-sync[7097]: {"time":1790997481248,"response":"airplayInactive Success"} Oct 03 12:18:07 volumiopi4 shairport-sync[7117]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:18:07 volumiopi4 shairport-sync[7117]: Dload Upload Total Spent Left Speed Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Oct 03 12:18:07 volumiopi4 volumio[1296]: ---------------------------- Client requests Start Airplay PlaybackRoutine Oct 03 12:18:07 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Airplay playback start Oct 03 12:18:07 volumiopi4 shairport-sync[7117]: [79B blob data] Oct 03 12:18:07 volumiopi4 shairport-sync[7116]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:18:07 volumiopi4 shairport-sync[7116]: Dload Upload Total Spent Left Speed Oct 03 12:18:07 volumiopi4 shairport-sync[7116]: [79B blob data] Oct 03 12:18:07 volumiopi4 shairport-sync[7117]: [79B blob data] Oct 03 12:18:07 volumiopi4 volumio[1296]: info: Oct 03 12:18:07 volumiopi4 volumio[1296]: ---------------------------- Client requests AirplayActive Oct 03 12:18:07 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Oct 03 12:18:07 volumiopi4 shairport-sync[7117]: {"time":1790997487566,"response":"startAirplayPlayback Success"} Oct 03 12:18:07 volumiopi4 shairport-sync[7116]: [79B blob data] Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:08 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:09 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:10 volumiopi4 shairport-sync[7116]: {"time":1790997487575,"response":"airplayActive Success"} Oct 03 12:18:10 volumiopi4 shairport-sync[7124]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:18:10 volumiopi4 shairport-sync[7124]: Dload Upload Total Spent Left Speed Oct 03 12:18:10 volumiopi4 volumio[1296]: info: Oct 03 12:18:10 volumiopi4 volumio[1296]: ---------------------------- Client requests Stop Airplay Playback Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Oct 03 12:18:10 volumiopi4 volumio[1296]: info: Airplay playback stop Oct 03 12:18:10 volumiopi4 volumio[1296]: info: Airplay Playback Stopped, clearing state Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::resetVolumioState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::getcurrentVolume Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 12:18:10 volumiopi4 shairport-sync[7124]: [158B blob data] Oct 03 12:18:10 volumiopi4 volumio[1296]: info: VolumeController:: Volume=33 Mute =false Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::updateTrackBlock Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CorePlayQueue::getTrackBlock Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 12:18:10 volumiopi4 volumio[1296]: info: VolumeController:: Volume=33 Mute =false Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:10 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:11 volumiopi4 shairport-sync[7124]: {"time":1790997490280,"response":"stopAirplayPlayback Success"} Oct 03 12:18:11 volumiopi4 shairport-sync[7132]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 03 12:18:11 volumiopi4 shairport-sync[7132]: Dload Upload Total Spent Left Speed Oct 03 12:18:11 volumiopi4 volumio[1296]: info: Oct 03 12:18:11 volumiopi4 volumio[1296]: ---------------------------- Client requests Start Airplay PlaybackRoutine Oct 03 12:18:11 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Oct 03 12:18:11 volumiopi4 volumio[1296]: info: Airplay playback start Oct 03 12:18:11 volumiopi4 shairport-sync[7132]: [158B blob data] Oct 03 12:18:11 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:11 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:11 volumiopi4 volumio[1296]: info: Airplay started streaming, receiving metadatas Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:12 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::servicePushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:13 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:16 volumiopi4 volumio[1296]: info: Updating volume from AirPlay: -18.12; 40% Oct 03 12:18:16 volumiopi4 volumio[1296]: info: VolumeController::SetAlsaVolume40 Oct 03 12:18:16 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:16 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:16 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:17 volumiopi4 volumio[1296]: info: Updating volume from AirPlay: -16.25; 46% Oct 03 12:18:17 volumiopi4 volumio[1296]: info: VolumeController::SetAlsaVolume46 Oct 03 12:18:17 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:17 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:17 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:18 volumiopi4 volumio[1296]: info: Updating volume from AirPlay: -14.37; 52% Oct 03 12:18:18 volumiopi4 volumio[1296]: info: VolumeController::SetAlsaVolume52 Oct 03 12:18:18 volumiopi4 volumio[1296]: info: CoreStateMachine::pushState Oct 03 12:18:18 volumiopi4 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 12:18:18 volumiopi4 volumio[1296]: info: CoreCommandRouter::volumioPushState Oct 03 12:18:22 volumiopi4 volumio[1296]: info: [1790997502202] [80s80s] Pushing the next song state David Bowie - Seven Years in Tibet and getting next track. Oct 03 12:18:22 volumiopi4 volumio[1296]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 12:18:22 volumiopi4 volumio[1296]: TypeError: Cannot set properties of undefined (setting 'name') Oct 03 12:18:22 volumiopi4 volumio[1296]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Oct 03 12:18:22 volumiopi4 volumio[1296]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Oct 03 12:18:22 volumiopi4 volumio[1296]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Oct 03 12:18:22 volumiopi4 volumio[1296]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Oct 03 12:18:22 volumiopi4 volumio[1296]: at process.processImmediate (node:internal/timers:478:21) Oct 03 12:18:22 volumiopi4 volumio[1296]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 12:18:22 volumiopi4 sudo[7185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-03 12:17' Oct 03 12:18:22 volumiopi4 sudo[7185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"