New issue
Advanced search Search tips

Issue 602951 link

Starred by 3 users

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Flaky LoginUIKeyboardTest.CheckPODScreenWithUsers

Project Member Reported by vabr@chromium.org, Apr 13 2016

Issue description

The test is failing flakily on Linux ChromiumOS tests, the oldest build I saw failing was https://build.chromium.org/p/chromium.chromiumos/builders/Linux%20ChromiumOS%20Tests%20%28dbg%29%281%29/builds/13407

The failure is:
../../chrome/browser/chromeos/login/login_ui_keyboard_browsertest.cc:174: Failure
Value of: input_method::InputMethodManager::Get() ->GetActiveIMEState() ->GetCurrentInputMethod() .id()
  Actual: "_comp_ime_fgoepimhcoialccpbmpnnblemnepkkaoxkb:fr::fra"
Expected: user_input_methods[1]
Which is: "_comp_ime_fgoepimhcoialccpbmpnnblemnepkkaoxkb:de::ger"

Full log attached.

Assigning to alemate@ based on git blame, please feel free to route as appropriate.
 
Log File contents.html
20.0 KB View Download
Project Member

Comment 1 by bugdroid1@chromium.org, Apr 13 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/ed3291e93c10b52a18f96cb15581f3d827b04378

commit ed3291e93c10b52a18f96cb15581f3d827b04378
Author: vabr <vabr@chromium.org>
Date: Wed Apr 13 09:18:42 2016

Disable LoginUIKeyboardTest.CheckPODScreenWithUsers

TBR=alemate@chromium.org
BUG=602951

Review URL: https://codereview.chromium.org/1882773002

Cr-Commit-Position: refs/heads/master@{#386945}

[modify] https://crrev.com/ed3291e93c10b52a18f96cb15581f3d827b04378/chrome/browser/chromeos/login/login_ui_keyboard_browsertest.cc

Cc: alemate@chromium.org jdufault@chromium.org xiy...@chromium.org
Owner: dzhioev@chromium.org
This happens, because after "signin screen visible" is sent to chrome, handleAfterShow() is triggered.
I've added some debug there:


[12872:12872:0414/014354:INFO:CONSOLE(7222)] "Loading asset bundle", source: chrome://oobe/login.js (7222)
[12872:12872:0414/014354:INFO:CONSOLE(7305)] "Oobe.showOobeUI(false)", source: chrome://oobe/login.js (7305)
[12872:12872:0414/014354:INFO:signin_screen_handler.cc(1217)] Login WebUI >> active: 1, source: account-picker
[12872:12872:0414/014354:INFO:CONSOLE(6608)] "Got focusPod at:
Error
    at HTMLDivElement.focusPod (chrome://oobe/login.js:6607:19)
    at HTMLDivElement.maybePreselectPod (chrome://oobe/login.js:7036:13)
    at HTMLDivElement.handleBeforeShow (chrome://oobe/login.js:7001:14)
    at HTMLDivElement.onBeforeShow (chrome://oobe/login.js:3415:14)
    at Object.toggleStep_ (chrome://oobe/login.js:2281:17)
    at Object.showScreen (chrome://oobe/login.js:2435:14)
    at Function.Oobe.showScreen (chrome://oobe/login.js:7282:24)
    at <anonymous>:1:12", source: chrome://oobe/login.js (6608)
[12872:12872:0414/014354:ERROR:signin_screen_handler.cc(345)] SigninScreenHandler::SetUserInputMethod(username='test-user1@gmail.com'): input_method='_comp_ime_jkghodnilhceideoidjikpgommlajknkxkb:fr::fra', succeed=1
[12872:12872:0414/014354:INFO:screenlock_bridge.cc(146)] Focused user changed to {"email":"test-user1@gmail.com","gaia_id":""}
[12872:12872:0414/014354:ERROR:signin_screen_handler.cc(1170)] SigninScreenHandler::HandleLoginVisible(): sending NOTIFICATION_LOGIN_OR_LOCK_WEBUI_VISIBLE on behalf of 'oobe'

############
##### At this moment, LoginManagerTest::SetUpOnMainThread() was waiting for NOTIFICATION_LOGIN_OR_LOCK_WEBUI_VISIBLE, and this notification triggers the CheckPODScreenWithUsers test function.
############

[12872:12872:0414/014354:INFO:CONSOLE(7206)] "Finished loading asset bundle", source: chrome://oobe/login.js (7206)
[12872:12872:0414/014354:INFO:CONSOLE(6608)] "Got focusPod at:
Error
    at HTMLDivElement.focusPod (chrome://oobe/login.js:6607:19)
    at <anonymous>:1:64", source: chrome://oobe/login.js (6608)

############
##### This call was made by test:

  FocusPODWaiter waiter;                                                         
  js_checker().Evaluate("$('pod-row').focusPod($('pod-row').pods[1])");          
  waiter.Wait();

#####, so focused user was changed to test-user2 . But before test continues, we are getting this:
############

[12872:12872:0414/014354:ERROR:signin_screen_handler.cc(345)] SigninScreenHandler::SetUserInputMethod(username='test-user2@gmail.com'): input_method='_comp_ime_jkghodnilhceideoidjikpgommlajknkxkb:de::ger', succeed=1
[12872:12872:0414/014354:INFO:screenlock_bridge.cc(146)] Focused user changed to {"email":"test-user2@gmail.com","gaia_id":""}
[12872:12872:0414/014354:INFO:CONSOLE(6608)] "Got focusPod at:
Error
    at HTMLDivElement.focusPod (chrome://oobe/login.js:6607:19)
    at HTMLDivElement.handleFocus_ (chrome://oobe/login.js:6872:16)
    at HTMLDivElement.focusInput (chrome://oobe/login.js:4953:22)
    at HTMLDivElement.reset (chrome://oobe/login.js:5038:16)
    at HTMLDivElement.f (chrome://oobe/login.js:6980:22)", source: chrome://oobe/login.js (6608)

############
##### and this was a result of handleAfterShow() method, that called reset() on focusedPod thus triggering setting it to the first user pod.
############

[12872:12872:0414/014354:ERROR:signin_screen_handler.cc(345)] SigninScreenHandler::SetUserInputMethod(username='test-user1@gmail.com'): input_method='_comp_ime_jkghodnilhceideoidjikpgommlajknkxkb:fr::fra', succeed=1
[12872:12872:0414/014354:INFO:screenlock_bridge.cc(146)] Focused user changed to {"email":"test-user1@gmail.com","gaia_id":""}
../../../../../../../usr/local/google/home/alemate/src/chromium/src/chrome/browser/chromeos/login/login_ui_keyboard_browsertest.cc:177: Failure
Value of: input_method::InputMethodManager::Get() ->GetActiveIMEState() ->GetCurrentInputMethod() .id()
  Actual: "_comp_ime_jkghodnilhceideoidjikpgommlajknkxkb:fr::fra"
Expected: user_input_methods[1]
Which is: "_comp_ime_jkghodnilhceideoidjikpgommlajknkxkb:de::ger"

#############
##### And now test verifies that test-user2@ is still focused, which is wrong.
#############

[12872:12872:0414/014354:INFO:screenlock_bridge.cc(146)] Focused user changed to {"email":"","gaia_id":""}
[12872:12872:0414/014354:INFO:power_button_observer.cc(69)] Destroying PowerButtonObserver 0x136a4289faa0
[12872:12872:0414/014354:INFO:lock_state_controller.cc(101)] Destroying LockStateController instance 0x136a426c9620
[12872:12872:0414/014355:WARNING:pref_notifier_impl.cc(27)] pref observer found at shutdown EulaAccepted
[  FAILED  ] LoginUIKeyboardTest.CheckPODScreenWithUsers, where TypeParam =  and GetParam() =  (5273 ms)
[----------] 1 test from LoginUIKeyboardTest (5273 ms total)


So it looks to me, that this test has always been flaky. But handleAfterShow() is also broken.
I believe recent https://codereview.chromium.org/1811113003 has changed timings a little (and probably it introduced an error in handleAfterShow(), but I don't see it).
And now debug build of browser_tests sometimes fail for me.


Assigning to dzhioev@, as he probably known this code better.
To sum it up:

I believe that NOTIFICATION_LOGIN_OR_LOCK_WEBUI_VISIBLE is actually broken, because focused user pod may be reset after this notification. So fixing handleAfterShow() actually means fixing this (very important) event.
Or, probably, handleAfterShow() is broken, because remembers old focused pod in local context of 'webkitTransitionEnd' event listener. And probably it should resolve currently focused pod on event before resetting user pod.
Status: Available (was: Assigned)
Owner: ----
Status: Untriaged (was: Available)
Moving these all back to untriaged state so we can find a new owner.
Owner: alemate@chromium.org
alemate@, are you still the right owner for this?
Status: Assigned (was: Untriaged)
This bug has an owner, thus, it's been triaged. Changing status to "assigned".

Sign in to add a comment