Skip to content

[BUG][CML] "ASoC: Neither/both codec name/of_node are set for SSP1-Codec" shows when boot up system #2168

Closed

Description

@YvonneYang2

Describe the bug
"ASoC: Neither/both codec name/of_node are set for SSP1-Codec" shows when boot up system with latest topic/sof-dev

Tested it with kernel topic/sof-dev commit: 0d22f66, issue cannot be reproduced. Will do bisect later.

To Reproduce
1.Boot up .
2.Check dmesg.

Reproduce rate
4/5

Expected result
System boot up successfully

Actual result
aplay -l shows no sound card and "ASoC: Neither/both codec name/of_node are set for SSP1-Codec" shows in boot up dmesg.

dmesg

[    1.747530] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp2
[    1.747532] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp3
[    1.747535] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link SSP1-Codec
[    1.747680] cml_rt1011_rt5682 cml_rt1011_rt5682: ASoC: Neither/both codec name/of_node are set for SSP1-Codec
[    1.747820] cml_rt1011_rt5682: probe of cml_rt1011_rt5682 failed with error -22
[    1.790841] usb 1-2.2: new low-speed USB device number 6 using xhci_hcd
[    1.896128] usb 1-2.2: New USB device found, idVendor=0000, idProduct=0538, bcdDevice= 1.00
[    1.896133] usb 1-2.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    1.896136] usb 1-2.2: Product:  USB OPTICAL MOUSE
[    1.902059] input:  USB OPTICAL MOUSE as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2.2/1-2.2:1.0/0003:0000:0538.0002/input/input10
[    1.902209] hid-generic 0003:0000:0538.0002: input,hidraw1: USB HID v1.11 Mouse [ USB OPTICAL MOUSE] on usb-0000:00:14.0-2.2/input0
[    1.990624] usb 1-2.4: new low-speed USB device number 7 using xhci_hcd
[    2.045623] random: crng init done
[    2.097964] usb 1-2.4: New USB device found, idVendor=046d, idProduct=c31c, bcdDevice=64.00
[    2.097966] usb 1-2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.097967] usb 1-2.4: Product: USB Keyboard

Test recipe
Kernel:https://github.com/thesofproject/linux/commits/topic/sof-dev commit: 16d98cd
FW: https://github.com/thesofproject/sof/tree/tgl-006-drop-stable commit: a21cba1
Tplg: same as FW, sof-cml-rt1011-rt5682.tplg
Platform: CML chrome book with i2s rt5682

dmesg.log
logger.log

Activity

  1. added
    bugSomething isn't working
    CMLApplies to Comet Lake platform
    on Jun 4, 2020
  2. keyonjie commented on Jun 4, 2020

    @keyonjie

    Can you help add below change to print out the codec->name for debugging when the issue happen?

    diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c
    index e1b65059c0c4..dbd8ed35035c 100644
    --- a/sound/soc/soc-core.c
    +++ b/sound/soc/soc-core.c
    @@ -846,8 +846,8 @@ static int soc_dai_link_sanity_check(struct snd_soc_card *card,
                     * not both or neither.
                     */
                    if (!!codec->name == !!codec->of_node) {
    -                       dev_err(card->dev, "ASoC: Neither/both codec name/of_node are set for %s\n",
    -                               link->name);
    +                       dev_err(card->dev, "ASoC: Neither/both codec name/of_node are set for %s, codec->name:%s\n",
    +                               link->name, codec->name);
                            return -EINVAL;
                    }
    
  3. YvonneYang2 commented on Jun 4, 2020

    @YvonneYang2
    Author

    Dmesg shows as below after patch applied.

    [    1.897455] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp1
    [    1.897456] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp2
    [    1.897457] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp3
    [    1.897459] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link SSP1-Codec
    [    1.897548] cml_rt1011_rt5682 cml_rt1011_rt5682: ASoC: Neither/both codec name/of_node are set for SSP1-Codec, codec->name:(null)
    [    1.897653] cml_rt1011_rt5682: probe of cml_rt1011_rt5682 failed with error -22
    [    2.245309] asix 1-2.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-2.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:53:56:a2
    [    2.245333] usbcore: registered new interface driver asix
    [    2.251899] asix 1-2.1:1.0 enx000ec65356a2: renamed from eth0
    [    2.381509] random: crng init done
    [    2.427875] Console: switching to colour frame buffer device 240x67
    

    dmesg.log

  4. keyonjie commented on Jun 4, 2020

    @keyonjie

    Thanks @YvonneYang2.

    The codec-name here is NULL, we need add more debug logs to print out the full information of the SSP1-Codec dailink.

    In case you have time, can you help to try with:

    diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c
    index e1b65059c0c4..8c6b8ab7b4b0 100644
    --- a/sound/soc/soc-core.c
    +++ b/sound/soc/soc-core.c
    @@ -845,6 +845,8 @@ static int soc_dai_link_sanity_check(struct snd_soc_card *card,
                     * Codec must be specified by 1 of name or OF node,
                     * not both or neither.
                     */
    +               dev_info(card->dev, "dailink %s: codec[%d] name:%s, dai_name:%s\n",
    +                       link->name, i, codec->dai_name);
                    if (!!codec->name == !!codec->of_node) {
                            dev_err(card->dev, "ASoC: Neither/both codec name/of_node are set for %s\n",
                                    link->name);
    
  5. YvonneYang2 commented on Jun 4, 2020

    @YvonneYang2
    Author

    @keyonjie I tried to test it with your patch, but it cannot enter ubuntu and hang in the black screen after choose the kernel. Then i do the bisect, the result shows the commit f6c8ab5 cause the issue. Could please have a look?

  6. plbossart commented on Jun 4, 2020

    @plbossart
    Member

    @keyonjie I tried to test it with your patch, but it cannot enter ubuntu and hang in the black screen after choose the kernel. Then i do the bisect, the result shows the commit f6c8ab5 cause the issue. Could please have a look?

    @YvonneYang2 use a blacklist and manual modprobe snd-sof-pci to avoid boot issues.

  7. keyonjie commented on Jun 4, 2020

    @keyonjie

    @keyonjie I tried to test it with your patch, but it cannot enter ubuntu and hang in the black screen after choose the kernel. Then i do the bisect, the result shows the commit f6c8ab5 cause the issue. Could please have a look?

    My bad, I missed an item with copy/paste:

    diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c
    index e1b65059c0c4..dd3edc359747 100644
    --- a/sound/soc/soc-core.c
    +++ b/sound/soc/soc-core.c
    @@ -845,6 +845,8 @@ static int soc_dai_link_sanity_check(struct snd_soc_card *card,
                     * Codec must be specified by 1 of name or OF node,
                     * not both or neither.
                     */
    +               dev_info(card->dev, "dailink %s: codec[%d] name:%s, dai_name:%s\n",
    +                       link->name, i, codec->name, codec->dai_name);
                    if (!!codec->name == !!codec->of_node) {
                            dev_err(card->dev, "ASoC: Neither/both codec name/of_node are set for %s\n",
                                    link->name);
    
  8. YvonneYang2 commented on Jun 5, 2020

    @YvonneYang2
    Author

    Here is the boot up log after applied the patch.

    [    1.818931] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link iDisp3
    [    1.818933] cml_rt1011_rt5682 cml_rt1011_rt5682: info: override BE DAI link SSP1-Codec
    [    1.818940] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink SSP0-Codec: codec[0] name:i2c-10EC5682:00, dai_name:rt5682-aif1
    [    1.818974] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink dmic01: codec[0] name:dmic-codec, dai_name:dmic-hifi
    [    1.818994] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink dmic16k: codec[0] name:dmic-codec, dai_name:dmic-hifi
    [    1.819010] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink iDisp1: codec[0] name:ehdaudio0D2, dai_name:intel-hdmi-hifi1
    [    1.819026] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink iDisp2: codec[0] name:ehdaudio0D2, dai_name:intel-hdmi-hifi2
    [    1.819043] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink iDisp3: codec[0] name:ehdaudio0D2, dai_name:intel-hdmi-hifi3
    [    1.819066] cml_rt1011_rt5682 cml_rt1011_rt5682: dailink SSP1-Codec: codec[0] name:(null), dai_name:��\x83�	
    [    1.819068] cml_rt1011_rt5682 cml_rt1011_rt5682: ASoC: Neither/both codec name/of_node are set for SSP1-Codec
    [    1.819194] cml_rt1011_rt5682: probe of cml_rt1011_rt5682 failed with error -22
    

    dmesg.log

  9. ranj063 commented on Jun 5, 2020

    @ranj063
    Collaborator

    @YvonneYang2 could you please try if this change helps?

    diff --git a/sound/soc/intel/boards/cml_rt1011_rt5682.c b/sound/soc/intel/boards/cml_rt1011_rt5682.c
    index 68eff29daf8f..f6837b6e1210 100644
    --- a/sound/soc/intel/boards/cml_rt1011_rt5682.c
    +++ b/sound/soc/intel/boards/cml_rt1011_rt5682.c
    @@ -584,8 +584,9 @@ static int snd_cml_rt1011_probe(struct platform_device *pdev)
                    snd_soc_card_cml.num_configs = SPK_CH;
     
                    for (i = 0; i < ARRAY_SIZE(cml_rt1011_rt5682_dailink); i++) {
    -                       if (!strcmp(cml_rt1011_rt5682_dailink[i].codecs->dai_name,
    -                                       CML_RT1011_CODEC_DAI)) {
    +                       if (cml_rt1011_rt5682_dailink[i].num_codecs &&
    +                           !strcmp(cml_rt1011_rt5682_dailink[i].codecs[0]->dai_name,
    +                                   CML_RT1011_CODEC_DAI)) {
                                    cml_rt1011_rt5682_dailink[i].codecs = rt1011_dais_components;
                                    cml_rt1011_rt5682_dailink[i].num_codecs = SPK_CH;
                            }
    
    
  10. ranj063 commented on Jun 5, 2020

    @ranj063
    Collaborator

    hmm looking more into the dmesg there's something really fishy :
    [ 1.713561] cml_rt1011_rt5682 cml_rt1011_rt5682: sof_rt1011_quirk = f

    This string should be printed only once when the machine driver probes. But it is printed 4 times over.

  11. YvonneYang2 commented on Jun 5, 2020

    @YvonneYang2
    Author

    @YvonneYang2 could you please try if this change helps?

    diff --git a/sound/soc/intel/boards/cml_rt1011_rt5682.c b/sound/soc/intel/boards/cml_rt1011_rt5682.c
    index 68eff29daf8f..f6837b6e1210 100644
    --- a/sound/soc/intel/boards/cml_rt1011_rt5682.c
    +++ b/sound/soc/intel/boards/cml_rt1011_rt5682.c
    @@ -584,8 +584,9 @@ static int snd_cml_rt1011_probe(struct platform_device *pdev)
                    snd_soc_card_cml.num_configs = SPK_CH;
     
                    for (i = 0; i < ARRAY_SIZE(cml_rt1011_rt5682_dailink); i++) {
    -                       if (!strcmp(cml_rt1011_rt5682_dailink[i].codecs->dai_name,
    -                                       CML_RT1011_CODEC_DAI)) {
    +                       if (cml_rt1011_rt5682_dailink[i]->num_codecs &&
    +                           !strcmp(cml_rt1011_rt5682_dailink[i].codecs[0]->dai_name,
    +                                   CML_RT1011_CODEC_DAI)) {
                                    cml_rt1011_rt5682_dailink[i].codecs = rt1011_dais_components;
                                    cml_rt1011_rt5682_dailink[i].num_codecs = SPK_CH;
                            }
    

    Sorry, I tried to compile the kernel after this patch applied, but there were some error info during compiling.

      CC      drivers/acpi/acpica/nsrepair2.o
      HDRTEST usr/include/linux/iso_fs.h
    sound/soc/intel/boards/cml_rt1011_rt5682.c: In function ‘snd_cml_rt1011_probe’:
    sound/soc/intel/boards/cml_rt1011_rt5682.c:587:36: error: invalid type argument of ‘->’ (have ‘struct snd_soc_dai_link’)
        if (cml_rt1011_rt5682_dailink[i]->num_codecs &&
                                        ^~
    sound/soc/intel/boards/cml_rt1011_rt5682.c:588:52: error: invalid type argument of ‘->’ (have ‘struct snd_soc_dai_link_component’)
          !strcmp(cml_rt1011_rt5682_dailink[i].codecs[0]->dai_name,
                                                        ^~
    scripts/Makefile.build:266: recipe for target 'sound/soc/intel/boards/cml_rt1011_rt5682.o' failed
    make[7]: *** [sound/soc/intel/boards/cml_rt1011_rt5682.o] Error 1
    make[7]: *** Waiting for unfinished jobs....
       CC      drivers/acpi/acpica/nsrepair2.o
      HDRTEST usr/include/linux/iso_fs.h
    sound/soc/intel/boards/cml_rt1011_rt5682.c: In function ‘snd_cml_rt1011_probe’:
    sound/soc/intel/boards/cml_rt1011_rt5682.c:587:36: error: invalid type argument of ‘->’ (have ‘struct snd_soc_dai_link’)
        if (cml_rt1011_rt5682_dailink[i]->num_codecs &&
                                        ^~
    sound/soc/intel/boards/cml_rt1011_rt5682.c:588:52: error: invalid type argument of ‘->’ (have ‘struct snd_soc_dai_link_component’)
          !strcmp(cml_rt1011_rt5682_dailink[i].codecs[0]->dai_name,
                                                        ^~
    scripts/Makefile.build:266: recipe for target 'sound/soc/intel/boards/cml_rt1011_rt5682.o' failed
    make[7]: *** [sound/soc/intel/boards/cml_rt1011_rt5682.o] Error 1
    make[7]: *** Waiting for unfinished jobs....
      CC      drivers/char/agp/intel-gtt.o 
    
  12. ranj063 commented on Jun 5, 2020

    @ranj063
    Collaborator

    Sorry, I tried to compile the kernel after this patch applied, but there were some error info during compiling.

    @YvonneYang2 thanks but nevermind. I dont think that will fix the issue.

  13. ranj063 commented on Jun 5, 2020

    @ranj063
    Collaborator

    it looks like a50067d could be suspicious. @YvonneYang2 please update the results of reverting this patch. @bardliao FYI

  14. bardliao commented on Jun 5, 2020

    @bardliao
    Collaborator

    @YvonneYang2 We need more log. Please add "options snd_soc_core dyndbg=+p" to /etc/modprobe.d/sof-debug.conf and get dmesg again. Thanks

  15. 4 remaining items

  16. bardliao commented on Jun 5, 2020

    @bardliao
    Collaborator
    diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c
    index 364cab70f4b2..d8848b1e57f8 100644
    --- a/sound/soc/soc-core.c
    +++ b/sound/soc/soc-core.c
    @@ -845,6 +845,7 @@ static int soc_dai_link_sanity_check(struct snd_soc_card *card,
     		 * Codec must be specified by 1 of name or OF node,
     		 * not both or neither.
     		 */
    +		dev_err(card->dev, "bard: codec name %s\n", codec->name);
     		if (!!codec->name == !!codec->of_node) {
     			dev_err(card->dev, "ASoC: Neither/both codec name/of_node are set for %s\n",
     				link->name);
    @@ -1816,6 +1817,10 @@ static int snd_soc_bind_card(struct snd_soc_card *card)
     
     	/* add predefined DAI links to the list */
     	card->num_rtd = 0;
    +	for_each_card_prelinks(card, i, dai_link) {
    +		pr_err("bard: check %s\n", dai_link->name);
    +		soc_dai_link_sanity_check(card, dai_link);
    +	}
     	for_each_card_prelinks(card, i, dai_link) {
     		ret = snd_soc_add_pcm_runtime(card, dai_link);
     		if (ret < 0)

    I can see codec name in link SSP1-Codec exists before ASoC: codec component i2c-10EC5682:00 not found for link SSP0-Codec. I guess something in the error handling.
    dmesg.txt

  17. bardliao commented on Jun 5, 2020

    @bardliao
    Collaborator

    I will also check if there is anything wrong on snd_cml_rt1011_probe(). It is my most suspicious function.

  18. plbossart commented on Jun 5, 2020

    @plbossart
    Member

    can you add this to /etc/modprobe.d/sof-ddebug.conf:
    options snd_soc_core dyndbg=+p
    so that we see what resource is missing for the probe?

    And it wouldn't hurt as well to compile with the https://github.com/thesofproject/kconfig/blob/master/memory-debug-defconfig added to https://github.com/thesofproject/kconfig/blob/master/kconfig-sof-default.sh
    Adding KASAN will make the boot become much slower but will tell us if we have any memory corruption, as the trace suggests it.

  19. fredoh9 commented on Jun 5, 2020

    @fredoh9
    Collaborator

    I applied Ranj's quick patch and tested. Same result. Below log is with this patch on 16d98cd(today's topic/sof-dev)
    ranj_diff.txt

    With enabled dyndbg, with snd_soc_core also. I have a working booting log
    0605_dmesg04_ranj_patch_dyndbg_working.log

    And same problem case also. I will try with Kasan eanabled also.
    0605_dmesg05_ranj_patch_no_soundcard_dyndbg_error.log

  20. fredoh9 commented on Jun 5, 2020

    @fredoh9
    Collaborator

    I enabled memory-debug-defconfig. And found a KASAN error.

    [   23.301373] cml_rt1011_rt5682 cml_rt1011_rt5682: sof_rt1011_quirk = f
    [   23.301875] ==================================================================
    [   23.302018] BUG: KASAN: use-after-free in snd_cml_rt1011_probe+0x23a/0x3d0 [snd_soc_cml_rt1011_rt5682]
    [   23.302178] Read of size 8 at addr ffff8881ec6acae0 by task kworker/0:2/105
    
    [   23.302320] CPU: 0 PID: 105 Comm: kworker/0:2 Not tainted 5.7.0-rc7-test+ #3
    [   23.302322] Hardware name: Google Helios/Helios, BIOS  01/21/2020
    [   23.302329] Workqueue: events deferred_probe_work_func
    

    0605_dmesg06_ranj_patch_dyndbg_ksan_working.log

  21. ranj063 commented on Jun 5, 2020

    @ranj063
    Collaborator

    Thanks @fredoh9. @plbossart what is the expectation when devm_snd_soc_register_card() returns a -EPROBEDEFER? Does this mean that when a codec component is available at a later point, the machine driver will probe again? Then what happens to the memory allocated in the first attempt at probing then?

  22. plbossart commented on Jun 5, 2020

    @plbossart
    Member

    The memory allocated during the probe should have been freed.
    I am not very good at debugging hex codes, what I typically do is add manual traces to find out what was the last point before the KASAN error and figure out what goes on.

  23. ranj063 commented on Jun 6, 2020

    @ranj063
    Collaborator

    The memory allocated during the probe should have been freed.
    I am not very good at debugging hex codes, what I typically do is add manual traces to find out what was the last point before the KASAN error and figure out what goes on.

    @plbossart it looks like the memory that is dynamically allocated for the 4spk conf and codec components is what is corrupted. @fredoh9 and I have a patch to fix this problem.

    But in general it makes me wonder if we should avoid using devm_kzalloc() in the machine driver probe and instead use kzalloc() and free the memory when card registration fails.

  24. YvonneYang2 commented on Jun 8, 2020

    @YvonneYang2
    Author

    Error not seen after 50 iterations reboot test with latest topic/sof-dev(1af84d0) + #2173 and master branch (428804e).

  25. bardliao commented on Jun 8, 2020

    @bardliao
    Collaborator

    @YvonneYang2 Can you test with #2174?

  26. bardliao commented on Jun 8, 2020

    @bardliao
    Collaborator

    The memory allocated during the probe should have been freed.
    I am not very good at debugging hex codes, what I typically do is add manual traces to find out what was the last point before the KASAN error and figure out what goes on.

    @plbossart it looks like the memory that is dynamically allocated for the 4spk conf and codec components is what is corrupted. @fredoh9 and I have a patch to fix this problem.

    But in general it makes me wonder if we should avoid using devm_kzalloc() in the machine driver probe and instead use kzalloc() and free the memory when card registration fails.

    @ranj063 @plbossart The issue is that somehow if (!strcmp(cml_rt1011_rt5682_dailink[i].codecs->dai_name, CML_RT1011_CODEC_DAI)) fails. I guess the reason is that we assign codecs with a dynamically allocated component, and it could be freed at any time after probe failed. But what I expect is that cml_rt1011_rt5682_dailink[] will be the preset value in any probe. That's something I don't know yet.

  27. YvonneYang2 commented on Jun 8, 2020

    @YvonneYang2
    Author

    @YvonneYang2 Can you test with #2174?

    Error not seen after 50 iterations reboot test with latest topic/sof-dev(1af84d0) + #2174 and master branch (428804e).

  28. bardliao commented on Jun 8, 2020

    @bardliao
    Collaborator

    But what I expect is that cml_rt1011_rt5682_dailink[] will be the preset value in any probe. That's something I don't know yet.

    I think I get the reason now. We don't remove the driver at that moment, so it is still the same cml_rt1011_rt5682_dailink[]. Everything makes sense now.

  29. plbossart commented on Jun 8, 2020

    @plbossart
    Member

    @bardliao I find your explanations confusing. What happens is rather simple with this code:

    			if (!strcmp(cml_rt1011_rt5682_dailink[i].codecs->dai_name,
    					CML_RT1011_CODEC_DAI)) {
    				cml_rt1011_rt5682_dailink[i].codecs = rt1011_dais_components;

    For the first run, cml_rt1011_rt5682_dailink[i].codecs points to the statically values. But if it is modified, then on the next run, we do test a value that was freed, before setting it again. That test is indeed completely wrong, we need to use a condition that is not modified/dynamically allocated. Your fix is fine but you may want to update the commit message

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    CMLApplies to Comet Lake platformbugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions