Skip to content

[Proposal] Add token acquisition metrics that cover both successful and failed t… #5928

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
ssmelov wants to merge 4 commits into from
Closed

[Proposal] Add token acquisition metrics that cover both successful and failed t… #5928

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
e6073dc
Add token acquisition metrics that cover both successful and failed t…
ssmelov Apr 15, 2026
43a844c
Add tests
ssmelov Apr 15, 2026
e85108e
Update
ssmelov Apr 16, 2026
f7251e0
Update
ssmelov May 13, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 15 additions & 7 deletions src/client/Microsoft.Identity.Client/Http/HttpManager.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -254,15 +254,23 @@ private async Task<HttpResponse> ExecuteAsync(

HttpClient client = GetHttpClient(bindingCertificate, validateServerCert);

using (HttpResponseMessage responseMessage =
await client.SendAsync(requestMessage, cancellationToken).ConfigureAwait(false))
try
{
LastRequestDurationInMs = sw.ElapsedMilliseconds;
logger.Verbose(() => $"[HttpManager] Received response. Status code: {responseMessage.StatusCode}. ");
using (HttpResponseMessage responseMessage =
await client.SendAsync(requestMessage, cancellationToken).ConfigureAwait(false))
{
LastRequestDurationInMs = sw.ElapsedMilliseconds;
logger.Verbose(() => $"[HttpManager] Received response. Status code: {responseMessage.StatusCode}. ");

HttpResponse returnValue = await CreateResponseAsync(responseMessage).ConfigureAwait(false);
returnValue.UserAgent = requestMessage.Headers.UserAgent.ToString();
return returnValue;
HttpResponse returnValue = await CreateResponseAsync(responseMessage).ConfigureAwait(false);
returnValue.UserAgent = requestMessage.Headers.UserAgent.ToString();
return returnValue;
}
}
catch
{
LastRequestDurationInMs = sw.ElapsedMilliseconds;

@neha-bhargava neha-bhargava May 6, 2026 •
edited
Loading

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

finally block might be a good place to place the duration here that will cover all the cases. Here and in the RequestBase.cs as well

@ssmelov ssmelov May 13, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd keep it scoped to the network‑bound portion — putting it in finally would also include response body read.

throw;
}
}
}
Expand Down
38 changes: 18 additions & 20 deletions src/client/Microsoft.Identity.Client/Internal/Requests/RequestBase.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,7 @@ public async Task<AuthenticationResult> RunAsync(CancellationToken cancellationT
AuthenticationRequestParameters.RequestContext.ApiEvent = apiEvent;
});

var requestStopwatch = Stopwatch.StartNew();
try
{
AuthenticationResult authenticationResult = null;
Expand Down Expand Up @@ -106,44 +107,41 @@ public async Task<AuthenticationResult> RunAsync(CancellationToken cancellationT
}
AuthenticationRequestParameters.RequestContext.Logger.ErrorPii(ex);

LogFailureTelemetryToOtel(ex.ErrorCode, apiEvent, apiEvent.CacheInfo);
int httpStatusCode = ex is MsalServiceException serviceEx ? serviceEx.StatusCode : 0;
LogFailureTelemetryToOtel(apiEvent, apiEvent.ApiErrorCode, httpStatusCode, requestStopwatch.ElapsedMilliseconds + measureTelemetryDurationResult.Milliseconds);
Comment on lines +110 to +111

Copilot AI Apr 15, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

measureTelemetryDurationResult.Milliseconds is the millisecond component (0–999) of the TimeSpan, not the full duration. This will under-report total duration for telemetry whenever measureTelemetryDurationResult is >= 1 second. Use measureTelemetryDurationResult.TotalMilliseconds (cast/rounded to long as needed) instead of .Milliseconds when computing totalDurationInMs.

Copilot uses AI. Check for mistakes.
throw;
}
catch (Exception ex)
{
apiEvent.ApiErrorCode = ex.GetType().Name;
AuthenticationRequestParameters.RequestContext.Logger.ErrorPii(ex);

LogFailureTelemetryToOtel(ex.GetType().Name, apiEvent, apiEvent.CacheInfo);
LogFailureTelemetryToOtel(apiEvent, apiEvent.ApiErrorCode, httpStatusCode: 0, requestStopwatch.ElapsedMilliseconds + measureTelemetryDurationResult.Milliseconds);
throw;
}
}

private void LogSuccessTelemetryToOtel(AuthenticationResult authenticationResult, ApiEvent apiEvent, long durationInUs)
{
// Log metrics
ServiceBundle.PlatformProxy.OtelInstrumentation.LogSuccessMetrics(
ServiceBundle.PlatformProxy.GetProductName(),
apiEvent.ApiId,
apiEvent.CallerSdkApiId,
apiEvent.CallerSdkVersion,
GetCacheLevel(authenticationResult),
durationInUs,
authenticationResult.AuthenticationResultMetadata,
AuthenticationRequestParameters.RequestContext.Logger);
ServiceBundle.PlatformProxy.GetProductName(),
apiEvent.ApiId,
apiEvent.CallerSdkApiId,
apiEvent.CallerSdkVersion,
GetCacheLevel(authenticationResult),
durationInUs,
authenticationResult.AuthenticationResultMetadata,
AuthenticationRequestParameters.RequestContext.Logger);
}

private void LogFailureTelemetryToOtel(string errorCodeToLog, ApiEvent apiEvent, CacheRefreshReason cacheRefreshReason)
private void LogFailureTelemetryToOtel(ApiEvent apiEvent, string errorCode, int httpStatusCode, long totalDurationInMs)
{
// Log metrics
ServiceBundle.PlatformProxy.OtelInstrumentation.LogFailureMetrics(
ServiceBundle.PlatformProxy.GetProductName(),
errorCodeToLog,
apiEvent.ApiId,
apiEvent.CallerSdkApiId,
apiEvent.CallerSdkVersion,
cacheRefreshReason,
apiEvent.TokenType);
ServiceBundle.PlatformProxy.GetProductName(),
apiEvent,
errorCode,
httpStatusCode,
totalDurationInMs);
}

private Tuple<string, string> ParseScopesForTelemetry()
Expand Down
1 change: 1 addition & 0 deletions src/client/Microsoft.Identity.Client/Internal/Requests/Silent/SilentRequest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,7 @@ protected override async Task<AuthenticationResult> ExecuteAsync(CancellationTok
if (isBrokerConfigured && !isAccountSourceDeviceCodeFlow)
{
_logger.Info("Broker is configured and enabled, attempting to use broker instead.");
AuthenticationRequestParameters.RequestContext.ApiEvent.TokenSource = TokenSource.Broker;
var brokerResult = await _brokerStrategyLazy.Value.ExecuteAsync(cancellationToken).ConfigureAwait(false);

// fallback to local cache if broker fails
Comment on lines 68 to 74

Copilot AI Apr 16, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ApiEvent.TokenSource is set to Broker before attempting the broker flow, but it is never reset when the broker returns null and the code falls back to the local cache. This can mis-tag failure telemetry (and any other ApiEvent-based telemetry) as coming from the broker even when the cache path was used. Set TokenSource back to Cache before _clientStrategy.ExecuteAsync(...) or right before the "Attempting to acquire token using local cache" path.

Copilot uses AI. Check for mistakes.
Expand Down
32 changes: 15 additions & 17 deletions src/client/Microsoft.Identity.Client/Internal/Requests/SilentRequestHelper.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -99,11 +99,15 @@ internal static void ProcessFetchInBackground(
apiEvent.ApiId,
callerSdkId,
callerSdkVersion,
TokenSource.IdentityProvider,
CacheRefreshReason.ProactivelyRefreshed,
TokenSource.IdentityProvider,
CacheRefreshReason.ProactivelyRefreshed,
Cache.CacheLevel.None,
logger,
apiEvent.TokenType);
serviceBundle.PlatformProxy.OtelInstrumentation.LogSuccessHttpDuration(
serviceBundle.PlatformProxy.GetProductName(),
apiEvent.ApiId,
authResult.AuthenticationResultMetadata);
Comment on lines +107 to +110
}
catch (MsalServiceException ex)
{
Expand All @@ -119,36 +123,30 @@ internal static void ProcessFetchInBackground(

serviceBundle.PlatformProxy.OtelInstrumentation.LogFailureMetrics(
serviceBundle.PlatformProxy.GetProductName(),
apiEvent,
ex.ErrorCode,
apiEvent.ApiId,
callerSdkId,
callerSdkVersion,
CacheRefreshReason.ProactivelyRefreshed,
apiEvent.TokenType);
ex.StatusCode,
totalDurationInMs: 0);
}
catch (OperationCanceledException ex)
{
logger.WarningPiiWithPrefix(ex, ProactiveRefreshCancellationError);
serviceBundle.PlatformProxy.OtelInstrumentation.LogFailureMetrics(
serviceBundle.PlatformProxy.GetProductName(),
apiEvent,
ex.GetType().Name,
apiEvent.ApiId,
callerSdkId,
callerSdkVersion,
CacheRefreshReason.ProactivelyRefreshed,
apiEvent.TokenType);
httpStatusCode: 0,
totalDurationInMs: 0);
}
catch (Exception ex)
{
logger.ErrorPiiWithPrefix(ex, ProactiveRefreshGeneralError);
serviceBundle.PlatformProxy.OtelInstrumentation.LogFailureMetrics(
serviceBundle.PlatformProxy.GetProductName(),
apiEvent,
ex.GetType().Name,
apiEvent.ApiId,
callerSdkId,
callerSdkVersion,
CacheRefreshReason.ProactivelyRefreshed,
apiEvent.TokenType);
httpStatusCode: 0,
totalDurationInMs: 0);
}
});
}
Expand Down
5 changes: 5 additions & 0 deletions src/client/Microsoft.Identity.Client/OAuth2/OAuth2Client.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -170,6 +170,11 @@ internal async Task<T> ExecuteRequestAsync<T>(
}
catch (Exception ex)
{
if (requestContext.ApiEvent != null)
{
requestContext.ApiEvent.DurationInHttpInMs += _httpManager.LastRequestDurationInMs;
Comment on lines +173 to +175
}

if (ex is TaskCanceledException && requestContext.UserCancellationToken.IsCancellationRequested)
{
throw;
Expand Down
Loading