Bug 208829 - Multiple "spurious response" errors on resume from snd_hda_intel for NVIDIA
Summary: Multiple "spurious response" errors on resume from snd_hda_intel for NVIDIA
Status: RESOLVED WILL_NOT_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: Sound(ALSA) (show other bugs)
Hardware: x86-64 Linux
: P1 normal
Assignee: Jaroslav Kysela
URL: https://forums.developer.nvidia.com/t...
Keywords:
: 202423 208487 (view as bug list)
Depends on: 204199
Blocks:
  Show dependency tree
 
Reported: 2020-08-06 11:51 UTC by Artem S. Tashkinov
Modified: 2021-12-30 20:16 UTC (History)
8 users (show)

See Also:
Kernel Version: 5.7.10, git
Subsystem:
Regression: No
Bisected commit-id:


Attachments
Silence snd_hda_intel spurious response last cmd messages (872 bytes, patch)
2020-08-26 12:02 UTC, Artem S. Tashkinov
Details | Diff

Description Artem S. Tashkinov 2020-08-06 11:51:24 UTC
On boot:

[    0.148139] pci 0000:07:00.1: [10de:1aeb] type 00 class 0x040300
[    0.148156] pci 0000:07:00.1: reg 0x10: [mem 0xf7080000-0xf7083fff]
[    0.161356] pci 0000:07:00.1: D0 power state depends on 0000:07:00.0
[    0.163459] pci 0000:07:00.1: Adding to iommu group 21
[    2.487804] snd_hda_intel 0000:07:00.1: Disabling MSI
[    2.567083] input: HDA NVidia HDMI/DP,pcm=3 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input3
[    2.568632] input: HDA NVidia HDMI/DP,pcm=7 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input4
[    2.569455] input: HDA NVidia HDMI/DP,pcm=8 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input5
[    2.571032] input: HDA NVidia HDMI/DP,pcm=9 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input6
[    2.573023] input: HDA NVidia HDMI/DP,pcm=10 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input7
[    2.573457] input: HDA NVidia HDMI/DP,pcm=11 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input8
[    2.573816] input: HDA NVidia HDMI/DP,pcm=12 as /devices/pci0000:00/0000:00:03.1/0000:07:00.1/sound/card0/input9

here goes the output after a resume:

[ 9426.756113] snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to polling mode: last cmd=0x001f000a
[ 9426.756115] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756116] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756117] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756117] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756118] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x1f000a
[ 9426.756118] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756119] snd_hda_intel 0000:07:00.1: spurious response 0xc0:0x0, last cmd=0x1f000a
[ 9426.756120] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
[ 9426.756120] snd_hda_intel 0000:07:00.1: spurious response 0x84:0x0, last cmd=0x1f000a
[ 9426.756121] snd_hda_intel 0000:07:00.1: spurious response 0x1:0x0, last cmd=0x1f000a
[ 9427.760124] snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to single_cmd mode: last cmd=0x005f0900
[ 9433.335926] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
[ 9433.335961] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
[ 9433.336045] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
[ 9433.336086] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
[ 9433.336127] snd_hda_intel 0000:07:00.1: spurious response 0x40:0x0, last cmd=0x470700
[ 9433.336169] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[ 9800.556610] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
[ 9800.556652] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
[ 9800.568066] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
[ 9800.568107] snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
[12030.729603] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
[12030.729643] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[12030.729684] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
[12030.729725] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[12030.729767] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[12030.729809] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
[12030.729850] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[12030.729892] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[12030.729933] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
[12030.729975] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[12384.141937] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
[12384.141977] snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
[13235.057059] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
[13235.057117] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[13235.057140] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
[13235.057182] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[13235.057223] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[13235.057265] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
[13235.057306] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[13235.057348] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
[13235.057390] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
[13235.057431] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[13240.090349] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
[13240.090372] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
[13240.090470] snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
[13240.090497] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
[13240.090537] snd_hda_intel 0000:07:00.1: spurious response 0x40:0x0, last cmd=0x470700
[13240.090580] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
[13547.955550] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
[13547.955590] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
[13547.967550] snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
[13547.967591] snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500

Device is:

07:00.1 Audio device: NVIDIA Corporation TU116 High Definition Audio Controller (rev a1)
        Subsystem: Micro-Star International Co., Ltd. [MSI] Device 375a
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin B routed to IRQ 117
        Region 0: Memory at f7080000 (32-bit, non-prefetchable) [size=16K]
        Capabilities: [60] Power Management version 3
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
                Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [68] MSI: Enable- Count=1/1 Maskable- 64bit+
                Address: 0000000000000000  Data: 0000
        Capabilities: [78] Express (v2) Endpoint, MSI 00
                DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s unlimited, L1 <64us
                        ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W
                DevCtl: CorrErr- NonFatalErr- FatalErr- UnsupReq-
                        RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+
                        MaxPayload 128 bytes, MaxReadReq 512 bytes
                DevSta: CorrErr- NonFatalErr- FatalErr- UnsupReq- AuxPwr- TransPend+
                LnkCap: Port #0, Speed 8GT/s, Width x16, ASPM L0s L1, Exit Latency L0s <512ns, L1 <4us
                        ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp+
                LnkCtl: ASPM L0s L1 Enabled; RCB 64 bytes Disabled- CommClk+
                        ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 2.5GT/s (downgraded), Width x16 (ok)
                        TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
                DevCap2: Completion Timeout: Range AB, TimeoutDis+, NROPrPrP-, LTR+
                         10BitTagComp-, 10BitTagReq-, OBFF Via message, ExtFmt-, EETLPPrefix-
                         EmergencyPowerReduction Not Supported, EmergencyPowerReductionInit-
                         FRS-, TPHComp-, ExtTPHComp-
                         AtomicOpsCap: 32bit- 64bit- 128bitCAS-
                DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
                         AtomicOpsCtl: ReqEn-
                LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
                         EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
        Capabilities: [100 v2] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr-
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr+
                AERCap: First Error Pointer: 00, ECRCGenCap- ECRCGenEn- ECRCChkCap- ECRCChkEn-
                        MultHdrRecCap- MultHdrRecEn- TLPPfxPres- HdrLogCap-
                HeaderLog: 00000000 00000000 00000000 00000000
        Kernel driver in use: snd_hda_intel
        Kernel modules: snd_hda_intel

$ grep -i hda interrupts 
 117:          0          0        771          0          0          0          0          0          0          0          0          0          0          0          0       1154  IR-IO-APIC   31-fasteoi   snd_hda_intel:card0
 119:          0      73805          0          0          0          0          0          0          0          0          0          0          0          0          0          0  IR-PCI-MSI 4726784-edge      snd_hda_intel:card1

card0 - NVIDIA

Superios interrupts messages appear each time I read /proc/asound/NVidia/codec#0 file:

# cat codec#0 
Codec: Nvidia GPU 99 HDMI/DP
Address: 0
AFG Function Id: 0x1 (unsol 0)
Vendor Id: 0x10de0099
Subsystem Id: 0x1462375a
Revision Id: 0x100100
No Modem Function Group found
Default PCM:
    rates [0x0]:
    bits [0x0]:
    formats [0x0]:
Default Amp-In caps: N/A
Default Amp-Out caps: N/A
State of AFG node 0x01:
  Power states:  D0 D1 D2 D3 CLKSTOP EPSS
  Power: setting=D0, actual=D0
GPIO: io=0, o=0, i=0, unsolicited=0, wake=0
Node 0x04 [Pin Complex] wcaps 0x407381: 8-Channels Digital CP
  Pincap 0x09000094: OUT Detect HBR HDMI DP
  Pin Default 0x185600f0: [Jack] Digital Out at Int HDMI
    Conn = Digital, Color = Unknown
    DefAssociation = 0xf, Sequence = 0x0
  Pin-ctls: 0x00:
  Unsolicited: tag=01, enabled=1
  Devices: 4
    *Dev 00: PD = 1, ELDV = 1, IA = 0
     Dev 01: PD = 0, ELDV = 0, IA = 0
     Dev 02: PD = 0, ELDV = 0, IA = 0
     Dev 03: PD = 0, ELDV = 0, IA = 0
  Connection: 4
     0x08* 0x09 0x0a 0x0b
Node 0x05 [Pin Complex] wcaps 0x407381: 8-Channels Digital CP
  Pincap 0x09000094: OUT Detect HBR HDMI DP
  Pin Default 0x185600f0: [Jack] Digital Out at Int HDMI
    Conn = Digital, Color = Unknown
    DefAssociation = 0xf, Sequence = 0x0
  Pin-ctls: 0x00:
  Unsolicited: tag=05, enabled=1
  Devices: 4
     Dev 00: PD = 0, ELDV = 0, IA = 0
     Dev 01: PD = 0, ELDV = 0, IA = 0
     Dev 02: PD = 0, ELDV = 0, IA = 0
    *Dev 03: PD = 0, ELDV = 0, IA = 0
  Connection: 4
     0x08* 0x09 0x0a 0x0b
Node 0x06 [Pin Complex] wcaps 0x407381: 8-Channels Digital CP
  Pincap 0x09000094: OUT Detect HBR HDMI DP
  Pin Default 0x185600f0: [Jack] Digital Out at Int HDMI
    Conn = Digital, Color = Unknown
    DefAssociation = 0xf, Sequence = 0x0
  Pin-ctls: 0x00:
  Unsolicited: tag=09, enabled=1
  Devices: 4
     Dev 00: PD = 0, ELDV = 0, IA = 0
     Dev 01: PD = 0, ELDV = 0, IA = 0
     Dev 02: PD = 0, ELDV = 0, IA = 0
    *Dev 03: PD = 0, ELDV = 0, IA = 0
  Connection: 4
     0x08* 0x09 0x0a 0x0b
Node 0x07 [Pin Complex] wcaps 0x407381: 8-Channels Digital CP
  Pincap 0x09000094: OUT Detect HBR HDMI DP
  Pin Default 0x185600f0: [Jack] Digital Out at Int HDMI
    Conn = Digital, Color = Unknown
    DefAssociation = 0xf, Sequence = 0x0
  Pin-ctls: 0x00:
  Unsolicited: tag=0d, enabled=1
  Devices: 4
     Dev 00: PD = 0, ELDV = 0, IA = 0
     Dev 01: PD = 0, ELDV = 0, IA = 0
     Dev 02: PD = 0, ELDV = 0, IA = 0
    *Dev 03: PD = 0, ELDV = 0, IA = 0
  Connection: 4
     0x08* 0x09 0x0a 0x0b
Node 0x08 [Audio Output] wcaps 0x62b1: 8-Channels Digital Stripe
  Converter: stream=0, channel=0
  Digital: Enabled
  Digital category: 0x0
  IEC Coding Type: 0x0
  PCM:
    rates [0x7f0]: 32000 44100 48000 88200 96000 176400 192000
    bits [0xe]: 16 20 24
    formats [0x5]: PCM AC3
  Unsolicited: tag=00, enabled=0
Node 0x09 [Audio Output] wcaps 0x62b1: 8-Channels Digital Stripe
  Converter: stream=0, channel=0
  Digital:
  Digital category: 0x0
  IEC Coding Type: 0x0
  PCM:
    rates [0x7f0]: 32000 44100 48000 88200 96000 176400 192000
    bits [0xe]: 16 20 24
    formats [0x5]: PCM AC3
  Unsolicited: tag=00, enabled=0
Node 0x0a [Audio Output] wcaps 0x62b1: 8-Channels Digital Stripe
  Converter: stream=0, channel=0
  Digital:
  Digital category: 0x0
  IEC Coding Type: 0x0
  PCM:
    rates [0x7f0]: 32000 44100 48000 88200 96000 176400 192000
    bits [0xe]: 16 20 24
    formats [0x5]: PCM AC3
  Unsolicited: tag=00, enabled=0
Node 0x0b [Audio Output] wcaps 0x62b1: 8-Channels Digital Stripe
  Converter: stream=0, channel=0
  Digital:
  Digital category: 0x0
  IEC Coding Type: 0x0
  PCM:
    rates [0x7f0]: 32000 44100 48000 88200 96000 176400 192000
    bits [0xe]: 16 20 24
    formats [0x5]: PCM AC3
  Unsolicited: tag=00, enabled=0
Comment 1 Artem S. Tashkinov 2020-08-25 16:34:45 UTC
Is there a way to at least silence these messages?
Comment 2 Artem S. Tashkinov 2020-08-25 16:38:40 UTC
I'm looking at void snd_hdac_bus_update_rirb(struct hdac_bus *bus) and it looks like there's no way to silence it.

It would be great if you made it possible to silence it or to limit it to a single message, e.g.

snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: further spurious response messages will not be omitted
Comment 3 Artem S. Tashkinov 2020-08-25 16:48:31 UTC
A similar bug was filed more than a year ago, see bug 202423. Not a single reply from ALSA developers. Is there any information I can provide so that you fixed it? It's really annoying.
Comment 4 Artem S. Tashkinov 2020-08-25 16:49:40 UTC
Then there's bug 208487 which mentions a similar device: NVIDIA Corporation TU106 High Definition Audio Controller (rev a1)
Comment 5 Artem S. Tashkinov 2020-08-25 16:56:46 UTC
After resuming there's an unusual message in dmesg:

On boot:

snd_hda_intel 0000:07:00.1: Disabling MSI
snd_hda_intel 0000:09:00.4: enabling device (0000 -> 0002)
snd_hda_codec_realtek hdaudioC1D0: ALCS1200A: SKU not ready 0x00000000
snd_hda_codec_realtek hdaudioC1D0: autoconfig for ALCS1200A: line_outs=3 (0x14/0x15/0x16/0x0/0x0) type:line
snd_hda_codec_realtek hdaudioC1D0:    speaker_outs=0 (0x0/0x0/0x0/0x0/0x0)
snd_hda_codec_realtek hdaudioC1D0:    hp_outs=1 (0x1b/0x0/0x0/0x0/0x0)
snd_hda_codec_realtek hdaudioC1D0:    mono: mono_out=0x0
snd_hda_codec_realtek hdaudioC1D0:    dig-out=0x1e/0x0
snd_hda_codec_realtek hdaudioC1D0:    inputs:
snd_hda_codec_realtek hdaudioC1D0:      Front Mic=0x19
snd_hda_codec_realtek hdaudioC1D0:      Rear Mic=0x18
snd_hda_codec_realtek hdaudioC1D0:      Line=0x1a

After resuming:

snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to polling mode: last cmd=0x001f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0xc0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x84:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: spurious response 0x1:0x0, last cmd=0x1f000a
snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to single_cmd mode: last cmd=0x005f0900
snd_hda_codec_hdmi hdaudioC0D0: HDMI: invalid ELD buf size -1
snd_hda_codec_hdmi hdaudioC0D0: HDMI: invalid ELD buf size -1
snd_hda_codec_hdmi hdaudioC0D0: HDMI: invalid ELD buf size -1
snd_hdac_bus_update_rirb: 500 callbacks suppressed
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
snd_hda_intel 0000:07:00.1: spurious response 0x40:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hdac_bus_update_rirb: 203 callbacks suppressed
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
snd_hda_intel 0000:07:00.1: spurious response 0x40:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hdac_bus_update_rirb: 65 callbacks suppressed
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hdac_bus_update_rirb: 301 callbacks suppressed
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x870e00
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
snd_hda_intel 0000:07:00.1: spurious response 0x40:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x820000
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473500
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473501
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x4f0015
snd_hda_intel 0000:07:00.1: spurious response 0x3:0x0, last cmd=0x473502
snd_hda_intel 0000:07:00.1: spurious response 0x0:0x0, last cmd=0x470700
Comment 6 Artem S. Tashkinov 2020-08-25 17:02:43 UTC
Related issues:

https://forums.developer.nvidia.com/t/hdmi-audio-changes-the-eld-pin-node-after-resume-from-suspend-mode/78190

The affected GPUs so far: NVIDIA GeForce GTX 1050, NVIDIA GeForce RTX 2080, NVIDIA GeForce RTX 2070, NVIDIA GeForce GTX 1660 Ti
Comment 7 Artem S. Tashkinov 2020-08-25 17:05:00 UTC
*** Bug 208487 has been marked as a duplicate of this bug. ***
Comment 8 Artem S. Tashkinov 2020-08-25 17:06:09 UTC
*** Bug 202423 has been marked as a duplicate of this bug. ***
Comment 9 Julian Sikorski 2020-08-25 17:07:27 UTC
A much older gpu is also affected - Geforce 680M.
Comment 10 Artem S. Tashkinov 2020-08-25 17:10:32 UTC
A possible workaround is mentioned here: https://bugzilla.kernel.org/show_bug.cgi?id=204199#c14 however I'm not concerned with the switch to polling mode, I'm annoyed by a large number of never-ending error messages.
Comment 11 Artem S. Tashkinov 2020-08-26 12:02:06 UTC
Created attachment 292171 [details]
Silence  snd_hda_intel spurious response last cmd messages

Totally untested
Comment 12 Artem S. Tashkinov 2020-08-26 12:09:16 UTC
OK, the patch works for me, great. No more dmesg spam.

I could have made it a snd_hda_module option but I see no reason to see thousands of these messages in the first place.
Comment 13 Takashi Iwai 2020-08-26 13:37:17 UTC
It's a HDMI device in Nvidia GPU, and it means that the GPU doens't respond to the audio verbs, so basically a bug in the graphics side.

Are you using Nvidia graphics driver?  If it were nouveau, it should have been done better in the audio component and the power management is linked tightly.
Comment 14 Artem S. Tashkinov 2020-08-26 15:09:17 UTC
(In reply to Takashi Iwai from comment #13)
> It's a HDMI device in Nvidia GPU, and it means that the GPU doens't respond
> to the audio verbs, so basically a bug in the graphics side.

Somehow it's only happening after resume and it doesn't affect audio output at all, so the hundreds of error messages serve no purpose.

> 
> Are you using Nvidia graphics driver?  If it were nouveau, it should have
> been done better in the audio component and the power management is linked
> tightly.

Yes, I am, in fact I indicated it right away, comment #0

07:00.1 Audio device: NVIDIA Corporation TU116 High Definition Audio Controller (rev a1)

Since NVIDIA doesn't want to address the bug (it's been known for a year and a half now) it would be great if kernel maintainers could at least somewhat alleviate it.
Comment 15 Takashi Iwai 2020-08-26 16:45:21 UTC
Basically it's a problem in the resume procedure where Nvidia graphics doesn't resume quickly enough before the audio gets resumed -- that's the wild guess, but who knows.  It's Nvidia binary-only stuff.

You might try to change
  codec->relaxed_resume = 0;
in generic_hdmi_free() in patch_hdmi.c to
  codec->relaxed_resume = 1;

This would suppress the forced resume when the device has been already runtime-suspended beforehand.
Comment 16 Artem S. Tashkinov 2020-08-26 20:44:45 UTC
(In reply to Takashi Iwai from comment #15)
> Basically it's a problem in the resume procedure where Nvidia graphics
> doesn't resume quickly enough before the audio gets resumed -- that's the
> wild guess, but who knows.  It's Nvidia binary-only stuff.

I'm not sure about that - these messages keep on coming _infinitely_ after resume. It surely looks like it's because PulseAudio is poking and probing the card regularly. For instance, I've noticed that unlocking the PC generates a storm of these messages. Again it would be nice to silence them because I doubt a single user in the world can use them and they are mostly meant for kernel audio developers and one error message would be enough to realize that something doesn't work correctly.

TLDR It would be nice if these messages were silenced unless kernel/ALSA debugging is turned on.

> 
> You might try to change
>   codec->relaxed_resume = 0;
> in generic_hdmi_free() in patch_hdmi.c to
>   codec->relaxed_resume = 1;
> 
> This would suppress the forced resume when the device has been already
> runtime-suspended beforehand.

I'm not sure that'll help - see above.
Comment 17 Takashi Iwai 2020-08-27 08:04:58 UTC
Well, look at the messages you posted initially:

[ 9426.756113] snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to polling mode: last cmd=0x001f000a

This starts showing the spurious response.  This already indicates something broken.  And later on, it reaches to the state:

[ 9427.760124] snd_hda_intel 0000:07:00.1: azx_get_response timeout, switching to single_cmd mode: last cmd=0x005f0900

and this means that the communication with the codec is completely broken, hence it switched to the emergency mode.  After this point, the codec shouldn't return anything via the interrupt, but it still keeps doing that, and this unexpected behavior appears as the flood of response error messages.

That is, the very cause is the communication error at the resume, and then the chip continues behaving weirdly after that, even if the HD-audio controller tries to communicate in the single command mode.

And *why* it happens: no one knows, it's Nvidia voodoo box, hence nothing but guesses.  So I asked you to try that.  You can guess, but that's all about guess.

For suppressing the spurious error messages after the single cmd mode switch, the change below might help.  But this doesn't solve the primary problem at all, of course.

--- a/sound/pci/hda/hda_controller.c
+++ b/sound/pci/hda/hda_controller.c
@@ -1122,7 +1122,7 @@ irqreturn_t azx_interrupt(int irq, void *dev_id)
 			 */
 			azx_writeb(chip, RIRBSTS, RIRB_INT_MASK);
 			active = true;
-			if (status & RIRB_INT_RESPONSE) {
+			if (!chip->single_cmd && (status & RIRB_INT_RESPONSE)) {
 				if (chip->driver_caps & AZX_DCAPS_CTX_WORKAROUND)
 					udelay(80);
 				snd_hdac_bus_update_rirb(bus);
Comment 18 william 2020-12-24 15:41:34 UTC
Ho ho ho -- Merry Christmas

I too am seeing these messages when various terminal sessons start to go into "lock-down".  The resulting malfunction is to lock-out TERM sessions under my X-Windows session.  Strangely, using CTRL/ALT/F1 (console) and resuming vis CTRL/ALT/F7on an Ubuntu system give me some "better" performance on the terminal ... 

On the coonsole and checked htop, etc, and every thing looks "OK" apart from teh dmes output showing likes like...

  snd_hda_intel 0000:07:00.1: spurious response 0x233:0x0, 
last cmd=0x1f0500
Comment 19 william 2020-12-24 16:01:13 UTC
...  What I'd like is to find a way to identify these HEX values.  For instance, what is/are ...

  1. cmd=0x1f0500
  2. snd_intel => 0000:07:00.1
       * I presume this is a message kind???
  3. response; "0000:07:00.1"
       * What is that string?   What service(s) usees that IPv6 address?
       * Ought the miscreant responsible for publishing such "stories" as-if 
         they were .. could be... fact-s / plausibilities
  4.
Comment 20 Michel Hanzen 2020-12-30 13:48:07 UTC
For me it looks solved with kernel 5.9

kernel 5.4.0-58:
Dec 29 13:03:33 michel-System-Test kernel: [   49.837340] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837342] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837343] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837344] snd_hda_intel 0000:0b:00.1: spurious response 0x4011:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837345] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837346] snd_hda_intel 0000:0b:00.1: spurious response 0x4015:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837347] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837348] snd_hda_intel 0000:0b:00.1: spurious response 0x4017:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837349] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x6f0900
Dec 29 13:03:33 michel-System-Test kernel: [   49.837350] snd_hda_intel 0000:0b:00.1: spurious response 0x4011:0x0, last cmd=0x6f0900

kernel 5.8.0-33:
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709281] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0xa70e00
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709323] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0xa70e00
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709394] snd_hda_intel 0000:0b:00.1: spurious response 0x3:0x0, last cmd=0x473500
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709435] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x4f0700
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709477] snd_hda_intel 0000:0b:00.1: spurious response 0x40:0x0, last cmd=0x470700
Dec 27 17:26:26 michel-System-Test kernel: [ 7340.709519] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x470700
Dec 27 17:26:28 michel-System-Test kernel: [ 7341.898578] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0xa20000
Dec 27 17:26:28 michel-System-Test kernel: [ 7341.898586] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0xa20000
Dec 27 17:26:28 michel-System-Test kernel: [ 7341.917887] snd_hda_intel 0000:0b:00.1: spurious response 0x0:0x0, last cmd=0x1f0500
Dec 27 17:26:28 michel-System-Test kernel: [ 7341.917913] snd_hda_intel 0000:0b:00.1: spurious response 0x233:0x0, last cmd=0x1f0500


kernel 5.9.16-050916: no "/var/log/kern.log" messages

Happy New Year 2021!
Comment 21 Ákos Szőts 2021-02-11 07:34:47 UTC
It is still happening with 5.10.12. However, according to NVIDIA, they are working on a fix (as of 2021-02-08): https://forums.developer.nvidia.com/t/nvidia-hdmi-audio-errors-after-resume-snd-hda-intel-spurious-response-last-cmd/149003/12
Comment 22 murphy 2021-02-14 00:59:56 UTC
This issue goes back to 2009. End User setup issues are the hardest to fix.
resolution requires reading.


* When you run lspci and then a different backended hardware identification utility, are there differing naming anomolies.??? What is the exact hardware spec'd? as per Manufacturer whitepaper.?
#
After every install, kernel,firmware,hardware, driver change or just because ..biannually;
* I run update-pciids with the latest pci.ids.(and the rest)
 So the hardware is identified correctly.
*
#
I then check off the "indentified" HW against the HW actual.
#
Is the correct hardware audio codec pinned on the mainboard and or in the bios? Can the "driver be incorrectly chosen by the system codec?"
#
What about the correct dma mask/ buff setup.?
# Is nvidia choking(64Mb or Higher) and the kernel is defaulting to intel??
#
* I run fwupd and the relevent modprobe / dkms if needed.
Is the issue that these systems are not being installed and set up.
#
"The cost of Open Source Free Software is the End User is free to finish the integration"
#
https://www.kernel.org/doc/html/latest/PCI/index.html
#
https://www.kernel.org/doc/html/latest/sound/hd-audio/models.html
#
https://help.ubuntu.com/community/SoundTroubleshootingGuide#Ae_.28.28Make_NVIDIA_HDMI_Audio_work.29

My systems have been running by the book ever since I started reading it.
Hope this helps someone and for the others...flame away.
Comment 23 Artem S. Tashkinov 2021-10-23 10:20:20 UTC
NVIDIA has solved the issue themselves in the latest drivers but it may still affect older drivers which haven't been updated to include the fix.

Can anyone running older NVIDIA drivers and a sufficiently recent kernel, 5.14.14, confirm that this is still an issue?
Comment 24 Artem S. Tashkinov 2021-12-30 20:16:47 UTC
NVIDIA has fixed this in their driver.

Note You need to log in before you can comment on or make changes to this bug.