New issue
Advanced search Search tips

Issue 638774 link

Starred by 1 user

Issue metadata

Status: Archived
Owner:
Closed: Sep 2016
Cc:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

peach_pit-chrome-pfq failure login_Cryptohome with session_manager crash in login_manager::DBusMethodCompletion::~DBusMethodCompletion

Project Member Reported by jamescook@chromium.org, Aug 17 2016

Issue description

https://uberchromegw.corp.google.com/i/chromeos/builders/peach_pit-chrome-pfq/builds/2423

I'm not sure if the session_manager crash (or CHECK?) is a cause or a symptom. There's nothing interesting in the logs.

Dan, does this make any sense?

Call stack for session_manager:
Crash reason:  SIGABRT
Crash address: 0x0
Process uptime: not available

Thread 0 (crashed)
 0  libc-2.19.so!__libc_do_syscall + 0x5
     r0 = 0x00000000    r1 = 0x00005448    r2 = 0x00000006    r3 = 0xb663b000
     r4 = 0xb663b4c0    r5 = 0xb663b000    r6 = 0xb6b27f14    r7 = 0x0000010c
     r8 = 0xbea1a15c    r9 = 0x00000001   r10 = 0xbea1a298   r12 = 0x0000010c
     fp = 0xb6f62eb0    sp = 0xbea1a144    lr = 0xb6a5b315    pc = 0xb6a4b636
    Found by: given as instruction pointer in context
 1  libc-2.19.so!raise [raise.c : 56 + 0x7]
     r4 = 0xb663b4c0    r5 = 0xb663b000    r6 = 0xb6b27f14    r7 = 0xbea1a14c
     r8 = 0xbea1a15c    r9 = 0x00000001   r10 = 0xbea1a298    fp = 0xb6f62eb0
     sp = 0xbea1a14c    pc = 0xb6a5b315
    Found by: call frame info
 2  libc-2.19.so!abort [abort.c : 89 + 0x5]
     r4 = 0x00000002    r5 = 0xb663b000    r6 = 0xb6b27f14    r7 = 0xbea1a158
     r8 = 0xbea1a15c    r9 = 0x00000001   r10 = 0xbea1a298    fp = 0xb6f62eb0
     sp = 0xbea1a158    pc = 0xb6a5c301
    Found by: call frame info
 3  libbase-core-395517.so!base::debug::BreakDebugger [debugger_posix.cc : 219 + 0x3]
     r4 = 0x00000002    r5 = 0xb663b000    r6 = 0xb6b27f14    r7 = 0xbea1a270
     r8 = 0xbea1a15c    r9 = 0x00000001   r10 = 0xbea1a298    fp = 0xb6f62eb0
     sp = 0xbea1a270    pc = 0xb6dde423
    Found by: call frame info
 4  libbase-core-395517.so!logging::LogMessage::~LogMessage [logging.cc : 755 + 0x3]
     r4 = 0x00000002    r5 = 0xb663b000    r6 = 0xb6b27f14    r7 = 0xbea1a280
     r8 = 0xbea1a15c    r9 = 0x00000001   r10 = 0xbea1a298    fp = 0xb6f62eb0
     sp = 0xbea1a278    pc = 0xb6df7517
    Found by: call frame info
 5  session_manager!login_manager::DBusMethodCompletion::~DBusMethodCompletion [session_manager_dbus_adaptor.cc : 168 + 0x3]
     r4 = 0xb8195080    r5 = 0xb6f62eb0    r6 = 0xbea1a7cc    r7 = 0xbea1a7c8
     r8 = 0xbea1a7d4    r9 = 0x00000000   r10 = 0xb8153728    fp = 0xbea1ab68
     sp = 0xbea1a7c8    pc = 0xb6f8641d
    Found by: call frame info
 6  session_manager!login_manager::DBusMethodCompletion::~DBusMethodCompletion [session_manager_dbus_adaptor.cc : 171 + 0x3]
     r4 = 0xb8195080    r5 = 0xb6fee944    r6 = 0xb6f62eb0    r7 = 0xbea1a8b0
     r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728    fp = 0xbea1ab68
     sp = 0xbea1a8b0    pc = 0xb6f86485
    Found by: call frame info
 7  session_manager!base::internal::BindState<base::internal::RunnableAdapter<void (login_manager::DBusMethodCompletion::*)(const login_manager::PolicyService::Error&)>, void(login_manager::DBusMethodCompletion*, const login_manager::PolicyService::Error&), base::internal::OwnedWrapper<login_manager::DBusMethodCompletion> >::Destroy [bind_helpers.h : 366 + 0x3]
     r3 = 0xb6f86475    r4 = 0xb8190c48    r5 = 0xb6fee944    r6 = 0xb6f62eb0
     r7 = 0xbea1a8c0    r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728
     fp = 0xbea1ab68    sp = 0xbea1a8c0    pc = 0xb6f8a181
    Found by: call frame info
 8  libbase-core-395517.so!base::internal::CallbackBase<(base::internal::CopyMode)0>::~CallbackBase [ref_counted.h : 407 + 0x3]
     r3 = 0xb6f8a169    r4 = 0xb81537f0    r5 = 0xb6fee944    r6 = 0xb6f62eb0
     r7 = 0xbea1a8d0    r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728
     fp = 0xbea1ab68    sp = 0xbea1a8d0    pc = 0xb6dd9ce5
    Found by: call frame info
 9  session_manager!login_manager::SessionManagerService::~SessionManagerService [callback_internal.h : 108 + 0x3]
     r3 = 0xb6fec3cc    r4 = 0xb8153728    r5 = 0xb6fee944    r6 = 0xb6f62eb0
     r7 = 0xbea1a8e0    r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728
     fp = 0xbea1ab68    sp = 0xbea1a8e0    pc = 0xb6f7a959
    Found by: call frame info
10  session_manager!login_manager::SessionManagerService::~SessionManagerService [session_manager_service.cc : 161 + 0x3]
     r4 = 0xb8153728    r5 = 0xbea1a9d8    r6 = 0xbea1a980    r7 = 0xbea1a900
     r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728    fp = 0xbea1ab68
     sp = 0xbea1a900    pc = 0xb6f7aa59
    Found by: call frame info
11  session_manager!main [ref_counted.h : 196 + 0x5]
     r3 = 0xb6f7aa49    r4 = 0xbea1a9c0    r5 = 0xbea1a9d8    r6 = 0xbea1a980
     r7 = 0xbea1a928    r8 = 0xbea1aa40    r9 = 0x00000000   r10 = 0xb8153728
     fp = 0xbea1ab68    sp = 0xbea1a910    pc = 0xb6f71b49
    Found by: call frame info

 

Comment 1 by derat@chromium.org, Aug 23 2016

Cc: mnissler@chromium.org
I'm not familiar with this code, but I think that the crash indicates that session_manager exited while it was handling an async StorePolicy or StorePolicyForUser D-Bus request. I suspect that the NOTREACHED() was added to catch internal bugs where session_manager forgets to send the reply, but I suspect that this is expected behavior here (although I don't know whether it's reasonable to exit while we're doing this). It seems like we probably shouldn't crash for this, though.
Dan's comment #1 sounds correct to me after a cursory look, but I'd need to check session_manager's shutdown code more closely before concluding whether that stack is a legit code path to destroy the DBusMethodCompletion (I believe the completion object is owned by a posted task, so the above only makes sense if this happens as part of message loop destruction, but the stack doesn't contain any hints at that - might be due to optimization though).

Comment 3 by derat@chromium.org, Aug 29 2016

~SessionManagerService is on the bottom of the stack, which means that the process is exiting. It looks like we've quit the message loop at that point, although from looking at the implementation of main(), I'd expect the MessageLoopForIO to still be around (although it'd be about to be destroyed).

Comment 4 by derat@chromium.org, Aug 29 2016

Cc: igorcov@chromium.org
Igor, this might be related to your change at https://chromium-review.googlesource.com/336438.

I'm unsure of whether the right approach is to:

a) Run all of the pending completions when we're shutting down. This may be tricky since I don't think there's an easy way to get the completions right now. Would we reply with errors since the requests didn't complete?

b) Make DBusMethodCompletion's d'tor only NOTREACHED() on an uninvoked call if the message loop is still running. This may be tricky due to session_manager using libbrillo's MessageLoop wrapper. Maybe main() should call brillo::MessageLoop::ReleaseFromCurrent() when it's shutting down. (I'm not sure if that'll make other code fail, though.)
Re #4:

Agreed for (a). I think we should either (1) reply with errors or (2) not reply at all, in which case the call should error out on session_manager termination (I haven't verified though) or at least time out on the caller side eventually (default is 30s IIRC).

As an alternative to (b) we could just as well introduce a global flag (maybe a static member in DBusMethodCompletion?) to disarm the NOTREACHED() before shutdown. Not as pretty, but simple and straightforward.

Comment 6 by derat@chromium.org, Aug 31 2016

Status: Started (was: Assigned)
The static member approach sounds fine to me -- simpler than other options, and it doesn't feel too gross since this is an implementation detail of SessionManagerDBusAdaptor rather than part of a public interface.

I've uploaded https://chromium-review.googlesource.com/c/379075/, although I'm not sure how to test it. Have we only seen this happen once? I don't know how anything policy-related works; is there some way I can try instructing session_manager to store policy on-demand and then end the session immediately? How long does storing policy take?
Project Member

Comment 7 by bugdroid1@chromium.org, Sep 8 2016

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

commit b7198fcadc51e9ffaae51b1977a5aad16d065427
Author: Daniel Erat <derat@chromium.org>
Date: Wed Aug 31 17:34:35 2016

login: Don't abort when exiting while handling D-Bus calls.

Add a static variable to DBusMethodCompletion that can be
used to avoid hitting a NOTREACHED() when session_manager
shuts down while handling a StorePolicy or
StorePolicyForUser D-Bus method call.

BUG= chromium:638774 
TEST=hacked up SessionManagerDBusAdaptor::StorePolicy() to
     pass a DBusMethodCompletion's callback to a
     10-second-delayed task. called the method using
     "dbus-send --system --type=method_call --print-reply
     --dest=org.chromium.SessionManager
     /org/chromium/SessionManager
     org.chromium.SessionManagerInterface.StorePolicy" and
     verified that i see an abort without this change and
     that session_manager exits cleanly with this change

Change-Id: Idfd75f9ab2c6d90cbaf61fdf0ee21deb0392ba8f
Reviewed-on: https://chromium-review.googlesource.com/379075
Commit-Ready: Dan Erat <derat@chromium.org>
Tested-by: Dan Erat <derat@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>

[modify] https://crrev.com/b7198fcadc51e9ffaae51b1977a5aad16d065427/login_manager/session_manager_dbus_adaptor.cc

Comment 8 by derat@chromium.org, Sep 8 2016

Status: Fixed (was: Started)

Comment 9 by dchan@chromium.org, Oct 7 2016

Labels: VerifyIn-55

Comment 10 by dchan@google.com, Nov 19 2016

Labels: VerifyIn-56

Comment 11 by dchan@google.com, Jan 21 2017

Labels: VerifyIn-57

Comment 12 by dchan@google.com, Mar 4 2017

Labels: VerifyIn-58

Comment 13 by dchan@google.com, Apr 17 2017

Labels: VerifyIn-59

Comment 14 by dchan@google.com, May 30 2017

Labels: VerifyIn-60
Labels: VerifyIn-61

Comment 16 by dchan@chromium.org, Oct 14 2017

Status: Archived (was: Fixed)

Sign in to add a comment