My favorites | Sign in
Project Home Downloads Wiki Issues Code Search
New issue   Search
for
  Advanced search   Search tips   Subscriptions
Issue 176329: login_CryptohomeMounted failed with "Login failed" error on "x86 generic incremental"
2 people starred this issue and may be notified of changes. Back to list
Status:  Fixed
Moved from:  issue chromium-os:38288
Owner:  zelidrag@chromium.org
Closed:  Feb 2013
Cc:  achuith@chromium.org

Blocking:
issue 177357


Sign in to add a comment
 
Project Member Reported by benc...@chromium.org, Jan 27, 2013
http://build.chromium.org/p/chromiumos/builders/x86%20generic%20incremental/builds/8737/

tmp.combined-control.WykF4/login_CryptohomeMounted              FAIL: Exception raised during login: Login failed. Perhaps Chrome crashed, failed to start, or the login flow is broken? Error message: Chrome automation timed out after 120 seconds for {"command": "GetNextEvent", "observer_id": -1, "blocking": true}. See the file named login-fail-screenshot.png in the results folder.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.948 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.950 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.951 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.952 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.953 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.953 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.954 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.955 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.956 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.957 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.958 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.958 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.960 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.960 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.961 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.961 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.963 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:08.964 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.989 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.989 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.990 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.991 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.991 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.992 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.992 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.993 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.994 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.994 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.995 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.995 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.996 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.997 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.997 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.998 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.999 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:11.999 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.027 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.027 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.028 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.029 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.029 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.030 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.030 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.031 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.032 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.032 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.033 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.033 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.034 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.035 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.035 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.036 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.037 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:15.037 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.065 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.066 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.066 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.067 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.068 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.068 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.069 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.070 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.071 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.071 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.072 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.073 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.073 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.074 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.075 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.076 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.076 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:18.077 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.104 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.105 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.106 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.107 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.108 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.108 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.109 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.110 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.110 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.111 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.112 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.113 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.113 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.114 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.115 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.116 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.116 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:21.117 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.144 ERROR| traceback:0013| Traceback (most recent call last):
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.144 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 560, in process_request_thread
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.145 ERROR| traceback:0013|     self.finish_request(request, client_address)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.145 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 322, in finish_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.146 ERROR| traceback:0013|     self.RequestHandlerClass(request, client_address, self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.147 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/SocketServer.py", line 617, in __init__
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.147 ERROR| traceback:0013|     self.handle()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.148 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 329, in handle
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.148 ERROR| traceback:0013|     self.handle_one_request()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.149 ERROR| traceback:0013|   File "/usr/local/lib/python2.6/BaseHTTPServer.py", line 323, in handle_one_request
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.150 ERROR| traceback:0013|     method()
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.150 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 22, in wrapper
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.151 ERROR| traceback:0013|     func(self)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.151 ERROR| traceback:0013|   File "/usr/local/autotest/cros/httpd.py", line 72, in do_POST
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.152 ERROR| traceback:0013|     self.server._url_handlers[path](self, form)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.153 ERROR| traceback:0013|   File "/usr/local/autotest/cros/auth_server.py", line 370, in _oauth2_get_token_responder
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.153 ERROR| traceback:0013|     '%s called with incorrect params.' % handler.path)
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:37:24.154 ERROR| traceback:0013| TestError: /o/oauth2/token called with incorrect params.
tmp.combined-control.WykF4/login_CryptohomeMounted              01/25 23:39:04.300 ERROR|logging_ma:0579| [17827:17827:0125/233904:606297449:ERROR:pyautolib.cc(139)] Error during automation: Chrome automation timed out after 120 seconds for {"command": "GetNextEvent", "observer_id": -1, "blocking": true}
tmp.combined-control.WykF4/login_CryptohomeUnmounted          [  PASSED  ]
Jan 31, 2013
#1 vpala...@chromium.org
Hit again today :
http://chromegw/i/chromiumos/builders/x86%20generic%20incremental/builds/8823
Feb 7, 2013
#4 davidjames@chromium.org
zelidrag is this related to recent oauth2 changes?

"TestError: /o/oauth2/token called with incorrect params." is new after the recent oauth2 changes
Owner: zelidrag@chromium.org
Feb 13, 2013
#9 semenz...@chromium.org
It's happening a bit too often.
Labels: -Pri-1 Pri-0
Feb 14, 2013
#11 cmasone@chromium.org
Moving to the Chromium tracker, so it might get some attention from the UI team?
Labels: Mstone-26
Feb 14, 2013
#13 vapier@chromium.org
this is now closing the CrOS tree multiple times (like more than 5) a day :/
Feb 15, 2013
#14 davidjames@chromium.org
Per Zel, achuith@ is in the process of landing telemetry based automation now and the test fixes should come soon after that. Zel is hoping this will land early next week. 

Switching to telemetry should (hopefully!) fix this flake. If not, the Chrome team will start looking at other causes.

Status: Started
Owner: achuith@chromium.org
Feb 15, 2013
#15 zelidrag@chromium.org
achuith@, let's convert this test first to new automation stack. The prototype that I've build should already have OOBE/login screen covered (see https://codereview.chromium.org/11412238/) even though some refresh of this code might be needed after your changes.
Labels: Iteration-76
Feb 19, 2013
#17 zelidrag@chromium.org
(No comment was entered for this change.)
Labels: -Mstone-26 Mstone-27
Feb 20, 2013
#19 ellyjo...@chromium.org
Closing the tree every half hour.
Labels: -Sev-2 Sev-0
Feb 20, 2013
#20 achuith@chromium.org
Zel, is there perhaps a real bug here? I don't think this is simply flakiness in the framework. Do you think any of the recent login flow changes have caused a regression? Feel free to reassign back if this is not the case.
Owner: zelidrag@chromium.org
Cc: achuith@chromium.org
Feb 20, 2013
#21 zelidrag@chromium.org
yeah, it seems that test auth server is again checking stuff it can't certainly know about (like production oauth2 client id and secret)

The fix is in CQ - https://gerrit.chromium.org/gerrit/#/c/43628/
Feb 20, 2013
#22 bugdro...@chromium.org
Project: chromiumos/third_party/autotest
Branch : master
Author : Zelidrag Hornung <zelidrag@chromium.org>
Commit : 3491115021cd5b1bfe0dce4c2f3032157029fe18

Code Review +2: Achuith Bhandarkar
Verified    +1: Zelidrag Hornung
Change-Id     : I8edc4cefcd74d77f106f46883ea0a9f46ad8bbf5
Reviewed-at   : https://gerrit.chromium.org/gerrit/43628

Removed check for client_secert param value.

BUG=chromium:176329
TEST=happy BVTs

Commit-Queue: Zelidrag Hornung <zelidrag@chromium.org>

M  client/cros/auth_server.py
Feb 20, 2013
#23 zelidrag@chromium.org
(No comment was entered for this change.)
Status: Fixed
Feb 20, 2013
#24 davidjames@chromium.org
(No comment was entered for this change.)
Blocking: chromium:177357
Mar 10, 2013
#25 bugdro...@chromium.org
(No comment was entered for this change.)
Labels: -Area-Test -TreeCloser -Mstone-27 Cr-Test M-27 Hotlist-TreeCloser
Sign in to add a comment

Powered by Google Project Hosting