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>9.0.0</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/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
     {
+        private readonly ConfigurationManagerTelemetryInstrumentation _telemetryClient = new();
+
         /// <summary>
         /// Returns a value that indicates if this handler can validate a <see cref="SecurityToken"/>.
         /// </summary>
@@ -511,6 +513,10 @@ await ValidateJWEAsync(jsonWebToken, validationParameters, currentConfiguration)
                     // where a new valid configuration was somehow published during validation time.
                     if (currentConfiguration != null)
                     {
+                        _telemetryClient.IncrementOperationCounter(
+                            IdentityModelTelemetryUtil.ClientVer,
+                            TelemetryConstants.LKG);
+
                         validationParameters.ConfigurationManager.RequestRefresh();
                         validationParameters.RefreshBeforeValidation = true;
                         var lastConfig = currentConfiguration;

src/Microsoft.IdentityModel.Logging/ConfigurationManagerTelemetryInstrumentation.cs

@@ -0,0 +1,54 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System.Diagnostics;
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal class ConfigurationManagerTelemetryInstrumentation : ITelemetryInstrumentation
+    {
+        public void IncrementOperationCounter(string clientVer, string operationStatus)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.OperationStatusTag, operationStatus }
+            };
+
+            IdentityModelTelemetry.IncrementConfigurationManagerCounter(tagList);
+        }
+
+        public void IncrementOperationCounter(string clientVer, string operationStatus, string exceptionType)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.OperationStatusTag, operationStatus },
+                { TelemetryConstants.ExceptionTypeTag, exceptionType }
+            };
+
+            IdentityModelTelemetry.IncrementConfigurationManagerCounter(tagList);
+        }
+
+        public void LogOperationDuration(string clientVer, long durationInMilliseconds)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer }
+            };
+
+            IdentityModelTelemetry.RecordTotalDurationHistogram(durationInMilliseconds, tagList);
+        }
+
+        public void LogOperationDuration(string clientVer, long durationInMilliseconds, string exceptionType)
+        {
+            var tagList = new TagList()
+            {
+                { TelemetryConstants.IdentityModelVersionTag, IdentityModelTelemetryUtil.ClientVer },
+                { TelemetryConstants.ExceptionTypeTag, exceptionType }
+            };
+
+            IdentityModelTelemetry.RecordTotalDurationHistogram(durationInMilliseconds, tagList);
+        }
+    }
+}

src/Microsoft.IdentityModel.Logging/ITelemetryInstrumentation.cs

@@ -0,0 +1,26 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+namespace Microsoft.IdentityModel.Logging
+{
+    internal interface ITelemetryInstrumentation
+    {
+        internal void LogOperationDuration(
+            string clientVer,
+            long durationInMilliseconds);
+
+        internal void LogOperationDuration(
+            string clientVer,
+            long durationInMilliseconds,
+            string exceptionType);
+
+        internal void IncrementOperationCounter(
+            string clientVer,
+            string operationStatus);
+
+        internal void IncrementOperationCounter(
+            string clientVer,
+            string operationStatus,
+            string exceptionType);
+    }
+}

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: "Performance of getting configuration calls total latency");
+
+        internal static void RecordTotalDurationHistogram(long requestDurationInMs, in TagList tagList)
+        {
+            TotalDurationHistogram.Record(requestDurationInMs, tagList);
+        }
+
+        internal static void IncrementConfigurationManagerCounter(in TagList tagList)
+        {
+            ConfigurationManagerCounter.Add(1, tagList);
+        }
+    }
+}

src/Microsoft.IdentityModel.Logging/IdentityModelTelemetryUtil.cs

@@ -135,5 +135,52 @@ internal static bool UpdateDefaultTelemetryData(string key, string value)
             telemetryData[key] = value;
             return true;
         }
+
+        //internal static void IncrementConfigurationManagerCounter(
+        //    string operationStatus)
+        //{
+        //    var tagList = new TagList()
+        //    {
+        //        { TelemetryConstants.IdentityModelVersionTag, ClientVer },
+        //        { TelemetryConstants.OperationStatusTag, operationStatus }
+        //    };
+
+        //    IdentityModelTelemetry.IncrementConfigurationManagerCounter(tagList);
+        //}
+
+        //internal static void IncrementConfigurationManagerCounter(
+        //    string operationStatus,
+        //    string exceptionType)
+        //{
+        //    var tagList = new TagList()
+        //    {
+        //        { TelemetryConstants.IdentityModelVersionTag, ClientVer },
+        //        { TelemetryConstants.OperationStatusTag, operationStatus },
+        //        { TelemetryConstants.ExceptionTypeTag, exceptionType }
+        //    };
+
+        //    IdentityModelTelemetry.IncrementConfigurationManagerCounter(tagList);
+        //}
+
+        //internal static void RecordTotalDuration(long totalMilliseconds)
+        //{
+        //    var tagList = new TagList()
+        //    {
+        //        { TelemetryConstants.IdentityModelVersionTag, ClientVer }
+        //    };
+
+        //    IdentityModelTelemetry.RecordTotalDurationHistogram(totalMilliseconds, tagList);
+        //}
+
+        //internal static void RecordTotalDuration(long totalMilliseconds, string exception)
+        //{
+        //    var tagList = new TagList()
+        //    {
+        //        { TelemetryConstants.IdentityModelVersionTag, ClientVer },
+        //        { TelemetryConstants.ExceptionTypeTag, exception }
+        //    };
+
+        //    IdentityModelTelemetry.RecordTotalDurationHistogram(totalMilliseconds, tagList);
+        //}
     }
 }

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

@@ -0,0 +1,48 @@
+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.IdentityModelTelemetryUtil.Automatic = "Automatic" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.ConfigurationInvalid = "ConfigurationInvalid" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.ConfigurationRetrievalFailed = "ConfigurationRetrievalFailed" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.Direct = "Direct" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.ExceptionTypeTag = "ExceptionType" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.FirstRefresh = "FirstRefresh" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.IdentityModelVersionTag = "IdentityModelVersion" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.LKG = "LastKnownGood" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.MetadataAddressTag = "MetadataAddress" -> string
+const Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.OperationStatusTag = "OperationStatus" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.Automatic = "Automatic" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ConfigurationInvalid = "ConfigurationInvalid" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ConfigurationRetrievalFailed = "ConfigurationRetrievalFailed" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.Direct = "Direct" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.ExceptionTypeTag = "ExceptionType" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.FirstRefresh = "FirstRefresh" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.IdentityModelVersionTag = "IdentityModelVersion" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.LKG = "LastKnownGood" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.MetadataAddressTag = "MetadataAddress" -> string
+const Microsoft.IdentityModel.Logging.TelemetryConstants.OperationStatusTag = "OperationStatus" -> string
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation.ConfigurationManagerTelemetryInstrumentation() -> void
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation.IncrementOperationCounter(string clientVer, string operationStatus) -> void
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation.IncrementOperationCounter(string clientVer, string operationStatus, string exceptionType) -> void
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation.LogOperationDuration(string clientVer, long durationInMilliseconds) -> void
+Microsoft.IdentityModel.Logging.ConfigurationManagerTelemetryInstrumentation.LogOperationDuration(string clientVer, long durationInMilliseconds, string exceptionType) -> void
+Microsoft.IdentityModel.Logging.IdentityModelTelemetry
+Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IdentityModelTelemetry() -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.IncrementOperationCounter(string clientVer, string operationStatus) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.IncrementOperationCounter(string clientVer, string operationStatus, string exceptionType) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.LogOperationDuration(string clientVer, long durationInMilliseconds) -> void
+Microsoft.IdentityModel.Logging.ITelemetryInstrumentation.LogOperationDuration(string clientVer, long durationInMilliseconds, string exceptionType) -> void
+Microsoft.IdentityModel.Logging.TelemetryConstants
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetry.IncrementConfigurationManagerCounter(in System.Diagnostics.TagList tagList) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetry.RecordTotalDurationHistogram(long requestDurationInMs, in System.Diagnostics.TagList tagList) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.IncrementConfigurationManagerCounter(string operationStatus) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.IncrementConfigurationManagerCounter(string operationStatus, string exceptionType) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.RecordTotalDuration(long totalMilliseconds) -> void
+static Microsoft.IdentityModel.Logging.IdentityModelTelemetryUtil.RecordTotalDuration(long totalMilliseconds, string exception) -> 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,11 @@
 // 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.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")]

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 = "Automatic";
+        public const string Direct = "Direct";
+        public const string FirstRefresh = "FirstRefresh";
+        public const string LKG = "LastKnownGood";
+
+        // Configuration manager exception types
+        public const string ConfigurationInvalid = "ConfigurationInvalid";
+        public const string ConfigurationRetrievalFailed = "ConfigurationRetrievalFailed";
+    }
+}