Add request count and duration telemetry #3022

westin-m · 2024-11-20T21:55:54Z

Addresses client telemetry repair item

Add counter for get configuration requests and histogram for total duration of the same requests.

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs

…zure-activedirectory-identitymodel-extensions-for-dotnet into westin/clientTelemetry

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

build/dependenciesTest.props

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs

build/dependencies.props

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetry.cs

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs

src/Microsoft.IdentityModel.Logging/WatchUtility.cs

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

.../Microsoft.IdentityModel.Protocols.OpenIdConnect.Tests/ConfigurationManagerTelemetryTests.cs

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs

src/Microsoft.IdentityModel.JsonWebTokens/JsonWebTokenHandler.ValidateToken.cs

src/Microsoft.IdentityModel.Logging/ConfigurationManagerTelemetryInstrumentation.cs

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

src/Microsoft.IdentityModel.Logging/TelemetryConstants.cs

brentschmaltz

Asking for laying changes.

src/System.IdentityModel.Tokens.Jwt/JwtSecurityTokenHandler.cs

src/Microsoft.IdentityModel.Logging/TelemetryConstants.cs

src/Microsoft.IdentityModel.Logging/TelemetryInstrumentation.cs

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetry.cs

skblr2022 · 2024-12-13T21:34:32Z

Table identitymodelconfigurationmanager_counter
1> Could the field net_IdentityModelVersion be named as "net_WilsonVersion" to maintain parity with other tables?
2> Any wiki doc explaining the different values of net_OperationStatus? What does Direct / Automatic / FirstRefresh / LastKnownGood indicate?
3> Does this table capture both data for both successful and failed metadata requests? Ex: In the case of validation failure with msg "SignatureKeyNotFound" there would be an eSTS metadata request. So, wondering how to identify failure requests?
4> Why is the net_MetadataAddress add empty or null for some records?

Table identitymodelconfigurationrequesttotaldurationinms_histogram
1> I am inferring from the table name, as it has inms_ instead of inus_, the net_bounds data in this table is recorded in milliseconds. Why is the data not captured in microseconds?
2> Here again, could the field net_IdentityModelVersion be named as "net_WilsonVersion" to maintain parity with other tables?
3> Similar to #3 above are failed metadata requests captured in this table?

westin-m · 2024-12-13T21:39:12Z

2> Any wiki doc explaining the different values of net_OperationStatus? What does Direct / Automatic / FirstRefresh / LastKnownGood indicate?

I can make a doc, good idea

3> Does this table capture both data for both successful and failed metadata requests? Ex: In the case of validation failure with msg "SignatureKeyNotFound" there would be an eSTS metadata request. So, wondering how to identify failure requests?

failed requests will have an exception message attached, they just aren't in the table right now because I was going for success cases to show all the operations. Unit tests prove the existence of this in the taglist right now

4> Why is the net_MetadataAddress add empty or null for some records?

I added metadata address partway through testing. We weren't sure at first if we wanted it. It is null in some of the LKG entries because I used some unit test-like code to contrive the error which precedes that tag being used. Normally, it will look like the LKG entry that has a metadata address

Table identitymodelconfigurationrequesttotaldurationinms_histogram 1> I am inferring from the table name, as it has inms_ instead of inus_, the net_bounds data in this table is recorded in milliseconds. Why is the data not captured in microseconds?

Milliseconds was recommended to me and it matched other, similar code. I can change it if microseconds is preferred.

3> Similar to #3 above are failed metadata requests captured in this table?

same as above, a different taglist is created that contains an exception. right now, unit tests prove that this portion is populated

…zure-activedirectory-identitymodel-extensions-for-dotnet into westin/clientTelemetry

Copilot reviewed 7 out of 22 changed files in this pull request and generated no comments.

Files not reviewed (15)

build/dependencies.props: Language not supported
build/dependenciesTest.props: Language not supported
src/Microsoft.IdentityModel.JsonWebTokens/InternalAPI.Unshipped.txt: Language not supported
src/Microsoft.IdentityModel.Logging/Microsoft.IdentityModel.Logging.csproj: Language not supported
src/Microsoft.IdentityModel.Protocols/InternalAPI.Unshipped.txt: Language not supported
src/Microsoft.IdentityModel.Tokens/InternalAPI.Unshipped.txt: Language not supported
src/System.IdentityModel.Tokens.Jwt/InternalAPI.Unshipped.txt: Language not supported
test/Microsoft.IdentityModel.Logging.Tests/Microsoft.IdentityModel.Logging.Tests.csproj: Language not supported
test/Microsoft.IdentityModel.Protocols.OpenIdConnect.Tests/Microsoft.IdentityModel.Protocols.OpenIdConnect.Tests.csproj: Language not supported
src/Microsoft.IdentityModel.JsonWebTokens/JsonWebTokenHandler.ValidateToken.cs: Evaluated as low risk
src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs: Evaluated as low risk
src/Microsoft.IdentityModel.Protocols/InternalsVisibleTo.cs: Evaluated as low risk
src/Microsoft.IdentityModel.Tokens/Telemetry/ITelemetryInstrumentation.cs: Evaluated as low risk
src/Microsoft.IdentityModel.Tokens/Telemetry/IdentityModelTelemetry.cs: Evaluated as low risk
src/Microsoft.IdentityModel.Tokens/Telemetry/TelemetryConstants.cs: Evaluated as low risk

Comments suppressed due to low confidence (2)

src/System.IdentityModel.Tokens.Jwt/JwtSecurityTokenHandler.cs:893

Ensure that validationParameters.ConfigurationManager.MetadataAddress is not null or empty before logging it.

_telemetryClient.IncrementConfigurationRefreshRequestCounter(

src/Microsoft.IdentityModel.Tokens/Telemetry/TelemetryInstrumentation.cs:48

[nitpick] The method name 'RecordConfigurationRetrievalDurationHistogram' is too long and could be simplified to 'RecordRetrievalDuration' for better readability.

IdentityModelTelemetry.RecordConfigurationRetrievalDurationHistogram(durationInMilliseconds, tagList);

pmaytak · 2024-12-20T22:24:58Z

build/dependencies.props

@@ -8,6 +8,7 @@
    <MicrosoftSourceLinkGitHubVersion>1.0.0</MicrosoftSourceLinkGitHubVersion>
    <NetStandardVersion>2.0.3</NetStandardVersion>
    <NewtonsoftVersion>13.0.3</NewtonsoftVersion>
+    <SystemDiagnosticSourceVersion>8.0.1</SystemDiagnosticSourceVersion>


Is this the minimum version we can use? I remember we had issues with this when we added it to MSAL because Azure Functions didn't have this dependency. (I think it was in .NET 6 Azure Functions, so we downgraded to 6.0.1.)

Yep, we have to lower this.

brentschmaltz · 2024-12-20T23:59:58Z

src/Microsoft.IdentityModel.Tokens/Telemetry/TelemetryInstrumentation.cs

+{
+    internal class TelemetryInstrumentation : ITelemetryInstrumentation
+    {
+


could remove this extra line.

brentschmaltz · 2024-12-21T00:07:23Z

src/System.IdentityModel.Tokens.Jwt/JwtSecurityTokenHandler.cs

@@ -36,6 +37,8 @@ public class JwtSecurityTokenHandler : SecurityTokenHandler
        private static string _shortClaimType = _namespace + "/ShortTypeName";
        private bool _mapInboundClaims = DefaultMapInboundClaims;

+        internal ITelemetryInstrumentation _telemetryClient = new TelemetryInstrumentation();


There is a naming oddity here.
Should ITelemetryInstrumentation be ITelemeteryClient?
Then TelemetryInstrumentation be TelemetryClient?

brentschmaltz · 2024-12-21T00:25:27Z

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

+                                    LogMessages.IDX20810,
+                                    result.ErrorMessage));
+
+                            _telemetryClient.IncrementConfigurationRefreshRequestCounter(


This will be double counted as we report the same error in the catch.

brentschmaltz · 2024-12-21T00:28:10Z

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

@@ -311,6 +352,10 @@ public override void RequestRefresh()
        {
            DateTimeOffset now = DateTimeOffset.UtcNow;

+            _telemetryClient.IncrementConfigurationRefreshRequestCounter(
+                MetadataAddress,
+                TelemetryConstants.Protocols.Direct);


Using the name Protocols.Direct in a method called RequestRefresh is kind of confusing.

brentschmaltz · 2024-12-21T00:28:51Z

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs

                    UpdateConfiguration(configuration);
                }
                catch (Exception ex)
                {
                    fetchMetadataFailure = ex;
+                    _telemetryClient.IncrementConfigurationRefreshRequestCounter(
+                        MetadataAddress,
+                        TelemetryConstants.Protocols.FirstRefresh,


Perhaps this counter should be FirstAutomatic.

brentschmaltz · 2024-12-21T00:31:35Z

src/Microsoft.IdentityModel.Logging/Microsoft.IdentityModel.Logging.csproj

@@ -32,6 +32,10 @@
    </None>
  </ItemGroup>

+  <ItemGroup Condition="'$(TargetFrameworkIdentifier)' == '.NETFramework' or '$(TargetFramework)' == 'netstandard2.0' ">


This reference should be in the assembly where the types are used.
Currently this is M.IM.Tokens, which includes this reference, which allows the project to build.

I think the telemetry stuff should be in M.IM.Logging.

brentschmaltz · 2024-12-21T00:32:35Z

src/Microsoft.IdentityModel.Tokens/Telemetry/IdentityModelTelemetry.cs

+using System.Diagnostics;
+using System.Diagnostics.Metrics;
+
+namespace Microsoft.IdentityModel.Tokens.Telemetry


Curious why this we didn't put this in M.IM.Logging?

brentschmaltz · 2024-12-21T00:38:27Z

src/Microsoft.IdentityModel.Tokens/Telemetry/ITelemetryInstrumentation.cs

+
+namespace Microsoft.IdentityModel.Tokens.Telemetry
+{
+    internal interface ITelemetryInstrumentation


Since this is all internal, not seeing a strong reason for this interface.
How does it help?

brentschmaltz

Some naming.
Code should live in assembly where dependencies are included.
Why do we need an interface?

Add request count and duration telemetry

c5e5d91

westin-m linked an issue Nov 20, 2024 that may be closed by this pull request

Add metadata request time to client telemetry #3023

Open

westin-m commented Nov 20, 2024

View reviewed changes

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs Outdated Show resolved Hide resolved

westin-m added 2 commits November 21, 2024 14:58

Add request count and duration telemetry

c8bdbdf

Merge branch 'westin/clientTelemetry' of https://github.com/AzureAD/a…

f08864b

…zure-activedirectory-identitymodel-extensions-for-dotnet into westin/clientTelemetry

westin-m marked this pull request as ready for review November 21, 2024 23:05

westin-m requested a review from a team as a code owner November 21, 2024 23:05

Merge branch 'dev' into westin/clientTelemetry

2a739a3

westin-m changed the title ~~Add request count and duration telemetry DRAFT~~ Add request count and duration telemetry Nov 21, 2024

westin-m added 2 commits November 21, 2024 15:31

small fix

49790e3

Merge branch 'westin/clientTelemetry' of https://github.com/AzureAD/a…

ebc0740

…zure-activedirectory-identitymodel-extensions-for-dotnet into westin/clientTelemetry

brentschmaltz reviewed Nov 22, 2024

View reviewed changes

src/Microsoft.IdentityModel.Protocols/Configuration/ConfigurationManager.cs Outdated Show resolved Hide resolved