-- Logs begin at Thu 2019-02-14 12:11:59 EET, end at Fri 2024-08-23 21:08:52 EEST. -- Aug 23 21:07:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 21:07:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 21:07:07 volumio volumio[834]: info: Discovery: Getting this device information Aug 23 21:07:07 volumio volumio[834]: info: CoreCommandRouter::volumioGetState Aug 23 21:07:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 23 21:07:12 volumio volumio[834]: info: Getting Alsa Cards List without I2S DAC Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:12 volumio volumio[834]: Invalid card number. Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 23 21:07:12 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::volumioPlay Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::play index undefined Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::startPlaybackTimer Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand stop Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand stop took 5 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clear Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 9 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand clear took 8 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 6 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 4 milliseconds Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand add "http://stream-uk1.radioparadise.com/aac-320" Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 54ms Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 52ms Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: error: updateQueue error: null Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 57ms Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand playlistinfo took 54 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand add "http://stream-uk1.radioparadise.com/aac-320" took 55 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 13ms Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 12ms Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand play Aug 23 21:07:25 volumio volumio[834]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 99ms Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:25 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:25 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:25 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 42ms Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand play took 19 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 17ms Aug 23 21:07:25 volumio volumio[834]: info: ------------------------------ 15ms Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 31 milliseconds Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 25 milliseconds Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 23 milliseconds Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: info: Aug 23 21:07:25 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 50 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand clearerror took 36 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand clearerror took 35 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand clearerror took 33 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand playlistinfo took 19 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand playlistinfo took 26 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand playlistinfo took 25 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 22 milliseconds Aug 23 21:07:25 volumio volumio[834]: info: sendMpdCommand status took 21 milliseconds Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:25 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:25 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:25 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:25 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:25 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:25 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:25 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:25 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:26 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:26 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:26 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:26 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 169ms Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 167ms Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 158ms Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:26 volumio volumio[834]: info: sendMpdCommand clearerror took 121 milliseconds Aug 23 21:07:26 volumio volumio[834]: info: sendMpdCommand playlistinfo took 111 milliseconds Aug 23 21:07:26 volumio volumio[834]: info: sendMpdCommand playlistinfo took 108 milliseconds Aug 23 21:07:26 volumio volumio[834]: info: sendMpdCommand playlistinfo took 106 milliseconds Aug 23 21:07:26 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:26 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:26 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:26 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:26 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:26 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:26 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:26 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:26 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:26 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:26 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:26 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:26 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:26 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:26 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:26 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:26 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 263ms Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 225ms Aug 23 21:07:26 volumio volumio[834]: info: ------------------------------ 224ms Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:26 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:36 volumio volumio[834]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioGetState Aug 23 21:07:36 volumio volumio[834]: info: Restoring Previous Volume level: 30 false true Aug 23 21:07:36 volumio volumio[834]: info: VolumeController::SetAlsaVolume100 Aug 23 21:07:36 volumio volumio[834]: info: Enable softmixer device for audio device number 2 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioStop Aug 23 21:07:36 volumio volumio[834]: info: CoreStateMachine::stop Aug 23 21:07:36 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 21:07:36 volumio volumio[834]: info: Enable softmixer device for audio device undefined Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 23 21:07:36 volumio volumio[834]: info: Updating Volume Controller Parameters: Device: 2 Name: Generic I2S DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 23 21:07:36 volumio volumio[834]: info: Disabling external Volume Control Aug 23 21:07:36 volumio volumio[834]: info: Output device has changed, restarting MPD Aug 23 21:07:36 volumio sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 21:07:36 volumio sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:36 volumio volumio[834]: info: Output device has changed, restarting Shairport Sync Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:36 volumio sudo[1404]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:36 volumio sudo[1407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 21:07:36 volumio sudo[1407]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:36 volumio systemd[1]: Stopping Music Player Daemon... Aug 23 21:07:36 volumio volumio[834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 21:07:36 volumio volumio[834]: info: Volume configurations have been set Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 23 21:07:36 volumio volumio[834]: info: Updating Volume Controller Parameters: Device: 2 Name: Generic I2S DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 23 21:07:36 volumio volumio[834]: info: Disabling external Volume Control Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:07:36 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:36 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:36 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 23 21:07:36 volumio volumio[834]: SPOTIFY: SPOTIFY VOLUME 30 Aug 23 21:07:36 volumio volumio[834]: SPOTIFY: VOLUMIO VOLUME 100 Aug 23 21:07:36 volumio volumio[834]: SPOTIFY: DELTA VOLUME ENOUGH: true Aug 23 21:07:36 volumio volumio[834]: info: Setting Spotify Volume from Volumio: 100 Aug 23 21:07:36 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:36 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:36 volumio volumio[834]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Aug 23 21:07:36 volumio volumio[834]: info: MPD Permissions set Aug 23 21:07:36 volumio volumio[834]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Aug 23 21:07:36 volumio volumio[834]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Aug 23 21:07:36 volumio volumio[834]: info: Software Volume ALSA configuration written Aug 23 21:07:36 volumio volumio[834]: info: Preparing to generate the ALSA configuration file Aug 23 21:07:36 volumio volumio[834]: info: VolumeController:: Volume=undefined Mute =false Aug 23 21:07:36 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:36 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:36 volumio volumio[834]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 23 21:07:36 volumio volumio[834]: info: Reading ALSA contributions from plugins. Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 23 21:07:36 volumio systemd[1]: mpd.service: Succeeded. Aug 23 21:07:36 volumio systemd[1]: Stopped Music Player Daemon. Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 23 21:07:36 volumio volumio[834]: info: Getting Alsa Cards List without I2S DAC Aug 23 21:07:36 volumio systemd[1]: Starting Music Player Daemon... Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:36 volumio volumio[834]: Invalid card number. Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:07:36 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio sudo[1424]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 21:07:37 volumio sudo[1424]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio sudo[1424]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio volumio[834]: info: Starting Shairport Sync Aug 23 21:07:37 volumio volumio[834]: info: Asound.conf file written Aug 23 21:07:37 volumio sudo[1438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 21:07:37 volumio sudo[1438]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 23 21:07:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 23 21:07:37 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 23 21:07:37 volumio sudo[1441]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 23 21:07:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 23 21:07:37 volumio sudo[1441]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio sudo[1438]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio volumio[834]: info: Output device has changed, restarting MPD Aug 23 21:07:37 volumio volumio[834]: info: Output device has changed, restarting Shairport Sync Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:37 volumio sudo[1451]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 21:07:37 volumio sudo[1450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 21:07:37 volumio sudo[1450]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1451]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1450]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 23 21:07:37 volumio systemd[1]: mpd.service: Succeeded. Aug 23 21:07:37 volumio systemd[1]: Stopped Music Player Daemon. Aug 23 21:07:37 volumio volumio[834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 21:07:37 volumio volumio[834]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Aug 23 21:07:37 volumio volumio[834]: aplay: main:828: audio open error: No such device Aug 23 21:07:37 volumio systemd[1]: Starting Music Player Daemon... Aug 23 21:07:37 volumio volumio[834]: info: Output device has changed, restarting MPD Aug 23 21:07:37 volumio sudo[1463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 21:07:37 volumio volumio[834]: info: Output device has changed, restarting Shairport Sync Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio sudo[1463]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:37 volumio sudo[1463]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio sudo[1466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 21:07:37 volumio sudo[1466]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1457]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 21:07:37 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio volumio[834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 21:07:37 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 23 21:07:37 volumio systemd[1]: mpd.service: Succeeded. Aug 23 21:07:37 volumio systemd[1]: Stopped Music Player Daemon. Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 23 21:07:37 volumio volumio[834]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 23 21:07:37 volumio systemd[1]: Starting Music Player Daemon... Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 23 21:07:37 volumio volumio[834]: info: Disabling external Volume Control Aug 23 21:07:37 volumio volumio[834]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Aug 23 21:07:37 volumio volumio[834]: info: MPD Permissions set Aug 23 21:07:37 volumio volumio[834]: info: MPD Permissions set Aug 23 21:07:37 volumio volumio[834]: info: Shairport-Sync Started Aug 23 21:07:37 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:37 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 21:07:37 volumio volumio[834]: info: Discovery: Getting this device information Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::volumioGetState Aug 23 21:07:37 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 21:07:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 21:07:37 volumio sudo[1472]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 21:07:37 volumio volumio[834]: info: Starting Shairport Sync Aug 23 21:07:37 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:37 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:37 volumio volumio[834]: info: Starting Shairport Sync Aug 23 21:07:37 volumio sudo[1493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 21:07:37 volumio sudo[1493]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:38 volumio volumio[834]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Aug 23 21:07:38 volumio volumio[834]: info: Sending Spotify command with payload to local API: /player/volume Aug 23 21:07:38 volumio go-librespot[1007]: time="2024-08-23T21:07:38+03:00" level=debug msg="update volume to 65535/65535" Aug 23 21:07:37 volumio sudo[1496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 21:07:37 volumio sudo[1496]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:38 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 23 21:07:38 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 23 21:07:38 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 23 21:07:38 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 23 21:07:38 volumio sudo[1496]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:38 volumio volumio[834]: info: Shairport-Sync Started Aug 23 21:07:38 volumio sudo[1493]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:38 volumio volumio[834]: info: Shairport-Sync Started Aug 23 21:07:38 volumio go-librespot[1007]: time="2024-08-23T21:07:38+03:00" level=debug msg="put connect state because VOLUME_CHANGED" Aug 23 21:07:38 volumio go-librespot[1007]: time="2024-08-23T21:07:38+03:00" level=trace msg="emitting websocket event: volume" Aug 23 21:07:38 volumio volumio[834]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Aug 23 21:07:38 volumio volumio[834]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Aug 23 21:07:39 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Aug 23 21:07:39 volumio sudo[1502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 21:07:39 volumio sudo[1502]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:39 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 23 21:07:39 volumio systemd[1]: mpd.service: Succeeded. Aug 23 21:07:39 volumio systemd[1]: Stopped Music Player Daemon. Aug 23 21:07:39 volumio systemd[1]: Starting Music Player Daemon... Aug 23 21:07:39 volumio sudo[1504]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 21:07:39 volumio sudo[1504]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:07:39 volumio sudo[1504]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:40 volumio volumio[834]: info: VolumeController::SetAlsaVolume30 Aug 23 21:07:40 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:40 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:40 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:40 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:40 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:40 volumio volumio[834]: SPOTIFY: SPOTIFY VOLUME 100 Aug 23 21:07:40 volumio volumio[834]: SPOTIFY: VOLUMIO VOLUME 30 Aug 23 21:07:40 volumio volumio[834]: SPOTIFY: DELTA VOLUME ENOUGH: true Aug 23 21:07:40 volumio volumio[834]: info: Setting Spotify Volume from Volumio: 30 Aug 23 21:07:40 volumio volumio[834]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Aug 23 21:07:41 volumio mpd[1506]: Aug 23 21:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 23 21:07:41 volumio systemd[1]: Started Music Player Daemon. Aug 23 21:07:41 volumio sudo[1407]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:41 volumio sudo[1451]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:41 volumio sudo[1502]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:41 volumio sudo[1466]: pam_unix(sudo:session): session closed for user root Aug 23 21:07:41 volumio volumio[834]: error: MPD error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: MPD error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: MPD error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: The expression evaluated to a falsy value: Aug 23 21:07:41 volumio volumio[834]: assert.ok(self.idling) Aug 23 21:07:41 volumio volumio[834]: error: updateQueue error: null Aug 23 21:07:42 volumio volumio[834]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Aug 23 21:07:42 volumio volumio[834]: info: Sending Spotify command with payload to local API: /player/volume Aug 23 21:07:42 volumio go-librespot[1007]: time="2024-08-23T21:07:42+03:00" level=debug msg="update volume to 19660/65535" Aug 23 21:07:42 volumio go-librespot[1007]: time="2024-08-23T21:07:42+03:00" level=debug msg="put connect state because VOLUME_CHANGED" Aug 23 21:07:42 volumio go-librespot[1007]: time="2024-08-23T21:07:42+03:00" level=trace msg="emitting websocket event: volume" Aug 23 21:07:42 volumio volumio[834]: SPOTIFY: received: {"type":"volume","data":{"value":30,"max":100}} Aug 23 21:07:42 volumio volumio[834]: SPOTIFY: RECEIVED SPOTIFY VOLUME 30 Aug 23 21:07:50 volumio volumio[834]: info: CoreCommandRouter::volumioPlay Aug 23 21:07:50 volumio volumio[834]: info: CoreStateMachine::play index undefined Aug 23 21:07:50 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 21:07:50 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:50 volumio volumio[834]: info: CoreStateMachine::startPlaybackTimer Aug 23 21:07:50 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:50 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand stop Aug 23 21:07:50 volumio volumio[834]: info: sendMpdCommand stop took 1 milliseconds Aug 23 21:07:50 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clear Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: sendMpdCommand clear took 2 milliseconds Aug 23 21:07:50 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand add "http://stream-uk1.radioparadise.com/aac-320" Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: error: updateQueue error: null Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 8ms Aug 23 21:07:50 volumio volumio[834]: info: sendMpdCommand add "http://stream-uk1.radioparadise.com/aac-320" took 7 milliseconds Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 6ms Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 5ms Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 4ms Aug 23 21:07:50 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand play Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: Aug 23 21:07:50 volumio volumio[834]: ---------------------------- MPD announces system playlist update Aug 23 21:07:50 volumio volumio[834]: info: Ignoring MPD Status Update Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 17ms Aug 23 21:07:50 volumio volumio[834]: info: sendMpdCommand play took 7 milliseconds Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 6ms Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 8ms Aug 23 21:07:50 volumio volumio[834]: info: ------------------------------ 7ms Aug 23 21:07:50 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 31 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 40 milliseconds Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 39 milliseconds Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 38 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand clearerror took 14 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 13 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand playlistinfo took 12 milliseconds Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:51 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:51 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:51 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:51 volumio volumio[834]: info: ------------------------------ 96ms Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: info: Aug 23 21:07:51 volumio volumio[834]: ---------------------------- MPD announces state update: player Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::getState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand status Aug 23 21:07:51 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand clearerror took 75 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand clearerror took 74 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand clearerror took 74 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand playlistinfo took 59 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand playlistinfo took 56 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand playlistinfo took 54 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand playlistinfo took 54 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 16 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 13 milliseconds Aug 23 21:07:51 volumio volumio[834]: info: sendMpdCommand status took 12 milliseconds Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::parseState Aug 23 21:07:51 volumio volumio[834]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:51 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:51 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:51 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:51 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:51 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:51 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:51 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:51 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:51 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:51 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:51 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:51 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:51 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:51 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:51 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 192ms Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 191ms Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 190ms Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 176ms Aug 23 21:07:52 volumio volumio[834]: info: sendMpdCommand playlistinfo took 76 milliseconds Aug 23 21:07:52 volumio volumio[834]: info: sendMpdCommand playlistinfo took 77 milliseconds Aug 23 21:07:52 volumio volumio[834]: info: sendMpdCommand playlistinfo took 77 milliseconds Aug 23 21:07:52 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:52 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:52 volumio volumio[834]: verbose: ControllerMpd::parseTrackInfo Aug 23 21:07:52 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:52 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:52 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:52 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:52 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:52 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:52 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:52 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:52 volumio volumio[834]: info: ControllerMpd::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::servicePushState Aug 23 21:07:52 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Aug 23 21:07:52 volumio volumio[834]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"aac-320","artist":null,"album":null,"uri":"http://stream-uk1.radioparadise.com/aac-320","trackType":""} Aug 23 21:07:52 volumio volumio[834]: verbose: CURRENT POSITION 0 Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState stateService pause Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus stop Aug 23 21:07:52 volumio volumio[834]: info: CoreStateMachine::pushState Aug 23 21:07:52 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 157ms Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 150ms Aug 23 21:07:52 volumio volumio[834]: info: ------------------------------ 148ms Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:07:52 volumio volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 23 21:08:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 21:08:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 21:08:07 volumio volumio[834]: info: Discovery: Getting this device information Aug 23 21:08:07 volumio volumio[834]: info: CoreCommandRouter::volumioGetState Aug 23 21:08:07 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: info: Retrieving Cloud Streaming UI Aug 23 21:08:37 volumio volumio[834]: info: Getting Tidal Cloud Configuration Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: info: Getting Qobuz Cloud Configuration Aug 23 21:08:37 volumio volumio[834]: info: Asking plugin for UI Config Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: info: Getting Spotify Cloud Configuration Aug 23 21:08:37 volumio volumio[834]: info: Asking plugin for UI Config Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: info: Saving Spotify Acccount Aug 23 21:08:37 volumio volumio[834]: info: Got Tidal Cloud Configuration Aug 23 21:08:37 volumio volumio[834]: info: Got it Aug 23 21:08:37 volumio volumio[834]: info: Got it Aug 23 21:08:37 volumio volumio[834]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 23 21:08:37 volumio volumio[834]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::volumioGetBrowseSources Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::volumioGetBrowseSources Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::volumioGetBrowseSources Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 21:08:37 volumio volumio[834]: info: Discovery: Getting this device information Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::volumioGetState Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 23 21:08:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 23 21:08:41 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 23 21:08:45 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 23 21:08:48 volumio volumio[834]: info: Disabling MyMusic plugin upnp Aug 23 21:08:48 volumio sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Aug 23 21:08:48 volumio sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 21:08:48 volumio volumio[834]: error: Upnp client error: Error: This socket has been ended by the other party Aug 23 21:08:48 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Aug 23 21:08:49 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 23 21:08:51 volumio volumio[834]: info: Enabling MyMusic plugin upnp Aug 23 21:08:51 volumio volumio[834]: info: Enabling plugin upnp Aug 23 21:08:51 volumio volumio[834]: info: Loading plugin "upnp"... Aug 23 21:08:51 volumio volumio[834]: info: [1724436531172] Starting Upmpd Daemon Aug 23 21:08:51 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 23 21:08:51 volumio volumio[834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 23 21:08:51 volumio volumio[834]: Error: listen EADDRINUSE: address already in use :::6599 Aug 23 21:08:51 volumio volumio[834]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Aug 23 21:08:51 volumio volumio[834]: at listenInCluster (net.js:1366:12) Aug 23 21:08:51 volumio volumio[834]: at Server.listen (net.js:1452:7) Aug 23 21:08:51 volumio volumio[834]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Aug 23 21:08:51 volumio volumio[834]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Aug 23 21:08:51 volumio volumio[834]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Aug 23 21:08:51 volumio volumio[834]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 23 21:08:51 volumio volumio[834]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Aug 23 21:08:51 volumio volumio[834]: code: 'EADDRINUSE', Aug 23 21:08:51 volumio volumio[834]: errno: -98, Aug 23 21:08:51 volumio volumio[834]: syscall: 'listen', Aug 23 21:08:51 volumio volumio[834]: address: '::', Aug 23 21:08:51 volumio volumio[834]: port: 6599 Aug 23 21:08:51 volumio volumio[834]: } Aug 23 21:08:51 volumio volumio[834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 23 21:08:52 volumio sudo[1569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-23 21:07 Aug 23 21:08:52 volumio sudo[1569]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"