Re: tpm-tis-device-swtpm-test timeout

[Fabiano Rosas <farosas@suse.de>]

Stefan Berger <stefanb@linux.ibm.com> writes:

> On 10/15/24 3:22 PM, Fabiano Rosas wrote:
>> Stefan Berger <stefanb@linux.ibm.com> writes:
>> 
>>> On 10/15/24 2:11 PM, Fabiano Rosas wrote:
>>>> Hi Stefan,
>>>>
>>>> I see the tpm-tis-device-swtpm test timing out, could you take a look?
>>>>
>>>> qemu:qtest+qtest-aarch64 / qtest-aarch64/tpm-tis-device-swtpm-test time out (After 60.0 seconds)
>>>> 135/138 qemu:qtest+qtest-aarch64 /
>>>> qtest-aarch64/tpm-tis-device-swtpm-test TIMEOUT 60.01s killed by signal 11 SIGSEGV
>>>
>>> Is this something new or been happening for a while? Does it happen
>>> consistently? I just build the master branch and ran the tests on a very
>>> old machine, I mean 13 years old. The host runs Fedora 40 with
>>> libtpms-0.96-6 + swtpm-0.9.0 from the distro:
>> 
>> It's the first time I see it. I can reproduce consistently by running
>> that test in a loop while make -j16 check is running in another window.
>
> So this here is failing for you every time?
>
> QTEST_QEMU_BINARY=build/qemu-system-aarch64 
> ./build/tests/qtest/tpm-tis-device-swtpm-test

Sorry, I was unclear. No, that runs for about 30 iterations before it
fails. I just ran each of these in a terminal window:

$ for i in $(seq 1 999); do echo "$i =============";  QTEST_QEMU_BINARY=./qemu-system-aarch64 ./tests/qtest/tpm-tis-device-swtpm-test || break ; done
$ make -j$(nproc) check
$ while :; do ps aux | grep -v grep | grep swtpm; done

The result is:

$ for i in $(seq 1 999); do echo "$i =============";
QTEST_QEMU_BINARY=./qemu-system-aarch64
./tests/qtest/tpm-tis-device-swtpm-test || break ; done
...
...
22 =============                               
# random seed: R02Se1d542a529b7d9bfdfdcaf9d5359cbb9                                            
1..2                                           
# Start of aarch64 tests                       
# Start of tpm tests                           
# Start of tis-swtpm tests                     
# starting QEMU: exec ./qemu-system-aarch64 -qtest unix:/tmp/qtest-14870.sock -qtest-log /dev/null -chardev socket,path=/tmp/qtest-14870.qmp,id=char0 -mon chardev=char0,mode=control -display 
none -audio none -machine virt,gic-version=max -accel tcg -chardev socket,id=chr,path=/tmp/qemu-tpm-tis-device-swtpm-test.VWOBV2/sock -tpmdev emulator,id=dev,chardev=chr -device tpm-tis-devic
e,tpmdev=dev -accel qtest
ok 1 /aarch64/tpm/tis-swtpm/test               
# End of tis-swtpm tests                       
# Start of tis-swtpm-migration tests                                                           
# starting QEMU: exec ./qemu-system-aarch64 -qtest unix:/tmp/qtest-14870.sock -qtest-log /dev/null -chardev socket,path=/tmp/qtest-14870.qmp,id=char0 -mon chardev=char0,mode=control -display 
none -audio none -machine virt,gic-version=max -accel tcg -chardev socket,id=chr,path=/tmp/qemu-tpm-tis-device-swtpm-test.VWOBV2/sock -tpmdev emulator,id=dev,chardev=chr -device tpm-tis-devic
e,tpmdev=dev  -accel qtest
# starting QEMU: exec ./qemu-system-aarch64 -qtest unix:/tmp/qtest-14870.sock -qtest-log /dev/null -chardev socket,path=/tmp/qtest-14870.qmp,id=char0 -mon chardev=char0,mode=control -display 
none -audio none -machine virt,gic-version=max -accel tcg -chardev socket,id=chr,path=/tmp/qemu-tpm-tis-device-swtpm-test.QXOBV2/sock -tpmdev emulator,id=dev,chardev=chr -device tpm-tis-devic
e,tpmdev=dev -incoming unix:/tmp/qemu-tpm-tis-device-swtpm-test.VWOBV2/migsocket -accel qtest
Segmentation fault (core dumped)               
$ swtpm: Data client disconnected
swtpm: Data client disconnected

>
> This test would start swtpm. Do you see it running while this test is 
> running? It should show process like this running for a very short time 
> obviously  [ while :; do ps aux | grep -v grep | grep swtpm; done ]:

I see several of:

fabiano 30146 0.0 0.0 18056 5564 pts/9 S 15:11 0:00 swtpm socket
--tpmstate dir=/tmp/qemu-tpm-tis-device-swtpm-test.DQFLV2 --ctrl
type=unixio,path=/tmp/qemu-tpm-tis-device-swtpm-test.DQFLV2/sock --tpm2

> stefanb  4087462  0.0  0.0  11040  3732 pts/6    S+   15:30   0:00 swtpm 
> socket --tpmstate dir=/tmp/qemu-tpm-tis-device-swtpm-test.D3SLV2 --ctrl 
> type=unixio,path=/tmp/qemu-tpm-tis-device-swtpm-test.D3SLV2/sock --tpm2
> stefanb  4087467  0.0  0.0  11040  3660 pts/6    S+   15:30   0:00 swtpm 
> socket --tpmstate dir=/tmp/qemu-tpm-tis-device-swtpm-test.H1SLV2 --ctrl 
> type=unixio,path=/tmp/qemu-tpm-tis-device-swtpm-test.H1SLV2/sock --tpm2
>
>
>> 
>> I'm on openSUSE Leap 15.5:
>> 
>> $ rpm -qa | grep libtpms
>> libtpms0-0.8.2-150300.3.9.1.x86_64
>> 
>> $ rpm -qa | grep swtpm
>> swtpm-0.7.3-150500.2.1.x86_64
>>