Issue metadata
Sign in to add a comment
|
login_OwnershipNotRetaken failing on coral-paladin with "Unhandled DevtoolsTargetCrashException: Devtools target crashed" |
||||||||||||||||||||||
Issue descriptionlogin_OwnershipNotRetaken has been consistently failing on coral-paladin with "UnhandledTestFail: Unhandled DevtoolsTargetCrashException: Devtools target crashed". https://luci-milo.appspot.com/buildbot/chromeos/coral-paladin/ reports that: 3415 passed 3416 failed, but in security_StatefulPermissions 3417 died in CommitQueueSync 3418 failed in login_OwnershipNotRetaken It's still failing as of 3425: https://luci-milo.appspot.com/buildbot/chromeos/coral-paladin/3425 Looking at login_OwnershipNotRetaken.INFO, the failure happens shortly after Chrome is restarted for testing. (I have no idea why Chrome is being restarted twice here.) ... 05/27 11:37:44.662 INFO | cros_interface:0575| (Re)starting the ui (logs the user out) 05/27 11:37:47.508 INFO |cros_browser_backe:0068| Restarting Chrome (pid=25243) with remote port ... 05/27 11:37:48.711 INFO | oobe:0035| Invoking Oobe.loginForTesting 05/27 11:37:52.736 INFO |chrome_browser_bac:0118| Got devtools config: ws://127.0.0.1:33779/devtools/browser/746f9ffe-a475-488b-b9e1-ead82af9f2c0 05/26 19:37:58.968 INFO |cros_browser_backe:0112| Browser is up! 05/26 19:37:59.023 INFO | browser:0099| Browser started (pid=25292). ... 05/26 19:37:59.505 INFO | browser:0207| Closing browser (pid=25292) ... 05/26 19:37:59.508 INFO | cros_interface:0575| (Re)starting the ui (logs the user out) 05/26 19:38:03.506 INFO | browser:0220| Browser is closed. 05/26 19:38:03.512 INFO | browser_finder:0123| Chose browser: PossibleCrOSBrowser(browser_type=system) 05/26 19:38:03.513 INFO | cros_interface:0575| (Re)starting the ui (logs the user out) 05/26 19:38:04.357 INFO |cros_browser_backe:0068| Restarting Chrome (pid=26211) with remote port 05/26 19:38:04.359 INFO |cros_browser_backe:0076| dbus-send --system --type=method_call --dest=org.chromium.SessionManager /org/chromium/SessionManager org.chromium.SessionManagerInterface.EnableChromeTesting boolean:true array:string:"--enable-net-benchmarking,--metrics-recording-only,--no-default-browser-check,--no-first-run,--enable-gpu-benchmarking,--deny-permission-prompts,--autoplay-policy=no-user-gesture-required,--disable-component-extensions-with-background-pages,--disable-default-apps,--disable-search-geolocation-disclosure,--enable-smooth-scrolling,--enable-threaded-compositing,--remote-debugging-port=0,--start-maximized,--ash-disable-system-sounds,--oobe-skip-postlogin,--disable-logging-redirect,--vmodule=*/chromeos/net/*=2\,*/chromeos/login/*=2\,chrome_browser_main_posix=2,--allow-failed-policy-fetch-for-test,--disable-gaia-services" array:string: 05/26 19:38:05.245 INFO | __init__:0047| DoNothingForwarder started between 127.0.0.1:33025 and 33025 05/26 19:38:05.245 INFO |chrome_browser_bac:0118| Got devtools config: ws://127.0.0.1:33025/devtools/browser/99b770a2-6a4d-464e-9691-61ae96e69a38 05/26 19:38:05.730 INFO | oobe:0035| Invoking Oobe.loginForTesting 05/26 19:38:11.105 ERROR| browser:0054| Failed with DevtoolsTargetCrashException while starting the browser backend. 05/26 19:38:11.248 INFO | browser:0207| Closing browser (pid=None) ... 05/26 19:38:11.252 INFO | cros_interface:0575| (Re)starting the ui (logs the user out) 05/26 19:38:12.206 INFO | browser:0220| Browser is closed. 05/26 19:38:19.865 WARNI| test:0637| The test failed with the following exception Traceback (most recent call last): File "/usr/local/autotest/common_lib/test.py", line 631, in _exec _call_test_function(self.execute, *p_args, **p_dargs) File "/usr/local/autotest/common_lib/test.py", line 837, in _call_test_function raise error.UnhandledTestFail(e) UnhandledTestFail: Unhandled DevtoolsTargetCrashException: Devtools target crashed ******************************************************************************** (/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py:492 _ConvertExceptionFromInspectorWebsocket) Original exception: Connection is already closed. ******************************************************************************** (/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py:513 _AddDebuggingInformation) Received a socket error in the browser connection and the tab no longer exists. The tab probably crashed. ******************************************************************************** (/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py:514 _AddDebuggingInformation) Debugger url: ws://127.0.0.1:33025/devtools/page/8C53E5430C189FB7C8E38E807ACF27D8 Found Minidump: False Stack Trace: ******************************************************************************** Cannot get stack trace on CrOS ******************************************************************************** Standard output: ******************************************************************************** Cannot get standard output on CrOS ******************************************************************************** System log: (Not implemented) Traceback (most recent call last): File "/usr/local/autotest/common_lib/test.py", line 831, in _call_test_function return func(*args, **dargs) File "/usr/local/autotest/common_lib/test.py", line 495, in execute dargs) File "/usr/local/autotest/common_lib/test.py", line 362, in _call_run_once_with_retry postprocess_profiled_run, args, dargs) File "/usr/local/autotest/common_lib/test.py", line 400, in _call_run_once self.run_once(*args, **dargs) File "/usr/local/autotest/tests/login_OwnershipNotRetaken/login_OwnershipNotRetaken.py", line 55, in run_once gaia_id=self._TEST_GAIAID) as cr: File "/usr/local/autotest/common_lib/cros/chrome.py", line 172, in __init__ self._browser = self._browser_to_create.Create() File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/cros_browser_finder.py", line 101, in Create browser_backend, self._platform_backend, startup_args) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/cros_browser_with_oobe.py", line 14, in __init__ backend, platform_backend, startup_args) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/browser/browser.py", line 48, in __init__ self._browser_backend.Start(startup_args, startup_url=startup_url) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/cros_browser_backend.py", line 104, in Start not self.browser_options.disable_gaia_services) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/oobe.py", line 71, in NavigateFakeLogin enterprise_enroll) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/oobe.py", line 37, in _ExecuteOobeApi "typeof Oobe == 'function' && Oobe.readyForTesting", timeout=120) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/browser/web_contents.py", line 239, in WaitForJavaScriptCondition return self._inspector_backend.WaitForJavaScriptCondition(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 289, in WaitForJavaScriptCondition return py_utils.WaitFor(IsJavaScriptExpressionTrue, timeout) File "/usr/local/telemetry/src/third_party/catapult/common/py_utils/py_utils/__init__.py", line 136, in WaitFor res = condition() File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 286, in IsJavaScriptExpressionTrue return self._EvaluateJavaScript(condition, context_id, timeout) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 41, in Inner inspector_backend._ConvertExceptionFromInspectorWebsocket(e) File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function return func(*args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 38, in Inner return func(inspector_backend, *args, **kwargs) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 519, in _EvaluateJavaScript return self._runtime.Evaluate(expression, context_id, timeout) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_runtime.py", line 44, in Evaluate res = self._inspector_websocket.SyncRequest(request, timeout) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_websocket.py", line 116, in SyncRequest res = self._Receive(timeout) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_websocket.py", line 155, in _Receive data = self._socket.recv() File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_core.py", line 293, in recv opcode, data = self.recv_data() File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_core.py", line 310, in recv_data opcode, frame = self.recv_data_frame(control_frame) File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_core.py", line 323, in recv_data_frame frame = self.recv_frame() File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_core.py", line 357, in recv_frame return self.frame_buffer.recv_frame() File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_abnf.py", line 336, in recv_frame self.recv_header() File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_abnf.py", line 286, in recv_header header = self.recv_strict(2) File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_abnf.py", line 371, in recv_strict bytes_ = self.recv(min(16384, shortage)) File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_core.py", line 427, in _recv return recv(self.sock, bufsize) File "/usr/local/telemetry/src/third_party/catapult/telemetry/third_party/websocket-client/websocket/_socket.py", line 93, in recv "Connection is already closed.")
,
May 27 2018
Presumably Chrome is crashing, though. I see the following in https://storage.cloud.google.com/chromeos-autotest-results/203080221-chromeos-test/chromeos2-row4-rack4-host15/login_OwnershipNotRetaken/sysinfo/messages from run 3424: 2018-05-26T23:27:30.211111+00:00 WARNING kernel: [ 1339.724358] show_signal_msg: 6 callbacks suppressed 2018-05-26T23:27:30.211123+00:00 INFO kernel: [ 1339.724371] chrome[26920]: segfault at 0 ip 000059eefbe5ea29 sp 00007ffed579fec0 error 4 in chrome[59eefaae7000+8925000] 2018-05-26T23:27:30.222928+00:00 INFO crash_reporter[27138]: libminijail[27138]: mount /dev/log -> /dev/log type '' 2018-05-26T23:27:30.235750+00:00 WARNING crash_reporter[27138]: [user] Received crash notification for chrome[26920] sig 11, user 1000 (developer build - not testing - always dumping) 2018-05-26T23:27:30.240028+00:00 INFO crash_reporter[27138]: State of crashed process [26920]: S (sleeping) 2018-05-26T23:27:30.244900+00:00 INFO metrics_daemon[2542]: [INFO:metrics_daemon.cc(427)] Got org.chromium.CrashReporter.UserCrash D-Bus signal 2018-05-26T23:27:31.875919+00:00 INFO crash_reporter[27138]: Stored minidump to /var/spool/crash/chrome.20180526.162730.26920.dmp 2018-05-26T23:27:31.876263+00:00 INFO crash_reporter[27138]: Leaving core file at /var/spool/crash/chrome.20180526.162730.26920.core due to developer image 2018-05-26T23:27:31.876803+00:00 WARNING crash_reporter[27138]: [ARC] Received crash notification for chrome[26920] sig 11, user 1000 (ignoring - crash origin is not ARC) 2018-05-26T23:27:31.994881+00:00 NOTICE autotest[27166]: 16:27:31.984 ERROR| browser:0054| Failed with DevtoolsTargetCrashException while starting the browser backend. 2018-05-26T23:27:32.101820+00:00 INFO session_manager[26786]: [INFO:child_exit_dispatcher.cc(59)] Handling 26920 exit. 2018-05-26T23:27:32.102014+00:00 ERR session_manager[26786]: [ERROR:child_exit_dispatcher.cc(67)] Exited with signal 11 2018-05-26T23:27:32.102123+00:00 INFO session_manager[26786]: [INFO:session_manager_service.cc(297)] Exiting process is chrome. Unless I'm missing something, there are no crash files in Autotest's log dir, though.
,
May 27 2018
Here's a Stainless query showing the failures: http://stainless/search?view=matrix&row=model&col=build&first_date=2018-04-29&last_date=2018-05-27&builder_name=%5Ecoral-paladin%24&test=%5Elogin%5C_&exclude_cts=false&exclude_not_run=false&exclude_non_release=false&exclude_au=true&exclude_acts=true&exclude_retried=true&exclude_non_production=false Passed at R69-10720.0.0-rc1, started failing at R69-10721.0.0-rc2. There's a crash file at https://storage.cloud.google.com/chromeos-autotest-results/202910157-chromeos-test/chromeos2-row4-rack4-host15/login_OwnershipNotRetaken/sysinfo/iteration.1/var/spool/crash/chrome.20180525.195531.15019.dmp, which was easier to see using the new Stainless file listing at http://stainless/browse/chromeos-autotest-results/202910157-chromeos-test/ . Operating system: Linux 0.0.0 Linux 4.4.132-14139-gdcaac3cf2b91 #1 SMP PREEMPT Fri May 25 18:19:46 PDT 2018 x86_64 CPU: amd64 family 6 model 92 stepping 9 1 CPU GPU: UNKNOWN Crash reason: SIGSEGV Crash address: 0x0 Process uptime: not available Thread 0 (crashed) 0 chrome!<name omitted> [browser_context_keyed_base_factory.cc : 25 + 0x0] rax = 0x00005679b0f02a20 rdx = 0x0000000000000001 rcx = 0x0000000000000176 rbx = 0x0000000000000000 rsi = 0x0000000000000000 rdi = 0x000013cc1a7688a0 rbp = 0x00007fff4985c0f0 rsp = 0x00007fff4985c0e0 r8 = 0x0000000000000000 r9 = 0x000000000000001c r10 = 0x0000000000000005 r11 = 0x00007fff4985c40a r12 = 0x0000000000000000 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc1a7688a0 r15 = 0x0000000000000001 rip = 0x00005679b0f02a29 Found by: given as instruction pointer in context 1 chrome!KeyedServiceFactory::GetServiceForContext(base::SupportsUserData*, bool) [keyed_service_factory.cc : 63 + 0xc] rbx = 0x00005679b8b6a0c0 rbp = 0x00007fff4985c1c0 rsp = 0x00007fff4985c100 r12 = 0x0000000000000000 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc1a7688a0 r15 = 0x0000000000000001 rip = 0x00005679b3de3077 Found by: call frame info 2 chrome!chromeos::quick_unlock::PinBackend::CanAuthenticate(AccountId const&, base::OnceCallback<void (bool)>) [quick_unlock_factory.cc : 30 + 0x8] rbx = 0x000013cc1825ff00 rbp = 0x00007fff4985c210 rsp = 0x00007fff4985c1d0 r12 = 0x000013cc193d24e0 r13 = 0x000013cc1a76c7a8 r14 = 0x00007fff4985c220 r15 = 0x000013cc19e4fab8 rip = 0x00005679b13ea655 Found by: call frame info 3 chrome!base::internal::Invoker<base::internal::BindState<void (chromeos::quick_unlock::PinBackend::*)(AccountId const&, base::OnceCallback<void (bool)>), base::internal::UnretainedWrapper<chromeos::quick_unlock::PinBackend>, AccountId, base::OnceCallback<void (bool)> >, void ()>::RunOnce(base::internal::BindStateBase*) [bind_internal.h : 496 + 0x2] rbx = 0x000013cc18d21b40 rbp = 0x00007fff4985c230 rsp = 0x00007fff4985c220 r12 = 0x000013cc18d21b48 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc193d24e0 r15 = 0x000013cc19e4fa80 rip = 0x00005679b13eaa7f Found by: call frame info 4 chrome!chromeos::quick_unlock::PinBackend::OnIsCryptohomeBackendSupported(bool) [callback.h : 96 + 0x7] rbx = 0x000013cc18d21b40 rbp = 0x00007fff4985c260 rsp = 0x00007fff4985c240 r12 = 0x000013cc18d21b48 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc193d24e0 r15 = 0x000013cc19e4fa80 rip = 0x00005679b13e9b21 Found by: call frame info 5 chrome!chromeos::quick_unlock::(anonymous namespace)::OnGetSupportedKeyPolicies(base::OnceCallback<void (bool)>, base::Optional<cryptohome::BaseReply>) [callback.h : 96 + 0x6] rbx = 0x000013cc1a76a440 rbp = 0x00007fff4985c290 rsp = 0x00007fff4985c270 r12 = 0x000013cc1a76c7c0 r13 = 0x000013cc1a76c7a8 r14 = 0x00007fff4985c370 r15 = 0x00007fff4985c2a0 rip = 0x00005679b13ecf11 Found by: call frame info 6 chrome!base::internal::Invoker<base::internal::BindState<void (*)(base::OnceCallback<void (bool)>, base::Optional<cryptohome::BaseReply>), base::OnceCallback<void (bool)> >, void (base::Optional<cryptohome::BaseReply>)>::RunOnce(base::internal::BindStateBase*, base::Optional<cryptohome::BaseReply>&&) [bind_internal.h : 407 + 0x2] rbx = 0x00005679b13eced0 rbp = 0x00007fff4985c300 rsp = 0x00007fff4985c2a0 r12 = 0x000013cc1a76c7c0 r13 = 0x000013cc1a76c7a8 r14 = 0x00007fff4985c370 r15 = 0x00007fff4985c4b0 rip = 0x00005679b13ed012 Found by: call frame info 7 chrome!chromeos::(anonymous namespace)::CryptohomeClientImpl::OnBaseReplyMethod(base::OnceCallback<void (base::Optional<cryptohome::BaseReply>)>, dbus::Response*) [callback.h : 96 + 0x6] rbx = 0x000013cc1a76d6c0 rbp = 0x00007fff4985c4a0 rsp = 0x00007fff4985c310 r12 = 0x000013cc1a76c7c0 r13 = 0x000013cc1a76c7a8 r14 = 0x00007fff4985c370 r15 = 0x00007fff4985c4b0 rip = 0x00005679b2fddd7b Found by: call frame info 8 chrome!base::internal::Invoker<base::internal::BindState<void (ChromeBrowsingDataRemoverDelegate::*)(base::OnceCallback<void ()>, base::WaitableEvent*), base::WeakPtr<ChromeBrowsingDataRemoverDelegate>, base::OnceCallback<void ()> >, void (base::WaitableEvent*)>::RunOnce(base::internal::BindStateBase*, base::WaitableEvent*) [bind_internal.h : 496 + 0x5] rbx = 0x000013cc1a44fc80 rbp = 0x00007fff4985c4c0 rsp = 0x00007fff4985c4b0 r12 = 0x000013cc1a76c7c0 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc180d64e0 r15 = 0x00007fff4985c5d0 rip = 0x00005679b067125d Found by: call frame info 9 chrome!dbus::ObjectProxy::OnCallMethod(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, base::OnceCallback<void (dbus::Response*)>, dbus::Response*, dbus::ErrorResponse*) [callback.h : 96 + 0x9] rbx = 0x000013cc1a44fc80 rbp = 0x00007fff4985c5c0 rsp = 0x00007fff4985c4d0 r12 = 0x000013cc1a76c7c0 r13 = 0x000013cc1a76c7a8 r14 = 0x000013cc180d64e0 r15 = 0x00007fff4985c5d0 rip = 0x00005679b2ffdfd8 Found by: call frame info 10 chrome!base::internal::Invoker<base::internal::BindState<void (dbus::ObjectProxy::*)(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, base::OnceCallback<void (dbus::Response*)>, dbus::Response*, dbus::ErrorResponse*), scoped_refptr<dbus::ObjectProxy>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, base::OnceCallback<void (dbus::Response*)> >, void (dbus::Response*, dbus::ErrorResponse*)>::RunOnce(base::internal::BindStateBase*, dbus::Response*, dbus::ErrorResponse*) [bind_internal.h : 496 + 0x2] rbx = 0x000013cc1a76c770 rbp = 0x00007fff4985c5e0 rsp = 0x00007fff4985c5d0 r12 = 0x0000000000000000 r13 = 0x00007fff4985c630 r14 = 0x000000004cb7984d r15 = 0x000013cc18def270 rip = 0x00005679b30011d8 Found by: call frame info 11 chrome!dbus::ObjectProxy::RunResponseOrErrorCallback(dbus::ObjectProxy::ReplyCallbackHolder, base::TimeTicks, dbus::Response*, dbus::ErrorResponse*) [callback.h : 96 + 0xc] rbx = 0x000013cc1a76c770 rbp = 0x00007fff4985c620 rsp = 0x00007fff4985c5f0 r12 = 0x0000000000000000 r13 = 0x00007fff4985c630 r14 = 0x000000004cb7984d r15 = 0x000013cc18def270 rip = 0x00005679b2ffe57b Found by: call frame info 12 chrome!base::internal::Invoker<base::internal::BindState<void (dbus::ObjectProxy::*)(dbus::ObjectProxy::ReplyCallbackHolder, base::TimeTicks, dbus::Response*, dbus::ErrorResponse*), scoped_refptr<dbus::ObjectProxy>, dbus::ObjectProxy::ReplyCallbackHolder, base::TimeTicks, dbus::Response*, dbus::ErrorResponse*>, void ()>::RunOnce(base::internal::BindStateBase*) [bind_internal.h : 496 + 0x8] rbx = 0x00005679b2ffe540 rbp = 0x00007fff4985c660 rsp = 0x00007fff4985c630 r12 = 0x000013cc1810aa0c r13 = 0x00007fff4985c9c0 r14 = 0x00007fff4985c630 r15 = 0x00007fff4985c6b0 rip = 0x00005679b30016f1 Found by: call frame info 13 chrome!base::(anonymous namespace)::PostTaskAndReplyRelay::RunTaskAndPostReply(base::(anonymous namespace)::PostTaskAndReplyRelay) [callback.h : 96 + 0x6] rbx = 0x000013cc1a7687e0 rbp = 0x00007fff4985c6a0 rsp = 0x00007fff4985c670 r12 = 0x000013cc1810aa0c r13 = 0x00007fff4985c9c0 r14 = 0x0000000000000000 r15 = 0x00007fff4985c6b0 rip = 0x00005679b246f83f Found by: call frame info 14 chrome!base::internal::Invoker<base::internal::BindState<void (*)(base::(anonymous namespace)::PostTaskAndReplyRelay), base::(anonymous namespace)::PostTaskAndReplyRelay>, void ()>::RunOnce(base::internal::BindStateBase*) [bind_internal.h : 407 + 0x5] rbx = 0x00007fff4985c6b0 rbp = 0x00007fff4985c700 rsp = 0x00007fff4985c6b0 r12 = 0x000013cc1810aa0c r13 = 0x00007fff4985c9c0 r14 = 0x0000000000000000 r15 = 0x00005679b8b69f00 rip = 0x00005679b246fa73 Found by: call frame info 15 chrome!base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) [callback.h : 96 + 0x6] rbx = 0x000013cc18d566c0 rbp = 0x00007fff4985c7e0 rsp = 0x00007fff4985c710 r12 = 0x000013cc1810aa0c r13 = 0x00007fff4985c9c0 r14 = 0x0000000000000000 r15 = 0x00005679b8b69f00 rip = 0x00005679b241032e Found by: call frame info 16 chrome!base::MessageLoop::RunTask(base::PendingTask*) [incoming_task_queue.cc : 124 + 0xf] rbx = 0x00005679b3000a73 rbp = 0x00007fff4985c9b0 rsp = 0x00007fff4985c7f0 r12 = 0x000013cc181f8120 r13 = 0x00007fff4985c9c8 r14 = 0x00007fff4985c9c0 r15 = 0x000013cc181f81d0 rip = 0x00005679b24271c9 Found by: call frame info 17 chrome!base::MessageLoop::DoWork() [message_loop.cc : 329 + 0x8] rbx = 0x000013cc181f8120 rbp = 0x00007fff4985cb70 rsp = 0x00007fff4985c9c0 r12 = 0x00007fff4985ca88 r13 = 0x00007fff4985c9c8 r14 = 0x000013cc181f8120 r15 = 0x00007fff4985ca80 rip = 0x00005679b2427d40 Found by: call frame info 18 chrome!base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [message_pump_libevent.cc : 210 + 0x8] rbx = 0x000013cc18185ac0 rbp = 0x00007fff4985cbd0 rsp = 0x00007fff4985cb80 r12 = 0x000013cc18185ad0 r13 = 0x0000000000000000 r14 = 0x000013cc181f8120 r15 = 0x000013cc19ccd880 rip = 0x00005679b24ae458 Found by: call frame info 19 chrome!ChromeBrowserMainParts::MainMessageLoopRun(int*) [run_loop.cc : 102 + 0x8] rbx = 0x00005679b8b69ec0 rbp = 0x00007fff4985cc90 rsp = 0x00007fff4985cbe0 r12 = 0x00007fff4985cde8 r13 = 0x00007fff4985d4a8 r14 = 0x000013cc180a2a98 r15 = 0x000013cc180a2000 rip = 0x00005679b20c3f7b Found by: call frame info 20 chrome!content::BrowserMainLoop::RunMainMessageLoopParts() [browser_main_loop.cc : 970 + 0x3] rbx = 0x00005679b8b69ec0 rbp = 0x00007fff4985cd50 rsp = 0x00007fff4985cca0 r12 = 0x00007fff4985cde8 r13 = 0x00007fff4985d4a8 r14 = 0x000013cc180a2a80 r15 = 0x00007fff4985ce90 rip = 0x00005679b0798f51 Found by: call frame info 21 chrome!content::BrowserMainRunnerImpl::Run() [browser_main_runner_impl.cc : 169 + 0x5] rbx = 0x000013cc180db880 rbp = 0x00007fff4985cd70 rsp = 0x00007fff4985cd60 r12 = 0x00007fff4985cde8 r13 = 0x00007fff4985d4a8 r14 = 0x00000000ffffffff r15 = 0x00007fff4985ce90 rip = 0x00005679b079be82 Found by: call frame info 22 chrome!content::BrowserMain(content::MainFunctionParams const&, std::__1::unique_ptr<content::BrowserProcessSubThread, std::__1::default_delete<content::BrowserProcessSubThread> >) [browser_main.cc : 51 + 0x8] rbx = 0x000013cc180db880 rbp = 0x00007fff4985ce30 rsp = 0x00007fff4985cd80 r12 = 0x00007fff4985cde8 r13 = 0x00007fff4985d4a8 r14 = 0x00000000ffffffff r15 = 0x00007fff4985ce90 rip = 0x00005679b079249e Found by: call frame info 23 chrome!content::ContentMainRunnerImpl::Run() [content_main_runner_impl.cc : 620 + 0x5] rbx = 0x000013cc18094ea0 rbp = 0x00007fff4985d090 rsp = 0x00007fff4985ce40 r12 = 0x00000000ffffffff r13 = 0x00007fff4985d4a8 r14 = 0x00007fff4985d420 r15 = 0x000013cc180d6c30 rip = 0x00005679b20ae6bd Found by: call frame info 24 chrome!service_manager::Main(service_manager::MainParams const&) [main.cc : 459 + 0xa] rbx = 0x000013cc18093ce0 rbp = 0x00007fff4985d400 rsp = 0x00007fff4985d0a0 r12 = 0x00000000ffffffff r13 = 0x00007fff4985d4a8 r14 = 0x0000000000000003 r15 = 0x0000000000000000 rip = 0x00005679b20b82c5 Found by: call frame info 25 chrome!ChromeMain [content_main.cc : 19 + 0x5] rbx = 0x00005679b8932e80 rbp = 0x00007fff4985d510 rsp = 0x00007fff4985d410 r12 = 0x0000000000000033 r13 = 0x00007fff4985d4a8 r14 = 0x00007fff4985d608 r15 = 0x00007fff4985d420 rip = 0x00005679afc05808 Found by: call frame info 26 libc-2.23.so!__libc_start_main [libc-start.c : 289 + 0x1a] rbx = 0x0000000000000000 rbp = 0x00007fff4985d5e0 rsp = 0x00007fff4985d520 r12 = 0x00005679b797c000 r13 = 0x00007fff4985d600 r14 = 0x0000000000000000 r15 = 0x0000000000000000 rip = 0x00007bdbea50d736 Found by: call frame info 27 chrome!_start + 0x29 rbx = 0x0000000000000000 rbp = 0x0000000000000000 rsp = 0x00007fff4985d5f0 r12 = 0x00005679afbf80e0 r13 = 0x00007fff4985d600 r14 = 0x0000000000000000 r15 = 0x0000000000000000 rip = 0x00005679afbf8109 Found by: call frame info 28 0x7fff4985d5f8 rbx = 0x0000000000000000 rbp = 0x0000000000000000 rsp = 0x00007fff4985d5f8 r12 = 0x00005679afbf80e0 r13 = 0x00007fff4985d600 r14 = 0x0000000000000000 r15 = 0x0000000000000000 rip = 0x00007fff4985d5f8 Found by: call frame info
,
May 27 2018
No recent changes to chrome/browser/chromeos/login/quick_unlock/quick_unlock_factory.cc. It looks like this is called in response to a reply from cryptohome, so maybe something's changed such that that response is happening earlier. It looks like Sarah is out this coming week. Jacob, can you take a look?
,
May 27 2018
Actually, https://chromium-review.googlesource.com/1033212 is recent.
,
May 27 2018
+jhawkins who was looking at BCKS and PIN unlock recently.
,
May 29 2018
I think this problem was caused by a bad CL; this problem wasn't happening in coral-release until we marked coral-paladin experimental. Then it showed up.
,
May 29 2018
This is the first coral-paladin run to show the failure:
https://uberchromegw.corp.google.com/i/chromeos/builders/coral-paladin/builds/3418
So, the blamelist there would be a good place to start.
,
May 29 2018
Hmmm... One hole in the "bad CL" theory is the CQ master has been consistently failing with test failures (not infra); if it were a bad CL, those test errors should have rejected the bad CL, stopping the problem. I also don't think we can explain it as "entered through the Chrome PFQ". That would have had the failure show up first in the canary, but the canary was last to see the failure.
,
May 29 2018
https://chromium-review.googlesource.com/c/chromium/src/+/1073954 should fix this. I can cherry-pick the needed parts and land ASAP if required.
,
May 29 2018
Looking more closely at the stack, the CL I commented above may not fix the issue. The CL fixes a null-deref in [1], but the stack indicates we are calling GetServiceForContext. 1 chrome!KeyedServiceFactory::GetServiceForContext(base::SupportsUserData*, bool) [keyed_service_factory.cc : 63 + 0xc] Either way, some frames are being elided in the stack. 1: https://cs.chromium.org/chromium/src/chrome/browser/chromeos/login/quick_unlock/pin_backend.cc?l=228-229&rcl=8a686447d8ee0a6b57f3c8d9b2dd6883f5a4bdb5
,
May 29 2018
Thanks Jacob. Let's get the crash fixed first.
,
May 29 2018
This is tangential, but do we have an autotest that tests login with the PIN?
,
May 29 2018
> This is tangential, but do we have an autotest that tests login with the PIN? Not yet, I believe we are still waiting for hardware support for PIN to be enabled.
,
May 29 2018
hardware support -> platform support
,
May 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4c830fcccea032f42954a0c5bed7ae98f924b881 commit 4c830fcccea032f42954a0c5bed7ae98f924b881 Author: Jacob Dufault <jdufault@google.com> Date: Tue May 29 21:56:19 2018 cros: Fix login crash when determining if PIN is supported. Bug: 847040 Change-Id: Id32b31abdfa1dff8e8229bfb4eaa610d782d4789 Reviewed-on: https://chromium-review.googlesource.com/1077017 Reviewed-by: Achuith Bhandarkar <achuith@chromium.org> Reviewed-by: Xiyuan Xia <xiyuan@chromium.org> Commit-Queue: Jacob Dufault <jdufault@chromium.org> Cr-Commit-Position: refs/heads/master@{#562611} [modify] https://crrev.com/4c830fcccea032f42954a0c5bed7ae98f924b881/chrome/browser/chromeos/login/quick_unlock/pin_backend.cc
,
May 30 2018
We should merge #15 to M68 since https://chromium-review.googlesource.com/1033212 is in M68 hence the crash is there too.
,
May 30 2018
,
May 30 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/11b08f2c25b85768f42ae6b1d9b71970594a1d54 commit 11b08f2c25b85768f42ae6b1d9b71970594a1d54 Author: Jacob Dufault <jdufault@google.com> Date: Wed May 30 21:57:09 2018 cros: Fix login crash when determining if PIN is supported. TBR=jdufault@google.com (cherry picked from commit 4c830fcccea032f42954a0c5bed7ae98f924b881) Bug: 847040 Change-Id: Id32b31abdfa1dff8e8229bfb4eaa610d782d4789 Reviewed-on: https://chromium-review.googlesource.com/1077017 Reviewed-by: Achuith Bhandarkar <achuith@chromium.org> Reviewed-by: Xiyuan Xia <xiyuan@chromium.org> Commit-Queue: Jacob Dufault <jdufault@chromium.org> Cr-Original-Commit-Position: refs/heads/master@{#562611} Reviewed-on: https://chromium-review.googlesource.com/1080038 Reviewed-by: Jacob Dufault <jdufault@chromium.org> Cr-Commit-Position: refs/branch-heads/3440@{#52} Cr-Branched-From: 010ddcfda246975d194964ccf20038ebbdec6084-refs/heads/master@{#561733} [modify] https://crrev.com/11b08f2c25b85768f42ae6b1d9b71970594a1d54/chrome/browser/chromeos/login/quick_unlock/pin_backend.cc
,
Nov 21
Hey folks, is there anything left to do here?
,
Nov 21
I think this is fixed |
|||||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||||
Comment 1 by derat@chromium.org
, May 27 2018