[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Tadeusz Struk]

[-- Attachment #1: Type: text/plain, Size: 678 bytes --]

On 3/12/21 6:25 AM, Kenneth Goldman wrote:
>> CRITICAL **: 10:43:39.780: CreateConnection expected to return 1
>> handles, received 2
>>
>> what might happen is that for whatever reason it leaks one of this dbus
>> proxy objects on every pcr_read and finally runs out of them.
>> It might be that it is very WSL specific.
> 
> I don't think it's a hard limit.  As I said, it runs longer after
> debug is turned on and longer with a sleep.  The actual failure
> count varies a lot from run to run.

Ken,
Could you try if this patch fixes the problem for you:
https://patch-diff.githubusercontent.com/raw/tpm2-software/tpm2-abrmd/pull/770.patch

Thanks,
Tadeusz

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Tadeusz Struk]

[-- Attachment #1: Type: text/plain, Size: 1044 bytes --]

On 3/16/21 11:46 AM, Tadeusz Struk wrote:
> After some investigation I found out that WSL
> has its own problems with the Unix sockets [2] and socketpair()
> implementation [3], which we rely on.
> To fix that would require some redesigning of the underlined dbus
> back-end and validation time, which we can't afford at the moment.
> All the validation for for tpm2-abrmd was done on Linux and FreeBSD and
> these are the systems we support and recommend.
> I would consider running tpm2-abrmd on WSL as experimental.
> 
> [1]
> https://developer.gnome.org/gio/stable/GDBusMethodInvocation.html#g-dbus-method-invocation-return-value-with-unix-fd-list
> [2] https://github.com/microsoft/WSL/issues/4240
> [3] https://github.com/microsoft/WSL/issues/3100
> 

FWIW I was running the same tests on native Linux with many processes
talking to tabrmd on the session bus for hours. It looks pretty stable.
With the same thing running on WSL the dbus daemon crashes after 5-10
minutes and with it I'm crashing my whole mate-session.

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Tadeusz Struk]

[-- Attachment #1: Type: text/plain, Size: 1295 bytes --]

On 3/16/21 8:41 AM, Kenneth Goldman wrote:
> This fixes the startup problem, where abrmd expected one handle and
> receives two.
> 
> It does not fix the crash.
> 
> On a loop of pcrread, it fails after 695, 324, 951, and 26 passes. This
> looks random to me, not some hard limit.

Thanks Ken,
So what I've found so far is that some the functions we are using to
interact with dbus, like
g_dbus_method_invocation_return_value_with_unix_fd_list() [1], which use
the AF_LOCAL aka Unix type sockets, behave differently on WSL compering
to a native Linux system. After some investigation I found out that WSL
has its own problems with the Unix sockets [2] and socketpair()
implementation [3], which we rely on.
To fix that would require some redesigning of the underlined dbus
back-end and validation time, which we can't afford at the moment.
All the validation for for tpm2-abrmd was done on Linux and FreeBSD and
these are the systems we support and recommend.
I would consider running tpm2-abrmd on WSL as experimental.

[1]
https://developer.gnome.org/gio/stable/GDBusMethodInvocation.html#g-dbus-method-invocation-return-value-with-unix-fd-list
[2] https://github.com/microsoft/WSL/issues/4240
[3] https://github.com/microsoft/WSL/issues/3100

Thanks,
-- 
Tadeusz

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Kenneth Goldman]

[-- Attachment #1: Type: text/plain, Size: 1461 bytes --]


This fixes the startup problem, where abrmd expected one handle and
receives two.

It does not fix the crash.

On a loop of pcrread, it fails after 695, 324, 951, and 26 passes.  This
looks random to me, not some hard limit.

--
Ken Goldman   kgoldman(a)us.ibm.com
914-945-2415 (862-2415)




From:	Tadeusz Struk <tstruk(a)gmail.com>
To:	Kenneth Goldman <kgoldman(a)us.ibm.com>
Cc:	tpm2(a)lists.01.org
Date:	03/15/2021 10:15 PM
Subject:	[EXTERNAL] Re: [tpm2] Re: abrmd crashing - how to debug? - dbus
            logs?



On 3/12/21 6:25 AM, Kenneth Goldman wrote:
>> CRITICAL **: 10:43:39.780: CreateConnection expected to return 1
>> handles, received 2
>>
>> what might happen is that for whatever reason it leaks one of this dbus
>> proxy objects on every pcr_read and finally runs out of them.
>> It might be that it is very WSL specific.
>
> I don't think it's a hard limit.  As I said, it runs longer after
> debug is turned on and longer with a sleep.  The actual failure
> count varies a lot from run to run.

Ken,
Could you try if this patch fixes the problem for you:
https://urldefense.proofpoint.com/v2/url?u=https-3A__patch-2Ddiff.githubusercontent.com_raw_tpm2-2Dsoftware_tpm2-2Dabrmd_pull_770.patch&d=DwID-g&c=jf_iaSHvJObTbx-siA1ZOg&r=DZCVG43VcL8GTneMZb8k8lEwb-O1GZktFfre1-mlmiA&m=Nrt6cxuFCHXflg-6IA0GtxS67OeMf3npnorQvzu2PoE&s=jyIln4AEW6cPuvpeUmCLxuOq199pc--dVTj9AZYwcds&e=


Thanks,
Tadeusz




[-- Attachment #2: attachment.htm --]
[-- Type: text/html, Size: 2977 bytes --]

[-- Attachment #3: graycol.gif --]
[-- Type: image/gif, Size: 105 bytes --]

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Kenneth Goldman]

[-- Attachment #1: Type: text/plain, Size: 1323 bytes --]

> From: Tadeusz Struk <tadeusz.struk(a)intel.com>

> >> > After about 5 minutes of sending commands, abrmd crashes. I
> >> originally found it with keylime, but I can reproduce it with a
> >> simple bash loop on pcrread.
> >
> > A few data points:
> >
> > When I run with the debug flag on, it runs 5x longer.
> > When I run with a 5 second sleep between commands, it runs 10x longer.
> >
> > It seems to be related to how fast I send the pcr read commands,
> > but I'm not sure.
> >
> > ~~
> >
> > I'm happy to post abrmd dbus logs, but I don't know where they are.
>
> I think that we still need to find out what was wrong in the initial
> problem in tcti_tabrmd_connect() that it returned 2 handles instead of 1
> as expected:
>
> CRITICAL **: 10:43:39.780: CreateConnection expected to return 1
> handles, received 2
>
> what might happen is that for whatever reason it leaks one of this dbus
> proxy objects on every pcr_read and finally runs out of them.
> It might be that it is very WSL specific.

I don't think it's a hard limit.  As I said, it runs longer after
debug is turned on and longer with a sleep.  The actual failure
count varies a lot from run to run.

> Did you try it on any other
> environment like Linux in a VM maybe?

Can you recommend any distro and release?

[-- Attachment #2: attachment.htm --]
[-- Type: text/html, Size: 1820 bytes --]

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Tadeusz Struk]

[-- Attachment #1: Type: text/plain, Size: 2705 bytes --]

On 3/11/21 9:34 AM, Kenneth Goldman wrote:
>> From: Tadeusz Struk <tstruk(a)gmail.com>
>> To: Kenneth Goldman <kgoldman(a)us.ibm.com>, tpm2(a)lists.01.org
>> Date: 03/09/2021 02:50 PM
>> Subject: [EXTERNAL] [tpm2] Re: abrmd crashing - how to debug?
>>
>> Hi Ken,
>> On 3/5/21 2:29 PM, Kenneth Goldman wrote:
>> > Ubuntu focal with WSL, abrmd compiled from source
>> >
>> > After about 5 minutes of sending commands, abrmd crashes. I
>> originally found it with keylime, but I can reproduce it with a
>> simple bash loop on pcrread.
>> >
>> > abrmd exits, the tool output is:
>> >
>> > ** (process:21067): CRITICAL **: 17:25:10.862: failed to allocate
>> dbus proxy object: Could not connect: Connection refused
>> > WARNING:tcti:src/tss2-tcti/tctildr.c:79:tcti_from_init() TCTI init
>> for function 0x7ff5f6dbbe10 failed with a0008
>> > WARNING:tcti:src/tss2-tcti/tctildr.c:109:tcti_from_info() Could
>> not initialize TCTI named: tcti-abrmd
>> > ERROR:tcti:src/tss2-tcti/tctildr-dl.c:154:tcti_from_file() Could
>> not initialize TCTI file: tabrmd
>> > ERROR:tcti:src/tss2-tcti/tctildr.c:416:Tss2_TctiLdr_Initialize_Ex
>> () Failed to instantiate TCTI
>> > ERROR: Could not load tcti, got: "tabrmd:bus_name=com.intel.tss2.Tabrmd"
>> >
>> > How would I debug?
>> >
>> > I would expect that nothing that a single application does should
>> crash abrmd.
>>
>> I think it's not the abrmd that's failing, but the application that
>> is trying to
>> use tcti-abrmd to communicate with abrmd running in the background.
>> It can not get the dbus handler so it just prints an error and fails.
>> Can you look for some system dbus logs to see if there are any errors
> there?
> 
> What I meant by abrmd crashing is that it runs for a while, and then
> exits back to a command prompt.  There is no error message.
> 
> A few data points:
> 
> When I run with the debug flag on, it runs 5x longer.
> When I run with a 5 second sleep between commands, it runs 10x longer.
> 
> It seems to be related to how fast I send the pcr read commands,
> but I'm not sure.
> 
> ~~
> 
> I'm happy to post abrmd dbus logs, but I don't know where they are.

I think that we still need to find out what was wrong in the initial
problem in tcti_tabrmd_connect() that it returned 2 handles instead of 1
as expected:

CRITICAL **: 10:43:39.780: CreateConnection expected to return 1
handles, received 2

what might happen is that for whatever reason it leaks one of this dbus
proxy objects on every pcr_read and finally runs out of them.
It might be that it is very WSL specific. Did you try it on any other
environment like Linux in a VM maybe?

Thanks,
-- 
Tadeusz

[tpm2] Re: abrmd crashing - how to debug? - dbus logs?

[Kenneth Goldman]

[-- Attachment #1: Type: text/plain, Size: 2072 bytes --]

> From: Tadeusz Struk <tstruk(a)gmail.com>
> To: Kenneth Goldman <kgoldman(a)us.ibm.com>, tpm2(a)lists.01.org
> Date: 03/09/2021 02:50 PM
> Subject: [EXTERNAL] [tpm2] Re: abrmd crashing - how to debug?
>
> Hi Ken,
> On 3/5/21 2:29 PM, Kenneth Goldman wrote:
> > Ubuntu focal with WSL, abrmd compiled from source
> >
> > After about 5 minutes of sending commands, abrmd crashes. I
> originally found it with keylime, but I can reproduce it with a
> simple bash loop on pcrread.
> >
> > abrmd exits, the tool output is:
> >
> > ** (process:21067): CRITICAL **: 17:25:10.862: failed to allocate
> dbus proxy object: Could not connect: Connection refused
> > WARNING:tcti:src/tss2-tcti/tctildr.c:79:tcti_from_init() TCTI init
> for function 0x7ff5f6dbbe10 failed with a0008
> > WARNING:tcti:src/tss2-tcti/tctildr.c:109:tcti_from_info() Could
> not initialize TCTI named: tcti-abrmd
> > ERROR:tcti:src/tss2-tcti/tctildr-dl.c:154:tcti_from_file() Could
> not initialize TCTI file: tabrmd
> > ERROR:tcti:src/tss2-tcti/tctildr.c:416:Tss2_TctiLdr_Initialize_Ex
> () Failed to instantiate TCTI
> > ERROR: Could not load tcti, got:
"tabrmd:bus_name=com.intel.tss2.Tabrmd"
> >
> > How would I debug?
> >
> > I would expect that nothing that a single application does should
> crash abrmd.
>
> I think it's not the abrmd that's failing, but the application that
> is trying to
> use tcti-abrmd to communicate with abrmd running in the background.
> It can not get the dbus handler so it just prints an error and fails.
> Can you look for some system dbus logs to see if there are any errors
there?

What I meant by abrmd crashing is that it runs for a while, and then
exits back to a command prompt.  There is no error message.

A few data points:

When I run with the debug flag on, it runs 5x longer.
When I run with a 5 second sleep between commands, it runs 10x longer.

It seems to be related to how fast I send the pcr read commands,
but I'm not sure.

~~

I'm happy to post abrmd dbus logs, but I don't know where they are.

[-- Attachment #2: attachment.htm --]
[-- Type: text/html, Size: 2833 bytes --]