-- Logs begin at Wed 2024-11-20 20:02:06 EST, end at Wed 2024-11-20 20:16:26 EST. -- Nov 20 20:15:00 volumio volumio[1035]: info: CoreCommandRouter::volumioGetBrowseSources Nov 20 20:15:00 volumio volumio[1035]: info: CoreCommandRouter::volumioGetBrowseSources Nov 20 20:15:00 volumio volumio[1035]: info: CoreCommandRouter::updateGlobalSearchableBrowseSources Nov 20 20:15:01 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 20 20:15:05 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 20 20:15:10 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 20 20:15:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 20 20:15:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 20 20:15:14 volumio volumio[1035]: info: Discovery: Getting this device information Nov 20 20:15:14 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:15:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 20 20:15:22 volumio ntpd[1374]: 24.31.150.237 local addr 192.168.1.164 -> Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: info: Nov 20 20:15:23 volumio volumio[1035]: ---------------------------- MPD announces state update: update Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: info: Nov 20 20:15:23 volumio volumio[1035]: ---------------------------- MPD announces state update: update Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: info: Nov 20 20:15:23 volumio volumio[1035]: ---------------------------- MPD announces state update: update Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 2 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand status took 0 milliseconds Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: info: Command Router : Notfying DB Updatefalse Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::Close All Modals sent Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: info: Command Router : Notfying DB Updatefalse Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::Close All Modals sent Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: info: Command Router : Notfying DB Updatefalse Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::Close All Modals sent Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 156 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 58 milliseconds Nov 20 20:15:23 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:23 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:23 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:23 volumio volumio[1035]: verbose: STATE SERVICE {"status":"play","position":0,"seek":545507,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:23 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState stateService play Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus play Nov 20 20:15:23 volumio volumio[1035]: info: Received an update from plugin. extracting info from payload Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:23 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:23 volumio volumio[1035]: verbose: STATE SERVICE {"status":"play","position":0,"seek":545507,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:23 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState stateService play Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus play Nov 20 20:15:23 volumio volumio[1035]: info: Received an update from plugin. extracting info from payload Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:23 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:23 volumio volumio[1035]: verbose: STATE SERVICE {"status":"play","position":0,"seek":545507,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:23 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState stateService play Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus play Nov 20 20:15:23 volumio volumio[1035]: info: Received an update from plugin. extracting info from payload Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:23 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:23 volumio volumio[1035]: info: ------------------------------ 307ms Nov 20 20:15:23 volumio volumio[1035]: info: ------------------------------ 306ms Nov 20 20:15:23 volumio volumio[1035]: info: ------------------------------ 306ms Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:23 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:30 volumio ntpd[1374]: 73.234.118.31 local addr 192.168.1.164 -> Nov 20 20:15:31 volumio volumio[1035]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 20 20:15:31 volumio volumio[1035]: info: Preparing to save Alsa Options, stopping services first Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::stPlaybackTimer Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::servicePause Nov 20 20:15:31 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::servicePause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::pause Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand pause Nov 20 20:15:31 volumio volumio[1035]: info: Saving Audio Output to: {"output_device":{"value":"1,0","label":"Analog Out"}} Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:31 volumio volumio[1035]: info: Found match in Cards Database: setting mixer for card Analog Out Nov 20 20:15:31 volumio volumio[1035]: info: Setting default mixerSoftMaster for Softvolume device Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 20 20:15:31 volumio volumio[1035]: info: Updating Volume Controller Parameters: Device: 1,0 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 20 20:15:31 volumio volumio[1035]: info: Disabling external Volume Control Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 20 20:15:31 volumio volumio[1035]: info: Enable softmixer device for audio device undefined Nov 20 20:15:31 volumio volumio[1035]: info: Nov 20 20:15:31 volumio volumio[1035]: ---------------------------- MPD announces state update: player Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand pause took 92 milliseconds Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:31 volumio volumio[1035]: info: Nov 20 20:15:31 volumio volumio[1035]: ---------------------------- MPD announces state update: player Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:31 volumio volumio[1035]: info: Nov 20 20:15:31 volumio volumio[1035]: ---------------------------- MPD announces state update: player Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::getState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand status Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand status took 1 milliseconds Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseState Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 20 20:15:31 volumio volumio[1035]: info: Software Volume ALSA configuration written Nov 20 20:15:31 volumio volumio[1035]: info: Preparing to generate the ALSA configuration file Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 42 milliseconds Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 42 milliseconds Nov 20 20:15:31 volumio volumio[1035]: info: sendMpdCommand playlistinfo took 41 milliseconds Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:31 volumio volumio[1035]: verbose: ControllerMpd::parseTrackInfo Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:31 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:31 volumio volumio[1035]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":553633,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:31 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState stateService pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::stPlaybackTimer Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:31 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:31 volumio volumio[1035]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":553633,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:31 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState stateService pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::stPlaybackTimer Nov 20 20:15:31 volumio volumio[1035]: info: ControllerMpd::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::servicePushState Nov 20 20:15:31 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:31 volumio volumio[1035]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":553633,"duration":3079,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hi-Res Audio ( Flac 32bit 320kbs )","artist":"Sound source","album":"YouTube","uri":"https://rr5---sn-8xgp1vo-2iae7.googlevideo.com/videoplayback?expire=1732172776&ei=iIc-Z8TLKLCEkucP_9bn4As&ip=173.49.115.143&id=o-AGAWDfRfKTpMr9qmLyKgOFrpSdw_dAmEWpuII0Uga2vp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1732151176%2C&mh=IP&mm=31%2C29&mn=sn-8xgp1vo-2iae7%2Csn-8xgp1vo-ab5e&ms=au%2Crdu&mv=m&mvi=5&pl=16&rms=au%2Cau&initcwndbps=1248750&bui=AQn3pFSI2j6FJJUMElM0gRKSNpol1w382l5-mD7nh1YFpwYHLHt7FgRSt_YVUsmnFBYRD5Ccc_IPnqwf&spc=qtApAYtPTzlFO9oX_pYB2-rYwyzL7lX6B30dbGxUJ4iQlxzg7g&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=XNcDM3psuOJ_-rV2rlaoizUQ&rqh=1&gir=yes&clen=53809106&dur=3078.621&lmt=1701575885149085&mt=1732150641&fvip=1&keepalive=yes&fexp=51312688%2C51326932%2C51335594%2C51348766&c=WEB&sefc=1&txp=4432434&n=cK6pEZdN-4XBXg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIgXuBLXo8mubQKc8ZOvA2rmpG_GjlxdviKRLLwukXnqWMCIQCMOSRgkaaSKPfiDODk4CFt2dhyFVes91ap8KWTAn5azw%3D%3D&sig=AJfQdSswRQIhAK2zyyqIT7CRLpCUHo4iJ7SnPKucU6rALN0nubJogpGqAiBBR9nRlxy3DrdD4g7iaRWBe5APcSdL2US1cIIxK-Zh4A%3D%3D&cver=2.20230104.01.00&t.YouTube","trackType":"YouTube"} Nov 20 20:15:31 volumio volumio[1035]: verbose: CURRENT POSITION 0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState stateService pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::syncState currentStatus pause Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::stPlaybackTimer Nov 20 20:15:31 volumio volumio[1035]: info: ------------------------------ 58ms Nov 20 20:15:31 volumio volumio[1035]: info: ------------------------------ 58ms Nov 20 20:15:31 volumio volumio[1035]: info: ------------------------------ 58ms Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio volumio[1035]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 20 20:15:31 volumio volumio[1035]: info: Reading ALSA contributions from plugins. Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:31 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:31 volumio volumio[1035]: info: Asound.conf file written Nov 20 20:15:31 volumio sudo[4229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 20 20:15:31 volumio sudo[4229]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio sudo[4229]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: info: Output device has changed, restarting MPD Nov 20 20:15:31 volumio sudo[4235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 20 20:15:31 volumio sudo[4235]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio volumio[1035]: info: Output device has changed, restarting Shairport Sync Nov 20 20:15:31 volumio sudo[4235]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:31 volumio sudo[4238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 20 20:15:31 volumio sudo[4238]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio systemd[1]: Stopping Music Player Daemon... Nov 20 20:15:31 volumio volumio[1035]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 20 20:15:31 volumio volumio[1035]: info: Output device has changed, restarting MPD Nov 20 20:15:31 volumio sudo[4244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 20 20:15:31 volumio sudo[4244]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio sudo[4244]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: info: Output device has changed, restarting Shairport Sync Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:31 volumio sudo[4247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 20 20:15:31 volumio sudo[4247]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio volumio[1035]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 20 20:15:31 volumio volumio[1035]: info: MPD Permissions set Nov 20 20:15:31 volumio volumio[1035]: info: MPD Permissions set Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio systemd[1]: mpd.service: Succeeded. Nov 20 20:15:31 volumio systemd[1]: Stopped Music Player Daemon. Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio systemd[1]: Starting Music Player Daemon... Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:31 volumio volumio[1035]: info: VolumeController::SetAlsaVolume0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio sudo[4253]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 20 20:15:31 volumio sudo[4253]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio sudo[4253]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: info: VolumeController::SetAlsaVolume0 Nov 20 20:15:31 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:31 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:31 volumio volumio[1035]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Nov 20 20:15:31 volumio volumio[1035]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Nov 20 20:15:31 volumio volumio[1035]: info: Starting Shairport Sync Nov 20 20:15:31 volumio volumio[1035]: info: Starting Shairport Sync Nov 20 20:15:31 volumio sudo[4271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 20 20:15:31 volumio sudo[4271]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 20 20:15:31 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 20 20:15:31 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:31 volumio sudo[4274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 20 20:15:31 volumio sudo[4274]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:31 volumio sudo[4271]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:31 volumio volumio[1035]: info: Shairport-Sync Started Nov 20 20:15:31 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 20 20:15:31 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 20 20:15:31 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 20 20:15:31 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:31 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:31 volumio sudo[4274]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: info: Shairport-Sync Started Nov 20 20:15:31 volumio mpd[4267]: Nov 20 20:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 20 20:15:31 volumio systemd[1]: Started Music Player Daemon. Nov 20 20:15:31 volumio sudo[4247]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio sudo[4238]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:31 volumio volumio[1035]: error: MPD error: The expression evaluated to a falsy value: Nov 20 20:15:31 volumio volumio[1035]: assert.ok(self.idling) Nov 20 20:15:31 volumio volumio[1035]: error: The expression evaluated to a falsy value: Nov 20 20:15:31 volumio volumio[1035]: assert.ok(self.idling) Nov 20 20:15:31 volumio volumio[1035]: error: updateQueue error: null Nov 20 20:15:32 volumio volumio[1035]: error: Upnp client error: Error: This socket has been ended by the other party Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 20 20:15:35 volumio volumio[1035]: info: CoreStateMachine::getcurrentVolume Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:35 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:35 volumio volumio[1035]: info: CoreStateMachine::updateTrackBlock Nov 20 20:15:35 volumio volumio[1035]: info: CorePlayQueue::getTrackBlock Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:35 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:35 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:40 volumio volumio[1035]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 20 20:15:40 volumio volumio[1035]: info: Preparing to save Alsa Options, stopping services first Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::volumioPause Nov 20 20:15:40 volumio volumio[1035]: info: CoreStateMachine::pause Nov 20 20:15:40 volumio volumio[1035]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"SMSL USB AUDIO"}} Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:40 volumio volumio[1035]: info: Setting default mixerSoftMaster for Softvolume device Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 20 20:15:40 volumio volumio[1035]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 20 20:15:40 volumio volumio[1035]: info: Disabling external Volume Control Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 20 20:15:40 volumio volumio[1035]: info: Enable softmixer device for audio device undefined Nov 20 20:15:40 volumio volumio[1035]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 20 20:15:40 volumio volumio[1035]: info: Software Volume ALSA configuration written Nov 20 20:15:40 volumio volumio[1035]: info: Preparing to generate the ALSA configuration file Nov 20 20:15:40 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:40 volumio volumio[1035]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 20 20:15:40 volumio volumio[1035]: info: Reading ALSA contributions from plugins. Nov 20 20:15:40 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:40 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:40 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:40 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:40 volumio volumio[1035]: info: Asound.conf file written Nov 20 20:15:40 volumio sudo[4314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 20 20:15:40 volumio sudo[4314]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio sudo[4314]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: info: Output device has changed, restarting MPD Nov 20 20:15:40 volumio sudo[4319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 20 20:15:40 volumio sudo[4319]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio sudo[4319]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: info: Output device has changed, restarting Shairport Sync Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:40 volumio sudo[4322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 20 20:15:40 volumio sudo[4322]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio systemd[1]: Stopping Music Player Daemon... Nov 20 20:15:40 volumio volumio[1035]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 20 20:15:40 volumio volumio[1035]: info: Output device has changed, restarting MPD Nov 20 20:15:40 volumio systemd[1]: mpd.service: Succeeded. Nov 20 20:15:40 volumio systemd[1]: Stopped Music Player Daemon. Nov 20 20:15:40 volumio sudo[4328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 20 20:15:40 volumio sudo[4328]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio systemd[1]: Starting Music Player Daemon... Nov 20 20:15:40 volumio volumio[1035]: info: Output device has changed, restarting Shairport Sync Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:40 volumio sudo[4328]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio sudo[4332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 20 20:15:40 volumio sudo[4332]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 20 20:15:40 volumio systemd[1]: mpd.service: Succeeded. Nov 20 20:15:40 volumio systemd[1]: Stopped Music Player Daemon. Nov 20 20:15:40 volumio systemd[1]: Starting Music Player Daemon... Nov 20 20:15:40 volumio volumio[1035]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 20 20:15:40 volumio volumio[1035]: info: MPD Permissions set Nov 20 20:15:40 volumio volumio[1035]: info: MPD Permissions set Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 20 20:15:40 volumio sudo[4337]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 20 20:15:40 volumio sudo[4337]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio sudo[4337]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 20 20:15:40 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:40 volumio volumio[1035]: info: Starting Shairport Sync Nov 20 20:15:40 volumio volumio[1035]: info: Starting Shairport Sync Nov 20 20:15:40 volumio sudo[4354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 20 20:15:40 volumio sudo[4354]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 20 20:15:40 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 20 20:15:40 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:40 volumio sudo[4357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 20 20:15:40 volumio sudo[4357]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:40 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:40 volumio sudo[4354]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: info: Shairport-Sync Started Nov 20 20:15:40 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 20 20:15:40 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 20 20:15:40 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 20 20:15:40 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:40 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:40 volumio sudo[4357]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: info: Shairport-Sync Started Nov 20 20:15:40 volumio mpd[4346]: Nov 20 20:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 20 20:15:40 volumio systemd[1]: Started Music Player Daemon. Nov 20 20:15:40 volumio sudo[4332]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio sudo[4322]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:40 volumio volumio[1035]: error: MPD error: The expression evaluated to a falsy value: Nov 20 20:15:40 volumio volumio[1035]: assert.ok(self.idling) Nov 20 20:15:40 volumio volumio[1035]: error: The expression evaluated to a falsy value: Nov 20 20:15:40 volumio volumio[1035]: assert.ok(self.idling) Nov 20 20:15:40 volumio volumio[1035]: error: updateQueue error: null Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 20 20:15:44 volumio volumio[1035]: info: CoreStateMachine::getcurrentVolume Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:44 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:44 volumio volumio[1035]: info: CoreStateMachine::updateTrackBlock Nov 20 20:15:44 volumio volumio[1035]: info: CorePlayQueue::getTrackBlock Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:44 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 84 Nov 20 20:15:44 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 20 20:15:44 volumio volumio[1035]: info: Discovery: Getting this device information Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:15:44 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 20 20:15:45 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:15:45 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:15:45 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:15:45 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:45 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:15:45 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:45 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:45 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:15:45 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:15:45 volumio volumio[1035]: info: sendMpdCommand play took 0 milliseconds Nov 20 20:15:46 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:15:46 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:15:46 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:15:46 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:46 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:15:46 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:46 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:46 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:15:46 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:15:46 volumio volumio[1035]: info: sendMpdCommand play took 0 milliseconds Nov 20 20:15:47 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:15:47 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:15:47 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:15:47 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:47 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:15:47 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:47 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:47 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:15:47 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:15:47 volumio volumio[1035]: info: sendMpdCommand play took 0 milliseconds Nov 20 20:15:48 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:15:48 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:15:48 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:15:48 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:48 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:15:48 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:48 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:48 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:15:48 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:15:48 volumio volumio[1035]: info: sendMpdCommand play took 1 milliseconds Nov 20 20:15:49 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:15:49 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:15:49 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:15:49 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:49 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:15:49 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:15:49 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:15:49 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:15:49 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:15:49 volumio volumio[1035]: info: sendMpdCommand play took 1 milliseconds Nov 20 20:15:51 volumio volumio[1035]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 20 20:15:51 volumio volumio[1035]: info: Preparing to save Alsa Options, stopping services first Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::volumioPause Nov 20 20:15:51 volumio volumio[1035]: info: CoreStateMachine::pause Nov 20 20:15:51 volumio volumio[1035]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"SMSL USB AUDIO"}} Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:51 volumio volumio[1035]: info: Setting default mixerSoftMaster for Softvolume device Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 20 20:15:51 volumio volumio[1035]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 20 20:15:51 volumio volumio[1035]: info: Disabling external Volume Control Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 20 20:15:51 volumio volumio[1035]: info: Enable softmixer device for audio device undefined Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 20 20:15:51 volumio volumio[1035]: info: Software Volume ALSA configuration written Nov 20 20:15:51 volumio volumio[1035]: info: Preparing to generate the ALSA configuration file Nov 20 20:15:51 volumio volumio[1035]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 20 20:15:51 volumio volumio[1035]: info: Reading ALSA contributions from plugins. Nov 20 20:15:51 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:51 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 20 20:15:51 volumio volumio[1035]: SPOTIFY: SPOTIFY VOLUME 83 Nov 20 20:15:51 volumio volumio[1035]: SPOTIFY: VOLUMIO VOLUME 100 Nov 20 20:15:51 volumio volumio[1035]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 20 20:15:51 volumio volumio[1035]: info: Setting Spotify Volume from Volumio: 100 Nov 20 20:15:51 volumio volumio[1035]: info: Asound.conf file unchanged, so no further update is needed Nov 20 20:15:51 volumio volumio[1035]: info: Output device has changed, restarting MPD Nov 20 20:15:51 volumio sudo[4443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 20 20:15:51 volumio sudo[4443]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:51 volumio sudo[4443]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:51 volumio volumio[1035]: info: Output device has changed, restarting Shairport Sync Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:51 volumio sudo[4446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 20 20:15:51 volumio sudo[4446]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:51 volumio systemd[1]: Stopping Music Player Daemon... Nov 20 20:15:51 volumio volumio[1035]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 20 20:15:51 volumio volumio[1035]: info: MPD Permissions set Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio systemd[1]: mpd.service: Succeeded. Nov 20 20:15:51 volumio systemd[1]: Stopped Music Player Daemon. Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 20 20:15:51 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 20 20:15:51 volumio volumio[1035]: info: Starting Shairport Sync Nov 20 20:15:51 volumio sudo[4459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 20 20:15:51 volumio sudo[4459]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:51 volumio systemd[1]: Starting Music Player Daemon... Nov 20 20:15:51 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 20 20:15:51 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 20 20:15:51 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:51 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 20 20:15:51 volumio sudo[4459]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:51 volumio volumio[1035]: info: Shairport-Sync Started Nov 20 20:15:51 volumio sudo[4452]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 20 20:15:51 volumio sudo[4452]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 20 20:15:51 volumio sudo[4452]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:52 volumio mpd[4465]: Nov 20 20:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 20 20:15:52 volumio systemd[1]: Started Music Player Daemon. Nov 20 20:15:52 volumio sudo[4446]: pam_unix(sudo:session): session closed for user root Nov 20 20:15:52 volumio volumio[1035]: error: updateQueue error: null Nov 20 20:15:53 volumio volumio[1035]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Nov 20 20:15:53 volumio volumio[1035]: info: Sending Spotify command with payload to local API: /player/volume Nov 20 20:15:53 volumio volumio[1035]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 20 20:15:55 volumio volumio[1035]: info: CoreStateMachine::getcurrentVolume Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:55 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:55 volumio volumio[1035]: info: CoreStateMachine::updateTrackBlock Nov 20 20:15:55 volumio volumio[1035]: info: CorePlayQueue::getTrackBlock Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::volumioRetrievevolume Nov 20 20:15:55 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 20 20:15:55 volumio volumio[1035]: info: CoreStateMachine::pushState Nov 20 20:15:55 volumio volumio[1035]: info: CoreCommandRouter::volumioPushState Nov 20 20:15:55 volumio volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 20 20:15:58 volumio volumio[1035]: info: CoreCommandRouter::volumioNext Nov 20 20:15:58 volumio volumio[1035]: info: CoreStateMachine::next Nov 20 20:15:58 volumio volumio[1035]: info: ControllerMpd::next Nov 20 20:15:58 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand next Nov 20 20:16:01 volumio volumio[1035]: info: CoreCommandRouter::volumioPlay Nov 20 20:16:01 volumio volumio[1035]: info: CoreStateMachine::play index undefined Nov 20 20:16:01 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 20 20:16:01 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:16:01 volumio volumio[1035]: info: CoreStateMachine::startPlaybackTimer Nov 20 20:16:01 volumio volumio[1035]: info: CorePlayQueue::getTrack 0 Nov 20 20:16:01 volumio volumio[1035]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 20 20:16:01 volumio volumio[1035]: info: ControllerMpd::resume Nov 20 20:16:01 volumio volumio[1035]: verbose: ControllerMpd::sendMpdCommand play Nov 20 20:16:01 volumio volumio[1035]: info: sendMpdCommand play took 0 milliseconds Nov 20 20:16:06 volumio ntpd[1374]: 71.19.144.140 local addr 192.168.1.164 -> Nov 20 20:16:08 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: ytmusic , handleBrowseUri Nov 20 20:16:08 volumio volumio[1035]: info: [ytmusic-browse] browseUri: ytmusic Nov 20 20:16:08 volumio volumio[1035]: info: Preload queue cleared Nov 20 20:16:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 20 20:16:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 20 20:16:14 volumio volumio[1035]: info: Discovery: Getting this device information Nov 20 20:16:14 volumio volumio[1035]: info: CoreCommandRouter::volumioGetState Nov 20 20:16:14 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 20 20:16:26 volumio volumio[1035]: info: CoreCommandRouter::executeOnPlugin: metavolumio , superSearch Nov 20 20:16:26 volumio volumio[1035]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 20 20:16:26 volumio volumio[1035]: TypeError: Cannot read property 'then' of undefined Nov 20 20:16:26 volumio volumio[1035]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:498:20) Nov 20 20:16:26 volumio volumio[1035]: at Socket.emit (events.js:400:28) Nov 20 20:16:26 volumio volumio[1035]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 20 20:16:26 volumio volumio[1035]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Nov 20 20:16:26 volumio volumio[1035]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 20 20:16:26 volumio sudo[4493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-20 20:15 Nov 20 20:16:26 volumio sudo[4493]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"