Re: [BUG] tpm: prolonged stall in vtpm_proxy_fops_release() on Linux 7.3

[Jarkko Sakkinen <jarkko@kernel.org>]

On Sun, Nov 01, 2026 at 09:22:30AM +0800, 铮 wrote:
> Hi Peter, Jarkko and Jason,

Adding Stefan. 

> 
> I observed a task hang in vtpm_proxy_fops_release() while fuzzing the
> vTPM proxy with syzkaller. I reproduced it on Linux 7.3.0: the campaign
> observed the hang 4 times; replaying the stored sequence reproduced it
> once in an automated replay and three times in manual replays. In every
> case a process is blocked for 143+ seconds in
> vtpm_proxy_fops_release() -> vtpm_proxy_work_stop() -> flush_work(),
> while at the same time the sysrq-t dumps show a chip-register work
> (vtpm_proxy_work -> tpm_chip_register() -> tpm_chip_start() ->
> vtpm_proxy_request_locality()) running on the tpm-vtpm workqueue plus a
> backlog of further queued chip-register works. Which queued work the
> blocked release is waiting for is unconfirmed. All logs end while the
> task is still blocked, so I cannot say how long the stall ultimately
> lasts; I am not claiming a permanent deadlock.
> 
> Environment
> -----------
> - Kernel: 7.3.0-kernsight-kasan #1 SMP PREEMPT_DYNAMIC, built 2026-10-20,
>   x86_64. Vanilla 7.3.0 source tarball (sha256
>   87363c24f10e06321eb362765521094e94471f6bff8bce2d6b3e40f39f004953),
>   built with KASAN/KCOV. No TPM changes were made for this testing
>   (drivers/char/tpm/ matches vanilla apart from build artifacts).
> - Guest: QEMU/KVM, 4 vCPU, 6 GiB, 8 scratch virtio disks, 2 NVDIMM/pmem
>   devices, 2 NUMA nodes (the syzkaller standard environment). A fresh VM
>   was used for every reproduction run.
> - Syzkaller: revision 853b104bb454141a5b0fc0e4218ec78e9f34ffb1+
>   (2026-09-18). The "+" denotes local KernSight integration changes
>   (seed ordering/state feedback: pkg/kernsight, prog/kernsight_*,
>   syz-manager/kernsight_*, pkg/execbackend, snapshot support in vm/qemu).
>   They do not change the TPM syscall descriptions or the executor
>   semantics.
> - Reproduction: the campaign observed the hang 4 times; replaying the
>   stored programs reproduced it once in an automated replay, three
>   times as a single 50-program sequence, and once with the two-step
>   form above (one of the manual replays is captured only as a sysrq-t
>   dump). Four runs on a bare fresh VM with a *different kernel command
>   line* and without the scratch/pmem/NUMA layout recorded no hang --
>   since the command line differs as well, these runs cannot attribute
>   the effect to the device layout.
> 
> Kernel command line (full text in the repository, cmdline/cmdline-7.3.txt):
>   root=/dev/sda console=ttyS0 fstab=no rw earlyprintk=serial net.ifnames=0
>   oops=panic panic_on_warn=1 panic=86400 hung_task_panic=1 softlockup_panic=1
>   nmi_watchdog=panic ... page_owner=on secretmem.enable=1
>   dummy_hcd.num=16 max_loop=32 nbd.nbds_max=32 kunit.autorun=0
>   (for the live-inspection runs, hung_task_panic=0 was used instead; see
>   cmdline/cmdline-7.3-retest.txt)
> 
> Reproduction
> ------------
> Two equivalent ways are verified; the two-step form is the simplest.
> 
> From the host:
> 
>   scp syz-execprog syz-executor repro.priming.prog repro.prog root@guest:/tmp/
>   ssh root@guest
>   cd /tmp && chmod +x syz-execprog syz-executor
> 
> Step 1 -- run the state-construction sequence (49 programs) once:
> 
>   ./syz-execprog -executor=/tmp/syz-executor -procs=1 -repeat=1
> /tmp/repro.priming.prog
> 
> It runs for ~20 s and exits normally. When its executor process exits,
> the vtpm fds it holds are released and the release path hangs: the
> hung-task monitor reports at t≈267 s (logs/serial-twostep.log):
> 
>   INFO: task syz.0.33:10843 blocked for more than 143 seconds.
>         Blocked by coredump.
> 
> while `ps` shows `kworker/X:Y+tpm-vtpm` and the executor task both in
> state D (sysrq-t dump: logs/dmesg-sysrq-twostep.txt), and the serial log
> shows `tpm tpm1/tpm2: Operation Timed out` while the release is blocked.
> Step 2 -- optionally run the crashing testcase afterwards
> (./syz-execprog ... /tmp/repro.prog); on the already-blocked VM it
> simply runs and exits.
> 
> The single-file form replays the state construction and the crashing
> testcase as one 50-program sequence (logs/execprog-verify4.out:
> "parsed 50 programs"):
> 
>   ./syz-execprog -executor=/tmp/syz-executor -procs=1 -repeat=1
> /tmp/repro.kernsight.prog
> 
> In both forms programs run sequentially (procs=1, repeat=1,
> sandbox=none), but a program can leave asynchronous kernel-side work
> behind. The sequence creates several vTPM proxy devices and
> closes/exits over them. The hang appears when a closing task's release
> path races a still-running or queued chip-register work. The
> hung-task monitor then reports (t≈480 s in logs/serial-verify4.log):
> 
>   INFO: task syz.0.33:10857 blocked for more than 143 seconds.
>         Not tainted 7.3.0-kernsight-kasan #1
>         Blocked by coredump.
>   task:syz.0.33        state:D stack:26264 pid:10857 tgid:10857 ppid:10246
>   Call Trace:
>    <TASK>
>    __schedule+0x134d/0x6880
>    schedule_timeout+0x24a/0x290
>    __wait_for_common+0x1d3/0x4e0
>    __flush_work+0x6ab/0xd90
>    vtpm_proxy_work_stop     drivers/char/tpm/tpm_vtpm_proxy.c:470 [inline]
>    vtpm_proxy_delete_device drivers/char/tpm/tpm_vtpm_proxy.c:590 [inline]
>    vtpm_proxy_fops_release+0xa8/0x1d0 drivers/char/tpm/tpm_vtpm_proxy.c:239
>    __fput+0x408/0xb60
>    task_work_run+0x170/0x260
>    do_exit+0x90c/0x2b60
>    ...
> 
>   Showing all locks held in the system:
>    locks held by kworker/3:2/1235: 2, on CPU#3:
>     #0: ff110000267a8540 ((wq_completion)tpm-vtpm){+.+.}-{0:0}
>     #1: ffa0000006cafd08 ((work_completion)(&proxy_dev->work)){+.+.}-{0:0}
> 
> While the task was blocked I captured full task dumps with
> `echo t > /proc/sysrq-trigger` (hung_task_panic=0 variant; three dumps
> included). In the first dump the kworker running a vtpm_proxy_work is
> itself blocked in the transmit loop:
> 
>   task:kworker/2:3     state:D stack:24648 pid:9703
>   Workqueue: tpm-vtpm vtpm_proxy_work
>   Call Trace:
>    <TASK>
>    schedule+0xec/0x2d0
>    schedule_hrtimeout_range_clock+0x11d/0x310
>    usleep_range_state+0x178/0x220
>    ? vtpm_proxy_tpm_req_canceled
>    tpm_transmit+0x4bf/0xb90
>    tpm_transmit_cmd+0x62/0x1f0
>    vtpm_proxy_request_locality+0x140/0x280
>    tpm_chip_start+0x18f/0x340
>    tpm_chip_bootstrap+0x80/0x1c0
>    tpm_chip_register+0x27/0x4d0
>    vtpm_proxy_work+0x41/0x100
>    process_one_work+0xa9c/0x1dc0
>    ...
> 
> All three dumps also show that the tpm-vtpm workqueue carries a backlog
> of further chip-register works behind the running one
> (logs/dmesg-sysrq-verify3.txt):
> 
>   workqueue tpm-vtpm: flags=0x40108
>     pwq 6: cpus=1 node=0 active=1 refcnt=33
>       in-flight: 24:vtpm_proxy_work for 75s
>       inactive: 4*vtpm_proxy_work BAR(10837), 26*vtpm_proxy_work
> 
> (logs/dmesg-sysrq-verify4.txt: in-flight for 109 s,
> inactive: 29*vtpm_proxy_work BAR(10857).) With this backlog I cannot
> tell which specific queued work the blocked release is waiting for; the
> running work shown in the stacks may or may not be that one.
> 
> While the release was blocked, the serial log shows
> "tpm tpm3: Operation Timed out" / "tpm tpm31: Operation Timed out"
> lines. All included logs end while the task is still blocked, so I have
> no log evidence of the release completing; I have also not established
> an upper bound for the stall.
> 
> Two entry paths were observed for the blocked release:
> - process exit: do_exit() -> task_work_run() -> __fput()
>   (campaign reports, the automated reproduction, dmesg-sysrq-verify4.txt)
> - close_range() returning to user space: task_work_run() -> __fput()
>   (dmesg-sysrq-verify3.txt)
> 
> The minimized single-program testcase does not reproduce the hang; the
> full 50-program sequence above is the reproducer. I have not isolated
> which preceding operations or timing conditions are required.
> 
> Question
> --------
> vtpm_proxy_tpm_req_canceled() already exists and the driver marks the
> device as being torn down before flush_work(); from the captured dumps
> I cannot tell why the wait nevertheless persists for minutes. Should
> the release path be bounded, or should the in-flight chip-register work
> be ended more promptly once the proxy is being torn down? I am happy to
> test proposed patches.
> 
> Materials (the reproducer, the sysrq-t task dumps, full serial logs,
> the syz-execprog output, kernel config, command lines, a sha256 manifest,
> and a verify.sh that re-checks the numbers quoted here):
>   https://github.com/Zheng-zheng-codes/vtpm-proxy-release-hang-repro

Thanks for making it public on one go. Here it is the best pick.

> 
> Repository contents
> -------------------
>   repro/repro.priming.prog           state-construction sequence (49 programs)
>   repro/repro.prog                   crashing testcase (use after the
> priming run)
>   repro/repro.kernsight.prog         single-file form (50 programs)
>   logs/vtpm-sysrq-t-all-tasks.txt    sysrq-t dump: kworker stack +
> backlog (run 1)
>   logs/dmesg-sysrq-verify3.txt       sysrq-t dump: backlog,
> close_range entry path
>   logs/dmesg-sysrq-verify4.txt       sysrq-t dump: backlog, do_exit entry path
>   logs/serial-7.3-auto-repro.log     automated state-primed reproduction
>   logs/serial-7.3-manual-repro.log   manual replay, run 1
>   logs/serial-verify4.log            manual replay, run 2 (serial)
>   logs/serial-twostep.log            two-step reproduction (serial)
>   logs/execprog-twostep-step1.out    two-step step 1 output ("parsed
> 49 programs")
>   logs/dmesg-sysrq-twostep.txt       two-step sysrq-t dump
>   logs/execprog-verify4.out          run 2 syz-execprog stdout
> ("parsed 50 programs")
>   logs/serial-7.3-bare-no-trigger-*.log  4 bare-VM runs (no hang recorded)
>   logs/report-7.3-*.txt, log-7.3-*.txt   the 4 campaign instances
>   logs/crash-title.txt               crash title
>   kernel/kernel-7.3.config           kernel configuration
>   cmdline/cmdline-7.3.txt            kernel command line (syzkaller
> standard set)
>   cmdline/cmdline-7.3-retest.txt     verification variant (hung_task_panic=0)
>   verify.sh                          re-checks the numbers quoted in this mail
>   MANIFEST.sha256                    sha256 of every file (except itself)
> 
> I am happy to provide additional information and test proposed patches.
> 
> Best regards,
> Zheng Zheng

Thank you for reporting this.

Br, Jarkko