Skip to content

Commit

Permalink
Identity API TRACE_EVENT logging
Browse files Browse the repository at this point in the history 
This change adds "identity" events to chrome://tracing, mostly for
getAuthToken calls. This will allow users or developers to capture
traces to debug identity API issues.

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

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@286131 0039d316-1c4b-4281-b951-d872f2087c98
  • Loading branch information
courage@chromium.org committed Jul 29, 2014
1 parent 94bdde9 commit 5dc43ec
Show file tree
Hide file tree
Showing 6 changed files with 171 additions and 6 deletions.
33 changes: 33 additions & 0 deletions chrome/browser/extensions/api/identity/gaia_web_auth_flow.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@

#include "chrome/browser/extensions/api/identity/gaia_web_auth_flow.h"

#include "base/debug/trace_event.h"
#include "base/strings/string_number_conversions.h"
#include "base/strings/string_split.h"
#include "base/strings/string_util.h"
Expand All @@ -26,6 +27,14 @@ GaiaWebAuthFlow::GaiaWebAuthFlow(Delegate* delegate,
: delegate_(delegate),
profile_(profile),
account_id_(token_key->account_id) {
TRACE_EVENT_ASYNC_BEGIN2("identity",
"GaiaWebAuthFlow",
this,
"extension_id",
token_key->extension_id,
"account_id",
token_key->account_id);

const char kOAuth2RedirectPathFormat[] = "/%s#";
const char kOAuth2AuthorizeFormat[] =
"?response_type=token&approval_prompt=force&authuser=0&"
Expand Down Expand Up @@ -57,6 +66,8 @@ GaiaWebAuthFlow::GaiaWebAuthFlow(Delegate* delegate,
}

GaiaWebAuthFlow::~GaiaWebAuthFlow() {
TRACE_EVENT_ASYNC_END0("identity", "GaiaWebAuthFlow", this);

if (web_flow_)
web_flow_.release()->DetachDelegateAndDelete();
}
Expand All @@ -71,6 +82,9 @@ void GaiaWebAuthFlow::Start() {
}

void GaiaWebAuthFlow::OnUbertokenSuccess(const std::string& token) {
TRACE_EVENT_ASYNC_STEP_PAST0(
"identity", "GaiaWebAuthFlow", this, "OnUbertokenSuccess");

const char kMergeSessionQueryFormat[] = "?uberauth=%s&"
"continue=%s&"
"source=appsv2";
Expand All @@ -87,6 +101,13 @@ void GaiaWebAuthFlow::OnUbertokenSuccess(const std::string& token) {
}

void GaiaWebAuthFlow::OnUbertokenFailure(const GoogleServiceAuthError& error) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"GaiaWebAuthFlow",
this,
"OnUbertokenSuccess",
"error",
error.ToString());

DVLOG(1) << "OnUbertokenFailure: " << error.error_message();
delegate_->OnGaiaFlowFailure(
GaiaWebAuthFlow::SERVICE_AUTH_ERROR, error, std::string());
Expand All @@ -109,13 +130,25 @@ void GaiaWebAuthFlow::OnAuthFlowFailure(WebAuthFlow::Failure failure) {
break;
}

TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"GaiaWebAuthFlow",
this,
"OnAuthFlowFailure",
"error",
gaia_failure);

delegate_->OnGaiaFlowFailure(
gaia_failure,
GoogleServiceAuthError(GoogleServiceAuthError::NONE),
std::string());
}

void GaiaWebAuthFlow::OnAuthFlowURLChange(const GURL& url) {
TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"GaiaWebAuthFlow",
this,
"OnAuthFlowURLChange");

const char kOAuth2RedirectAccessTokenKey[] = "access_token";
const char kOAuth2RedirectErrorKey[] = "error";
const char kOAuth2ExpiresInKey[] = "expires_in";
Expand Down
68 changes: 65 additions & 3 deletions chrome/browser/extensions/api/identity/identity_api.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
#include <utility>
#include <vector>

#include "base/debug/trace_event.h"
#include "base/lazy_instance.h"
#include "base/prefs/pref_service.h"
#include "base/strings/string_number_conversions.h"
Expand Down Expand Up @@ -286,9 +287,17 @@ ExtensionFunction::ResponseAction IdentityGetAccountsFunction::Run() {
IdentityGetAuthTokenFunction::IdentityGetAuthTokenFunction()
: OAuth2TokenService::Consumer("extensions_identity_api"),
should_prompt_for_scopes_(false),
should_prompt_for_signin_(false) {}
should_prompt_for_signin_(false) {
TRACE_EVENT_ASYNC_BEGIN1("identity",
"IdentityGetAuthTokenFunction",
this,
"extension",
extension()->id());
}

IdentityGetAuthTokenFunction::~IdentityGetAuthTokenFunction() {}
IdentityGetAuthTokenFunction::~IdentityGetAuthTokenFunction() {
TRACE_EVENT_ASYNC_END0("identity", "IdentityGetAuthTokenFunction", this);
}

bool IdentityGetAuthTokenFunction::RunAsync() {
if (GetProfile()->IsOffTheRecord()) {
Expand Down Expand Up @@ -405,6 +414,12 @@ void IdentityGetAuthTokenFunction::CompleteFunctionWithResult(

void IdentityGetAuthTokenFunction::CompleteFunctionWithError(
const std::string& error) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"IdentityGetAuthTokenFunction",
this,
"CompleteFunctionWithError",
"error",
error);
error_ = error;
CompleteAsyncRun(false);
}
Expand Down Expand Up @@ -458,6 +473,13 @@ void IdentityGetAuthTokenFunction::CompleteMintTokenFlow() {

void IdentityGetAuthTokenFunction::StartMintToken(
IdentityMintRequestQueue::MintType type) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"IdentityGetAuthTokenFunction",
this,
"StartMintToken",
"type",
type);

const OAuth2Info& oauth2_info = OAuth2Info::GetOAuth2Info(extension());
IdentityAPI* id_api = IdentityAPI::GetFactoryInstance()->Get(GetProfile());
IdentityTokenCacheValue cache_entry = id_api->GetCachedToken(*token_key_);
Expand Down Expand Up @@ -519,6 +541,11 @@ void IdentityGetAuthTokenFunction::StartMintToken(

void IdentityGetAuthTokenFunction::OnMintTokenSuccess(
const std::string& access_token, int time_to_live) {
TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"IdentityGetAuthTokenFunction",
this,
"OnMintTokenSuccess");

IdentityTokenCacheValue token(access_token,
base::TimeDelta::FromSeconds(time_to_live));
IdentityAPI::GetFactoryInstance()->Get(GetProfile())->SetCachedToken(
Expand All @@ -530,6 +557,12 @@ void IdentityGetAuthTokenFunction::OnMintTokenSuccess(

void IdentityGetAuthTokenFunction::OnMintTokenFailure(
const GoogleServiceAuthError& error) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"IdentityGetAuthTokenFunction",
this,
"OnMintTokenFailure",
"error",
error.ToString());
CompleteMintTokenFlow();

switch (error.state()) {
Expand All @@ -554,6 +587,11 @@ void IdentityGetAuthTokenFunction::OnMintTokenFailure(

void IdentityGetAuthTokenFunction::OnIssueAdviceSuccess(
const IssueAdviceInfo& issue_advice) {
TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"IdentityGetAuthTokenFunction",
this,
"OnIssueAdviceSuccess");

IdentityAPI::GetFactoryInstance()->Get(GetProfile())->SetCachedToken(
*token_key_, IdentityTokenCacheValue(issue_advice));
CompleteMintTokenFlow();
Expand All @@ -566,6 +604,11 @@ void IdentityGetAuthTokenFunction::OnIssueAdviceSuccess(
}

void IdentityGetAuthTokenFunction::SigninSuccess() {
TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"IdentityGetAuthTokenFunction",
this,
"SigninSuccess");

// If there was no account associated this profile before the
// sign-in, we may not have an account_id in the token_key yet.
if (token_key_->account_id.empty()) {
Expand All @@ -576,6 +619,10 @@ void IdentityGetAuthTokenFunction::SigninSuccess() {
}

void IdentityGetAuthTokenFunction::SigninFailed() {
TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"IdentityGetAuthTokenFunction",
this,
"SigninFailed");
CompleteFunctionWithError(identity_constants::kUserNotSignedIn);
}

Expand Down Expand Up @@ -620,7 +667,10 @@ void IdentityGetAuthTokenFunction::OnGaiaFlowFailure(
void IdentityGetAuthTokenFunction::OnGaiaFlowCompleted(
const std::string& access_token,
const std::string& expiration) {

TRACE_EVENT_ASYNC_STEP_PAST0("identity",
"IdentityGetAuthTokenFunction",
this,
"OnGaiaFlowCompleted");
int time_to_live;
if (!expiration.empty() && base::StringToInt(expiration, &time_to_live)) {
IdentityTokenCacheValue token_value(
Expand All @@ -637,13 +687,25 @@ void IdentityGetAuthTokenFunction::OnGetTokenSuccess(
const OAuth2TokenService::Request* request,
const std::string& access_token,
const base::Time& expiration_time) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"IdentityGetAuthTokenFunction",
this,
"OnGetTokenSuccess",
"account",
request->GetAccountId());
login_token_request_.reset();
StartGaiaRequest(access_token);
}

void IdentityGetAuthTokenFunction::OnGetTokenFailure(
const OAuth2TokenService::Request* request,
const GoogleServiceAuthError& error) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"IdentityGetAuthTokenFunction",
this,
"OnGetTokenFailure",
"error",
error.ToString());
login_token_request_.reset();
OnGaiaFlowFailure(GaiaWebAuthFlow::SERVICE_AUTH_ERROR, error, std::string());
}
Expand Down
25 changes: 23 additions & 2 deletions chrome/browser/extensions/api/identity/identity_mint_queue.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@

#include "chrome/browser/extensions/api/identity/identity_mint_queue.h"

#include "base/debug/trace_event.h"
#include "base/logging.h"
#include "base/stl_util.h"

Expand Down Expand Up @@ -31,28 +32,40 @@ void IdentityMintRequestQueue::RequestStart(
IdentityMintRequestQueue::MintType type,
const ExtensionTokenKey& key,
IdentityMintRequestQueue::Request* request) {
TRACE_EVENT_ASYNC_BEGIN1(
"identity", "IdentityMintRequestQueue", request, "type", type);
RequestQueue& request_queue = GetRequestQueueMap(type)[key];
request_queue.push_back(request);
// If this is the first request, start it now. RequestComplete will start
// all other requests.
if (request_queue.size() == 1)
request_queue.front()->StartMintToken(type);
RunRequest(type, request_queue);
}

void IdentityMintRequestQueue::RequestComplete(
IdentityMintRequestQueue::MintType type,
const ExtensionTokenKey& key,
IdentityMintRequestQueue::Request* request) {
TRACE_EVENT_ASYNC_END1("identity",
"IdentityMintRequestQueue",
request,
"completed",
"RequestComplete");
RequestQueue& request_queue = GetRequestQueueMap(type)[key];
CHECK_EQ(request_queue.front(), request);
request_queue.pop_front();
if (request_queue.size() > 0)
request_queue.front()->StartMintToken(type);
RunRequest(type, request_queue);
}

void IdentityMintRequestQueue::RequestCancel(
const ExtensionTokenKey& key,
IdentityMintRequestQueue::Request* request) {
TRACE_EVENT_ASYNC_END1("identity",
"IdentityMintRequestQueue",
request,
"completed",
"RequestCancel");
GetRequestQueueMap(MINT_TYPE_INTERACTIVE)[key].remove(request);
GetRequestQueueMap(MINT_TYPE_NONINTERACTIVE)[key].remove(request);
}
Expand All @@ -71,4 +84,12 @@ IdentityMintRequestQueue::GetRequestQueueMap(
: noninteractive_request_queue_map_;
}

void IdentityMintRequestQueue::RunRequest(
IdentityMintRequestQueue::MintType type,
RequestQueue& request_queue) {
TRACE_EVENT_ASYNC_STEP_INTO0(
"identity", "IdentityMintRequestQueue", request_queue.front(), "RUNNING");
request_queue.front()->StartMintToken(type);
}

} // namespace extensions
2 changes: 2 additions & 0 deletions chrome/browser/extensions/api/identity/identity_mint_queue.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,8 @@ class IdentityMintRequestQueue {
typedef std::map<const ExtensionTokenKey, RequestQueue> RequestQueueMap;

RequestQueueMap& GetRequestQueueMap(IdentityMintRequestQueue::MintType type);
void RunRequest(IdentityMintRequestQueue::MintType type,
RequestQueue& request_queue);

RequestQueueMap interactive_request_queue_map_;
RequestQueueMap noninteractive_request_queue_map_;
Expand Down
7 changes: 7 additions & 0 deletions chrome/browser/extensions/api/identity/web_auth_flow.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@

#include "apps/app_window.h"
#include "base/base64.h"
#include "base/debug/trace_event.h"
#include "base/location.h"
#include "base/message_loop/message_loop.h"
#include "base/strings/string_util.h"
Expand Down Expand Up @@ -221,6 +222,12 @@ void WebAuthFlow::DidFailProvisionalLoad(
const GURL& validated_url,
int error_code,
const base::string16& error_description) {
TRACE_EVENT_ASYNC_STEP_PAST1("identity",
"WebAuthFlow",
this,
"DidFailProvisionalLoad",
"error_code",
error_code);
if (delegate_)
delegate_->OnAuthFlowFailure(LOAD_FAILED);
}
Expand Down
Loading

0 comments on commit 5dc43ec

Please sign in to comment.