Bug 215297

Summary: Post resume system still shows 3.5mm headset Jack as detected even after unplugged it in suspend state
Product: Drivers Reporter: Jairaj Arava (jairaj.arava)
Component: Sound(ALSA)Assignee: Jaroslav Kysela (perex)
Status: CLOSED CODE_FIX    
Severity: high CC: jairaj.arava, jeffrj_wang, kai.vehmanen, tiwai
Priority: P1    
Hardware: Intel   
OS: Linux   
Kernel Version: 4.19 Subsystem:
Regression: Yes Bisected commit-id:
Attachments: Alsa info output captured after resume of device where issue is seen
Alsa info captured with Linus master
Alsa info captured with revert of patch with Linus master where issue is not seen
Ftrace logs with headset plugged out during suspend and resume
Ftrace logs without headset plugged out during suspend and resume

Description Jairaj Arava 2021-12-11 02:29:43 UTC
Created attachment 299987 [details]
Alsa info output captured after resume of device where issue is seen

Steps to reproduce the issue:
1. Connect the 3.5mm headset that has inbuilt mic.
2. Suspend the system.
3. Now plug out the 3.5mm headset and wake up the system.

Expected output: Once the system resumes from suspend, both headset & headset mic detection shouldn't be seen as it is plugged out during suspend.

Observed output: After system resumed, headset is still shown as detected but not headset MIC.

Tried the below upstream for-next kernel but still the issue is observed. 

Tip tried:
commit 8e7daf318d97f25e18b2fc7eb5909e34cd903575 (takashi/for-next)
Author: Bixuan Cui <cuibixuan@linux.alibaba.com>
Date:   Wed Dec 1 16:58:54 2021 +0800

    ALSA: oss: fix compile error when OSS_DEBUG is enabled


But after reverting https://lore.kernel.org/alsa-devel/20210310112809.9215-3-tiwai@suse.de/ from the patch series, the issue is not seen.

Attached the alsa-info.sh output(alsa-info) captured when the issue was seen.
Comment 1 Takashi Iwai 2021-12-11 08:14:09 UTC
Could you give the alsa-info.sh output from the latest Linus tree?

Also, you're overriding the setup somehow via model option and patch option.  Please drop those.

And, if it's a proto-type machine, you'll likely have to write your own fixup.  This codec might need to call alc_combo_jack_hp_jd_restart(codec) at resume, usually done via a fixup call with HDA_FIXUP_ACT_INIT.  (Or by luck, some existing fixup may work.)
Comment 2 Jairaj Arava 2021-12-18 00:42:27 UTC
Created attachment 300053 [details]
Alsa info captured with Linus master
Comment 3 Jairaj Arava 2021-12-18 00:45:07 UTC
Hi Takashi,

I have tried with Linus master (commit# below) and still see the issue. Attached above the alsa info captured when issue happened.

Merge: 93db8300f6870 0c3e247460558
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date:   Thu Dec 16 15:02:14 2021 -0800
    Merge tag 'net-5.16-rc6' of git://git.kernel.org/pub/scm/linux/kernel/git/netdev/net


Also, I have checked with the team both model and patch options are needed for headset jack detection.
Comment 4 Jairaj Arava 2021-12-20 20:49:22 UTC
Created attachment 300099 [details]
Alsa info captured with revert of patch with Linus master where issue is not seen
Comment 5 Jairaj Arava 2021-12-20 20:58:37 UTC
Hi Takashi,
I have also attached the alsa-info captured with the revert of https://lore.kernel.org/alsa-devel/20210310112809.9215-3-tiwai@suse.de/. I see the  mixer controls diff and also the headset node 
           Node 0x21 [Pin Complex] wcaps 0x40058d: Stereo Amp-Out
           Control: name="Headphone Playback Switch", index=0, device=0.

After adding couple of prints:
 
+	/* ignore unsol events during system suspend/resume */
+	if (codec->core.dev.power.power_state.event != PM_EVENT_ON)
+		return;
+
I see control is getting back from above during such unsol events and it is not reported & not handled and hence we are hitting the issue.
However, it seems the below lines are needed to be executed to handle such unsol events during suspend.

 	if (codec->patch_ops.unsol_event)
 		codec->patch_ops.unsol_event(codec, ev);
Comment 6 Jairaj Arava 2022-01-04 21:01:33 UTC
Hi Takashi,

Any inputs from the above observation. Thanks.
Comment 7 Jairaj Arava 2022-01-11 19:05:11 UTC
Hi Takashi,
Do you need any additional data for the issue?
Comment 8 JEFFRJ WANG 2022-05-31 07:05:20 UTC
Hi Takashi,

We still see this symptom on v5.10 kernel. Do you have any suggestion for this?
Comment 9 Jaroslav Kysela 2022-06-09 05:19:05 UTC
It's not the right place to resolve this problem.

If you look to hda_call_codec_resume() function, there is the jack state handling - snd_hda_jack_set_dirty_all() and snd_hda_jack_report_sync() / or jackpoll_work activation.

Try to figure the better solution for this hardware when the codec is resumed.

Alternatively, you can set the jackpoll_ms kernel module option (see modinfo snd_hda_intel).
Comment 10 Takashi Iwai 2022-06-09 05:50:10 UTC
Right, you need to verify whether the pin detection (AC_VERB_GET_PIN_SENSE) continues to work after the resume or not.  As Jaroslav mentioned in comment 9, the basic flow is like:

System resume ->
 hda_codec_pm_resume() ->
  hda_codec_runtime_resume() (with dev->power.power_state = PMSG_RESUME) ->
   hda_call_codec_resume()

Then in hda_call_codec_reusme(), it calls snd_hda_jack_set_dirty_all() to mark all registered pins as dirty to re-detect the pin states.  At the end of the function, it calls snd_hda_jack_report_sync() that updates the all pin states that have been still marked as dirty, and report the current jack states.

If the jack isn't updated, something is broken in the code flow above.
Comment 11 Jairaj Arava 2022-06-22 23:23:13 UTC
Hi Jarslov and Takashi,

Attached the ftrace log of suspend & resume with and without headset plugged out.
Comment 12 Jairaj Arava 2022-06-22 23:26:04 UTC
Created attachment 301259 [details]
Ftrace logs with headset plugged out during suspend and resume

Ftrace logs with headset plugged out during suspend and resume
Comment 13 Jairaj Arava 2022-06-22 23:27:30 UTC
Created attachment 301260 [details]
Ftrace logs without headset plugged out during suspend and resume
Comment 14 Jairaj Arava 2022-06-22 23:32:58 UTC
Also, added prints in the below section to see the jack pin sense and state.

@@ -475,8 +475,11 @@ void snd_hda_jack_report_sync(struct hda_codec *codec)
                        if (!jack->jack || jack->block_report)
                                continue;
                        state = jack->button_state;
-                       if (get_jack_plug_state(jack->pin_sense))
+                       if (get_jack_plug_state(jack->pin_sense)) {
+                               printk("**jai pin sense=%u***\n",jack->pin_sense);
                                state |= jack->type;
+                               printk("**jai State=%d***\n",state);
+                       }


Plugged In:

5606.494956] **jai pin sense=2147483648***
[ 5606.494961] **jai State=2***
[ 5606.494963] **jai pin sense=2147483648***
[ 5606.494965] **jai State=1***
[ 5606.494977] **jai pin sense=2147483648***
[ 5606.494979] **jai State=4***
[ 5607.139750] **jai pin sense=2147483648***
[ 5607.139754] **jai State=2***
[ 5607.139766] **jai pin sense=2147483648***
[ 5607.139768] **jai State=2***
[ 5607.139770] **jai pin sense=2147483648***
[ 5607.139771] **jai State=1***
[ 5607.139774] **jai pin sense=2147483648***
[ 5607.139776] **jai State=4***


Plugged out:
[ 5784.959105] **jai pin sense=2147483648***
[ 5784.959110] **jai State=2***
[ 5784.959113] **jai pin sense=2147483648***
[ 5784.959114] **jai State=2***
[ 5784.959125] **jai pin sense=2147483648***
[ 5784.959127] **jai State=4***
[ 5784.960604] **jai pin sense=2147483648***
[ 5784.960608] **jai State=2***
[ 5784.960612] **jai pin sense=2147483648***
[ 5784.960615] **jai State=4***


Headset Plugged out during suspend and resumed back:
[ 6169.237683] **jai pin sense=2147483648***
[ 6169.237686] **jai State=2***
[ 6169.237688] **jai pin sense=2147483648***
[ 6169.237689] **jai State=1***
[ 6169.237691] **jai pin sense=2147483648***
[ 6169.237692] **jai State=4***



with Headset pluged in during suspend and resume
[ 6380.498626] **jai pin sense=2147483648***
[ 6380.498630] **jai State=2***
[ 6380.498632] **jai pin sense=2147483648***
[ 6380.498633] **jai State=1***
[ 6380.498635] **jai pin sense=2147483648***
[ 6380.498636] **jai State=4***
[ 6380.512723] **jai pin sense=2147483648***
[ 6380.512724] **jai State=2***
[ 6380.512726] **jai pin sense=2147483648***
[ 6380.512727] **jai State=1***
[ 6380.512729] **jai pin sense=2147483648***
[ 6380.512730] **jai State=4***
[ 6381.156498] **jai pin sense=2147483648***
[ 6381.156507] **jai State=2***
[ 6381.156529] **jai pin sense=2147483648***
[ 6381.156533] **jai State=2***
[ 6381.156538] **jai pin sense=2147483648***
[ 6381.156541] **jai State=1***
[ 6381.156547] **jai pin sense=2147483648***
[ 6381.156550] **jai State=4***
Comment 15 Jairaj Arava 2022-07-02 00:14:24 UTC
(In reply to Takashi Iwai from comment #10)
> Right, you need to verify whether the pin detection (AC_VERB_GET_PIN_SENSE)
> continues to work after the resume or not.  As Jaroslav mentioned in comment
> 9, the basic flow is like:
> 
> System resume ->
>  hda_codec_pm_resume() ->
>   hda_codec_runtime_resume() (with dev->power.power_state = PMSG_RESUME) ->
>    hda_call_codec_resume()
> 
> Then in hda_call_codec_reusme(), it calls snd_hda_jack_set_dirty_all() to
> mark all registered pins as dirty to re-detect the pin states.  At the end
> of the function, it calls snd_hda_jack_report_sync() that updates the all
> pin states that have been still marked as dirty, and report the current jack
> states.
> 
> If the jack isn't updated, something is broken in the code flow above.




Hi Takashi,

Apart from the logs shared above, we added prints to track the pin detection AC_VERB_GET_PIN_SENSE and get_jack_plug_state(jack->pin_sense) in snd_hda_jack_report_sync after resume in the normal scenario (suspend resume with 3.5mm jack plugged in) and the issue scenario(3.5mm jack unplugged during suspend).

Normal scenario:
[ 6720.150710] ****jai is in hda_codec_unsol_event**
[ 6720.150714] ****jai is in hda_codec_unsol_event** in suspend resume
[ 6720.151003] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6720.151065] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6720.151071] **jai pin sense=2147483648***
[ 6720.151072] **jai State=2***
[ 6720.151073] **jai pin sense=2147483648***
[ 6720.151074] **jai State=1***
[ 6720.151076] **jai pin sense=2147483648***
[ 6720.151077] **jai State=4***
[ 6720.151084] snd_hda_codec_realtek hdaudioC0D0: hda_codec_pm_resume+0x0/0x19 [snd_hda_codec] returned 0 after 262253 usecs
[ 6720.171211] ****jai is in hda_codec_unsol_event**
[ 6720.171212] ****jai is in hda_codec_unsol_eventi normal unsol**
[ 6720.171274] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6720.171276] **jai pin sense=2147483648***
[ 6720.171277] **jai State=2***
[ 6720.171278] **jai pin sense=2147483648***
[ 6720.171279] **jai State=1***
[ 6720.171280] **jai pin sense=2147483648***
[ 6720.171282] **jai State=4***


Issue scenario:
[ 6890.170032] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6890.195996] ****jai is in hda_codec_unsol_event**
[ 6890.195999] ****jai is in hda_codec_unsol_event** in suspend resume
[ 6890.197304] ****jai is in hda_codec_unsol_event**
[ 6890.197306] ****jai is in hda_codec_unsol_event** in suspend resume
[ 6890.233027] elan_i2c i2c-ELAN0000:00: acpi_subsys_resume+0x0/0x79 returned 0 after 110512 usecs
[ 6890.233068] input input3: calling input_dev_resume+0x0/0x3e @ 19599, parent: i2c-ELAN0000:00
[ 6890.233072] input input3: input_dev_resume+0x0/0x3e returned 0 after 0 usecs
[ 6890.281955] usb usb1: usb_dev_resume+0x0/0x14 returned 0 after 158240 usecs
[ 6890.281965] usb 1-10: calling usb_dev_resume+0x0/0x14 @ 18928, parent: usb1
.
.
.
.
.
[ 6890.406263] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6890.406325] ***jai AC_VERB_GET_PIN_SENSE=0XF09** in read_ping_sense
[ 6890.406331] **jai pin sense=2147483648***
[ 6890.406332] **jai State=2***
[ 6890.406334] **jai pin sense=2147483648***
[ 6890.406335] **jai State=1***
[ 6890.406337] **jai pin sense=2147483648***
[ 6890.406338] **jai State=4***
[ 6890.406346] snd_hda_codec_realtek hdaudioC0D0: hda_codec_pm_resume+0x0/0x19 [snd_hda_codec] returned 0 after 264468 usecs

////NO prints of jack pin sense and AC_VERB_GET_PIN_SENSE////

we don't see any jack pin sense and AC_VERB_GET_PIN_SENSE update happening after resume in issue scenario.
Comment 16 Jairaj Arava 2022-07-18 17:10:59 UTC
Hi Takashi & Jaroslav,

Can we interpret driver behavior based on above info during the failure case?
Comment 17 Takashi Iwai 2022-07-19 05:27:01 UTC
The change in comment 14 does report only when get_jack_plug_state() returns true, i.e. only when the *already existing* jack state contains the bit.  So, it makes little sense to track that point at all; it just reflects the known result.

Instead, you should track jack_detect_update() call and what value is read at each invocation.  I guess the hardware doesn't detect the jack properly by some reason during the resume there.
Comment 18 Jairaj Arava 2023-03-14 00:29:38 UTC
Hi,
The issue got addressed in the latest TOT kernel. Hence, closing this bug.
Thanks for all your support.