New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 682695 link

Starred by 4 users

Issue metadata

Status: Verified
Owner:
Closed: Jan 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Sign-in error due to token refresh being cancelled for network change

Project Member Reported by derat@chromium.org, Jan 19 2017

Issue description

Chrome OS (M56 and earlier) displays a "Sign-in Error: Chrome OS could not sync your data because your account sign-in details are out of date." error to me periodically. I suspect that there may be multiple causes (more discussion at issue 593378 and http://b/33781803), but I've been able to reproduce this a few times now with multiple accounts by signing in very quickly just after the system boots.

From comparing log files and hearing from the backend team that these failing requests aren't being received by the server, it appears that this is triggered when the token refresh is cancelled, probably due to a network change (i.e. the device initially associating with a wifi network). I see something like the following in all of my failed logs:

[1453:1453:0118/192938.038514:VERBOSE1:oauth2_login_manager.cc(106)] Loading OAuth2 refresh token from database.
[1453:1453:0118/192938.116279:VERBOSE1:oauth2_login_manager.cc(136)] OnRefreshTokenAvailable
[1453:1453:0118/192938.151809:VERBOSE1:user_session_manager.cc(1698)] Launching browser...
[1453:1453:0118/192938.156717:WARNING:auth_service.cc(99)] AuthRequest: token request using refresh token failed: Request canceled.
[1453:1453:0118/192938.157945:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[1453:1453:0118/192938.158058:WARNING:account_tracker.cc(294)] Failed to get UserInfo for _@gmail.com
[1453:1453:0118/192938.158166:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[1453:1453:0118/192938.158210:WARNING:account_tracker.cc(294)] Failed to get UserInfo for _@gmail.com

Confusingly, this is usually followed by messages reporting success:

[1453:1453:0118/192942.227840:VERBOSE1:oauth2_login_manager.cc(305)] OAuth2 refresh and/or GAIA token verification succeeded.
[1453:1453:0118/192942.232443:VERBOSE1:oauth2_login_verifier.cc(82)] ListAccounts successful.
[1453:1453:0118/192942.232793:VERBOSE1:oauth2_login_verifier.cc(67)] MergeSession successful.
[1453:1453:0118/192942.232851:VERBOSE1:oauth2_login_manager.cc(305)] OAuth2 refresh and/or GAIA token verification succeeded.

After this, it's often the case that Chrome invalidates the OAuth token. This appears to be a symptom rather than the cause, though:

[1453:1453:0118/192943.294889:WARNING:auth_sync_observer.cc(66)] Invalidate OAuth token because of a sync error: Invalid credentials.
[1453:1453:0118/192943.405988:ERROR:account_info_fetcher.cc(58)] OnGetTokenFailure: Invalid credentials.
[1453:1453:0118/192943.406279:WARNING:account_fetcher_service.cc(300)] Failed to get UserInfo for _@gmail.com

I'll take a look at this code, but I'm not very familiar with it. Chrome probably needs to be changed to retry when the refresh is cancelled rather than displaying the error and invalidating the token. Alternately, maybe it should treat this as an offline signin.

Logs are at https://drive.google.com/a/google.com/file/d/0ByeZYyW9WlyvTEc5bTdQSGFjMlBoaUNyOHRqWWM4MkJuT25r/view?usp=sharing.
 
Screenshot 2016-11-08 at 13.25.42.png
107 KB View Download

Comment 1 by xiy...@chromium.org, Jan 19 2017

Cc: rogerta@chromium.org
+rogerta

AuthService and AccountTracker call into OAuth2TokenService to get access token for userinfo scope. AFAICT, network change should be handled [1].

I don't see how the request cancelled could cause the token being invalidated though. auth_sync_observer.cc(66) should not run for REQUEST_CANCELED [2]. We get there due to an INVALID_GAIA_CREDENTIALS error. Do you see sync service complaining about INVALID_GAIA_CREDENTIALS when you repro the problem?

[1]: https://cs.chromium.org/chromium/src/google_apis/gaia/oauth2_access_token_fetcher_impl.cc?rcl=1484828258&l=108
[2]:
https://cs.chromium.org/chromium/src/chrome/browser/chromeos/login/signin/auth_sync_observer.cc?rcl=0&l=66

Comment 2 by derat@chromium.org, Jan 19 2017

Whoops, the correct link to the folder with my logs is https://drive.google.com/drive/folders/0ByeZYyW9WlyvVUVlTzhHTXBZYWc?usp=sharing.

Thanks for taking a look, Xiyuan. I'll try to repro this on a dev machine with some more logging.

Comment 3 by xiy...@chromium.org, Jan 19 2017

It is probably interesting see whether ProfileSyncService::OnGetTokenFailure runs with an INVALID_GAIA_CREDENTIALS error and if possible, understand why.

https://cs.chromium.org/chromium/src/components/browser_sync/profile_sync_service.cc?rcl=0&l=658

Comment 4 by derat@chromium.org, Jan 20 2017

With some additional logging, here's what I see just before the AuthSyncObserver warning about the token being invalidated. It looks like there's actually a 400 response from https://www.googleapis.com/oauth2/v4/token. It also looks like GaiaAuthFetcher::StartRevokeOAuth2Token() gets called very early.

...
[6842:6842:0120/121419.159361:VERBOSE1:oauth2_login_manager.cc(136)] OnRefreshTokenAvailable
[6842:6842:0120/121419.160282:ERROR:mutable_profile_oauth2_token_service_delegate.cc(75)] XXX MutableProfileOAuth2TokenServiceDelegate::RevokeServerRefreshToken
[6842:6842:0120/121419.160358:ERROR:gaia_auth_fetcher.cc(526)] XXX GaiaAuthFetcher::StartRevokeOAuth2Token: [snip]
[6842:6842:0120/121419.160560:WARNING:auth_service.cc(99)] AuthRequest: token request using refresh token failed: Request canceled.
[6842:6842:0120/121419.160725:ERROR:profile_sync_service.cc(637)] XXX ProfileSyncService::OnGetTokenFailure: error=Request canceled.
[6842:6842:0120/121419.160830:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=
[6842:6842:0120/121419.160919:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[6842:6842:0120/121419.160957:WARNING:account_tracker.cc(294)] Failed to get UserInfo for derattest@gmail.com
[6842:6842:0120/121419.160993:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[6842:6842:0120/121419.161024:WARNING:account_tracker.cc(294)] Failed to get UserInfo for derattest@gmail.com
[6842:6842:0120/121419.161138:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[6842:6842:0120/121419.265807:VERBOSE1:input_events_blocker.cc(28)] InputEventsBlocker 0x8d0249a4f60 destroyed.
[6842:6842:0120/121419.266133:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[6842:6842:0120/121419.266635:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[6842:6842:0120/121419.267455:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled
...
[6842:7053:0120/121419.550623:ERROR:url_fetcher_core.cc(754)] XXX URLFetcherCore::RetryOrCompleteUrlFetch: url=https://accounts.google.com/o/oauth2/revoke response_code=200 status=0 error=0 num_retries=0 max_retries=3
...
[6842:7053:0120/121422.876689:ERROR:url_fetcher_core.cc(754)] XXX URLFetcherCore::RetryOrCompleteUrlFetch: url=https://accounts.google.com/ListAccounts?gpsia=1&source=ChromiumOAuth2LoginVerifier&json=standard response_code=200 status=0 error=0 num_retries=0 max_retries=3
[6842:6842:0120/121422.876972:VERBOSE1:oauth2_login_verifier.cc(67)] MergeSession successful.
[6842:6842:0120/121422.877007:VERBOSE1:oauth2_login_manager.cc(305)] OAuth2 refresh and/or GAIA token verification succeeded.
[6842:6842:0120/121422.877805:VERBOSE1:oauth2_login_verifier.cc(82)] ListAccounts successful.
[6842:6842:0120/121422.877990:VERBOSE1:oauth2_login_verifier.cc(67)] MergeSession successful.
[6842:6842:0120/121422.878032:VERBOSE1:oauth2_login_manager.cc(305)] OAuth2 refresh and/or GAIA token verification succeeded.
[6842:7053:0120/121422.885772:VERBOSE2:ppapi_plugin_process_host.cc(472)] ppapi plugin process launched.
[6842:6842:0120/121423.290045:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[6842:7053:0120/121423.778698:ERROR:url_fetcher_core.cc(754)] XXX URLFetcherCore::RetryOrCompleteUrlFetch: url=https://www.googleapis.com/oauth2/v4/token response_code=400 status=0 error=0 num_retries=0 max_retries=3
[6842:6842:0120/121423.780643:ERROR:profile_sync_service.cc(637)] XXX ProfileSyncService::OnGetTokenFailure: error=Invalid credentials.
[6842:6842:0120/121423.780783:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Invalid credentials.
[6842:6842:0120/121423.780816:WARNING:auth_sync_observer.cc(68)] Invalidate OAuth token because of a sync error: Invalid credentials.
[6842:7053:0120/121424.451535:ERROR:url_fetcher_core.cc(754)] XXX URLFetcherCore::RetryOrCompleteUrlFetch: url=https://www.google.com/async/ddljson response_code=200 status=0 error=0 num_retries=0 max_retries=0
[6842:6842:0120/121426.836630:ERROR:account_info_fetcher.cc(58)] OnGetTokenFailure: Invalid credentials.
[6842:6842:0120/121426.836712:WARNING:account_fetcher_service.cc(304)] Failed to get UserInfo for derattest@gmail.com
[6842:6842:0120/121429.114119:WARNING:profile_downloader.cc(329)] ProfileDownloader: token request using refresh token failed:Invalid credentials.
[6842:7053:0120/121442.692937:ERROR:url_fetcher_core.cc(754)] XXX URLFetcherCore::RetryOrCompleteUrlFetch: url=http://www.gstatic.com/generate_204 response_code=204 status=0 error=0 num_retries=0 max_retries=0

Comment 5 by xiy...@chromium.org, Jan 20 2017

Do we know what triggers MutableProfileOAuth2TokenServiceDelegate::RevokeServerRefreshToken? 

It seems like from TokenService loading the tokens [1]. But ChromeOS should not hit that line for the primary account.

[1]: https://cs.chromium.org/chromium/src/chrome/browser/signin/mutable_profile_oauth2_token_service_delegate.cc?rcl=1484929066&l=390

Comment 6 by derat@chromium.org, Jan 21 2017

Whew! It took many attempts, but I finally saw this again with more logging. I think that this is the part that you were interested in:

[1402:1402:0120/174722.632496:VERBOSE1:oauth2_login_manager.cc(136)] OnRefreshTokenAvailable
[1402:1402:0120/174722.638749:VERBOSE1:user_session_manager.cc(1712)] Launching browser...
[1402:1402:0120/174722.645950:ERROR:mutable_profile_oauth2_token_service_delegate.cc(322)] XXX MutableProfileOAuth2TokenServiceDelegate::LoadAllCredentialsIntoMemory: loading_primary_account_id
=
[1402:1402:0120/174722.646047:ERROR:mutable_profile_oauth2_token_service_delegate.cc(339)]     prefixed_account_id=AccountId-derattest@gmail.com refresh_token=[id]
K_rGWyLjamE
[1402:1402:0120/174722.646095:ERROR:mutable_profile_oauth2_token_service_delegate.cc(397)]       calling RevokeCredentialsOnServer with [id]
[1402:1402:0120/174722.646189:ERROR:mutable_profile_oauth2_token_service_delegate.cc(75)] XXX MutableProfileOAuth2TokenServiceDelegate::RevokeServerRefreshToken
[1402:1402:0120/174722.646221:ERROR:gaia_auth_fetcher.cc(526)] XXX GaiaAuthFetcher::StartRevokeOAuth2Token: [id]
[1402:1402:0120/174722.646357:WARNING:auth_service.cc(99)] AuthRequest: token request using refresh token failed: Request canceled.
[1402:1402:0120/174722.646491:ERROR:profile_sync_service.cc(637)] XXX ProfileSyncService::OnGetTokenFailure: error=Request canceled.
[1402:1402:0120/174722.646572:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=
[1402:1402:0120/174722.646653:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[1402:1402:0120/174722.646682:WARNING:account_tracker.cc(294)] Failed to get UserInfo for derattest@gmail.com
[1402:1402:0120/174722.646710:ERROR:account_tracker.cc(356)] OnGetTokenFailure: Request canceled.
[1402:1402:0120/174722.646736:WARNING:account_tracker.cc(294)] Failed to get UserInfo for derattest@gmail.com
[1402:1402:0120/174722.646831:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[1402:1402:0120/174722.818567:VERBOSE1:input_events_blocker.cc(28)] InputEventsBlocker 0x2eb9ccee420 destroyed.
[1402:1402:0120/174722.891639:VERBOSE1:gaia_screen_handler.cc(448)] Auth extension finished loading
[1402:1402:0120/174722.907612:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[1402:1402:0120/174722.908098:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.
[1402:1402:0120/174722.908331:ERROR:auth_sync_observer.cc(59)] XXX AuthSyncObserver::OnStateChanged: error=Request canceled.

It looks like loading_primary_account_id_ is empty when MutableProfileOAuth2TokenServiceDelegate::LoadAllCredentialsIntoMemory is called. This is unexpected, right? derattest@gmail.com (a.k.a. derat.test@gmail.com) is the device owner (per the login screen).

Comment 7 by derat@chromium.org, Jan 23 2017

Owner: xiy...@chromium.org
Status: Started (was: Assigned)
Xiyuan said that he has enough info now to start looking for a race in this code. Thanks!

Comment 8 by xiy...@chromium.org, Jan 25 2017

The problem happens when a network change triggers OAuth2LoginManager::ContinueSessionRestore [1] at a bad time. ContinueSessionRestore calls TokenService::LoadCredentials to load stored tokens. LoadCredentials is not safe to call again if there is a pending load request. Particularly, MutableProfileOAuth2TokenServiceDelegate has only one |loading_primary_account_id_| to track the pending webdata load and it is cleared when the webdata load finishes [2]. When the 2nd load request finishes, |loading_primary_account_id_| will be empty and this will trigger token revocation because the account id of loaded token does not match [3].

The events when this problem happens is like this:
1. User signs in
2. OAuth2LoginManager::RestoreSession -> ContinueSessionRestore is called,
   and token was not loaded at the time so a LoadCredentials call is issued;
3. Before TokenService finishes loading its tokens, network type change
   is detected, which result in another LoadCredentials from
   ContinueSessionRestore;
4. The first token load request finishes, everything is fine;
5. The second token load request comes back and oops, the account id does not
   match and TokenService revokes the stored token;

And user has to signs in again after step 5.


[1]: https://cs.chromium.org/chromium/src/chrome/browser/chromeos/login/session/user_session_manager.cc?rcl=0&l=881
[2]: https://cs.chromium.org/chromium/src/chrome/browser/signin/mutable_profile_oauth2_token_service_delegate.cc?rcl=0&l=315
[3]: https://cs.chromium.org/chromium/src/chrome/browser/signin/mutable_profile_oauth2_token_service_delegate.cc?rcl=0&l=390

Comment 9 by xiy...@chromium.org, Jan 25 2017

Found evidence in the log in #2.

For bad runs, we all have two "Loading OAuth2 refresh token from database." lines and some network log between the two lines.

For good runs, we only have one "Loading OAuth2 refresh token from database." there.

Comment 10 by derat@chromium.org, Jan 25 2017

Great, thank you so much for figuring this out! It's been driving me crazy. :-)
Project Member

Comment 11 by bugdroid1@chromium.org, Jan 26 2017

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

commit 29db500ff5473c212ebe3f1cebbc00ec87a023b8
Author: xiyuan <xiyuan@chromium.org>
Date: Thu Jan 26 00:55:53 2017

cros: Fix multiple LoadCredentials on network change

TokenService::LoadCredentials does not handle multiple concurrent
load requests. However, OAuth2LoginManager::ContinueSessionRestore
calls it when there is a network change and could end up having
multiple load requests in fly. This would cause the token of the
primary account being wrongly revoked. Adding a bool flag in
OAuth2LoginManager to prevent overlapping LoadCredentials calls.

BUG= 682695 

Review-Url: https://codereview.chromium.org/2650653007
Cr-Commit-Position: refs/heads/master@{#446180}

[modify] https://crrev.com/29db500ff5473c212ebe3f1cebbc00ec87a023b8/chrome/browser/chromeos/login/signin/oauth2_login_manager.cc
[modify] https://crrev.com/29db500ff5473c212ebe3f1cebbc00ec87a023b8/chrome/browser/chromeos/login/signin/oauth2_login_manager.h

Project Member

Comment 12 by bugdroid1@chromium.org, Jan 30 2017

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

commit 5555191b32d4d5e6b8b956e310e1eb64aa7bc188
Author: xiyuan <xiyuan@chromium.org>
Date: Mon Jan 30 18:43:25 2017

cros: Test for overlapping ContinueSessionRestore calls

OAuth2LoginManager::ContinueSessionRestore with strategy
RESTORE_FROM_SAVED_OAUTH2_REFRESH_TOKEN would call
TokenService::LoadCredentials that does not support
multiple concurrent calls. Add a test to verify that it
does not attempt to overlap LoadCredentials calls.

BUG= 682695 
TEST=OAuth2Test.OverlappingContinueSessionRestore

Review-Url: https://codereview.chromium.org/2658953002
Cr-Commit-Position: refs/heads/master@{#447020}

[modify] https://crrev.com/5555191b32d4d5e6b8b956e310e1eb64aa7bc188/chrome/browser/chromeos/login/signin/oauth2_browsertest.cc

Labels: -M-56 M-57 Merge-Request-57
Request merge #11 to M57.
Labels: -Merge-Request-57 Merge-Approved-57
Approving merge to M57 Chrome OS.
Project Member

Comment 15 by bugdroid1@chromium.org, Jan 30 2017

Labels: -merge-approved-57 merge-merged-2987
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/975ff3d0e39313b373256c7d4b87291beac2e5e1

commit 975ff3d0e39313b373256c7d4b87291beac2e5e1
Author: Xiyuan Xia <xiyuan@google.com>
Date: Mon Jan 30 22:08:00 2017

Merge "cros: Fix multiple LoadCredentials on network change"

> TokenService::LoadCredentials does not handle multiple concurrent
> load requests. However, OAuth2LoginManager::ContinueSessionRestore
> calls it when there is a network change and could end up having
> multiple load requests in fly. This would cause the token of the
> primary account being wrongly revoked. Adding a bool flag in
> OAuth2LoginManager to prevent overlapping LoadCredentials calls.
>
> BUG= 682695 
>
> Review-Url: https://codereview.chromium.org/2650653007
> Cr-Commit-Position: refs/heads/master@{#446180}
> (cherry picked from commit 29db500ff5473c212ebe3f1cebbc00ec87a023b8)

Review-Url: https://codereview.chromium.org/2663033002 .
Cr-Commit-Position: refs/branch-heads/2987@{#196}
Cr-Branched-From: ad51088c0e8776e8dcd963dbe752c4035ba6dab6-refs/heads/master@{#444943}

[modify] https://crrev.com/975ff3d0e39313b373256c7d4b87291beac2e5e1/chrome/browser/chromeos/login/signin/oauth2_login_manager.cc
[modify] https://crrev.com/975ff3d0e39313b373256c7d4b87291beac2e5e1/chrome/browser/chromeos/login/signin/oauth2_login_manager.h

Status: Fixed (was: Started)
Project Member

Comment 17 by bugdroid1@chromium.org, Jan 30 2017

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

commit dfecbb4466fbfa9ab590b5a9917d9515ab4630c2
Author: tsergeant <tsergeant@chromium.org>
Date: Mon Jan 30 23:58:02 2017

Revert of cros: Test for overlapping ContinueSessionRestore calls (patchset #1 id:1 of https://codereview.chromium.org/2658953002/ )

Reason for revert:
This new test fails flakily on the Linux ChromiumOS Tests (dbg)(1) bot.

See example failures:
https://luci-milo.appspot.com/buildbot/chromium.chromiumos/Linux%20ChromiumOS%20Tests%20%28dbg%29%281%29/22001
https://luci-milo.appspot.com/buildbot/chromium.chromiumos/Linux%20ChromiumOS%20Tests%20%28dbg%29%281%29/22005

Original issue's description:
> cros: Test for overlapping ContinueSessionRestore calls
>
> OAuth2LoginManager::ContinueSessionRestore with strategy
> RESTORE_FROM_SAVED_OAUTH2_REFRESH_TOKEN would call
> TokenService::LoadCredentials that does not support
> multiple concurrent calls. Add a test to verify that it
> does not attempt to overlap LoadCredentials calls.
>
> BUG= 682695 
> TEST=OAuth2Test.OverlappingContinueSessionRestore
>
> Review-Url: https://codereview.chromium.org/2658953002
> Cr-Commit-Position: refs/heads/master@{#447020}
> Committed: https://chromium.googlesource.com/chromium/src/+/5555191b32d4d5e6b8b956e310e1eb64aa7bc188

TBR=jdufault@chromium.org,derat@chromium.org,xiyuan@chromium.org
# Skipping CQ checks because original CL landed less than 1 days ago.
NOPRESUBMIT=true
NOTREECHECKS=true
NOTRY=true
BUG= 682695 

Review-Url: https://codereview.chromium.org/2663063002
Cr-Commit-Position: refs/heads/master@{#447115}

[modify] https://crrev.com/dfecbb4466fbfa9ab590b5a9917d9515ab4630c2/chrome/browser/chromeos/login/signin/oauth2_browsertest.cc

Sheriff here. I've created a revert of the CL in #12 here: https://codereview.chromium.org/2663063002/

This test is failing on Linux ChromiumOS Tests (dbg)(1), see https://luci-milo.appspot.com/buildbot/chromium.chromiumos/Linux%20ChromiumOS%20Tests%20%28dbg%29%281%29/22001.

Test output:

[ RUN      ] OAuth2Test.PRE_OverlappingContinueSessionRestore
HTTPS server started on 127.0.0.1:47287...
sending server_data: {"host": "127.0.0.1", "port": 47287} (36 bytes)
[25875:25875:0130/142713.635734:WARNING:audio_manager.cc(321)] Multiple instances of AudioManager detected
[25875:25875:0130/142713.635881:WARNING:audio_manager.cc(278)] Multiple instances of AudioManager detected
Xlib:  extension "RANDR" missing on display ":99".
[25875:25875:0130/142715.023622:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension  : mhjfbmdgcfjbbpaeojofohoefgiehjai / Chromium PDF Viewer because of 'signin_screen' is only allowed for packaged apps, but this is a extension.
[25875:25962:0130/142716.124781:WARNING:freezer_cgroup_process_manager.cc(61)] Cgroup freezer does not exist or is not writable. Unable to freeze renderer processes.
[25875:25875:0130/142716.212220:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension  : mhjfbmdgcfjbbpaeojofohoefgiehjai / Chromium PDF Viewer because of 'signin_screen' is only allowed for packaged apps, but this is a extension.
[25875:25875:0130/142727.565530:WARNING:CONSOLE(1)] "This file is deprecated. Please use `iron-flex-layout/iron-flex-layout-classes.html`, and one of the specific dom-modules instead", source: chrome://resources/polymer/v1_0/iron-flex-layout/classes/iron-shadow-flex-layout-extracted.js (1)
[25875:25875:0130/142728.443222:WARNING:CONSOLE(1)] "This file is deprecated. Please use `iron-flex-layout/iron-flex-layout-classes.html`, and one of the specific dom-modules instead", source: chrome://resources/polymer/v1_0/iron-flex-layout/classes/iron-flex-layout-extracted.js (1)
[25875:25875:0130/142737.959064:WARNING:CONSOLE(3812)] "/deep/ combinator is deprecated. See https://www.chromestatus.com/features/6750456638341120 for more details.", source: chrome://resources/polymer/v1_0/polymer/polymer-extracted.js (3812)
[25875:25875:0130/142744.407650:INFO:CONSOLE(7786)] "Loading asset bundle oauth-enrollment", source: chrome://oobe/oobe.js (7786)
[25875:25875:0130/142744.533977:INFO:signin_screen_handler.cc(340)] GetUserLRUInputMethod(''): no input method for this user
[25875:25875:0130/142747.854476:INFO:signin_screen_handler.cc(1349)] Login WebUI >> active: 1, source: gaia-signin
BrowserTestBase received signal: Terminated. Backtrace:
#0 0x7f6cf81d756b base::debug::StackTrace::StackTrace()
#1 0x7f6cf81d5bec base::debug::StackTrace::StackTrace()
#2 0x000004a45c97 content::(anonymous namespace)::DumpStackTraceSignalHandler()
#3 0x7f6cdc18c0b0 <unknown>
#4 0x7f6ced80146d std::unique_ptr<>::operator->()
#5 0x7f6ced800295 cc::ListContainerHelper::size()
#6 0x7f6ced80053d cc::ListContainerHelper::cend()
#7 0x7f6cecfa4507 cc::ListContainer<>::cend()
#8 0x7f6cecf9b28c cc::ListContainer<>::end()
#9 0x7f6cecf93c74 cc::SurfaceAggregator::CopyQuadsToPass()
#10 0x7f6cecf936d5 cc::SurfaceAggregator::HandleSurfaceQuad()
#11 0x7f6cecf93f57 cc::SurfaceAggregator::CopyQuadsToPass()
#12 0x7f6cecf949ff cc::SurfaceAggregator::CopyPasses()
#13 0x7f6cecf97023 cc::SurfaceAggregator::Aggregate()
#14 0x7f6cecf63ea5 cc::Display::DrawAndSwap()
#15 0x7f6cecf75e0b cc::DisplayScheduler::DrawAndSwap()
#16 0x7f6cecf75556 cc::DisplayScheduler::AttemptDrawAndSwap()
#17 0x7f6cecf74e4f cc::DisplayScheduler::OnBeginFrameDeadline()
#18 0x7f6cecf5bbe7 _ZN4base8internal13FunctorTraitsIMN2cc26CompositorFrameSinkSupportEFvvEvE6InvokeIRKNS_7WeakPtrIS3_EEJEEEvS5_OT_DpOT0_
#19 0x7f6cecf79bea _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN2cc16DisplaySchedulerEFvvERKNS_7WeakPtrIS5_EEJEEEvOT_OT0_DpOT1_
#20 0x7f6cecf79b72 _ZN4base8internal7InvokerINS0_9BindStateIMN2cc16DisplaySchedulerEFvvEJNS_7WeakPtrIS4_EEEEEFvvEE7RunImplIRKS6_RKSt5tupleIJS8_EEJLm0EEEEvOT_OT0_NS_13IndexSequenceIJXspT1_EEEE
#21 0x7f6cecf79abc _ZN4base8internal7InvokerINS0_9BindStateIMN2cc16DisplaySchedulerEFvvEJNS_7WeakPtrIS4_EEEEEFvvEE3RunEPNS0_13BindStateBaseE
#22 0x7f6cecf81d8b base::internal::RunMixin<>::Run()
#23 0x7f6cecf81839 base::CancelableCallback<>::Forward()
#24 0x7f6cecf5bbe7 _ZN4base8internal13FunctorTraitsIMN2cc26CompositorFrameSinkSupportEFvvEvE6InvokeIRKNS_7WeakPtrIS3_EEJEEEvS5_OT_DpOT0_
#25 0x7f6cecf81a2a _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMNS_18CancelableCallbackIFvvEEEKFvvERKNS_7WeakPtrIS6_EEJEEEvOT_OT0_DpOT1_
#26 0x7f6cecf819b2 _ZN4base8internal7InvokerINS0_9BindStateIMNS_18CancelableCallbackIFvvEEEKFvvEJNS_7WeakPtrIS5_EEEEES4_E7RunImplIRKS7_RKSt5tupleIJS9_EEJLm0EEEEvOT_OT0_NS_13IndexSequenceIJXspT1_EEEE
#27 0x7f6cecf818fc _ZN4base8internal7InvokerINS0_9BindStateIMNS_18CancelableCallbackIFvvEEEKFvvEJNS_7WeakPtrIS5_EEEEES4_E3RunEPNS0_13BindStateBaseE
#28 0x7f6cf81dcad1 _ZNO4base8internal8RunMixinINS_8CallbackIFvvELNS0_8CopyModeE0ELNS0_10RepeatModeE0EEEE3RunEv
#29 0x7f6cf81dc4d9 base::debug::TaskAnnotator::RunTask()
#30 0x7f6cf8263373 base::MessageLoop::RunTask()
#31 0x7f6cf82635d4 base::MessageLoop::DeferOrRunPendingTask()
#32 0x7f6cf82638be base::MessageLoop::DoWork()
#33 0x7f6cf8278a56 base::MessagePumpGlib::Run()
#34 0x7f6cf8262f62 base::MessageLoop::RunHandler()
#35 0x7f6cf8303c64 base::RunLoop::Run()
#36 0x000004adbf66 content::RunThisRunLoop()
#37 0x000004adcb73 content::MessageLoopRunner::Run()
#38 0x000004a4a28a content::DOMMessageQueue::WaitForMessage()
#39 0x000001832079 chromeos::OobeBaseTest::WaitForGaiaPageReload()
#40 0x000001831f62 chromeos::OobeBaseTest::WaitForGaiaPageLoad()
#41 0x000001818aef chromeos::OAuth2Test::StartNewUserSession()
#42 0x00000181699a chromeos::OAuth2Test_PRE_OverlappingContinueSessionRestore_Test::RunTestOnMainThread()
#43 0x00000399c265 InProcessBrowserTest::RunTestOnMainThreadLoop()
#44 0x000004a459c4 content::BrowserTestBase::ProxyRunTestOnMainThreadLoop()
#45 0x0000008fbb45 _ZN4base8internal13FunctorTraitsIM25RenderViewContextMenuBaseFvvEvE6InvokeIP21RenderViewContextMenuJEEEvS4_OT_DpOT0_
#46 0x0000008fba61 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKM25RenderViewContextMenuBaseFvvEJP21RenderViewContextMenuEEEvOT_DpOT0_
#47 0x000004a46927 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE7RunImplIRKS6_RKSt5tupleIJS8_EEJLm0EEEEvOT_OT0_NS_13IndexSequenceIJXspT1_EEEE
#48 0x000004a4686c _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE3RunEPNS0_13BindStateBaseE
#49 0x0000008e26db base::internal::RunMixin<>::Run()
#50 0x000003a4756b [25875:26202:0130/142752.117487:WARNING:fake_gaia.cc(312)] Serving request /embedded/setup/chromeos
localhost - - [30/Jan/2017 14:27:52] "GET /embedded/setup/chromeos?chrometype=chromedevice&client_id=dummytoken&client_version=58.0.2998.0&platform_version=0.0.0.0&endpoint_gen=1.0&hl=en-US HTTP/1.1" 200 -
ChromeBrowserMainParts::PreMainMessageLoopRunImpl()
#51 0x000003a46200 ChromeBrowserMainParts::PreMainMessageLoopRun()
#52 0x000001cd87d4 chromeos::ChromeBrowserMainPartsChromeos::PreMainMessageLoopRun()
#53 0x7f6cef9b7391 content::BrowserMainLoop::PreMainMessageLoopRun()
#54 0x7f6ceef31ea5 _ZN4base8internal13FunctorTraitsIMN7content22IndexedDBCallbacksImpl13InternalStateEFvvEvE6InvokeIPS4_JEEEvS6_OT_DpOT0_
#55 0x7f6cef9c1d31 _ZN4base8internal12InvokeHelperILb0EiE8MakeItSoIRKMN7content15BrowserMainLoopEFivEJPS5_EEEiOT_DpOT0_
#56 0x7f6cef9c1cd7 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE7RunImplIRKS6_RKSt5tupleIJS8_EEJLm0EEEEiOT_OT0_NS_13IndexSequenceIJXspT1_EEEE
#57 0x7f6cef9c1c1c _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE3RunEPNS0_13BindStateBaseE
#58 0x7f6ceee2beeb base::internal::RunMixin<>::Run()
#59 0x7f6cf04a383b content::StartupTaskRunner::RunAllTasksNow()
#60 0x7f6cef9b50a0 content::BrowserMainLoop::CreateStartupTasks()
#61 0x7f6cef9c5dd0 content::BrowserMainRunnerImpl::Initialize()
Project Member

Comment 19 by bugdroid1@chromium.org, Feb 6 2017

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

commit 5a99a823e8dcc16c9804df03ba30747255104c2b
Author: xiyuan <xiyuan@chromium.org>
Date: Mon Feb 06 21:22:39 2017

Reland cros: Test for overlapping ContinueSessionRestore calls

Original review: https://codereview.chromium.org/2658953002/

OAuth2LoginManager::ContinueSessionRestore with strategy
RESTORE_FROM_SAVED_OAUTH2_REFRESH_TOKEN would call
TokenService::LoadCredentials that does not support
multiple concurrent calls. Add a test to verify that it
does not attempt to overlap LoadCredentials calls.

BUG= 682695 
TEST=OAuth2Test.OverlappingContinueSessionRestore

Review-Url: https://codereview.chromium.org/2668043002
Cr-Commit-Position: refs/heads/master@{#448392}

[modify] https://crrev.com/5a99a823e8dcc16c9804df03ba30747255104c2b/chrome/browser/chromeos/login/signin/oauth2_browsertest.cc
[modify] https://crrev.com/5a99a823e8dcc16c9804df03ba30747255104c2b/chrome/browser/chromeos/login/test/oobe_base_test.cc
[modify] https://crrev.com/5a99a823e8dcc16c9804df03ba30747255104c2b/google_apis/gaia/fake_gaia.cc
[modify] https://crrev.com/5a99a823e8dcc16c9804df03ba30747255104c2b/google_apis/gaia/fake_gaia.h

Status: Verified (was: Fixed)

Sign in to add a comment