[q-mr1] [AUDIO] cirrus_sony: Calibration fix for mono calibration

[krnlyng]

On SailfishOS we observe that the calibration of the cirrus device fails, noticeable by a frequency sweep noise during bootup.
Fix this by cherry-picking the related fixed from the aosp/LA.UM.9.12.r1 branch. And also fix the calibration for mono.

Part 1: Cherry-pick #20 and #21 onto q-mr1 and fix conflicts.
Part 2:
64f5f62: Seems in mono calibration the different firmware names need to be accounted for too. Probably good to cherry-pick this onto aosp/LA.UM.9.12.r1 too.
af0763a: Initially i thought this was my issue but it turned out it wasn't, but i guess it's still a nice addition. Can drop if wanted.

[MarijnS95]

Damn sure I had a rebase-branch for these on Q at some point but forgot to submit it, thanks!

Looks like something went wrong during conflict resolution, 64f5f62 moves a function down presumably because the new functions were first added below and later moved above.

[krnlyng]

@MarijnS95 argh, sorry i am not sure why this happens, i actually changed the function cirrus_do_fw_mono_download to use the cirrus_write_cal_status and cirrus_write_cal_checksum. but i had to move the two functions up before the cirrus_do_fw_mono_download function. so the diff looks a bit strange, but it does what it's supposed to do :/
I'm not sure if there is a way to tell git to show this in a smarter way.

[krnlyng]

Maybe it might make sense to move the functions in a seperate commit and do the fix in another?

[krnlyng]

Ok now it should be more clear what i've actually done in 1b4c272 :)

[krnlyng]

Hmm it seems that even with those changes calibration fails in some cases and i am not sure why.

03-11 11:58:52.017 4452 4895 D audio_hw_primary: check_usecases_codec_backend:becf: check_usecases num.of Usecases to switch 0
03-11 11:58:52.017 4452 4895 D hardware_info: hw_info_append_hw_type : device_name = speaker
03-11 11:58:52.025 4452 4895 D audio_hw_sony_cirrus_playback: cirrus_set_force_wake: Set Hibernate Force Wake enable
03-11 11:58:52.025 4452 4895 I audio_hw_sony_cirrus_playback: spkr_prot_start_processing: Forbidden. Calibration failed.
03-11 11:58:52.026 4452 4895 E audio_hw_primary: enable_snd_device: spkr_start_processing failed

Any clues?

Sometimes the /data/vendor/audio/cirrus_sony.cal file appears, sometimes not.
If i strace pulseaudio (which in our case loads the audio.primary.sm6125.so file) it seems to work - timing issue?

Some more logs:
03-11 12:51:46.872 4710 4774 D audio_hw_sony_cirrus_playback: cirrus_play_silence: Usecase present retry speaker protection
03-11 12:51:46.872 4710 4774 W audio_hw_sony_cirrus_playback: cirrus_mono_calibration: Playing silence went wrong, calibration may fail...

[MarijnS95]

@krnlyng It is clear what happened: Angelo introduced those functions above cirrus_do_fw_stereo_download but not above cirrus_do_fw_mono_download for reuse. Over the total patch series the diff is simply adding the cirrus_write_cal_checksum/cirrus_write_cal_status helper functions in the right spot, but that single commit appears to be removing cirrus_do_fw_mono_download first, followed by those helper functions remaining untouched in-place.

Perhaps it is better to amend that commit and put those functions in the right place directly. Note that we are really not opposed to force-pushing branches where it improves workflow and readability so we might as well reapply those commits with proper ordering on 9.12 as well.

---

Is PA trying to play any audio while the calibration hasn't fully finished? We faced that while building and debugging the support for Edo devices - if anything is played, even during the 6 seconds of waiting for the firmware to complete its thing, it gets stuck in some unrecoverable error state. I don't exactly remember what error that is though.
This wasn't easily solvable and anyway not a case that is expected during boot calibration.

[jerpelea]

@krnlyng please fix it so that I can merge the PR

[krnlyng]

Ah yes we tried delaying the playback for a little bit in the calibration case but it wasn't enough (iirc we tried 2-3 seconds, but that is now obvious that this is too short when the calibration is running, 6 seconds is a lot :O). Will try with a bigger delay.
I have amened the commit which moves the functions into the one from @kholk. I hope it is better now. Please doublecheck it doesn't break on android i've only tested SailfishOS.

[kholk]

Last time I was debugging the calibration issues happening when a playback race happened (rather rare at Android first boot) with @MarijnS95 ... but anyway, I've extensively tested the calibration commits and they're perfectly working on my Edo device (dual CS345L41).

The sleep(6) was removed in the commit named "cirrus_sony: Loop around DSP state after calibration" - probably something went wrong during the cleanup phase, because effectively that commit doesn't contain the removal of that call, which becomes useless with the waitloop around calibration, as that was meant to be an optimization of that stupid blindly-sleep-until-done thing.

Regarding your concern about timing issues, yes - it looks like, as Marijn said, when the audio pipe gets opened issues come around. This is not a huge issue on Android, as the startup is mostly controlled.
With pulseaudio, though, the issue may be more visible and it may actually need some proper corner case fix.

Finally, this PR should be valid - at least, for Android - as I've been using this code for a month or more.

[MarijnS95]

I have amened the commit which moves the functions into the one from @kholk. I hope it is better now. Please doublecheck it doesn't break on android i've only tested SailfishOS.

Great, thanks! I'll give this a test on Android later and probably provide a branch to reset R to, to share the same clean history. If I may have one more picky question: how about moving the changes that call the new functions right after cirrus_sony: Fixes for new firmware mixer names and order? That should allow you to split cirrus_sony: Fixes for new firmware mixer names also for mono calibra… …tion. in two commits and get rid of the nasty title-too-long line break.

Delaying playback is a bit tough because calibration uses the same usecase and playback device, so we can't easily block there (well, we know what thread the call comes from, and iirc did some magic tricks). The plain spkr_prot part of the HAL does this by having a separate usecase and playback device solely for calibration so that the two don't clash.
Maybe we should get this resolved properly instead of the hacky way it is now. @kholk what do you remember, I said something about the exit/close handler changing the state to !calibration (when AOSP failed to grab the audio device) and that was throwing all our safeguards against running playback and calib in parallel astray?

[kholk]

We did it like that initially because we were in a big hurry, a screenshot from our brains at the time:

brain@Marijn-Angelo$ ./develop_edo
Error: -ENOTIME

brain@Marijn-Angelo$ ./develop_edo --force
Error: Working too hard, try again later

But yes you remember right, the audio hal is threaded and the audioserver is threaded, so we got a spkr_prot audio-start callback during "paths discovery" and we would get state changes, but then we sort of solved that with 2abf1a4 ... though there still was some very very rare corner case to be addressed.
I remember, though, at the time I told you "man just push this, the stuff works" - then I don't know what happened, I've been literally buried in work as you know, so I've lost track of this.... :(

[MarijnS95]

I think we ran out of thread ids, process ids, file descriptors and memory at the same time. Still recovering from the crash.

Correct, pthread_self() == handle.calibration_thread should have solved things - it is in both {start,stop}_processing - but then it did not. We both indeed agreed to continue as it works "well enough". Unfortunately some of the fallout seems to hit SFOS now, but I guess that's okay. We can only do so much on a rotten and unstable (== this audio HAL) foundation. The general consensus here is: "let's add more device/path specific edgecases" and our minds simply refuse to write code like that.

@krnlyng Perhaps you can litter some logs around the HAL and understand whether audio playback - or anything else poking the mixers - manages to sneak through while a calibration is still ongoing.

(@kholk Btw I just found get_spkr_prot_snd_device at the bottom of this file, that brings back a lot of memories and some inexplicable feeling of some yet-to-be-uncovered issue... 😬)

[kholk]

I think we ran out of thread ids, process ids, file descriptors and memory at the same time. Still recovering from the crash.

Yup, exactly.

Correct, pthread_self() == handle.calibration_thread should have solved things - it is in both {start,stop}_processing - but then it did not. We both indeed agreed to continue as it works "well enough". Unfortunately some of the fallout seems to hit SFOS now, but I guess that's okay. We can only do so much on a rotten and unstable (== this audio HAL) foundation. The general consensus here is: "let's add more device/path specific edgecases" and our minds simply refuse to write code like that.

It's a bit of a mess, yes, but... at the end of the day, if this is the only solution and the only way to make it work on SFOS and whatever else, probably at this point we should just stop being picky, take the defeat and just do whatever possible workaround on top of another workaround on top of ... :)

I mean, in the end, what counts is that stuff works. Not less, not more.

@krnlyng Perhaps you can litter some logs around the HAL and understand whether audio playback - or anything else poking the mixers - manages to sneak through while a calibration is still ongoing.

Since he is analyzing an usecase involving pulseaudio and a "strange" connection to the audio hal, that may be really useful.

(@kholk Btw I just found get_spkr_prot_snd_device at the bottom of this file, that brings back a lot of memories and some inexplicable feeling of some yet-to-be-uncovered issue... )

OMG no, why are you doing this to me :\

[krnlyng]

@MarijnS95 i can move the commit towards the other one, however i am not sure what you mean by splitting it? which parts should be split into a separate commit? or do you just mean shortening the commit message?

[MarijnS95]

It's a bit of a mess, yes, but... at the end of the day, if this is the only solution and the only way to make it work on SFOS and whatever else, probably at this point we should just stop being picky, take the defeat and just do whatever possible workaround on top of another workaround on top of ... :)

@kholk not saying that we shouldn't fix this, at all, because we really should. There was however no incentive to fix it back then when we were lost for time (we still are?) but this issue hitting SFOS is the right time to restart some debugging efforts.

Since he is analyzing an usecase involving pulseaudio and a "strange" connection to the audio hal, that may be really useful.

Correct. @krnlyng To be more specific - you probably already assumed this - place the logs in cirrus_sony specifically, around the calibration and start/stop_processing codepaths.

OMG no, why are you doing this to me :\

I think I was unsure about why SPEAKER was mapped to SPEAKER_PROTECTED because it did not happen by that generic function elsewhere in the HAL... I guess we were doing it ourselves...

@MarijnS95 i can move the commit towards the other one, however i am not sure what you mean by splitting it? which parts should be split into a separate commit? or do you just mean shortening the commit message?

Split it up in one part that calls the new functions, directly after 11f3eef cirrus_sony: Fixes for new firmware mixer names and order. The second part, retrying "Protection" firmware download should follow 35e6eab cirrus_sony: Loop around DSP state after calibration in a separate commit.

[jerpelea]

@krnlyng please update the PR

[krnlyng]

code changes: https://pastebin.com/EneivSTk
logs: https://pastebin.com/NvWZfD53

(this is a log from a failed calibration - i hope that's what you meant)

[krnlyng]

Ok we now have a solution for this on our side. Basically if the calibration has not been done yet (e.g. the file doesn't exist) we wait 10 seconds after opening the audio HAL before doing something. And if the calibration was already done (file exists) we do not wait and use the HAL immediately, this should be good enough since the calibration will (hopefully) only be done on the first boot.

Together with this PR this seems to work.

But two questions:
Is 10 seconds unreasonable(too long) or too short?
Is it normal that the frequency sweep is audible during calibration? (I see "play silence" methods)

[MarijnS95]

But two questions:
Is 10 seconds unreasonable(too long) or too short?

That's pretty horrible; we should just prevent audio from being played in the HAL, until the device is absolutely ready. I don't fully remember the entire chunk of code but there is no guarantee that the Amp/DSP is up and ready after we've cached the calibration data.

Is it normal that the frequency sweep is audible during calibration? (I see "play silence" methods)

Yes. Silence is for it to detect noise on the line (apparently this is going through an analog signal to the Amp/DSP combo, where it is converted to digital again for "DSP stuff" and finally analog and amplified before it reaches the speaker...), after that the DSP does the whoop all by itself.

[kholk]

Ok we now have a solution for this on our side. Basically if the calibration has not been done yet (e.g. the file doesn't exist) we wait 10 seconds after opening the audio HAL before doing something. And if the calibration was already done (file exists) we do not wait and use the HAL immediately, this should be good enough since the calibration will (hopefully) only be done on the first boot.

Together with this PR this seems to work.

But two questions:
Is 10 seconds unreasonable(too long) or too short?

That's probably the right wait time for a horrible temporary workaround, I don't think you'd need more than that, but it's possible that you get the thing calibrated in less than 6 seconds.
For paranoid safety, just keep it like that.

Is it normal that the frequency sweep is audible during calibration? (I see "play silence" methods)

As Marijn said, yes.

[MarijnS95]

@krnlyng Would you be able to debug this further from a HAL perspective? Afaik the PCM device should not be opened by the HAL if start_processing returns an error code in the first place. After all the right path is then not selected either. If that is true, something else breaks the DSP but we are unsure what - maybe it is selecting a different generic path (that pokes the wrong mixers) before/after start_processing anyway?

[MarijnS95]

Looking at those logs it seems like it happily continues after spkr_start_processing returns an error inside enable_snd_device, selecting low-latency-playback. Yes, it looks like thread 4930 - responsible for the playback - tries to open the PCM device after failing:

03-17 10:56:31.784  4585  4930 E audio_hw_primary: pcm_open_prepare_helper: pcm_prepare returned -1

Anyway, seeing something weird on the calibration thread (4923):

758:03-17 10:56:31.316  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_do_calibration()
759:03-17 10:56:31.316  4585  4923 I audio_hw_sony_cirrus_playback: cirrus_do_calibration: Calibrating with ambient values 0x0 0x0 0x0 0x16
760:03-17 10:56:31.316  4585  4923 D audio_hw_sony_cirrus_playback: cirrus_exec_fw_download: Asking for Calibration (mono/global) firmware without reset
798:03-17 10:56:31.732  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_get_mixer_array_by_name: Cannot get mixer control DSP1 Calibration cd CSPL_ENABLE
799:03-17 10:56:31.735  4585  4923 I audio_hw_sony_cirrus_playback: cirrus_exec_fw_download: Retrying...
863:03-17 10:56:31.750  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_get_mixer_array_by_name: Cannot get mixer control DSP1 Calibration cd CSPL_ENABLE
865:03-17 10:56:31.756  4585  4923 I audio_hw_sony_cirrus_playback: cirrus_exec_fw_download: Retrying...
866:03-17 10:56:31.777  4585  4923 I audio_hw_sony_cirrus_playback: cirrus_exec_fw_download: Cirrus Calibration Firmware Download SUCCESS.
895:03-17 10:56:31.877  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_mono_calibration()
959:03-17 10:56:31.890  4585  4923 D audio_hw_sony_cirrus_playback: cirrus_set_force_wake: Set Hibernate Force Wake enable
961:03-17 10:56:31.901  4585  4923 D audio_hw_sony_cirrus_playback: cirrus_play_silence: Usecase present retry speaker protection
962:03-17 10:56:31.901  4585  4923 W audio_hw_sony_cirrus_playback: cirrus_mono_calibration: Playing silence went wrong, calibration may fail...
963:03-17 10:56:31.907  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_mono_calibration: Calibration failure, status: 0x0 0x0 0x0 0x0
964:03-17 10:56:31.907  4585  4923 E audio_hw_sony_cirrus_playback: <- cirrus_mono_calibratio
965:03-17 10:56:31.907  4585  4923 E audio_hw_sony_cirrus_playback: cirrus_do_calibration: CRITICAL: Calibration failure
966:03-17 10:56:31.907  4585  4923 E audio_hw_sony_cirrus_playback: <- cirrus_do_calibration

I hadn't expected to see Usecase present retry speaker protection, as if we haven't cleaned up our usecase yet (or the playback thread has already attached a usecase for us), perhaps "falsely" failing the calibration. That's probably the area we need to look in: who or why has this usecase, and can we perhaps simply ignore/circumvent it?

[MarijnS95]

@krnlyng I'm picking this back to 9.12 to fix the mono ctls and have the timeout removed, but there are a ton of conflicts because 13b245e supposedly wasn't picked - meaning you had the same conflicts the other way around...

EDIT: Yeah, it even seems like Angelos commit that adds cirrus_write_cal_checksum/cirrus_write_cal_status has been modified to use the old heap-allocation method...

If I'm not mistaken these four are not on q-mr1 and not part of this PR, but come right before the picked commits:

• 06a77e0 - cirrus_sony: Do not return -EINVAL when cirrus_save_calibration succeeds (5 weeks ago)
• 13b245e - cirrus_sony: Remove unnecessary heap allocations for small strings (6 weeks ago)
• d5612b4 - cirrus_sony: Remove unnecessary pointer indirection for strings (6 weeks ago)
• 4793bad - cirrus_sony: Use cirrus_set_mixer_value_by_name_lr helper (6 weeks ago)

(In newest-to-oldest order)

Any reason why they have been unintentionally forgotten about or intentionally not picked? I'd appreciate if we can keep both branches as similar as possible. Attempts to resolve conflicts show that there is quite some divergence going on already.

[krnlyng]

Hi, sorry i got a bit distracted by other things. We tried investigating this a bit from HAL perspective whether we can come up with a better fix than the delays, but unfortunately time didn't agree.
I think i only picked what was on PR #20 and #21, but i will try to revisit this and pick the commits you mentioned as well.

[MarijnS95]

@krnlyng Thanks! I have also backported your patches into the existing 9.12 tree, perhaps it's just as easy to adopt the entire tree here: https://github.com/MarijnS95/vendor-qcom-opensource-audio-hal-primary-hal/commits/9.12-cirrus-patches starting from the initial missed patch, and compare that to what you have here. Those should, theoretically, pick to 8.1 without any conflicts.

[krnlyng]

Hey, sorry to ask again but before i push something/broken/useless:

It seems 1ee5303 is missing from https://github.com/MarijnS95/vendor-qcom-opensource-audio-hal-primary-hal/commits/9.12-cirrus-patches and that causes conflicts when picking. I can of course fix those but is that the right approach here? maybe 1ee5303 should also be on https://github.com/MarijnS95/vendor-qcom-opensource-audio-hal-primary-hal/commits/9.12-cirrus-patches ?

[MarijnS95]

Yes that patch is removed intentionally from my local branches because it is a really dirty way to cover up for https://github.com/sonyxperiadev/kernel/pull/2345/files. DAPM should turn on and off the hardware when it is (not) used but it doesn't always seem to come out of hibernate, and 1ee5303 has proven locally to not resolve that problem at all. Yet everyone keeps insisting to have that patch :(

Feel free to test it out, pick/backport it, I have no stake in this nor enough time in any way shape or form to investigate what is going on.

[krnlyng]

I have updated it now, there were two minor issues which i resolved in these commits: eb8355d cbc8455.

[MarijnS95]

Not worth mentioning (in the commit, in the PR is fine) that there was a conflict due to some added lines.

Fixed compliation due to extra: list_init(&uc_info_rx->device_list);.

What do you mean with this? list_init doesn't exist on 8.1, or ->device_list was only introduced since 9.12? If you can doublecheck mention that in the commit (and in a comment if leaving // list_init in) (and fix the typo in compliation) that's fine.

[MarijnS95]

@krnlyng As mentioned before it is not worth mentioning "Resolved conflicts due to extra 1ee5303." nor "Cherry-picked from aosp/LA.UM.9.12.r1 and conflicts resolved.", in particular when we want to reapply this tree (mono calibration) back to 9.12. If you can remove that this seems ready to be merged from my side.

Leaving the comment in the code about list_init is pro-ba-bly fine, we'll have to fix that up anyway when reapplying on 9.12.

[krnlyng]

Ok, thanks for the clarification, i hope it's alright now, i've reworded the two commits and dropped those 2 lines.