Add request count and duration telemetry

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>
     <SystemMemoryVersion>4.5.5</SystemMemoryVersion>
     <SystemSecurityCryptographyCngVersion>4.5.0</SystemSecurityCryptographyCngVersion>
     <SystemTextJson>8.0.5</SystemTextJson>

build/dependenciesTest.props

@@ -7,6 +7,7 @@
     <MicrosoftNETTestSdkVersion>17.11.1</MicrosoftNETTestSdkVersion>
     <NetStandardVersion>2.0.3</NetStandardVersion>
     <NewtonsoftVersion>13.0.3</NewtonsoftVersion>
+    <OpenTelemetryVersion>1.6.0</OpenTelemetryVersion>
     <SystemNetHttp>4.3.4</SystemNetHttp>
     <SystemSecurityClaimsVersion>4.3.0</SystemSecurityClaimsVersion>
     <SystemTextJson>8.0.5</SystemTextJson>

src/Microsoft.IdentityModel.JsonWebTokens/InternalAPI.Unshipped.txt

@@ -1,3 +1,4 @@
+Microsoft.IdentityModel.JsonWebTokens.JsonWebTokenHandler._telemetryClient -> Microsoft.IdentityModel.Logging.ITelemetryInstrumentation
 static Microsoft.IdentityModel.JsonWebTokens.JsonWebTokenHandler.CreateToken(string payload, Microsoft.IdentityModel.Tokens.SecurityTokenDescriptor tokenDescriptor) -> string
 static Microsoft.IdentityModel.JsonWebTokens.JsonWebTokenHandler.EncryptToken(byte[] innerTokenUtf8Bytes, Microsoft.IdentityModel.Tokens.EncryptingCredentials encryptingCredentials, string compressionAlgorithm, System.Collections.Generic.IDictionary<string, object> additionalHeaderClaims, string tokenType, bool includeKeyIdInHeader) -> string
 static Microsoft.IdentityModel.JsonWebTokens.JsonWebTokenHandler.EncryptToken(byte[] innerTokenUtf8Bytes, Microsoft.IdentityModel.Tokens.SecurityTokenDescriptor tokenDescriptor) -> string

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

@@ -17,6 +17,8 @@ namespace Microsoft.IdentityModel.JsonWebTokens
     /// <remarks>This partial class contains methods and logic related to the validation of tokens.</remarks>
     public partial class JsonWebTokenHandler : TokenHandler
     {
+        internal ITelemetryInstrumentation _telemetryClient = new TelemetryInstrumentation();
+
         /// <summary>
         /// Returns a value that indicates if this handler can validate a <see cref="SecurityToken"/>.
         /// </summary>
@@ -511,6 +513,9 @@ await ValidateJWEAsync(jsonWebToken, validationParameters, currentConfiguration)
                     // where a new valid configuration was somehow published during validation time.
                     if (currentConfiguration != null)
                     {
+                        _telemetryClient.IncrementOperationCounter(
+                            TelemetryConstants.LKG);
+
                         validationParameters.ConfigurationManager.RequestRefresh();
                         validationParameters.RefreshBeforeValidation = true;
                         var lastConfig = currentConfiguration;

src/Microsoft.IdentityModel.Logging/ITelemetryInstrumentation.cs

@@ -0,0 +1,24 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal interface ITelemetryInstrumentation
+    {
+        internal void LogOperationDuration(
+            TimeSpan operationDuration);
+
+        internal void LogOperationDuration(
+            TimeSpan operationDuration,
+            Exception exception);
+
+        internal void IncrementOperationCounter(
+            string operationStatus);
+
+        internal void IncrementOperationCounter(
+            string operationStatus,
+            Exception exception);
+    }
+}

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetry.cs

@@ -0,0 +1,49 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System.Diagnostics;
+using System.Diagnostics.Metrics;
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal class IdentityModelTelemetry
+    {
+        /// <summary>
+        /// Meter name for MicrosoftIdentityModel.
+        /// </summary>
+        public const string MeterName = "MicrosoftIdentityModel_Meter";
+        public const string ServiceName = "MicrosoftIdentityModel";
+
+        /// <summary>
+        /// The meter responsible for creating instruments.
+        /// </summary>
+        public static readonly Meter IdentityModelMeter = new(MeterName, "1.0.0");
+
+        internal const string TotalDurationHistogramName = "IdentityModelConfigurationRequestTotalDurationInMS";
+
+        /// <summary>
+        /// Counter to capture requests to configuration manager.
+        /// </summary>
+        internal const string IdentityModelConfigurationManagerCounterName = "IdentityModelConfigurationManagerCounter";
+        internal const string IdentityModelConfigurationManagerCounterDescription = "Counter capturing configuration manager operations.";
+        internal static readonly Counter<long> ConfigurationManagerCounter = IdentityModelMeter.CreateCounter<long>(IdentityModelConfigurationManagerCounterName, description: IdentityModelConfigurationManagerCounterDescription);
+
+        /// <summary>
+        /// Histogram to capture total duration of configuration manager operations in milliseconds.
+        /// </summary>
+        internal static readonly Histogram<long> TotalDurationHistogram = IdentityModelMeter.CreateHistogram<long>(
+            TotalDurationHistogramName,
+            unit: "ms",
+            description: "Configuration retrieval latency during configuration manager operations.");
+
+        internal static void RecordTotalDurationHistogram(long requestDurationInMs, in TagList tagList)
+        {
+            TotalDurationHistogram.Record(requestDurationInMs, tagList);
+        }
+
+        internal static void IncrementOperationCounter(in TagList tagList)
+        {
+            ConfigurationManagerCounter.Add(1, tagList);
+        }
+    }
+}

src/Microsoft.IdentityModel.Logging/InternalAPI.Unshipped.txt

@@ -0,0 +1,34 @@
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IdentityModelConfigurationManagerCounterDescription = "Counter capturing configuration manager operations." -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IdentityModelConfigurationManagerCounterName = "IdentityModelConfigurationManagerCounter" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetry.MeterName = "MicrosoftIdentityModel_Meter" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetry.ServiceName = "MicrosoftIdentityModel" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetry.TotalDurationHistogramName = "IdentityModelConfigurationRequestTotalDurationInMS" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.Automatic = "Microsoft.IdentityModel.Protocols.Automatic" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ConfigurationInvalid = "Microsoft.IdentityModel.Protocols.ConfigurationInvalid" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ConfigurationRetrievalFailed = "Microsoft.IdentityModel.Protocols.ConfigurationRetrievalFailed" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.Direct = "Microsoft.IdentityModel.Protocols.Direct" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ExceptionTypeTag = "ExceptionType" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.FirstRefresh = "Microsoft.IdentityModel.Protocols.FirstRefresh" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.IdentityModelVersionTag = "IdentityModelVersion" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.LKG = "Microsoft.IdentityModel.Protocols.LastKnownGood" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.MetadataAddressTag = "MetadataAddress" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.OperationStatusTag = "OperationStatus" -> string
+Microsoft.IdentityModel.Logging.IdentityModelTelemetry
+Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IdentityModelTelemetry() -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.IncrementOperationCounter(string operationStatus) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.IncrementOperationCounter(string operationStatus, System.Exception exception) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.LogOperationDuration(System.TimeSpan operationDuration) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.LogOperationDuration(System.TimeSpan operationDuration, System.Exception exception) -> void
+Microsoft.IdentityModel.Logging.TelemetryConstants
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation.IncrementOperationCounter(string operationStatus) -> void
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation.IncrementOperationCounter(string operationStatus, System.Exception exception) -> void
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation.LogOperationDuration(System.TimeSpan operationDuration) -> void
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation.LogOperationDuration(System.TimeSpan operationDuration, System.Exception exception) -> void
+Microsoft.IdentityModel.Logging.TelemetryInstrumentation.TelemetryInstrumentation() -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IncrementOperationCounter(in System.Diagnostics.TagList tagList) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetry.RecordTotalDurationHistogram(long requestDurationInMs, in System.Diagnostics.TagList tagList) -> void
+static readonly Microsoft.IdentityModel.Logging.IdentityModelTelemetry.ConfigurationManagerCounter -> System.Diagnostics.Metrics.Counter<long>
+static readonly Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IdentityModelMeter -> System.Diagnostics.Metrics.Meter
+static readonly Microsoft.IdentityModel.Logging.IdentityModelTelemetry.TotalDurationHistogram -> System.Diagnostics.Metrics.Histogram<long>

src/Microsoft.IdentityModel.Logging/InternalsVisibleTo.cs

@@ -1,8 +1,13 @@
 // Copyright (c) Microsoft Corporation. All rights reserved.
 // Licensed under the MIT License.
 
+[assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.JsonWebTokens, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
+[assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.JsonWebTokens.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
 [assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.S2S, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
 [assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.S2S.Tokens, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
 [assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.S2S.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
 [assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.S2S.Tokens.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
 [assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
+[assembly: System.Runtime.CompilerServices.InternalsVisibleTo("Microsoft.IdentityModel.Protocols.OpenIdConnect.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
+[assembly: System.Runtime.CompilerServices.InternalsVisibleTo("System.IdentityModel.Tokens.Jwt, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]
+[assembly: System.Runtime.CompilerServices.InternalsVisibleTo("System.IdentityModel.Tokens.Jwt.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100b5fc90e7027f67871e773a8fde8938c81dd402ba65b9201d60593e96c492651e889cc13f1415ebb53fac1131ae0bd333c5ee6021672d9718ea31a8aebd0da0072f25d87dba6fc90ffd598ed4da35e44c398c454307e8e33b8426143daec9f596836f97c8f74750e5975c64e2189f45def46b2a2b1247adc3652bf5c308055da9")]

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

@@ -32,6 +32,10 @@
     </None>
   </ItemGroup>
 
+  <ItemGroup Condition="'$(TargetFrameworkIdentifier)' == '.NETFramework' or '$(TargetFramework)' == 'netstandard2.0' ">
+    <PackageReference Include="System.Diagnostics.DiagnosticSource" Version="$(SystemDiagnosticSourceVersion)" />
+  </ItemGroup>
+
   <ItemGroup>
     <ProjectReference Include="..\Microsoft.IdentityModel.Abstractions\Microsoft.IdentityModel.Abstractions.csproj" />
   </ItemGroup>

src/Microsoft.IdentityModel.Logging/TelemetryConstants.cs

@@ -0,0 +1,24 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal static class TelemetryConstants
+    {
+        // Static attribute tags
+        public const string IdentityModelVersionTag = "IdentityModelVersion";
+        public const string MetadataAddressTag = "MetadataAddress";
+        public const string OperationStatusTag = "OperationStatus";
+        public const string ExceptionTypeTag = "ExceptionType";
+
+        // Configuration manager refresh statuses
+        public const string Automatic = "Microsoft.IdentityModel.Protocols.Automatic";
+        public const string Direct = "Microsoft.IdentityModel.Protocols.Direct";
+        public const string FirstRefresh = "Microsoft.IdentityModel.Protocols.FirstRefresh";
+        public const string LKG = "Microsoft.IdentityModel.Protocols.LastKnownGood";
+
+        // Configuration manager exception types
+        public const string ConfigurationInvalid = "Microsoft.IdentityModel.Protocols.ConfigurationInvalid";
+        public const string ConfigurationRetrievalFailed = "Microsoft.IdentityModel.Protocols.ConfigurationRetrievalFailed";
+    }
+}

src/Microsoft.IdentityModel.Logging/TelemetryInstrumentation.cs

@@ -0,0 +1,57 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Diagnostics;
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal class TelemetryInstrumentation : ITelemetryInstrumentation
+    {
+        static TagList ClientVerTagList = new TagList()
+        {
+            { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer }
+        };
+
+        public void IncrementOperationCounter(string operationStatus)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.OperationStatusTag, operationStatus }
+            };
+
+            IdentityModelTelemetry.IncrementOperationCounter(tagList);
+        }
+
+        public void IncrementOperationCounter(string operationStatus, Exception exception)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.OperationStatusTag, operationStatus },
+                { TelemetryConstants.ExceptionTypeTag, exception.GetType().ToString() }
+            };
+
+            IdentityModelTelemetry.IncrementOperationCounter(tagList);
+        }
+
+        public void LogOperationDuration(TimeSpan operationDuration)
+        {
+            long durationInMilliseconds = (long)operationDuration.TotalMilliseconds;
+            IdentityModelTelemetry.RecordTotalDurationHistogram(durationInMilliseconds, ClientVerTagList);
+        }
+
+        public void LogOperationDuration(TimeSpan operationDuration, Exception exception)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.ExceptionTypeTag, exception.GetType().ToString() }
+            };
+
+            long durationInMilliseconds = (long)operationDuration.TotalMilliseconds;
+            IdentityModelTelemetry.RecordTotalDurationHistogram(durationInMilliseconds, tagList);
+        }
+    }
+}