-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Tue 2024-08-27 19:50:34 CST. -- Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioNext Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::next Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::stop Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::updateTrackBlock Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrackBlock Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::stPlaybackTimer Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 2 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::serviceStop Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 2 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::serviceStop Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::stop Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand stop took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::play index undefined Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::startPlaybackTimer Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::clearAddPlayTracks USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3 Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::updateTrackBlock Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrackBlock Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 10 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand stop took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 5 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 2 milliseconds Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand clear Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand clear took 3 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand add "USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3" Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: 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":"In Your Corner","artist":"Ella Vos","album":"In Your Corner","uri":"USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Ella Vos - In Your Corner.mp3","trackType":"mp3"} Aug 27 19:49:04 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: No code Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 27 19:49:04 volumio volumio[753]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 44ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 38ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 38ms Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 34ms Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand add "USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3" took 31 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 6ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 4ms Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand play Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces system playlist update Aug 27 19:49:04 volumio volumio[753]: info: Ignoring MPD Status Update Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 20ms Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand play took 18 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 18ms Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 13ms Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: Aug 27 19:49:04 volumio volumio[753]: ---------------------------- MPD announces state update: player Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 7 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 8 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand status took 2 milliseconds Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: verbose: ControllerMpd::parseTrackInfo Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":273,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Hurricane","artist":"Kayleigh O'Connor","album":"Kayleigh O'Connor","uri":"USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3","trackType":"mp3"} Aug 27 19:49:04 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState stateService play Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":273,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Hurricane","artist":"Kayleigh O'Connor","album":"Kayleigh O'Connor","uri":"USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3","trackType":"mp3"} Aug 27 19:49:04 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState stateService play Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus play Aug 27 19:49:04 volumio volumio[753]: info: Received an update from plugin. extracting info from payload Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":273,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Hurricane","artist":"Kayleigh O'Connor","album":"Kayleigh O'Connor","uri":"USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3","trackType":"mp3"} Aug 27 19:49:04 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState stateService play Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus play Aug 27 19:49:04 volumio volumio[753]: info: Received an update from plugin. extracting info from payload Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":273,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Hurricane","artist":"Kayleigh O'Connor","album":"Kayleigh O'Connor","uri":"USB/43CC-F0A2/{ 空灵女声 }好听到完全窒息/Kayleigh O'Connor - Hurricane.mp3","trackType":"mp3"} Aug 27 19:49:04 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState stateService play Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus play Aug 27 19:49:04 volumio volumio[753]: info: Received an update from plugin. extracting info from payload Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 34ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 62ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 59ms Aug 27 19:49:04 volumio volumio[753]: info: ------------------------------ 56ms Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:49:04 volumio volumio[753]: info: Discovery: Getting this device information Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:49:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 19:49:09 volumio volumio[753]: info: Getting Alsa Cards List without I2S DAC Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 27 19:49:09 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:49:19 volumio volumio[753]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: Restoring Previous Volume level: 100 false true Aug 27 19:49:19 volumio volumio[753]: info: VolumeController::SetAlsaVolume100 Aug 27 19:49:19 volumio volumio[753]: info: Enable softmixer device for audio device number 2 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioStop Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::stop Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::stPlaybackTimer Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::updateTrackBlock Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrackBlock Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::serviceStop Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::serviceStop Aug 27 19:49:19 volumio volumio[753]: info: ControllerMpd::stop Aug 27 19:49:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 19:49:19 volumio volumio[753]: info: Enable softmixer device for audio device undefined Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 27 19:49:19 volumio volumio[753]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 27 19:49:19 volumio volumio[753]: info: Disabling external Volume Control Aug 27 19:49:19 volumio volumio[753]: info: Output device has changed, restarting MPD Aug 27 19:49:19 volumio sudo[2431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 19:49:19 volumio sudo[2431]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio volumio[753]: info: Output device has changed, restarting Shairport Sync Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:19 volumio sudo[2431]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:19 volumio sudo[2434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 19:49:19 volumio sudo[2434]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio systemd[1]: Stopping Music Player Daemon... Aug 27 19:49:19 volumio volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 19:49:19 volumio volumio[753]: info: Volume configurations have been set Aug 27 19:49:19 volumio systemd[1]: mpd.service: Succeeded. Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 27 19:49:19 volumio volumio[753]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 27 19:49:19 volumio volumio[753]: info: Disabling external Volume Control Aug 27 19:49:19 volumio systemd[1]: Stopped Music Player Daemon. Aug 27 19:49:19 volumio systemd[1]: Starting Music Player Daemon... Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:19 volumio volumio[753]: error: MPD error: Error: write EPIPE Aug 27 19:49:19 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:19 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:19 volumio volumio[753]: info: MPD Permissions set Aug 27 19:49:19 volumio volumio[753]: info: Software Volume ALSA configuration written Aug 27 19:49:19 volumio volumio[753]: info: Preparing to generate the ALSA configuration file Aug 27 19:49:19 volumio volumio[753]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 27 19:49:19 volumio volumio[753]: info: Reading ALSA contributions from plugins. Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 19:49:19 volumio volumio[753]: info: Getting Alsa Cards List without I2S DAC Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:49:19 volumio volumio[753]: info: Starting Shairport Sync Aug 27 19:49:19 volumio volumio[753]: info: Asound.conf file written Aug 27 19:49:19 volumio sudo[2463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 19:49:19 volumio sudo[2463]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 27 19:49:19 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 27 19:49:19 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:19 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:19 volumio sudo[2466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 27 19:49:19 volumio sudo[2466]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio sudo[2463]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:19 volumio sudo[2466]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:19 volumio volumio[753]: No state is present for card b1 Aug 27 19:49:19 volumio volumio[753]: No state is present for card Headphones Aug 27 19:49:19 volumio volumio[753]: No state is present for card sndrpihifiberry Aug 27 19:49:19 volumio volumio[753]: Found hardware: "RPi-simple" "" "" "" "" Aug 27 19:49:19 volumio volumio[753]: Hardware is initialized using a generic method Aug 27 19:49:19 volumio volumio[753]: No state is present for card sndrpihifiberry Aug 27 19:49:19 volumio volumio[753]: info: Output device has changed, restarting MPD Aug 27 19:49:19 volumio sudo[2474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 19:49:19 volumio sudo[2474]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio volumio[753]: info: Output device has changed, restarting Shairport Sync Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:19 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:19 volumio sudo[2474]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:19 volumio sudo[2476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 19:49:19 volumio sudo[2476]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:19 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 27 19:49:19 volumio systemd[1]: mpd.service: Succeeded. Aug 27 19:49:19 volumio systemd[1]: Stopped Music Player Daemon. Aug 27 19:49:19 volumio systemd[1]: Starting Music Player Daemon... Aug 27 19:49:19 volumio volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 19:49:20 volumio mpd[2486]: Aug 27 19:49 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 19:49:20 volumio mpd[2486]: Aug 27 19:49 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 27 19:49:20 volumio mpd[2486]: Aug 27 19:49 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 27 19:49:20 volumio systemd[1]: Started Music Player Daemon. Aug 27 19:49:20 volumio sudo[2476]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:20 volumio sudo[2434]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:21 volumio volumio[753]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Aug 27 19:49:21 volumio volumio[753]: No state is present for card b1 Aug 27 19:49:21 volumio volumio[753]: No state is present for card Headphones Aug 27 19:49:21 volumio volumio[753]: No state is present for card sndrpihifiberry Aug 27 19:49:21 volumio volumio[753]: Found hardware: "RPi-simple" "" "" "" "" Aug 27 19:49:21 volumio volumio[753]: Hardware is initialized using a generic method Aug 27 19:49:21 volumio volumio[753]: No state is present for card sndrpihifiberry Aug 27 19:49:21 volumio volumio[753]: info: Output device has changed, restarting MPD Aug 27 19:49:21 volumio sudo[2492]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 19:49:21 volumio sudo[2492]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:21 volumio volumio[753]: info: Output device has changed, restarting Shairport Sync Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:21 volumio sudo[2492]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:21 volumio sudo[2494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 19:49:21 volumio sudo[2494]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:21 volumio systemd[1]: Stopping Music Player Daemon... Aug 27 19:49:21 volumio volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 19:49:21 volumio systemd[1]: mpd.service: Succeeded. Aug 27 19:49:21 volumio systemd[1]: Stopped Music Player Daemon. Aug 27 19:49:21 volumio systemd[1]: Starting Music Player Daemon... Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 27 19:49:21 volumio volumio[753]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 27 19:49:21 volumio volumio[753]: info: Disabling external Volume Control Aug 27 19:49:21 volumio volumio[753]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Aug 27 19:49:21 volumio volumio[753]: info: MPD Permissions set Aug 27 19:49:21 volumio volumio[753]: info: MPD Permissions set Aug 27 19:49:21 volumio volumio[753]: info: Shairport-Sync Started Aug 27 19:49:21 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:21 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:21 volumio volumio[753]: info: Starting Shairport Sync Aug 27 19:49:21 volumio volumio[753]: info: Starting Shairport Sync Aug 27 19:49:21 volumio sudo[2521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 19:49:21 volumio sudo[2521]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:21 volumio sudo[2524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 19:49:21 volumio sudo[2524]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 27 19:49:21 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 27 19:49:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:21 volumio sudo[2521]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:21 volumio volumio[753]: info: Shairport-Sync Started Aug 27 19:49:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 27 19:49:21 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 27 19:49:21 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 27 19:49:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 27 19:49:21 volumio sudo[2524]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:21 volumio volumio[753]: info: Shairport-Sync Started Aug 27 19:49:21 volumio mpd[2515]: Aug 27 19:49 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 19:49:21 volumio mpd[2515]: Aug 27 19:49 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 27 19:49:21 volumio mpd[2515]: Aug 27 19:49 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 27 19:49:21 volumio systemd[1]: Started Music Player Daemon. Aug 27 19:49:21 volumio sudo[2494]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:21 volumio volumio[753]: error: MPD error: The expression evaluated to a falsy value: Aug 27 19:49:21 volumio volumio[753]: assert.ok(self.idling) Aug 27 19:49:21 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:21 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Aug 27 19:49:22 volumio sudo[2533]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 19:49:22 volumio sudo[2533]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:22 volumio systemd[1]: Stopping Music Player Daemon... Aug 27 19:49:22 volumio systemd[1]: mpd.service: Succeeded. Aug 27 19:49:22 volumio systemd[1]: Stopped Music Player Daemon. Aug 27 19:49:22 volumio systemd[1]: Starting Music Player Daemon... Aug 27 19:49:23 volumio mpd[2537]: Aug 27 19:49 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 19:49:23 volumio mpd[2537]: Aug 27 19:49 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 27 19:49:23 volumio mpd[2537]: Aug 27 19:49 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 27 19:49:23 volumio systemd[1]: Started Music Player Daemon. Aug 27 19:49:23 volumio sudo[2533]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:23 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:23 volumio volumio[753]: info: VolumeController::SetAlsaVolume100 Aug 27 19:49:23 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:49:23 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:49:23 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:49:24 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:49:24 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:26 volumio volumio[753]: error: updateQueue error: null Aug 27 19:49:34 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:49:34 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:49:34 volumio volumio[753]: info: Discovery: Getting this device information Aug 27 19:49:34 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:49:34 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:49:34 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:49:39 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:49:40 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:49:40 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Aug 27 19:49:40 volumio sudo[2546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Aug 27 19:49:40 volumio sudo[2546]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2546]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:49:40 volumio sudo[2551]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2551]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2560]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:49:40 volumio sudo[2560]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:49:40 volumio sudo[2565]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2560]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2565]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:49:40 volumio sudo[2571]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 27 19:49:40 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 27 19:49:40 volumio sudo[2571]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:49:40 volumio sudo[2574]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2574]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio sudo[2578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 19:49:40 volumio sudo[2578]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:40 volumio sudo[2578]: pam_unix(sudo:session): session closed for user root Aug 27 19:49:40 volumio kernel: ieee80211 phy0: brcmf_vif_set_mgmt_ie: vndr ie set error : -52 Aug 27 19:49:40 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: scan error (-52) Aug 27 19:49:40 volumio volumio[753]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 27 19:49:40 volumio volumio[753]: wlan0 Interface doesn't support scanning : Invalid exchange Aug 27 19:49:40 volumio volumio[753]: info: Cannot use regular scanning, forcing with ap-force Aug 27 19:49:40 volumio sudo[2581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 27 19:49:40 volumio sudo[2581]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:49:41 volumio sudo[2581]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:02 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Aug 27 19:50:02 volumio volumio[753]: info: Saving new wireless network Aug 27 19:50:02 volumio sudo[2585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Aug 27 19:50:02 volumio sudo[2585]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:02 volumio sudo[2585]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:02 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Aug 27 19:50:02 volumio volumio[753]: info: Discovery: Restarting Advertising due to device name change Aug 27 19:50:02 volumio sudo[2588]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Aug 27 19:50:02 volumio sudo[2588]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:02 volumio dhcpcd[2217]: received SIGTERM, stopping Aug 27 19:50:02 volumio dhcpcd[2217]: wlan0: removing interface Aug 27 19:50:02 volumio systemd[1]: Stopping Wireless Services... Aug 27 19:50:02 volumio dhcpcd[2217]: eth0: removing interface Aug 27 19:50:02 volumio dhcpcd[2217]: dhcpcd exited Aug 27 19:50:02 volumio systemd[1]: wireless.service: Succeeded. Aug 27 19:50:02 volumio systemd[1]: Stopped Wireless Services. Aug 27 19:50:02 volumio systemd[1]: Starting Wireless Services... Aug 27 19:50:02 volumio wireless.js[2592]: Cleaning previous... Aug 27 19:50:02 volumio systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Aug 27 19:50:03 volumio systemd[1]: hostapd.service: Succeeded. Aug 27 19:50:03 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Aug 27 19:50:03 volumio sudo[2606]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 27 19:50:03 volumio sudo[2606]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:03 volumio avahi-daemon[476]: Withdrawing address record for 192.168.211.1 on wlan0. Aug 27 19:50:03 volumio avahi-daemon[476]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Aug 27 19:50:03 volumio avahi-daemon[476]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.73.174. Aug 27 19:50:03 volumio avahi-daemon[476]: Withdrawing address record for 169.254.73.174 on wlan0. Aug 27 19:50:03 volumio avahi-daemon[476]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.73.174. Aug 27 19:50:03 volumio avahi-daemon[476]: Interface wlan0.IPv4 no longer relevant for mDNS. Aug 27 19:50:03 volumio volumio[753]: info: Discovery: A device disappeared from network Aug 27 19:50:03 volumio volumio[753]: info: Discovery: Device volumio disappeared from network Aug 27 19:50:03 volumio sudo[2606]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:03 volumio volumio[753]: info: Discovery: A device disappeared from network Aug 27 19:50:03 volumio sudo[2608]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 27 19:50:03 volumio sudo[2608]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:03 volumio sudo[2608]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:03 volumio wireless.js[2592]: Stopped aP Aug 27 19:50:03 volumio sudo[2615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 19:50:03 volumio sudo[2615]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:03 volumio sudo[2615]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:03 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:50:03 volumio sudo[2617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 27 19:50:03 volumio sudo[2617]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:03 volumio sudo[2617]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:03 volumio sudo[2624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 19:50:03 volumio sudo[2624]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:03 volumio sudo[2624]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:03 volumio sudo[2626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 27 19:50:03 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:04 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:50:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:50:04 volumio volumio[753]: info: Discovery: Getting this device information Aug 27 19:50:04 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:50:04 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:04 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:50:04 volumio wireless.js[2592]: Start wireless flow Aug 27 19:50:04 volumio wireless.js[2592]: Stopped hotspot (if there).. Aug 27 19:50:04 volumio sudo[2631]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 27 19:50:04 volumio sudo[2631]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:04 volumio sudo[2631]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:04 volumio sudo[2633]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 27 19:50:04 volumio sudo[2633]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:05 volumio sudo[2633]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:05 volumio wireless.js[2592]: DHCP IP Aug 27 19:50:05 volumio wireless.js[2592]: Start ap Aug 27 19:50:05 volumio wpa_supplicant[2635]: Successfully initialized wpa_supplicant Aug 27 19:50:05 volumio sudo[2636]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Aug 27 19:50:05 volumio sudo[2636]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:05 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:50:05 volumio dhcpcd[2637]: dev: loaded udev Aug 27 19:50:05 volumio dhcpcd-run-hooks[2646]: wlan0: starting wpa_supplicant Aug 27 19:50:05 volumio dhcpcd-run-hooks[2651]: wlan0: failed to start wpa_supplicant Aug 27 19:50:05 volumio dhcpcd-run-hooks[2652]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Aug 27 19:50:05 volumio dhcpcd[2637]: wlan0: connected to Access Point `' Aug 27 19:50:05 volumio dhcpcd[2637]: DUID 00:01:00:01:2b:75:13:44:dc:a6:32:55:e9:f5 Aug 27 19:50:05 volumio dhcpcd[2637]: eth0: IAID 32:55:e9:f5 Aug 27 19:50:05 volumio dhcpcd[2637]: eth0: adding address fe80::adbd:c2b8:b59b:c8d2 Aug 27 19:50:05 volumio dhcpcd[2637]: ipv6_addaddr1: Permission denied Aug 27 19:50:05 volumio dhcpcd[2637]: wlan0: waiting for carrier Aug 27 19:50:06 volumio dhcpcd[2637]: eth0: rebinding lease of 192.168.71.240 Aug 27 19:50:06 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:06 volumio dhcpcd[2637]: eth0: leased 192.168.71.240 for 86400 seconds Aug 27 19:50:06 volumio dhcpcd[2637]: eth0: adding route to 192.168.71.0/24 Aug 27 19:50:06 volumio dhcpcd[2637]: eth0: adding default route via 192.168.71.1 Aug 27 19:50:06 volumio wireless.js[2592]: trying... Aug 27 19:50:06 volumio dhcpcd[2637]: forked to background, child pid 2692 Aug 27 19:50:06 volumio dhcpcd[2692]: eth0: soliciting an IPv6 router Aug 27 19:50:06 volumio sudo[2691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:06 volumio sudo[2691]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:06 volumio sudo[2691]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:06 volumio sudo[2636]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:07 volumio volumio[753]: info: Discovery: Started advertising with name: Volumio Aug 27 19:50:07 volumio wireless.js[2592]: trying... Aug 27 19:50:07 volumio sudo[2696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:07 volumio sudo[2696]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:07 volumio sudo[2696]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:07 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:07 volumio ntpd[645]: Deleting interface #5 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=178 secs Aug 27 19:50:07 volumio ntpd[645]: Deleting interface #6 wlan0, 169.254.73.174#123, interface stats: received=0, sent=0, dropped=0, active_time=167 secs Aug 27 19:50:08 volumio volumio[753]: info: Discovery: adding undefined Aug 27 19:50:08 volumio volumio[753]: info: Discovery: Found device Volumio Aug 27 19:50:08 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:50:08 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:08 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:08 volumio wireless.js[2592]: trying... Aug 27 19:50:08 volumio sudo[2700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:08 volumio sudo[2700]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:08 volumio sudo[2700]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:09 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:09 volumio wireless.js[2592]: trying... Aug 27 19:50:09 volumio sudo[2703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:09 volumio sudo[2703]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:09 volumio sudo[2703]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:09 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:10 volumio wireless.js[2592]: trying... Aug 27 19:50:10 volumio sudo[2706]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:10 volumio sudo[2706]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:10 volumio sudo[2706]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:11 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:11 volumio wireless.js[2592]: trying... Aug 27 19:50:11 volumio sudo[2709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:11 volumio sudo[2709]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:11 volumio sudo[2709]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:12 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:12 volumio wireless.js[2592]: trying... Aug 27 19:50:12 volumio sudo[2712]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:12 volumio sudo[2712]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:12 volumio sudo[2712]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:50:13 volumio volumio[753]: info: Discovery: Getting this device information Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:50:13 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:50:13 volumio wireless.js[2592]: trying... Aug 27 19:50:13 volumio sudo[2715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:13 volumio sudo[2715]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:13 volumio sudo[2715]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:13 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: info: Retrieving Cloud Streaming UI Aug 27 19:50:13 volumio volumio[753]: info: Getting Tidal Cloud Configuration Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: info: Getting Qobuz Cloud Configuration Aug 27 19:50:13 volumio volumio[753]: info: Asking plugin for UI Config Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: info: Getting Spotify Cloud Configuration Aug 27 19:50:13 volumio volumio[753]: info: Asking plugin for UI Config Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: info: Saving Spotify Acccount Aug 27 19:50:13 volumio volumio[753]: info: Got Tidal Cloud Configuration Aug 27 19:50:13 volumio volumio[753]: info: Got it Aug 27 19:50:13 volumio volumio[753]: info: Got it Aug 27 19:50:13 volumio volumio[753]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:13 volumio volumio[753]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::volumioGetBrowseSources Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 27 19:50:13 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 27 19:50:14 volumio wireless.js[2592]: trying... Aug 27 19:50:14 volumio sudo[2718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:14 volumio sudo[2718]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:14 volumio sudo[2718]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:14 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:15 volumio wireless.js[2592]: trying... Aug 27 19:50:15 volumio sudo[2721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:15 volumio sudo[2721]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:15 volumio sudo[2721]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:15 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:16 volumio wireless.js[2592]: trying... Aug 27 19:50:16 volumio sudo[2724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:16 volumio sudo[2724]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:16 volumio sudo[2724]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:17 volumio wireless.js[2592]: trying... Aug 27 19:50:17 volumio sudo[2727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:17 volumio sudo[2727]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:17 volumio sudo[2727]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:17 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand rescan Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:17 volumio volumio[753]: info: Aug 27 19:50:17 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand rescan took 3 milliseconds Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:17 volumio volumio[753]: info: Aug 27 19:50:17 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:17 volumio volumio[753]: info: Aug 27 19:50:17 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 14 milliseconds Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: info: Command Router : Notfying DB Updatetrue Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 106 milliseconds Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 106 milliseconds Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 106 milliseconds Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 105 milliseconds Aug 27 19:50:17 volumio volumio[753]: info: sendMpdCommand status took 105 milliseconds Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: info: Command Router : Notfying DB Updatetrue Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: info: Command Router : Notfying DB Updatetrue Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:17 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 27 19:50:17 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: No code Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 27 19:50:17 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: No code Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 27 19:50:17 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: No code Aug 27 19:50:17 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:17 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:17 volumio volumio[753]: info: ------------------------------ 208ms Aug 27 19:50:17 volumio volumio[753]: info: ------------------------------ 237ms Aug 27 19:50:17 volumio volumio[753]: info: ------------------------------ 237ms Aug 27 19:50:17 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 27 19:50:18 volumio wireless.js[2592]: trying... Aug 27 19:50:18 volumio sudo[2737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:18 volumio sudo[2737]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:18 volumio sudo[2737]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:18 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:19 volumio wireless.js[2592]: trying... Aug 27 19:50:19 volumio sudo[2741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:19 volumio sudo[2741]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:19 volumio sudo[2741]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:19 volumio volumio[753]: info: MPD Database updated - AlbumList cache refreshed Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: database Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: MPD Database updated - AlbumList cache refreshed Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: database Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: MPD Database updated - AlbumList cache refreshed Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: database Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: Aug 27 19:50:19 volumio volumio[753]: ---------------------------- MPD announces state update: update Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: ControllerMpd::getState Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::sendMpdCommand status Aug 27 19:50:19 volumio volumio[753]: info: sendMpdCommand status took 67 milliseconds Aug 27 19:50:19 volumio volumio[753]: info: sendMpdCommand status took 66 milliseconds Aug 27 19:50:19 volumio volumio[753]: info: sendMpdCommand status took 66 milliseconds Aug 27 19:50:19 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio wireless.js[2592]: trying... Aug 27 19:50:20 volumio sudo[2746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:20 volumio sudo[2746]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:20 volumio sudo[2746]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:20 volumio volumio[753]: info: Command Router : Notfying DB Updatefalse Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio wpa_supplicant[2650]: wlan0: Trying to associate with SSID 'ChinaNet-CRFG' Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1129ms Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1129ms Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1184 milliseconds Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1184 milliseconds Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1184 milliseconds Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: info: Command Router : Notfying DB Updatefalse Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1278ms Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1279ms Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1309 milliseconds Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1308 milliseconds Aug 27 19:50:20 volumio volumio[753]: info: sendMpdCommand status took 1308 milliseconds Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: info: Command Router : Notfying DB Updatefalse Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::Close All Modals sent Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: verbose: ControllerMpd::parseState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: ControllerMpd::pushState Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::servicePushState Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: 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} Aug 27 19:50:20 volumio volumio[753]: verbose: CURRENT POSITION 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState stateService stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::syncState currentStatus stop Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: No code Aug 27 19:50:20 volumio volumio[753]: info: CoreStateMachine::pushState Aug 27 19:50:20 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:20 volumio volumio[753]: info: CoreCommandRouter::volumioPushState Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1363ms Aug 27 19:50:20 volumio volumio[753]: info: ------------------------------ 1363ms Aug 27 19:50:21 volumio wireless.js[2592]: trying... Aug 27 19:50:21 volumio sudo[2753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:21 volumio sudo[2753]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:21 volumio sudo[2753]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:21 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 19:50:21 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="ChinaNet-CRFG" auth_failures=1 duration=10 reason=CONN_FAILED Aug 27 19:50:22 volumio wireless.js[2592]: trying... Aug 27 19:50:22 volumio sudo[2756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:22 volumio sudo[2756]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:22 volumio sudo[2756]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 19:50:22 volumio volumio[753]: info: Getting Alsa Cards List without I2S DAC Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 27 19:50:22 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 27 19:50:23 volumio volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:50:23 volumio wireless.js[2592]: trying... Aug 27 19:50:23 volumio sudo[2767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:23 volumio sudo[2767]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:23 volumio sudo[2767]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:24 volumio wireless.js[2592]: trying... Aug 27 19:50:24 volumio sudo[2770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:24 volumio sudo[2770]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:24 volumio sudo[2770]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:25 volumio wireless.js[2592]: trying... Aug 27 19:50:25 volumio sudo[2773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:50:25 volumio sudo[2773]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:25 volumio sudo[2773]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:26 volumio wireless.js[2592]: Overtime, starting plan B Aug 27 19:50:26 volumio wireless.js[2592]: STARTING HOTSPOT Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: Failed to set IPv4 unicast in multicast filter Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: Failed to set IPv4 unicast in multicast filter Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Aug 27 19:50:26 volumio wpa_supplicant[2650]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Aug 27 19:50:26 volumio wpa_supplicant[2650]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Aug 27 19:50:27 volumio wpa_supplicant[2650]: wlan0: CTRL-EVENT-TERMINATING Aug 27 19:50:29 volumio sudo[2782]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 27 19:50:29 volumio sudo[2782]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:29 volumio sudo[2782]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:29 volumio sudo[2784]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 27 19:50:29 volumio sudo[2784]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 19:50:29 volumio sudo[2784]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:29 volumio avahi-daemon[476]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Aug 27 19:50:29 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:50:29 volumio avahi-daemon[476]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 19:50:29 volumio avahi-daemon[476]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Aug 27 19:50:29 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Aug 27 19:50:29 volumio hostapd[2790]: Configuration file: /etc/hostapd/hostapd.conf Aug 27 19:50:29 volumio hostapd[2790]: wlan0: Could not connect to kernel driver Aug 27 19:50:29 volumio hostapd[2790]: Using interface wlan0 with hwaddr dc:a6:32:55:e9:f6 and ssid "Volumio-5878F" Aug 27 19:50:29 volumio dhcpcd[2692]: wlan0: carrier acquired Aug 27 19:50:29 volumio hostapd[2790]: wlan0: interface state UNINITIALIZED->ENABLED Aug 27 19:50:29 volumio hostapd[2790]: wlan0: AP-ENABLED Aug 27 19:50:29 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Aug 27 19:50:29 volumio dhcpcd[2692]: wlan0: IAID 32:55:e9:f6 Aug 27 19:50:29 volumio dhcpcd[2692]: wlan0: adding address fe80::9d60:ae8:8fcb:a4df Aug 27 19:50:29 volumio dhcpcd[2692]: ipv6_addaddr1: Permission denied Aug 27 19:50:29 volumio systemd[1]: Started Wireless Services. Aug 27 19:50:29 volumio sudo[2588]: pam_unix(sudo:session): session closed for user root Aug 27 19:50:29 volumio dhcpcd[2692]: wlan0: soliciting an IPv6 router Aug 27 19:50:30 volumio volumio[753]: info: Discovery: this is already registered, undefined Aug 27 19:50:30 volumio volumio[753]: info: Discovery: Found device Volumio Aug 27 19:50:30 volumio volumio[753]: info: CoreCommandRouter::volumioGetState Aug 27 19:50:30 volumio volumio[753]: info: CorePlayQueue::getTrack 3 Aug 27 19:50:30 volumio dhcpcd[2692]: wlan0: soliciting a DHCP lease Aug 27 19:50:31 volumio ntpd[645]: Listen normally on 7 wlan0 192.168.211.1:123 Aug 27 19:50:31 volumio ntpd[645]: new interface(s) found: waking up resolver Aug 27 19:50:33 volumio volumio[753]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:50:33 volumio volumio[753]: Error: connect ETIMEDOUT 108.160.167.148:443 Aug 27 19:50:33 volumio volumio[753]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Aug 27 19:50:33 volumio volumio[753]: errno: -110, Aug 27 19:50:33 volumio volumio[753]: code: 'ETIMEDOUT', Aug 27 19:50:33 volumio volumio[753]: syscall: 'connect', Aug 27 19:50:33 volumio volumio[753]: address: '108.160.167.148', Aug 27 19:50:33 volumio volumio[753]: port: 443 Aug 27 19:50:33 volumio volumio[753]: } Aug 27 19:50:33 volumio volumio[753]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:50:34 volumio sudo[2804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 19:49 Aug 27 19:50:34 volumio sudo[2804]: 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="1d63a568b7d5e4a317f16be7d0961cbb2d82e282" VOLUMIO_FE_VERSION="c433755e569617abac52264d17ad61be303ef463" VOLUMIO_FE3_VERSION="2419ddd8e895c5bdc456962163c9dc7c0f187aa7" VOLUMIO_BE_VERSION="4f8978e0148ab5e1610548b80abf1b4b5e03ea0a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 07 Feb 2023 02:43:13 PM CET" VOLUMIO_VERSION="3.429" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3223bbb74b9427313a173f7908c19cfa"