Re: tpm_tis TPM2.0 not detected on cold boot

From: Michael Niewöhner
Date: Fri Jan 04 2019 - 13:26:46 EST

Next message: kbuild test robot: "Re: [PATCH] mm: Expose lazy vfree pages to control via sysctl"
Previous message: Will Deacon: "[GIT PULL] arm64: fixes for -rc1"
In reply to: Michael Niewöhner: "Re: tpm_tis TPM2.0 not detected on cold boot"
Next in thread: Jarkko Sakkinen: "Re: tpm_tis TPM2.0 not detected on cold boot"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Fri, 2019-01-04 at 16:28 +0100, Michael NiewÃhner wrote:
> On Fri, 2019-01-04 at 12:58 +0100, Michael NiewÃhner wrote:
> > On Thu, 2019-01-03 at 16:47 +0100, Michael NiewÃhner wrote:
> > > On Thu, 2019-01-03 at 17:04 +0200, Jarkko Sakkinen wrote:
> > > > On Thu, Jan 03, 2019 at 02:38:11PM +0100, Michael NiewÃhner wrote:
> > > > > On Thu, 2019-01-03 at 15:27 +0200, Jarkko Sakkinen wrote:
> > > > > > On Sun, Dec 23, 2018 at 12:55:12PM +0100, Michael NiewÃhner wrote:
> > > > > > > There is another issue but I don't know if both are related. Maybe
> > > > > > > that's
> > > > > > > just a
> > > > > > > timing issue...
> > > > > > >
> > > > > > > root@debian:~# dd if=/dev/hwrng bs=1 count=1
> > > > > > > dd: error reading '/dev/hwrng': Operation not permitted
> > > > > > > 0+0 records in
> > > > > > > 0+0 records out
> > > > > > > 0 bytes copied, 0.755958 s, 0.0 kB/s
> > > > > > > root@debian:~# dd if=/dev/hwrng bs=1 count=1 | xxd; dd
> > > > > > > if=/dev/hwrng
> > > > > > > bs=1
> > > > > > > count=1 | xxd
> > > > > > > dd: error reading '/dev/hwrng': Operation not permitted
> > > > > > > 0+0 records in
> > > > > > > 0+0 records out
> > > > > > > 0 bytes copied, 0.755697 s, 0.0 kB/s
> > > > > > > 1+0 records in
> > > > > > > 1+0 records out
> > > > > > > 00000000: 52 R
> > > > > > > 1 byte copied, 0.0106268 s, 0.1 kB/s
> > > > > > >
> > > > > > >
> > > > > > > Michael
> > > > > >
> > > > > > What does /sys/devices/virtual/misc/hw_random/rng_current show?
> > > > > >
> > > > > > Did run commands as a sanity check on my laptop and seem to work.
> > > > > >
> > > > > > /Jarkko
> > > > >
> > > > > rng_current says "tpm-rng-0", which should be correct
> > > >
> > > > Is /dev/tpm0 accessible and usable?
> > > >
> > > > /Jarkko
> > >
> > > No, it does not seem to work:
> > >
> > > root@debian:~# tpm_version
> > > Tspi_Context_Connect failed: 0x00003011 - layer=tsp, code=0011 (17),
> > > Communication failure
> > > root@debian:~# tcsd -f
> > > TCSD TDDL ioctl: (25) Inappropriate ioctl for device
> > > TCSD TDDL Falling back to Read/Write device support.
> > > TCSD TDDL ERROR: write to device /dev/tpm0 failed: Operation not permitted
> > > TCSD TCS ERROR: TCS GetCapability failed with result = 0x1087
> > > root@debian:~# stat /dev/tpm0
> > > File: /dev/tpm0
> > > Size: 0 Blocks: 0 IO Block: 4096 character
> > > special
> > > file
> > > Device: 6h/6d Inode: 1114 Links: 1 Device type: a,e0
> > > Access: (0600/crw-------) Uid: ( 104/ tss) Gid: ( 112/ tss)
> > > Access: 2019-01-03 16:39:20.627635333 +0100
> > > Modify: 2019-01-03 16:39:20.627635333 +0100
> > > Change: 2019-01-03 16:39:20.627635333 +0100
> > > Birth: -
> > >
> > > Michael
> >
> > I have done some more tests with tpm2-tests from
> > https://github.com/jethrogb/tpm2-utils.
> > These are my results:
> >
> >
> > (initramfs) ./tpm2-test /dev/tpm0 vendor_tpm_type
> > Error on write(fd,(char*)&tpm_cmd,sizeof(tpm_cmd)): Operation not permitted
> >
> > (initramfs) ./tpm2-test /dev/tpm0 vendor_tpm_type; ./tpm2-test /dev/tpm0
> > vendor_
> > tpm_type
> > Error on write(fd,(char*)&tpm_cmd,sizeof(tpm_cmd)): Operation not permitted
> > ï
> > nitramfs)
> >
> > -> Same symptom like with dd if=/dev/tpm....
> >
> >
> > Trying to read the firmware version:
> >
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > firmwa
> > re_version_1;) 2>/dev/null | hexdump -C
> > 00000000 80 01 00 00 00 1b 00 00 00 00 01 00 00 00 06
> > 00 |................|
> > 00000010 00 00 01 00 00 01 0b 00 01 00 03 |...........|
> > 0000001b
> >
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > firmwa
> > re_version_2;) 2>/dev/null | hexdump -C
> > 00000000 80 01 00 00 00 1b 00 00 00 00 01 00 00 00 06
> > 00 |................|
> > 00000010 00 00 01 00 00 01 0c 00 02 00 08 |...........|
> > 0000001b
> >
> > -> This version numbers are correct, 1.3.2.8 indeed is the current flashed
> > firmware.
> >
> >
> > Get the vendor strings:
> >
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > vendor
> > _string_1;) 2>/dev/null | xxd
> > 00000000: 8001 0000 001b 0000 0000 0100 0000 0600 ................
> > 00000010: 0000 0100 0001 0672 6c73 00 .......rls.
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > vendor
> > _string_2;) 2>/dev/null | xxd
> > 00000000: 8001 0000 001b 0000 0000 0100 0000 0600 ................
> > 00000010: 0000 0100 0001 074e 5043 54 .......NPCT
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > vendor
> > _string_3;) 2>/dev/null | xxd
> > 00000000: 8001 0000 001b 0000 0000 0100 0000 0600 ................
> > 00000010: 0000 0100 0001 0820 0000 00 ....... ...
> > (initramfs) (./tpm2-test /dev/tpm0 vendor_string_1; ./tpm2-test /dev/tpm0
> > vendor
> > _string_4;) 2>/dev/null | xxd
> > 00000000: 8001 0000 001b 0000 0000 0100 0000 0600 ................
> > 00000010: 0000 0100 0001 0920 0000 00 ....... ...
> >
> > Well, NPCT is correct...
> >
> >
> >
> > Michael
>
> Oh damn. I wasn not aware that trousers/tcsd does only support TPM<=1.2.
> Instead of trousers I now tested tpm2-tools and tss2.
> Guess what? Same symptoms... This is definitely some sort of timing issue...
>
>
> root@debian:~# tpm2_nvlist
> ERROR:tcti:src/util/io.c:102:write_all() failed to write to fd 3: Operation
> not
> permitted
> ERROR:tcti:src/tss2-tcti/tcti-device.c:86:tcti_device_transmit() wrong number
> of
> bytes written. Expected 22, wrote 0.
> ERROR: GetCapability:Get NV Index list Error. TPM Error:0xa000a
> ERROR: Unable to run tpm2_nvlist
> root@debian:~# tpm2_nvlist; tpm2_nvlist
> ERROR:tcti:src/util/io.c:102:write_all() failed to write to fd 3: Operation
> not
> permitted
> ERROR:tcti:src/tss2-tcti/tcti-device.c:86:tcti_device_transmit() wrong number
> of
> bytes written. Expected 22, wrote 0.
> ERROR: GetCapability:Get NV Index list Error. TPM Error:0xa000a
> ERROR: Unable to run tpm2_nvlist
> 0x1800001:
> hash algorithm:
> friendly: sha256
> value: 0xB
> attributes:
> friendly:
> authwrite|policydelete|writelocked|writedefine|authread|no_da|written|platform
> cr
> eate
> value: 0x42C0462
> size: 70
> ........
>
> root@debian:~# tpm2_pcrlist
> ERROR:tcti:src/util/io.c:102:write_all() failed to write to fd 3: Operation
> not
> permitted
> ERROR:tcti:src/tss2-tcti/tcti-device.c:86:tcti_device_transmit() wrong number
> of
> bytes written. Expected 22, wrote 0.
> ERROR: GetCapability: Get PCR allocation status Error. TPM Error:0xa000a......
> ERROR: Unable to run tpm2_pcrlist
> root@debian:~# tpm2_pcrlist; tpm2_pcrlist
> sha1 :
> 0 : 1ebb2be3b7103a09b5caeeb5827c1242cd6632ec
> 1 : 425e833da73cb511150d6ffcf6fac64e9a6feb58
> 2 : b2a83b0ebf2f8374299a5b2bdfc31ea955ad7236
> 3 : b2a83b0ebf2f8374299a5b2bdfc31ea955ad7236
> 4 : d13c141b174afbb568773adf1f39940a2df47c7d
> 5 : 756a3647403ab141ec2c1ac7325854f4a93f6efd
> ......
>
>
> Michael

Some straces for working vs non-working calls (I removed lib loading, many
identical lines etc. for better readability):

> strace -f -o /tmp/dbg3 tpm2_pcrlist # NON-WORKING
execve("/usr/bin/tpm2_pcrlist", ["tpm2_pcrlist"], 0x7fff5eb48698 /* 11 vars */)
= 0
<...>
openat(AT_FDCWD, "/dev/tpm0", O_RDWR|O_NONBLOCK) = 3
write(3, "\200\1\0\0\0\26\0\0\1z\0\0\0\5\0\0\0\0\0\0\0\1", 22) = -1 EPERM
(Operation not permitted)
write(2, "ERROR:tcti:src/util/io.c:102:wri"..., 91) = 91
write(2, "ERROR:tcti:src/tss2-tcti/tcti-de"..., 119) = 119
write(2, "ERROR: ", 7) = 7
write(2, "GetCapability: Get PCR allocatio"..., 71) = 71
write(2, "\n", 1) = 1
write(2, "ERROR: ", 7) = 7
write(2, "Unable to run tpm2_pcrlist", 26) = 26
write(2, "\n", 1) = 1
close(3) = 0
munmap(0x7f64f0ec9000, 24856) = 0
exit_group(1) = ?
+++ exited with 1 +++

> tpm2_pcrlist; strace -f -o /tmp/dbg4 tpm2_pcrlist # WORKING
execve("/usr/bin/tpm2_pcrlist", ["tpm2_pcrlist"], 0x7ffef20135f8 /* 11 vars */)
= 0
<...>
openat(AT_FDCWD, "/dev/tpm0", O_RDWR|O_NONBLOCK) = 3
write(3, "\200\1\0\0\0\26\0\0\1z\0\0\0\5\0\0\0\0\0\0\0\1", 22) = 22
poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
read(3,
"\200\1\0\0\0\37\0\0\0\0\0\0\0\0\5\0\0\0\2\0\4\3\377\377\377\0\v\3\377\377\377",
4096) = 31
write(3, "\200\1\0\0\0\32\0\0\1~\0\0\0\2\0\4\3\377\377\377\0\v\3\377\377\377",
26) = 26
poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
read(3,
"\200\1\0\0\0\322\0\0\0\0\0\0\0F\0\0\0\2\0\4\3\377\0\0\0\v\3\0\0\0\0\0"...,
4096) = 210
write(3, "\200\1\0\0\0\32\0\0\1~\0\0\0\2\0\4\3\0\377\377\0\v\3\377\377\377", 26)
= 26
poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
read(3,
"\200\1\0\0\0\322\0\0\0\0\0\0\0F\0\0\0\2\0\4\3\0\377\0\0\v\3\0\0\0\0\0"...,
4096) = 210
<...>
write(1, "sha1 :\n", 7) = 7
write(1, " 0 : 1ebb2be3b7103a09b5caeeb58"..., 48) = 48
write(1, " 1 : d3ac8d9c97272d8ea1c8443dc"..., 48) = 48
write(1, " 2 : b2a83b0ebf2f8374299a5b2bd"..., 48) = 48
<...>
write(1, " 23 : 0000000000000000000000000"..., 72) = 72
close(3) = 0
munmap(0x7f2bbebcf000, 24856) = 0
exit_group(0) = ?
+++ exited with 0 +++

> strace -f -o /tmp/dbg1 dd if=/dev/hwrng of=/dev/null bs=1 count=1 # NON-
WORKING
execve("/bin/dd", ["dd", "if=/dev/hwrng", "of=/dev/null", "bs=1", "count=1"],
0x7ffd5cf74948 /* 11 vars */) = 0
<...>
openat(AT_FDCWD, "/dev/hwrng", O_RDONLY) = 3
dup2(3, 0) = 0
close(3) = 0
lseek(0, 0, SEEK_CUR) = 0
openat(AT_FDCWD, "/dev/null", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
dup2(3, 1) = 1
close(3) = 0
read(0, 0x555e67d1a000, 1) = -1 EPERM (Operation not permitted)
write(2, "dd: ", 4) = 4
write(2, "error reading '/dev/hwrng'", 26) = 26
write(2, ": Operation not permitted", 25) = 25
write(2, "\n", 1) = 1
close(0) = 0
close(1) = 0
write(2, "0+0 records in\n0+0 records out\n", 31) = 31
write(2, "0 bytes copied, 0.75088 s, 0.0 k"..., 35) = 35
write(2, "\n", 1) = 1
close(2) = 0
exit_group(1) = ?
+++ exited with 1 +++

> dd if=/dev/hwrng of=/dev/null bs=1 count=1; tpm2_pcrlist; strace -f -o
/tmp/dbg2 dd if=/dev/hwrng of=/dev/null bs=1 count=1 # WORKING
execve("/bin/dd", ["dd", "if=/dev/hwrng", "of=/dev/null", "bs=1", "count=1"], 0x7ffd880f4cc8 /* 11 vars */) = 0
<...>
openat(AT_FDCWD, "/dev/hwrng", O_RDONLY) = 3
dup2(3, 0) = 0
close(3) = 0
lseek(0, 0, SEEK_CUR) = 0
openat(AT_FDCWD, "/dev/null", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
dup2(3, 1) = 1
close(3) = 0
read(0, "\242", 1) = 1
write(1, "\242", 1) = 1
close(0) = 0
close(1) = 0
write(2, "1+0 records in\n1+0 records out\n", 31) = 31
write(2, "1 byte copied, 0.000110891 s, 9."..., 38) = 38
write(2, "\n", 1) = 1
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++

Michael

Next message: kbuild test robot: "Re: [PATCH] mm: Expose lazy vfree pages to control via sysctl"
Previous message: Will Deacon: "[GIT PULL] arm64: fixes for -rc1"
In reply to: Michael Niewöhner: "Re: tpm_tis TPM2.0 not detected on cold boot"
Next in thread: Jarkko Sakkinen: "Re: tpm_tis TPM2.0 not detected on cold boot"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]