Re: [PATCH 1/3] tpm: Disable TCG_TPM2_HMAC by default

[Vitor Soares]

On Wed, 2024-05-22 at 17:13 +0300, Jarkko Sakkinen wrote:
> On Wed May 22, 2024 at 4:35 PM EEST, James Bottomley wrote:
> > On Wed, 2024-05-22 at 09:18 +0100, Vitor Soares wrote:
> > > On Tue, 2024-05-21 at 08:33 -0400, James Bottomley wrote:
> > > > On Tue, 2024-05-21 at 10:10 +0300, Jarkko Sakkinen wrote:
> > > > > This benchmark could be done in user space using /dev/tpm0.
> > > > 
> > > > Let's actually try that.  If you have the ibmtss installed, the
> > > > command to time primary key generation from userspace on your tpm
> > > > is
> > > > 
> > > > time tsscreateprimary -hi n -ecc nistp256
> > > > 
> > > > 
> > > > And just for chuckles and grins, try it in the owner hierarchy as
> > > > well (sometimes slow TPMs cache this)
> > > > 
> > > > time tsscreateprimary -hi o -ecc nistp256
> > > > 
> > > > And if you have tpm2 tools, the above commands should be:
> > > > 
> > > > time tpm2_createprimary -C n -G ecc256
> > > > time tpm2_createprimary -C o -G ecc256
> > > > 
> > > > James
> > > > 
> > > > 
> > > 
> > > Testing on an arm64 platform I get the following results.
> > > 
> > > hmac disabled:
> > >   time modprobe tpm_tis_spi
> > >   real    0m2.776s
> > >   user    0m0.006s
> > >   sys     0m0.015s
> > > 
> > >   time tpm2_createprimary -C n -G ecc256
> > >   real    0m0.686s
> > >   user    0m0.044s
> > >   sys     0m0.025s
> > > 
> > >   time tpm2_createprimary -C o -G ecc256
> > >   real    0m0.638s
> > >   user    0m0.048s
> > >   sys     0m0.009s
> > > 
> > > 
> > > hmac enabled:
> > >   time modprobe tpm_tis_spi
> > >   real    8m5.840s
> > >   user    0m0.005s
> > >   sys     0m0.018s
> > > 
> > > 
> > >   time tpm2_createprimary -C n -G ecc256
> > >   real    5m27.678s
> > >   user    0m0.059s
> > >   sys     0m0.009s
> > > 
> > >   (after first command)
> > >   real    0m0.395s
> > >   user    0m0.040s
> > >   sys     0m0.015s
> > > 
> > >   time tpm2_createprimary -C o -G ecc256
> > >   real    0m0.418s
> > >   user    0m0.049s
> > >   sys     0m0.009s
> > 
> > That's interesting: it suggests the create primary is fast (as
> > expected) but that the TPM is blocked for some reason.  Is there
> > anything else in dmesg if you do
> > 
> > dmesg|grep -i tpm
> > 
> > ?
> > 
> > Unfortunately we don't really do timeouts on our end (we have the TPM
> > do it instead), but we could instrument your kernel with command and
> > time sent and returned.  That may tell us where the problem lies.
> 
> If there was possibility to use bpftrace it is trivial to get histogram
> of time used where. I can bake a script but I need to know first if it
> is available in the first place before going through that trouble.
> 
> BR, Jarkko

I did run with ftrace, but need some more time to go through it.

Here the step I did:
kernel config:
  CONFIG_FUNCTION_TRACER
  CONFIG_FUNCTION_GRAPH_TRACER

ftrace:
  # set filters
  echo tpm* > set_ftrace_filter

  # set tracer
  echo function_graph > current_tracer

  # take the sample
  echo 1 > tracing_on; time modprobe tpm_tis_spi; echo 0 > tracing_on

regards,
Vitor Soares