On Fri, Feb 07, 2025 at 10:58:15AM +0100, Michal Suchánek wrote:
> On Fri, Feb 07, 2025 at 09:47:13AM +0000, Jonathan McDowell wrote:
> > On Fri, Feb 07, 2025 at 10:40:16AM +0100, Michal Suchánek wrote:
> > > On Fri, Feb 07, 2025 at 09:26:16AM +0000, Jonathan McDowell wrote:
> > > > So just to clarify, this more recent patch is working around a situation
> > > > where the status register gets stuck and needs a complete retry of the
> > > > command send - it's an Infineon errata, not something that would be
> > > > fixed with a longer timeout.
> > > >
> > > > We see what looks like Michal's issue with timeouts as well, I just
> > > > haven't made the step of instrumenting it all the way he has.
> > >
> > > And I haven't seen the issue that needs re-sending the command so far.
> >
> > Your SLB9672 is on the latest firmware, which I believe fixes the
> > problem.
> >
> > > Maybe it happens even less frequently than the excessive processing
> > > time.
> > >
> > > Fully restarting the syscall would fix both issues but manual restart of
> > > the userspace task reportedly did not work so I have my doubts that
> > > this method with returning from the syscall would be effective.
> >
> > Hmmm. I wonder if e3aaebcbb7c6b403416f442d1de70d437ce313a7 (tpm: Clean
> > up TPM space after command failure) would help the userspace restart
>
> It's backported to the frankenkernel already so it would not help this
> particular case.
>
> Unfortunately, it's not clear what the userspace task does, and why it
> would not complete after the first failure.
>
> Would need to come up with some way of tracing it.
FWIW bpftrace is great for this. I'm using the attached script as a
basis for investigations. Obviously the timings it reports are the whole
command rather than just the wait for status, but over a long period it
can then show you the latency histogram. (Run it in one terminal, do TPM
stuff elsewhere, hit Ctrl-C when you're done and it dumps the
histogram.)
J.
--
101 things you can't have too much of : 47 - More coffee.
#!/usr/bin/bpftrace
struct tpm_header {
uint8_t tag[2];
uint8_t length[4];
uint8_t ordinal[4];
}
struct tpm_buf {
uint32_t flags;
uint32_t length;
struct tpm_header *hdr;
}
kprobe:tpm_transmit_cmd
{
$buf = (struct tpm_buf *) arg1;
printf("%s (0x%02X%02X%02X%02X) (%s)\n", comm,
$buf->hdr->ordinal[0],
$buf->hdr->ordinal[1],
$buf->hdr->ordinal[2],
$buf->hdr->ordinal[3],
str(arg3));
}
kprobe:tpm_transmit
{
$hdr = (struct tpm_header *) arg1;
$cmd = $hdr->ordinal[0] << 24 | $hdr->ordinal[1] << 16 |
$hdr->ordinal[2] << 8 | $hdr->ordinal[3];
@start[tid] = nsecs;
@tpmcmd[tid] = $cmd;
}
kretprobe:tpm_transmit
/@start[tid]/ {
$dur = nsecs - @start[tid];
@cmdhist[@tpmcmd[tid]] = hist($dur);
printf("%s (0x%08X): %d (%d ns)\n", comm, @tpmcmd[tid], retval, $dur);
delete(@start[tid]);
delete(@tpmcmd[tid]);
}
