Setting voice volume fails with ADSP_EFAILED error

fredldotme commented 3 years ago
Snippet from the dmesg output (call is initiated, then volume attempted to be changed):
[  358.419558] msm_tdm_snd_startup: cpu_dai->id is not 2nd tdm, do nothing.
[  358.431893] afe_get_cal_topology_id: cal_type 8 not initialized for this port 36865
[  358.431909] afe_get_cal_topology_id: cal_type 9 not initialized for this port 36865
[  358.431918] send_afe_cal_type cal_block not found!!
[  358.431923] send_afe_cal_type cal_block not found!!
[  358.432612] afe_tdm_port_start: port_id:0x9001
[  358.439061] msm_anlg_cdc_codec_micbias_control: event = 1 micbias_enable = 0 lower_micbias = 0
[  358.439082] pmic_analog_codec c440000.qcom,spmi:qcom,pm660l@3:analog-codec@f000: msm_anlg_cdc_codec_enable_on_demand_supply: enable cdc-vdd-mic-bias success
[  358.495036] CPU4: Booted secondary processor [517f803c]
[  358.501164] CPU2: update max cpu_capacity 517
[  358.530744] cs35l36 0-0040: PLL Unlocked
[  358.532291] afe_get_cal_topology_id: cal_type 8 not initialized for this port 36880
[  358.532308] afe_get_cal_topology_id: cal_type 9 not initialized for this port 36880
[  358.532319] send_afe_cal_type cal_block not found!!
[  358.533066] afe_tdm_port_start: port_id:0x9010
[  358.536779] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536815] crus_afe_set_param: afe port is not cirrus's topology
[  358.536820] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536822] crus_afe_set_param: afe port is not cirrus's topology
[  358.536826] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536829] crus_afe_set_param: afe port is not cirrus's topology
[  358.536832] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536834] crus_afe_set_param: afe port is not cirrus's topology
[  358.536838] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536840] crus_afe_set_param: afe port is not cirrus's topology
[  358.536843] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536845] crus_afe_set_param: afe port is not cirrus's topology
[  358.536849] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536851] crus_afe_set_param: afe port is not cirrus's topology
[  358.536854] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536856] crus_afe_set_param: afe port is not cirrus's topology
[  358.536860] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536862] crus_afe_set_param: afe port is not cirrus's topology
[  358.536865] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536867] crus_afe_set_param: afe port is not cirrus's topology
[  358.536870] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536872] crus_afe_set_param: afe port is not cirrus's topology
[  358.536877] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536879] crus_afe_set_param: afe port is not cirrus's topology
[  358.536882] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536884] crus_afe_set_param: afe port is not cirrus's topology
[  358.536888] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536889] crus_afe_set_param: afe port is not cirrus's topology
[  358.536893] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536895] crus_afe_set_param: afe port is not cirrus's topology
[  358.536898] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536900] crus_afe_set_param: afe port is not cirrus's topology
[  358.536903] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536905] crus_afe_set_param: afe port is not cirrus's topology
[  358.536909] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536910] crus_afe_set_param: afe port is not cirrus's topology
[  358.536914] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536916] crus_afe_set_param: afe port is not cirrus's topology
[  358.536919] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536922] crus_afe_set_param: afe port is not cirrus's topology
[  358.536925] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536927] crus_afe_set_param: afe port is not cirrus's topology
[  358.536931] crus_afe_set_param: port = 36880 module = 268595283 param = 0x10002001 length = 4
[  358.536933] crus_afe_set_param: afe port is not cirrus's topology
[  358.551434] voice_get_cal: No cal data for cal 8!
[  358.551458] voice_send_cvs_register_cal_cmd: Voice_get_cal failed for cal 7!
[  358.552186] qdsp_cvp_callback: cmd = 0x11371 returned error = 0x2
[  358.552234] voice_send_cvp_register_dev_cfg_cmd: DSP returned error[ADSP_EBADPARAM]
[  358.552250] voice_get_cal: No cal data for cal 2!
[  358.552260] voice_send_cvp_register_cal_cmd: Voice_get_cal failed for cal 2!
[  358.552809] voice_get_cal: No cal data for cal 6!
[  358.552821] voice_send_cvp_register_vol_cal_cmd: Voice_get_cal failed for cal 3!
[  358.554162] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  358.554423] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  358.554436] voice volume failed
[  358.563256] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  358.563573] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  358.579519] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  358.579582] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  358.580081] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  358.580141] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  358.622464] CPU6: Booted secondary processor [516f802d]
[  358.630972] CPU0: update max cpu_capacity 517
[  358.631894] CPU6: update max cpu_capacity 1024
[  358.648557] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  358.648609] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  358.648629] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  358.781901] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  358.822049] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  358.822086] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  358.822102] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  359.020662] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  359.084831] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  359.402340] CPU2: update max cpu_capacity 517
[  359.402365] CPU6: update max cpu_capacity 1024
[  359.503856] binder: 2486 has pending async transaction, but still adding a new transaction to todo list (gbinder bug workaround)
[  359.795471] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  360.161033] CPU4: update max cpu_capacity 517
[  360.808654] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  360.921340] CPU2: update max cpu_capacity 517
[  361.377693] [KEY] gpio_keys_gpio_report_event: key 1-73, (1269) changed to 1
[  361.547696] [KEY] gpio_keys_gpio_report_event: key 1-73, (1269) changed to 0
[  361.706592] irq_migrate_all_off_this_cpu: 4 callbacks suppressed
[  361.706599] IRQ17 no longer affine to CPU2
[  361.706623] IRQ20 no longer affine to CPU2
[  361.706737] IRQ44 no longer affine to CPU2
[  361.706837] IRQ61 no longer affine to CPU2
[  361.706850] IRQ62 no longer affine to CPU2
[  361.706878] IRQ67 no longer affine to CPU2
[  361.706973] IRQ130 no longer affine to CPU2
[  361.706989] IRQ133 no longer affine to CPU2
[  361.707002] IRQ134 no longer affine to CPU2
[  361.707017] IRQ135 no longer affine to CPU2
[  361.710249] CPU1: update max cpu_capacity 517
[  361.821920] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  362.432129] PMIC input: code=114, sts=0x2, bit=0x2, type=1, os=0
[  362.623752] PMIC input: code=114, sts=0x0, bit=0x2, type=1, os=1
[  362.640881] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  362.644126] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  362.835347] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  363.182050] google_charger: l=82 vb=4300 vc=4300 c=-1053 fv=4400000 t=323 s=Fast usb=1 wlc=0
[  363.287892] PMI: smblib_get_apsd_result: APSD_STATUS = 0x01
[  363.287922] google_charger: usbchg=USB_PD usbv=4687 usbc=1579 usbMv=5000 usbMc=3000
[  363.287932] google_charger: MSC_LAST vbatt=4300770 ibatt=-1053222 fv_uv=4400000
[  363.287960] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  363.287979] PMI: smblib_get_prop_dc_online: POWER_PATH_STATUS = 0x95
[  363.850161] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  364.004775] PMIC input: code=114, sts=0x2, bit=0x2, type=1, os=0
[  364.161707] PMIC input: code=114, sts=0x0, bit=0x2, type=1, os=1
[  364.171448] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  364.171622] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  364.474859] PMIC input: code=114, sts=0x2, bit=0x2, type=1, os=0
[  364.646937] PMIC input: code=114, sts=0x0, bit=0x2, type=1, os=1
[  364.657754] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  364.657886] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  364.862367] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  364.871172] PMIC input: code=114, sts=0x2, bit=0x2, type=1, os=0
[  365.011752] PMIC input: code=114, sts=0x0, bit=0x2, type=1, os=1
[  365.021986] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  365.022757] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  365.345931] PMIC input: code=114, sts=0x2, bit=0x2, type=1, os=0
[  365.852373] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  365.852612] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  365.875187] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  365.902053] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  365.902108] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  365.955906] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  365.956481] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.005350] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.005637] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.053837] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.056543] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.110130] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.111510] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.146760] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  366.146780] PMI: smblib_get_prop_dc_online: POWER_PATH_STATUS = 0x95
[  366.146865] PMI: smblib_get_prop_batt_health: BATTERY_CHARGER_STATUS_2 = 0x80
[  366.147001] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  366.147073] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  366.147216] PMI: smblib_get_apsd_result: APSD_STATUS = 0x01
[  366.147348] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  366.147361] PMI: smblib_get_prop_dc_online: POWER_PATH_STATUS = 0x95
[  366.147772] healthd: battery l=82 v=4298 t=32.3 h=2 st=2 c=-1052 fc=2924000 cc=123 chg=a
[  366.155730] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.157002] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.206396] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.206501] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.273962] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.274131] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.308080] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.308885] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.356408] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.356499] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.406668] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.406818] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.458555] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  366.458882] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  366.532311] PMIC input: code=114, sts=0x0, bit=0x2, type=1, os=1
[  366.888612] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  367.127688] [KEY] gpio_keys_gpio_report_event: key 1-73, (1269) changed to 1
[  367.634151] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.634983] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.684370] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.684422] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.742309] CPU2: Booted secondary processor [517f803c]
[  367.750154] CPU0: update max cpu_capacity 517
[  367.756570] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.756789] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.778279] CPU0: update max cpu_capacity 517
[  367.787590] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.787656] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.837430] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.838175] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.868833] CPU1: Booted secondary processor [517f803c]
[  367.880225] CPU0: update max cpu_capacity 517
[  367.885822] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.885870] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.901862] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  367.936301] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.936430] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  367.989320] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  367.989463] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.039464] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.039633] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.087618] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.087763] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.139144] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.139316] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.188138] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.188212] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.240172] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.241790] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.289593] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.289643] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.341683] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.341884] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.379530] CPU3: Booted secondary processor [517f803c]
[  368.387962] CPU3: update max cpu_capacity 517
[  368.390079] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.390137] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.417666] [KEY] gpio_keys_gpio_report_event: key 1-73, (1269) changed to 0
[  368.422153] qdsp_cvp_callback: cmd = 0x112c2 returned error = 0x1
[  368.422200] voice_send_vol_step_cmd: DSP returned error[ADSP_EFAILED]
[  368.915784] PMI: smblib_get_prop_usb_online: POWER_PATH_STATUS = 0x95
[  369.158761] CPU0: update max cpu_capacity 517
[  369.693087] cs35l36_dai_mute_stream: get right impedance failed
[  369.693119] cs35l36_dai_mute_stream: get left impedance failed
[  369.708921] afe_close: port_id = 0x9010
[  369.723006] qdsp_cvp_callback: cmd = 0x1307c returned error = 0x9
[  369.723107] voice_send_cvp_deregister_vol_cal_cmd: DSP returned error[ADSP_EALREADY]
[  369.723298] qdsp_cvp_callback: cmd = 0x1307a returned error = 0x9
[  369.723370] voice_send_cvp_deregister_cal_cmd: DSP returned error[ADSP_EALREADY]
[  369.723566] qdsp_cvp_callback: cmd = 0x11372 returned error = 0xa
[  369.723641] voice_send_cvp_deregister_dev_cfg_cmd: DSP returned error[ADSP_ENOTREADY]
[  369.723845] qdsp_cvs_callback: cmd = 0x1307e returned error = 0x9
[  369.723918] voice_send_cvs_deregister_cal_cmd: DSP returned error[ADSP_EALREADY]
[  369.725658] voice_unmap_cal_block: Cal block is NULL, index 2!
[  369.725677] voice_destroy_mvm_cvs_session: Unmap VOCPROC cal failed
[  369.729927] afe_close: port_id = 0x9001
[  369.737401] msm_anlg_cdc_codec_micbias_control: event = 8 micbias_enable = 0 lower_micbias = 0
[  369.737439] pmic_analog_codec c440000.qcom,spmi:qcom,pm660l@3:analog-codec@f000: msm_anlg_cdc_codec_enable_on_demand_supply: disable cdc-vdd-mic-bias success
[  369.771697] CPU3: Booted secondary processor [517f803c]
[  369.777601] CPU2: update max cpu_capacity 517
rubencarneiro commented 3 years ago
So acess to ADSP by qdsp is broken.
raphaelthegreat commented 3 years ago
Has a fix for this been found? I'm facing the exact same issue with another kernel
fredldotme commented 2 years ago
Disabling the Android audio HAL service from the vendor partition seems to help silence the ADSP errors, but voice volume is still not applied. I'm pretty much out of ideas, so I would really appreciate someone else giving a hint on what is going on here.
rubencarneiro commented 2 years ago
Thats is fixed wit your latest patch @fredldotme . At least on Pixel 3a
rubencarneiro commented 2 years ago
Has a fix for this been found? I'm facing the exact same issue with another kernel
Whats is the device, and halium version
fredldotme commented 2 years ago
Thats is fixed wit your latest patch @fredldotme . At least on Pixel 3a
What do you mean "it's fixed"? I mean it doesn complain in dmesg, but it doesn't set voice call volume either.
rubencarneiro commented 2 years ago
ut it doesn't set voice call volume either.
your right we can only mute or unmute.
rubencarneiro commented 2 years ago
Maybe adding volume index as float int platform_set_voice_volume(void *platform, int volume)
like you didi in sony https://github.com/fredldotme/android_hardware_qcom_audio_aosp/blob/12e6d2f3518daccb3d143c7db5d34d06263926f2/hal/msm8916/platform.c#L1416
fredldotme commented 2 years ago
I tried that already, sadly didn't help. :/
fredldotme commented 2 years ago
Fixed by: https://github.com/fredldotme/android_device_google_bonito/commit/f7d003f1b9c8e4082f3878955ed23c28b318c706
fredldotme / android_kernel_google_bonito

Setting voice volume fails with ADSP_EFAILED error #4
