Bug#1087331: regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary

[Christoph Anton Mitterer]

Source: linux
Version: 16
Severity: normal


Hey.

That either started with 6.11.7-1 (or perhaps alo with 6.11.6, which I skipped),
but it's at least not present with 6.11.5-1.

After boot, the kernel starts "flooding" (well every 10s) the kernel log
with:
Nov 11 17:49:25 heisenberg kernel: wlan0: Limiting TX power to 27 (30 - 3) dBm as advertised by 50:e6:36:3c:99:36
Nov 11 17:49:50 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 11 17:50:00 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 11 17:50:10 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 11 17:50:20 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:50:30 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:50:41 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:50:51 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:51:01 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:51:11 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:51:22 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 11 17:51:32 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
...

The laptop does have a TPM device, and it is enabled in the BIOS.


Cheers,
Chris.


-- System Information:
Debian Release: trixie/sid
APT prefers unstable-debug
APT policy: (500, 'unstable-debug'), (500, 'unstable')
Architecture: amd64 (x86_64)

Kernel: Linux 6.11.7-amd64 (SMP w/16 CPU threads; PREEMPT)
Locale: LANG=en_DE.UTF-8, LC_CTYPE=en_DE.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)

[Debian Bug Tracking System]

Your message dated Mon, 11 Nov 2024 21:25:27 +0100
with message-id <***@scientia.org>
and subject line Re: regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
has caused the Debian Bug report #1087331,
regarding regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ***@bugs.debian.org
immediately.)

[Christoph Anton Mitterer]

Control: reopen -1

Hey.

It's back, so at least this wasn't a one time glitch, making it IMO
more likely that there actually is some regression.
Thus reopening for now.

Thanks,
Chris.

[Debian Bug Tracking System]

Post by Christoph Anton Mitterer
reopen -1

Bug #1087331 {Done: Christoph Anton Mitterer <***@scientia.org>} [src:linux] regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Bug reopened
Ignoring request to alter fixed versions of bug #1087331 to the same values previously set

[Christoph Anton Mitterer]

Control: forwarded -1 https://lore.kernel.org/linux-integrity/***@HansenPartnership.com/T/#t

Hey.

It seems that the problem is always triggered when the system is
resumed from hibernation.
I.e. it does not seem to happen after a fresh boot.

That's the kernel log from hibernate&resume:

Nov 13 12:32:31 heisenberg kernel: Filesystems sync: 0.007 seconds
Nov 13 12:32:31 heisenberg kernel: Freezing user space processes
Nov 13 12:32:31 heisenberg kernel: sh (31294): drop_caches: 1
Nov 13 12:32:31 heisenberg kernel: Freezing user space processes completed (elapsed 0.326 seconds)
Nov 13 12:32:31 heisenberg kernel: OOM killer disabled.
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x000a0000-0x000fffff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x2f2a9000-0x310a8fff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x310be000-0x310befff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x34f53000-0x35046fff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x39cbf000-0x43afefff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Marking nosave pages: [mem 0x43b00000-0xffffffff]
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Basic memory bitmaps created
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Preallocating image memory
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Allocated 3676637 pages for snapshot
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Allocated 14706548 kbytes in 1.90 seconds (7740.28 MB/s)
Nov 13 12:32:31 heisenberg kernel: Freezing remaining freezable tasks
Nov 13 12:32:31 heisenberg kernel: Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
Nov 13 12:32:31 heisenberg kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Nov 13 12:32:31 heisenberg kernel: intel-hid INTC1070:00: failed to get button capability
Nov 13 12:32:31 heisenberg kernel: ACPI: EC: interrupt blocked
Nov 13 12:32:31 heisenberg kernel: Disabling non-boot CPUs ...
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 15 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 14 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 13 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 12 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 11 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 10 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 9 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 8 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 7 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 6 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 5 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 4 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 3 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 2 is now offline
Nov 13 12:32:31 heisenberg kernel: smpboot: CPU 1 is now offline
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Creating image:
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Need to copy 3608962 pages
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Normal pages needed: 3608962 + 1024, available pages: 13065600
Nov 13 12:32:31 heisenberg kernel: Enabling non-boot CPUs ...
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 1 APIC 0x1
Nov 13 12:32:31 heisenberg kernel: CPU1 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 2 APIC 0x8
Nov 13 12:32:31 heisenberg kernel: CPU2 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 3 APIC 0x9
Nov 13 12:32:31 heisenberg kernel: CPU3 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 4 APIC 0x10
Nov 13 12:32:31 heisenberg kernel: CPU4 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 5 APIC 0x11
Nov 13 12:32:31 heisenberg kernel: CPU5 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 6 APIC 0x18
Nov 13 12:32:31 heisenberg kernel: CPU6 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 7 APIC 0x19
Nov 13 12:32:31 heisenberg kernel: CPU7 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 8 APIC 0x20
Nov 13 12:32:31 heisenberg kernel: core: cpu_atom PMU driver: PEBS-via-PT
Nov 13 12:32:31 heisenberg kernel: ... version: 5
Nov 13 12:32:31 heisenberg kernel: ... bit width: 48
Nov 13 12:32:31 heisenberg kernel: ... generic registers: 6
Nov 13 12:32:31 heisenberg kernel: ... value mask: 0000ffffffffffff
Nov 13 12:32:31 heisenberg kernel: ... max period: 00007fffffffffff
Nov 13 12:32:31 heisenberg kernel: ... fixed-purpose events: 3
Nov 13 12:32:31 heisenberg kernel: ... event mask: 000000070000003f
Nov 13 12:32:31 heisenberg kernel: CPU8 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 9 APIC 0x22
Nov 13 12:32:31 heisenberg kernel: CPU9 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 10 APIC 0x24
Nov 13 12:32:31 heisenberg kernel: CPU10 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 11 APIC 0x26
Nov 13 12:32:31 heisenberg kernel: CPU11 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 12 APIC 0x28
Nov 13 12:32:31 heisenberg kernel: CPU12 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 13 APIC 0x2a
Nov 13 12:32:31 heisenberg kernel: CPU13 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 14 APIC 0x2c
Nov 13 12:32:31 heisenberg kernel: CPU14 is up
Nov 13 12:32:31 heisenberg kernel: smpboot: Booting Node 0 Processor 15 APIC 0x2e
Nov 13 12:32:31 heisenberg kernel: CPU15 is up
Nov 13 12:32:31 heisenberg kernel: ACPI: EC: interrupt unblocked
Nov 13 12:32:31 heisenberg kernel: usb usb1: root hub lost power or was reset
Nov 13 12:32:31 heisenberg kernel: usb usb2: root hub lost power or was reset
Nov 13 12:32:31 heisenberg kernel: intel-hid INTC1070:00: failed to get button capability
Nov 13 12:32:31 heisenberg kernel: usb usb3: root hub lost power or was reset
Nov 13 12:32:31 heisenberg kernel: usb usb4: root hub lost power or was reset
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: GuC firmware i915/adlp_guc_70.bin version 70.29.2
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: HuC firmware i915/tgl_huc.bin version 7.9.3
Nov 13 12:32:31 heisenberg kernel: nvme nvme0: D3 entry latency set to 10 seconds
Nov 13 12:32:31 heisenberg kernel: nvme nvme0: 16/0/0 default/read/poll queues
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: HuC: authenticated for all workloads
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: GUC: submission enabled
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: GUC: SLPC enabled
Nov 13 12:32:31 heisenberg kernel: i915 0000:00:02.0: [drm] GT0: GUC: RC enabled
Nov 13 12:32:31 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x20
Nov 13 12:32:31 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
Nov 13 12:32:31 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
Nov 13 12:32:31 heisenberg kernel: iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x0
Nov 13 12:32:31 heisenberg kernel: iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
Nov 13 12:32:31 heisenberg kernel: usb 1-10: reset full-speed USB device number 6 using xhci_hcd
Nov 13 12:32:31 heisenberg kernel: usb 1-6: reset high-speed USB device number 3 using xhci_hcd
Nov 13 12:32:31 heisenberg kernel: usb 1-5: reset high-speed USB device number 2 using xhci_hcd
Nov 13 12:32:31 heisenberg kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: IMR restore failed, trying to cold boot
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: Basic memory bitmaps freed
Nov 13 12:32:31 heisenberg kernel: mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_ops [i915])
Nov 13 12:32:31 heisenberg kernel: OOM killer enabled.
Nov 13 12:32:31 heisenberg kernel: Restarting tasks ...
Nov 13 12:32:31 heisenberg kernel: mei_pxp 0000:00:16.0-fbf6fcf1-96cf-4e2e-a6a6-1bab8cbe36b1: bound 0000:00:02.0 (ops i915_pxp_tee_component_ops [i915])
Nov 13 12:32:31 heisenberg kernel: done.
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: USB disconnect, device number 4
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: new full-speed USB device number 7 using xhci_hcd
Nov 13 12:32:31 heisenberg kernel: PM: hibernation: hibernation exit
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: New USB device found, idVendor=058f, idProduct=9540, bcdDevice= 1.20
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: Product: EMV Smartcard Reader
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: Manufacturer: Generic
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: Device is not authorized for usage
Nov 13 12:32:31 heisenberg kernel: usb 1-5.2: authorized to connect
Nov 13 12:32:31 heisenberg kernel: e1000e 0000:00:1f.6 eth0: NIC Link is Down
Nov 13 12:32:32 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x20
Nov 13 12:32:32 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
Nov 13 12:32:32 heisenberg kernel: iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
Nov 13 12:32:32 heisenberg kernel: iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x0
Nov 13 12:32:32 heisenberg kernel: iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
Nov 13 12:33:06 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 13 12:33:16 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 13 12:33:26 heisenberg kernel: tpm tpm0: NULL Seed name comparison failed
Nov 13 12:33:30 heisenberg kernel: wlan0: authenticate with 40:e3:d6:51:2a:30 (local address=7c:b5:66:f7:a8:a5)
Nov 13 12:33:30 heisenberg kernel: wlan0: send auth to 40:e3:d6:51:2a:30 (try 1/3)
Nov 13 12:33:30 heisenberg kernel: wlan0: authenticated
Nov 13 12:33:30 heisenberg kernel: wlan0: associate with 40:e3:d6:51:2a:30 (try 1/3)
Nov 13 12:33:30 heisenberg kernel: wlan0: RX AssocResp from 40:e3:d6:51:2a:30 (capab=0x411 status=0 aid=8)
Nov 13 12:33:30 heisenberg kernel: wlan0: associated
Nov 13 12:33:30 heisenberg kernel: wlan0: Limiting TX power to 23 (23 - 0) dBm as advertised by 40:e3:d6:51:2a:30
Nov 13 12:33:31 heisenberg kernel: IPv4: martian source 255.255.255.255 from 10.183.63.252, on dev wlan0
Nov 13 12:33:31 heisenberg kernel: ll header: 00000000: 7c b5 66 f7 a8 a5 fc bd 67 c1 e2 ff 08 00
Nov 13 12:33:31 heisenberg kernel: IPv4: martian source 255.255.255.255 from 10.183.63.252, on dev wlan0
Nov 13 12:33:31 heisenberg kernel: ll header: 00000000: 7c b5 66 f7 a8 a5 fc bd 67 c1 e2 ff 08 00
Nov 13 12:33:31 heisenberg kernel: IPv4: martian source 255.255.255.255 from 10.183.63.253, on dev wlan0
Nov 13 12:33:31 heisenberg kernel: ll header: 00000000: 7c b5 66 f7 a8 a5 fc bd 67 16 62 33 08 00
Nov 13 12:33:31 heisenberg kernel: IPv4: martian source 255.255.255.255 from 10.183.63.253, on dev wlan0
Nov 13 12:33:31 heisenberg kernel: ll header: 00000000: 7c b5 66 f7 a8 a5 fc bd 67 16 62 33 08 00
Nov 13 12:33:36 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:33:46 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:33:57 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:34:07 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:34:17 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:34:27 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Nov 13 12:34:38 heisenberg kernel: tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary



Cheers,
Chris.

[Uwe Kleine-König]

Control: retitle -1 many TPM errors after hibernation
Control: tag -1 + upstream fixed-upstream
Thanks for bringing that to upstream's attention. Upstream already
worked out a fix, see
https://lore.kernel.org/linux-integrity/20241113184449.477731-1-***@kernel.org/T/#u
. It has made it into 6.12 as 423893fcbe7e9adc875bce4e55b9b25fc1424977.

The patch is marked for stable, so I'd expect this to be solved for
6.11.y soon, too.

Best regards
Uwe

[Christoph Anton Mitterer]

Hey.

Post by Uwe Kleine-König
The patch is marked for stable, so I'd expect this to be solved for
6.11.y soon, too.

Hasn't made it into .9, but since Greg KH already added it to the
stable tree, it should be in .10 :-)


Thanks,
Chris.

[Debian Bug Tracking System]

Bug #1087331 [src:linux] regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Set Bug forwarded-to-address to 'https://lore.kernel.org/linux-integrity/***@HansenPartnership.com/T/#t'.

[Debian Bug Tracking System]

retitle -1 many TPM errors after hibernation

Bug #1087331 [src:linux] regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary
Changed Bug title to 'many TPM errors after hibernation' from 'regression: kernel log "flooded" with tpm tpm0: A TPM error (2306) occurred attempting to create NULL primary'.

tag -1 + upstream fixed-upstream

Bug #1087331 [src:linux] many TPM errors after hibernation
Added tag(s) fixed-upstream.

[Debian Bug Tracking System]

Your message dated Sat, 23 Nov 2024 17:00:10 +0000
with message-id <E1tEtUQ-009eoP-***@fasolo.debian.org>
and subject line Bug#1087331: fixed in linux 6.11.10-1
has caused the Debian Bug report #1087331,
regarding many TPM errors after hibernation
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ***@bugs.debian.org
immediately.)

[Debian Bug Tracking System]

Your message dated Sat, 07 Dec 2024 11:00:11 +0000
with message-id <E1tJsXj-007wAC-***@fasolo.debian.org>
and subject line Bug#1087331: fixed in linux 6.12.3-1
has caused the Debian Bug report #1087331,
regarding many TPM errors after hibernation
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ***@bugs.debian.org
immediately.)