New issue
Advanced search Search tips

Issue 697295 link

Starred by 2 users

Issue metadata

Status: Archived
Owner:
Closed: Apr 2017
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

tpm_manager/trunks: trunksd start race

Project Member Reported by apronin@google.com, Mar 1 2017

Issue description

trunksd.conf upstart script assumes trunksd has started before it has actually completed initialization.
As a result, tpm_managerd may start and attempt talking to trunksd before it has registered d-bus handlers. If that happens, tpm_managerd crashes and respawns. A sample log is provided below (note that "Trunks service started" is printed *before* service.Run() in itrunksd.cc):

2017-02-28T15:13:31.659478-08:00 INFO trunksd[1507]: TPM: /dev/tpm0 opened successfully
2017-02-28T15:13:31.660049-08:00 WARNING trunksd[1507]: libminijail[1507]: allowing syscall: connect
2017-02-28T15:13:31.660074-08:00 WARNING trunksd[1507]: libminijail[1507]: allowing syscall: sendto
2017-02-28T15:13:31.664557-08:00 INFO tpm_managerd[1523]: Starting TPM Manager...
2017-02-28T15:13:31.673116-08:00 WARNING trunksd[1507]: libminijail[1507]: logging seccomp filter failures
2017-02-28T15:13:31.673419-08:00 INFO trunksd[1507]: Trunks service started.
2017-02-28T15:13:31.693110-08:00 ERR tpm_managerd[1523]: Failed to call method: org.chromium.Trunks.SendCommand: object_path= /org/chromium/Trunks: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Trunks was not provided by any .service files
2017-02-28T15:13:31.700419-08:00 ERR tpm_managerd[1523]: CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=The name org.chromium.Trunks was not provided by any .service files
2017-02-28T15:13:31.700650-08:00 ERR tpm_managerd[1523]: TrunksProxy could not parse response: The name org.chromium.Trunks was not provided by any .service files
2017-02-28T15:13:31.700754-08:00 ERR tpm_managerd[1523]: GetCapability: SAPI_RC_MALFORMED_RESPONSE
2017-02-28T15:13:31.700836-08:00 ERR tpm_managerd[1523]: Failed to query TPM properties: SAPI_RC_MALFORMED_RESPONSE
2017-02-28T15:13:31.700914-08:00 WARNING tpm_managerd[1523]: Error initializing trunks tpm state: SAPI_RC_MALFORMED_RESPONSE
2017-02-28T15:13:31.701301-08:00 CRIT tpm_managerd[1523]: Check failed: initialized_. #012/usr/lib64/libbase-core-395517.so(bas<IPv6: 22>ug<IPv6: 1>StackTr<IPv6: 23>StackTrace()+0x13) [0x7c8cfeca91d3]#012
...
2017-02-28T15:13:31.810849-08:00 INFO trunksd[1507]: CheckState: TPM State verified.
...
2017-02-28T15:13:31.855744-08:00 WARNING crash_reporter[1592]: [user] Received crash notification for tpm_managerd[1523] sig 6, user 0 (handling)
2017-02-28T15:13:31.869665-08:00 INFO crash_reporter[1592]: State of crashed process [1523]: D (disk sleep)
...
2017-02-28T15:13:32.077029-08:00 WARNING kernel: [    8.120847] init: tpm_managerd main process (1523) killed by ABRT signal
2017-02-28T15:13:32.077055-08:00 WARNING kernel: [    8.120879] init: tpm_managerd main process ended, respawning
 
Labels: -Pri-3 OS-Chrome Pri-2
Owner: apronin@chromium.org
Status: Assigned (was: Untriaged)
tpm_managerd must wait for trunksd, until it is available.
An alternative approach is waiting in post-start for trunksd to become available on d-bus. E.g. through trying to access it there from trunks_client:

post-start script
  while ! trunks_client --status ; do sleep 1 ; done
end script

But that'd unnecessarily slow down the boot process.
Project Member

Comment 3 by bugdroid1@chromium.org, Mar 24 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/aosp/platform/system/tpm/+/90a81a566bded63bd4ef2e67f8359b1723c59947

commit 90a81a566bded63bd4ef2e67f8359b1723c59947
Author: Andrey Pronin <apronin@chromium.org>
Date: Fri Mar 24 02:03:57 2017

trunks: wait for service readiness in dbus proxy init

The callers of TrunksDBusProxy::Init() assume that they can start
sending messages to trunksd as soon as this function returns true.
In reality, it was returning true wthout checking if trunksd has
already registered on dbus. That led to race conditions with
daemons attempting to send messages to trunksd before it was
initialized.

1) Fix that by returning true from TrunksDBusProxy::Init() only if
trunks service has an owner (wait for the owner, if needed, with
a timeout).

2) Check if the service is ready when sending messages to trunksd,
and return an appropriate error if the service is not ready. A new
code SAPI_RC_NO_CONNECTION was created for that purpose.

3) Modify tpm_managerd to check timestamps instead of counting
the number of attempts when waiting for TrunksDBusProxy
initialization to succeed.

4) Add unit tests for TrunksDBusProxy.

BUG= chromium:697295 
TEST=1) Unit tests (new added).
     2) Inject an artificial delay in trunksd start sequence,
        verify that tpm_managerd doesn't crash and waits for
        trunksd to start before sending messages to it.

Change-Id: Ic1b2eae7dc7f343b5debe694ba3742dce6a2ce1a
Reviewed-on: https://chromium-review.googlesource.com/456048
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Ben Chan <benchan@chromium.org>

[add] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/trunks_dbus_proxy_test.cc
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/trunks_dbus_proxy.h
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/tpm_manager/server/tpm_manager_service.cc
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/error_codes.h
[add] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/mock_dbus_bus.h
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/trunks_dbus_proxy.cc
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/error_codes.cc
[modify] https://crrev.com/90a81a566bded63bd4ef2e67f8359b1723c59947/trunks/trunks.gyp

Status: Started (was: Assigned)
Labels: -Pri-2 Merge-Request-58 M-58 Pri-1
Project Member

Comment 6 by sheriffbot@chromium.org, Mar 28 2017

Labels: -Merge-Request-58 Hotlist-Merge-Approved Merge-Approved-58
Your change meets the bar and is auto-approved for M58. Please go ahead and merge the CL to branch 3029 manually. Please contact milestone owner if you have questions.
Owners: amineer@(Android), cmasso@(iOS), bhthompson@(ChromeOS), govind@(Desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Project Member

Comment 7 by bugdroid1@chromium.org, Mar 28 2017

Labels: merge-merged-release-R58-9334.B
The following revision refers to this bug:
  https://chromium.googlesource.com/aosp/platform/system/tpm/+/5307ecc693c63f61be357f6a70315624a7a38007

commit 5307ecc693c63f61be357f6a70315624a7a38007
Author: Andrey Pronin <apronin@chromium.org>
Date: Tue Mar 28 20:00:26 2017

trunks: wait for service readiness in dbus proxy init

The callers of TrunksDBusProxy::Init() assume that they can start
sending messages to trunksd as soon as this function returns true.
In reality, it was returning true wthout checking if trunksd has
already registered on dbus. That led to race conditions with
daemons attempting to send messages to trunksd before it was
initialized.

1) Fix that by returning true from TrunksDBusProxy::Init() only if
trunks service has an owner (wait for the owner, if needed, with
a timeout).

2) Check if the service is ready when sending messages to trunksd,
and return an appropriate error if the service is not ready. A new
code SAPI_RC_NO_CONNECTION was created for that purpose.

3) Modify tpm_managerd to check timestamps instead of counting
the number of attempts when waiting for TrunksDBusProxy
initialization to succeed.

4) Add unit tests for TrunksDBusProxy.

BUG= chromium:697295 
TEST=1) Unit tests (new added).
     2) Inject an artificial delay in trunksd start sequence,
        verify that tpm_managerd doesn't crash and waits for
        trunksd to start before sending messages to it.

Change-Id: Ic1b2eae7dc7f343b5debe694ba3742dce6a2ce1a
Reviewed-on: https://chromium-review.googlesource.com/456048
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Ben Chan <benchan@chromium.org>
(cherry picked from commit 90a81a566bded63bd4ef2e67f8359b1723c59947)

[add] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/trunks_dbus_proxy_test.cc
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/trunks_dbus_proxy.h
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/tpm_manager/server/tpm_manager_service.cc
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/error_codes.h
[add] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/mock_dbus_bus.h
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/trunks_dbus_proxy.cc
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/error_codes.cc
[modify] https://crrev.com/5307ecc693c63f61be357f6a70315624a7a38007/trunks/trunks.gyp

Project Member

Comment 8 by bugdroid1@chromium.org, Mar 31 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/4f74aa99dd267a3e7da8b52446fc007c7f28230b

commit 4f74aa99dd267a3e7da8b52446fc007c7f28230b
Author: Andrey Pronin <apronin@chromium.org>
Date: Fri Mar 31 19:59:18 2017

cryptohome: recognize more tpm2 comm errors

Treat errors returned by TrunksDBusProxy when trunksd is not
present on dbus or didn't send back a (recognizable) response
as communication errors, which they are.

BUG= chromium:697295 
TEST=Unit tests

Change-Id: I8f0f6c910e7980612d8a38f74d656a43f79fb852
Reviewed-on: https://chromium-review.googlesource.com/461442
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Darren Krahn <dkrahn@chromium.org>
Reviewed-by: Ben Chan <benchan@chromium.org>

[modify] https://crrev.com/4f74aa99dd267a3e7da8b52446fc007c7f28230b/cryptohome/tpm2_impl.cc

Project Member

Comment 9 by sheriffbot@chromium.org, Apr 3 2017

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Project Member

Comment 10 by bugdroid1@chromium.org, Apr 3 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/e35f614cd7c404e4a356725d6534173c330c324f

commit e35f614cd7c404e4a356725d6534173c330c324f
Author: Andrey Pronin <apronin@chromium.org>
Date: Mon Apr 03 19:12:02 2017

cryptohome: recognize more tpm2 comm errors

Treat errors returned by TrunksDBusProxy when trunksd is not
present on dbus or didn't send back a (recognizable) response
as communication errors, which they are.

BUG= chromium:697295 
TEST=Unit tests

Change-Id: I8f0f6c910e7980612d8a38f74d656a43f79fb852
Reviewed-on: https://chromium-review.googlesource.com/461442
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Darren Krahn <dkrahn@chromium.org>
Reviewed-by: Ben Chan <benchan@chromium.org>
(cherry picked from commit 4f74aa99dd267a3e7da8b52446fc007c7f28230b)
Reviewed-on: https://chromium-review.googlesource.com/466606
Reviewed-by: Andrey Pronin <apronin@chromium.org>
Commit-Queue: Andrey Pronin <apronin@chromium.org>

[modify] https://crrev.com/e35f614cd7c404e4a356725d6534173c330c324f/cryptohome/tpm2_impl.cc

Labels: -Merge-Approved-58 Merge-Merged
Status: Fixed (was: Started)

Comment 12 by dchan@chromium.org, Jan 22 2018

Status: Archived (was: Fixed)

Sign in to add a comment