New issue
Advanced search Search tips

Issue 910811 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Dec 4
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

attestationd stops responding on M72 builds (sched_yield syscall suspected)

Project Member Reported by apronin@google.com, Dec 1

Issue description

[Spawned from  issue 910407 ]

Tests fail dues to cryptohome utility returning exit status 1. Looking at the logs discovers cryptohomed in a crash loop due to "The name org.chromium.Attestation was not provided by any .service files". See comments 5-6 from  issue 910407  for details.
 
Copying the most relevant info from  https://crbug.com/910407#c7 :

Finally, thanks to mruthven@, got a repro from the faft test runner (eve, R72-11310.0.0). 'messages' is attached.

messages don't contain anything suspicious re attestationd, but attestationd process is zombie (with 4 threads), init still considers it as 'running'.

# status attestationd
attestationd start/running, process 1307

# ps -mLF --pid 1307
UID        PID  PPID   LWP  C NLWP    SZ   RSS PSR STIME TTY          TIME CMD
attesta+  1307     1     -  0    4     0     0   - 16:34 ?        00:00:01 [attestationd] <defunct>
attesta+     -     -  1307  0    -     -     -   2 16:34 -        00:00:00 -
attesta+     -     -  1310  0    -     -     -   1 16:34 -        00:00:00 -
attesta+     -     -  1312  0    -     -     -   1 16:34 -        00:00:01 -
attesta+     -     -  1327  0    -     -     -   3 16:34 -        00:00:00 -

# cat /proc/1307/task/**/syscall 
24 0x781af16ab068 0x2b 0x7ffd397db220 0x58b101bd6010 0x0 0x0 0x7ffd397db028 0x781af0c93347
202 0x781aefd9c430 0x80 0x0 0x0 0x0 0x59d73a 0x781aefd9c2b0 0x781af126fa47
232 0x10 0x781ae0002000 0x20 0x950 0x0 0x0 0x781aef59baf0 0x781af0cacf3e
23 0x17 0x781aeed9a788 0x0 0x0 0x0 0x0 0x781aeed9a650 0x781af0ca3ea6

# cat /proc/1307/task/1307/stack 
[<ffffffffbad5a29d>] do_exit+0x411/0x80f
[<ffffffffbad7cf10>] seccomp_phase1+0x345/0x34a
[<ffffffffbaca47a1>] syscall_trace_enter_phase1+0xa7/0x123
[<ffffffffbb3ecbb0>] tracesys+0xd/0x44
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/1307/task/1310/stack 
[<ffffffffbad7b3d5>] futex_wait_queue_me+0x89/0xdf
[<ffffffffbad79f96>] futex_wait+0x2a9/0x7f1
[<ffffffffbad7aa85>] SyS_futex+0x5a7/0x951
[<ffffffffbb3ecb23>] entry_SYSCALL_64_fastpath+0x31/0xab
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/1307/task/1312/stack 
[<ffffffffbae97b83>] SYSC_epoll_wait+0x2fa/0x6dd
[<ffffffffbae97887>] SyS_epoll_wait+0xe/0x10
[<ffffffffbb3ecb23>] entry_SYSCALL_64_fastpath+0x31/0xab
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/1307/task/1327/stack 
[<ffffffffbae8f48b>] poll_schedule_timeout+0x51/0x78
[<ffffffffbae8fcc5>] do_select+0x813/0x8ce
[<ffffffffbae8ff4c>] core_sys_select+0x1cc/0x29d
[<ffffffffbaddd1de>] SyS_select+0x65/0xd0
[<ffffffffbb3ecb23>] entry_SYSCALL_64_fastpath+0x31/0xab
[<ffffffffffffffff>] 0xffffffffffffffff

I wonder if syscall_trace_enter_phase1 -> seccomp_phase1 -> do_exit indicates that the process was killed by seccomp filter.
Of the 3 current syscalls, 
 - futex and epoll_wait are present in platform2/attestation/server/attestationd-seccomp-x86.policy
 - select is not in attestationd-seccomp-x86.policy, though, it is in attestationd-seccomp-amd64.policy, and _newselect is in attestationd-seccomp-arm.policy and also in x86 (where it has no meaning iiuc, it is an arm-only syscall).

So, looks like we are again hit by the results of libc uprev (or something similar), and select is now used on x86. Adding it there.

Submitted CL https://crrev.com/c/1357727
Keeping _newselect in x86 filter as it exists in 32-bit case. On eve we apparently use this filter with 64 bit case, and there we have only select (nr 232).
Status: Started (was: Assigned)
I was wrong. Eve already uses attestationd-seccomp-amd64.policy, where select is allowed. So, it must have been some other syscall that triggered exit(). syscall called from the main thread itself.
Comment #1 above says the thread is now inside 24 = sched_yield.
Log file also mentions syscall 24, however, the thread continues after that:
2018-12-01T00:34:29.480784+00:00 INFO attestationd[1307]: Attestation Daemon Started.
2018-12-01T00:34:29.483386+00:00 WARNING attestationd[1307]: libminijail[1307]: non-debug build: ignoring request to enable seccomp logging
2018-12-01T00:34:29.486027+00:00 INFO attestationd[1307]: Attestation service started.
2018-12-01T00:34:29.487044+00:00 NOTICE kernel: [    2.507724] audit: type=1326 audit(1543624469.485:10): auid=4294967295 uid=247 gid=247 ses=4294967295 subj=u:r:chromeos:s0 pid=1307 comm="attestationd" exe="/usr/sbin/attestationd" sig=31 arch=c000003e syscall=24 compat=0 ip=0x781af0c93347 code=0x0
...
2018-12-01T00:34:29.498305+00:00 INFO attestationd[1307]: Loading attestation database.
...
2018-12-01T00:34:29.615821+00:00 ERR attestationd[1307]: Error fetching salting key public info: Handle 1: TPM_RC_HANDLE
2018-12-01T00:34:29.615838+00:00 ERR attestationd[1307]: Error encrypting salt: Handle 1: TPM_RC_HANDLE
2018-12-01T00:34:29.615851+00:00 ERR attestationd[1307]: Unseal: Failed to start encrypted session: Handle 1: TPM_RC_HANDLE
2018-12-01T00:34:29.615862+00:00 ERR attestationd[1307]: UnsealKey: Cannot unseal aes key.
2018-12-01T00:34:29.615873+00:00 ERR attestationd[1307]: Attestation: Could not unseal decryption key.
2018-12-01T00:34:29.615883+00:00 WARNING attestationd[1307]: Creating new attestation database.

That "sig=31" in kernel output line is also interesting.

Labels: Cros-Hwsec-Ready
Cc: vapier@chromium.org mnissler@chromium.org
Summary: attestationd stops responding on M72 builds (sched_yield syscall suspected) (was: attestationd stops responding on M72 builds (select syscall suspected))
sched_yield is indeed not in attestationd seccomp filters.

If the following line means that an attempt to call sched_yield(24) led to SIGSYS(31), then looks like that's indeed our missing syscall:

2018-12-01T00:34:29.487044+00:00 NOTICE kernel: [    2.507724] audit: type=1326 audit(1543624469.485:10): auid=4294967295 uid=247 gid=247 ses=4294967295 subj=u:r:chromeos:s0 pid=1307 comm="attestationd" exe="/usr/sbin/attestationd" sig=31 arch=c000003e syscall=24 compat=0 ip=0x781af0c93347 code=0x0

+mnissler, +vapier, do you know if I read that audit line right?
assuming it's an x86_64 process, yep, that analysis makes sense
> assuming it's an x86_64 process, yep, that analysis makes sense

yes, x86_64 (eve)
Project Member

Comment 9 by bugdroid1@chromium.org, Dec 3

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

commit 255c0c17c6b0e583316ccbcc6ca6d54e748ab748
Author: Andrey Pronin <apronin@chromium.org>
Date: Mon Dec 03 20:43:30 2018

attestation: allow sched_yield syscall

This change adds sched_yield syscall to attestationd seccomp
whitelists for all architectures.

BUG= chromium:910811 
TEST=emerge attestationd for eve,
     check that seccomp filter now contains sched_yield

Change-Id: Icb8ed45e94872f1840973099e67d08c8b37fcca2
Reviewed-on: https://chromium-review.googlesource.com/1357729
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Mattias Nissler <mnissler@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/255c0c17c6b0e583316ccbcc6ca6d54e748ab748/attestation/server/attestationd-seccomp-arm.policy
[modify] https://crrev.com/255c0c17c6b0e583316ccbcc6ca6d54e748ab748/attestation/server/attestationd-seccomp-amd64.policy
[modify] https://crrev.com/255c0c17c6b0e583316ccbcc6ca6d54e748ab748/attestation/server/attestationd-seccomp-x86.policy

Project Member

Comment 11 by sheriffbot@chromium.org, Dec 5

Labels: -Merge-Request-72 Hotlist-Merge-Approved Merge-Approved-72
Your change meets the bar and is auto-approved for M72. Please go ahead and merge the CL to branch 3626 manually. Please contact milestone owner if you have questions.
Owners: govind@(Android), kariahda@(iOS), djmm@(ChromeOS), abdulsyed@(Desktop)

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

Comment 12 by bugdroid1@chromium.org, Dec 5

Labels: merge-merged-release-R72-11316.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/570ae1813fbb2da0b3ac62c2ce099752ab5fb3c3

commit 570ae1813fbb2da0b3ac62c2ce099752ab5fb3c3
Author: Andrey Pronin <apronin@chromium.org>
Date: Wed Dec 05 18:25:59 2018

attestation: allow sched_yield syscall

This change adds sched_yield syscall to attestationd seccomp
whitelists for all architectures.

BUG= chromium:910811 
TEST=emerge attestationd for eve,
     check that seccomp filter now contains sched_yield

Change-Id: Icb8ed45e94872f1840973099e67d08c8b37fcca2
Reviewed-on: https://chromium-review.googlesource.com/1357729
Commit-Ready: Andrey Pronin <apronin@chromium.org>
Tested-by: Andrey Pronin <apronin@chromium.org>
Reviewed-by: Mattias Nissler <mnissler@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>
(cherry picked from commit 255c0c17c6b0e583316ccbcc6ca6d54e748ab748)
Reviewed-on: https://chromium-review.googlesource.com/c/1363334
Reviewed-by: Andrey Pronin <apronin@chromium.org>
Commit-Queue: Andrey Pronin <apronin@chromium.org>

[modify] https://crrev.com/570ae1813fbb2da0b3ac62c2ce099752ab5fb3c3/attestation/server/attestationd-seccomp-arm.policy
[modify] https://crrev.com/570ae1813fbb2da0b3ac62c2ce099752ab5fb3c3/attestation/server/attestationd-seccomp-amd64.policy
[modify] https://crrev.com/570ae1813fbb2da0b3ac62c2ce099752ab5fb3c3/attestation/server/attestationd-seccomp-x86.policy

Labels: -Merge-Approved-72

Sign in to add a comment