-- Logs begin at Thu 2019-02-14 06:11:58 AST, end at Thu 2025-05-01 13:25:56 AST. -- May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:24 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:24 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:24 volumio volumio[973]: verbose: New Socket.io Connection to 192.168.2.146:3000 from 192.168.2.113 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:24 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 01 13:25:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 01 13:25:26 volumio sudo[12084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 01 13:25:26 volumio sudo[12082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 01 13:25:26 volumio sudo[12084]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:26 volumio sudo[12082]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:26 volumio sudo[12084]: pam_unix(sudo:session): session closed for user root May 01 13:25:26 volumio sudo[12082]: pam_unix(sudo:session): session closed for user root May 01 13:25:26 volumio volumio[973]: verbose: New Socket.io Connection to 192.168.2.146 from 192.168.2.113 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_4_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 May 01 13:25:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 01 13:25:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 01 13:25:27 volumio sudo[12088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 01 13:25:27 volumio sudo[12088]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:27 volumio sudo[12088]: pam_unix(sudo:session): session closed for user root May 01 13:25:27 volumio sudo[12091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 01 13:25:27 volumio sudo[12091]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:27 volumio sudo[12091]: pam_unix(sudo:session): session closed for user root May 01 13:25:27 volumio volumio[973]: verbose: New Socket.io Connection to 192.168.2.146 from 192.168.2.113 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_4_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:27 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 01 13:25:27 volumio volumio[973]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 01 13:25:27 volumio volumio[973]: info: Received Get System Info May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:27 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:27 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:27 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:27 volumio volumio[973]: info: Listing playlists May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 01 13:25:27 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 01 13:25:28 volumio volumio[973]: info: Received Get System Info May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:28 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:28 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:28 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:29 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 01 13:25:33 volumio volumio[973]: info: CoreCommandRouter::volumioPlay May 01 13:25:33 volumio volumio[973]: info: CoreStateMachine::play index undefined May 01 13:25:33 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined May 01 13:25:33 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:33 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer May 01 13:25:33 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:33 volumio volumio[973]: info: [1746120333764] ControllerQobuz::clearAddPlayTrack May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand stop May 01 13:25:33 volumio volumio[973]: info: May 01 13:25:33 volumio volumio[973]: ---------------------------- MPD announces state update: player May 01 13:25:33 volumio volumio[973]: info: sendMpdCommand stop took 4 milliseconds May 01 13:25:33 volumio volumio[973]: info: ControllerMpd::getState May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clear May 01 13:25:33 volumio volumio[973]: info: May 01 13:25:33 volumio volumio[973]: ---------------------------- MPD announces system playlist update May 01 13:25:33 volumio volumio[973]: info: Ignoring MPD Status Update May 01 13:25:33 volumio volumio[973]: info: sendMpdCommand status took 1 milliseconds May 01 13:25:33 volumio volumio[973]: info: sendMpdCommand clear took 2 milliseconds May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::parseState May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/75133538" May 01 13:25:33 volumio volumio[973]: error: updateQueue error: null May 01 13:25:33 volumio volumio[973]: info: ------------------------------ 2ms May 01 13:25:33 volumio volumio[973]: info: sendMpdCommand playlistinfo took 2 milliseconds May 01 13:25:33 volumio volumio[973]: STREAMING PROXY: Handling url /?data=qobuz://song/75133538 May 01 13:25:33 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo May 01 13:25:33 volumio volumio[973]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 01 13:25:33 volumio volumio[973]: info: ------------------------------ 6ms May 01 13:25:33 volumio volumio[973]: info: Executing endpoint getStreamUrlqobuz May 01 13:25:33 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 01 13:25:34 volumio volumio[973]: info: getStreamUrl took 898 milliseconds May 01 13:25:34 volumio volumio[973]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1506481&eid=75133538&fmt=6&profile=raw&app_id=539451548&cid=2729228&etsp=1746123934&hmac=xatpXD8Ll9TPviZ8Ihmaixvfri4 May 01 13:25:35 volumio volumio[973]: STREAMING PROXY: Response: 200, length: 34186197 May 01 13:25:35 volumio volumio[973]: STREAMING PROXY: Client dropped request, destroying May 01 13:25:35 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/75133538" May 01 13:25:35 volumio volumio[973]: info: May 01 13:25:35 volumio volumio[973]: ---------------------------- MPD announces system playlist update May 01 13:25:35 volumio volumio[973]: info: Ignoring MPD Status Update May 01 13:25:35 volumio volumio[973]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/75133538" took 1 milliseconds May 01 13:25:35 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService mpd May 01 13:25:35 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand play May 01 13:25:35 volumio volumio[973]: info: ------------------------------ 2ms May 01 13:25:35 volumio volumio[973]: info: sendMpdCommand play took 1 milliseconds May 01 13:25:35 volumio volumio[973]: STREAMING PROXY: Handling url /?data=qobuz://song/75133538 May 01 13:25:35 volumio volumio[973]: info: Executing endpoint getStreamUrlqobuz May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 01 13:25:35 volumio volumio[973]: info: Received Get System Info May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:35 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:36 volumio volumio[973]: info: getStreamUrl took 999 milliseconds May 01 13:25:36 volumio volumio[973]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1506481&eid=75133538&fmt=6&profile=raw&app_id=539451548&cid=2729228&etsp=1746123936&hmac=p4kp3A22Zn6JTOhYMK8rgUN0cG8 May 01 13:25:36 volumio volumio[973]: STREAMING PROXY: Response: 200, length: 34186197 May 01 13:25:36 volumio volumio[973]: info: May 01 13:25:36 volumio volumio[973]: ---------------------------- MPD announces state update: player May 01 13:25:36 volumio volumio[973]: info: ControllerMpd::getState May 01 13:25:36 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status May 01 13:25:36 volumio volumio[973]: info: May 01 13:25:36 volumio volumio[973]: ---------------------------- MPD announces state update: player May 01 13:25:36 volumio volumio[973]: info: ControllerMpd::getState May 01 13:25:36 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand status took 10 milliseconds May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::parseState May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand status took 19 milliseconds May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand clearerror took 11 milliseconds May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand playlistinfo took 9 milliseconds May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::parseState May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo May 01 13:25:37 volumio volumio[973]: info: ControllerMpd::pushState May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::servicePushState May 01 13:25:37 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:37 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":291,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"75133538","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/75133538","trackType":"qobuz"} May 01 13:25:37 volumio volumio[973]: verbose: CURRENT POSITION 28 May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::pushState May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::volumioPushState May 01 13:25:37 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device May 01 13:25:37 volumio volumio[973]: info: MRS: Pushing multiroomSync output May 01 13:25:37 volumio volumio[973]: info: ------------------------------ 53ms May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand clearerror took 40 milliseconds May 01 13:25:37 volumio volumio[973]: info: sendMpdCommand playlistinfo took 38 milliseconds May 01 13:25:37 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo May 01 13:25:37 volumio volumio[973]: info: ControllerMpd::pushState May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::servicePushState May 01 13:25:37 volumio volumio[973]: info: CorePlayQueue::getTrack 28 May 01 13:25:37 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":291,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"75133538","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/75133538","trackType":"qobuz"} May 01 13:25:37 volumio volumio[973]: verbose: CURRENT POSITION 28 May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop May 01 13:25:37 volumio volumio[973]: info: CoreStateMachine::pushState May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::volumioPushState May 01 13:25:37 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device May 01 13:25:37 volumio volumio[973]: info: MRS: Pushing multiroomSync output May 01 13:25:37 volumio volumio[973]: info: ------------------------------ 90ms May 01 13:25:37 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 13:25:39 volumio volumio[973]: Invalid card number. May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 01 13:25:39 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 01 13:25:46 volumio volumio[973]: STREAMING PROXY: Client dropped request, destroying May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 01 13:25:47 volumio volumio[973]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 01 13:25:47 volumio volumio[973]: info: Received Get System Version May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 01 13:25:47 volumio volumio[973]: info: Received Get System Info May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:47 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:52 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 01 13:25:52 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 01 13:25:52 volumio volumio[973]: info: Discovery: Getting this device information May 01 13:25:52 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:52 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 13:25:53 volumio volumio[973]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 01 13:25:53 volumio volumio[973]: info: Preparing to save Alsa Options, stopping services first May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::volumioGetState May 01 13:25:53 volumio volumio[973]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"M15i Mobile Headphone Amplifier"},"i2s":true,"i2sid":{"value":"audiophonics-es9028q2m-dac","label":"Audiophonics I-Sabre ES9028Q2M"}} May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:53 volumio volumio[973]: info: Enabling I2S DAC: Audiophonics I-Sabre ES9028Q2M May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:53 volumio sudo[12150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l May 01 13:25:53 volumio sudo[12150]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:53 volumio sudo[12150]: pam_unix(sudo:session): session closed for user root May 01 13:25:53 volumio volumio[973]: info: No Overlays Loaded May 01 13:25:53 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio sudo[12153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay i-sabre-q2m May 01 13:25:54 volumio sudo[12153]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible May 01 13:25:54 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller May 01 13:25:54 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status May 01 13:25:54 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status May 01 13:25:54 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2c@7e804000/status May 01 13:25:54 volumio volumio[973]: warn: Unable to locate the device M15i Mobile Headphone Amplifier a reboot may be required. May 01 13:25:54 volumio sudo[12153]: pam_unix(sudo:session): session closed for user root May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio volumio[973]: info: Found match in i2s Card Database: setting mixer Digital for card Audiophonics I-Sabre ES9028Q2M May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 01 13:25:54 volumio volumio[973]: info: Updating Volume Controller Parameters: Device: 2 Name: Audiophonics I-Sabre ES9028Q2M Mixer: Digital Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 01 13:25:54 volumio volumio[973]: info: Disabling external Volume Control May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction May 01 13:25:54 volumio volumio[973]: info: Preparing to generate the ALSA configuration file May 01 13:25:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000001] -121 May 01 13:25:54 volumio kernel: snd-rpi-i-sabre-q2m soc:sound: Audiophonics Device ID : FFFFFF87 May 01 13:25:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000002] -121 May 01 13:25:54 volumio kernel: snd-rpi-i-sabre-q2m soc:sound: Audiophonics API revision : FFFFFF87 May 01 13:25:54 volumio volumio[973]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 01 13:25:54 volumio volumio[973]: info: Reading ALSA contributions from plugins. May 01 13:25:54 volumio volumio[973]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. May 01 13:25:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -5 May 01 13:25:54 volumio volumio[973]: info: I2S Param [object Object] successfully enabled May 01 13:25:54 volumio volumio[973]: info: VolumeController:: Volume=undefined Mute =false May 01 13:25:54 volumio volumio[973]: info: CoreStateMachine::pushState May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::volumioPushState May 01 13:25:54 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device May 01 13:25:54 volumio volumio[973]: info: MRS: Pushing multiroomSync output May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 13:25:54 volumio volumio[973]: info: Getting Alsa Cards List without I2S DAC May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio volumio[973]: Invalid card number. May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 01 13:25:54 volumio volumio[973]: info: Asound.conf file written May 01 13:25:54 volumio sudo[12200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 01 13:25:54 volumio sudo[12200]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio sudo[12200]: pam_unix(sudo:session): session closed for user root May 01 13:25:54 volumio volumio[973]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Digital Playback Switch:0' : Remote I/O error May 01 13:25:54 volumio volumio[973]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:FIR Filter Type:0' : Invalid argument May 01 13:25:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 01 13:25:54 volumio volumio[973]: info: Output device has changed, restarting MPD May 01 13:25:54 volumio sudo[12206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 13:25:54 volumio sudo[12206]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio volumio[973]: info: Output device has changed, restarting Shairport Sync May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio sudo[12206]: pam_unix(sudo:session): session closed for user root May 01 13:25:54 volumio sudo[12209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 13:25:54 volumio sudo[12209]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio systemd[1]: Stopping Music Player Daemon... May 01 13:25:54 volumio volumio[973]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 01 13:25:54 volumio volumio[973]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:54 volumio volumio[973]: info: Output device has changed, restarting MPD May 01 13:25:54 volumio vtcs[2191]: [2025-05-01 13:25:54.878] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 01 13:25:54 volumio vtcs[2191]: [2025-05-01 13:25:54.873] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 01 13:25:54 volumio sudo[12217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 01 13:25:54 volumio sudo[12217]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio systemd[1]: Stopping Volumio Tidal Connect Service... May 01 13:25:54 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 01 13:25:54 volumio systemd[1]: vtcs.service: Succeeded. May 01 13:25:54 volumio systemd[1]: Stopped Volumio Tidal Connect Service. May 01 13:25:54 volumio volumio[973]: info: Output device has changed, restarting Shairport Sync May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:54 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:54 volumio sudo[12217]: pam_unix(sudo:session): session closed for user root May 01 13:25:54 volumio sudo[12220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 13:25:54 volumio sudo[12220]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:54 volumio sudo[12220]: pam_unix(sudo:session): session closed for user root May 01 13:25:54 volumio sudo[12223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 13:25:54 volumio sudo[12223]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio volumio[973]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 01 13:25:55 volumio volumio[973]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio systemd[1]: mpd.service: Succeeded. May 01 13:25:55 volumio systemd[1]: Stopped Music Player Daemon. May 01 13:25:55 volumio sudo[12233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 01 13:25:55 volumio sudo[12233]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio systemd[1]: Starting Music Player Daemon... May 01 13:25:55 volumio sudo[12236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 01 13:25:55 volumio sudo[12236]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio sudo[12236]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio sudo[12233]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio sudo[12245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 01 13:25:55 volumio sudo[12245]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio sudo[12230]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 01 13:25:55 volumio sudo[12230]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio sudo[12245]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 01 13:25:55 volumio sudo[12230]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio volumio[973]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 01 13:25:55 volumio volumio[973]: info: MPD Permissions set May 01 13:25:55 volumio volumio[973]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 01 13:25:55 volumio volumio[973]: info: MPD Permissions set May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 13:25:55 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 13:25:55 volumio volumio[973]: info: Starting Shairport Sync May 01 13:25:55 volumio volumio[973]: info: Starting Shairport Sync May 01 13:25:55 volumio sudo[12301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 13:25:55 volumio sudo[12301]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio sudo[12304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 13:25:55 volumio sudo[12304]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 13:25:55 volumio systemd[1]: shairport-sync.service: Succeeded. May 01 13:25:55 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 01 13:25:55 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 13:25:55 volumio sudo[12301]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 13:25:55 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 01 13:25:55 volumio systemd[1]: shairport-sync.service: Succeeded. May 01 13:25:55 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running May 01 13:25:55 volumio volumio[973]: info: Shairport-Sync Started May 01 13:25:55 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 13:25:55 volumio sudo[12304]: pam_unix(sudo:session): session closed for user root May 01 13:25:55 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 01 13:25:55 volumio volumio[973]: info: Shairport-Sync Started May 01 13:25:56 volumio mpd[12263]: May 01 13:25 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 01 13:25:56 volumio systemd[1]: Started Music Player Daemon. May 01 13:25:56 volumio sudo[12209]: pam_unix(sudo:session): session closed for user root May 01 13:25:56 volumio sudo[12223]: pam_unix(sudo:session): session closed for user root May 01 13:25:56 volumio volumio[973]: error: MPD error: The expression evaluated to a falsy value: May 01 13:25:56 volumio volumio[973]: assert.ok(self.idling) May 01 13:25:56 volumio volumio[973]: error: The expression evaluated to a falsy value: May 01 13:25:56 volumio volumio[973]: assert.ok(self.idling) May 01 13:25:56 volumio volumio[973]: error: updateQueue error: null May 01 13:25:56 volumio volumio[973]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ May 01 13:25:56 volumio volumio[973]: info: PLUGIN onReboot : networkfs May 01 13:25:56 volumio volumio[973]: info: PLUGIN onReboot : audiophonicsonoff May 01 13:25:56 volumio volumio[973]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 13:25:56 volumio volumio[973]: TypeError: Cannot read property 'writeSync' of undefined May 01 13:25:56 volumio volumio[973]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25) May 01 13:25:56 volumio volumio[973]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) May 01 13:25:56 volumio volumio[973]: at HashMap. (/volumio/app/pluginmanager.js:668:31) May 01 13:25:56 volumio volumio[973]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 01 13:25:56 volumio volumio[973]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 01 13:25:56 volumio volumio[973]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) May 01 13:25:56 volumio volumio[973]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22) May 01 13:25:56 volumio volumio[973]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33) May 01 13:25:56 volumio volumio[973]: at Socket.emit (events.js:315:20) May 01 13:25:56 volumio volumio[973]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 01 13:25:56 volumio volumio[973]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 01 13:25:56 volumio volumio[973]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 13:25:56 volumio sudo[12324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-01 13:24 May 01 13:25:56 volumio sudo[12324]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"