Add ServiceClientTracingLogger to log Azure Search requests and respo…

…nses (#654) Related to NuGet/Engineering#2664
NuGet · Sep 13, 2019 · fc445c5 · fc445c5
1 parent 952deb3
commit fc445c5
Show file tree

Hide file tree

Showing 13 changed files with 134 additions and 84 deletions.
diff --git a/src/NuGet.Jobs.Auxiliary2AzureSearch/Job.cs b/src/NuGet.Jobs.Auxiliary2AzureSearch/Job.cs
@@ -1,9 +1,6 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
-using System.Net;
-using System.Threading.Tasks;
-using Autofac;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Options;
@@ -13,28 +10,13 @@
 
 namespace NuGet.Jobs
 {
-    public class Job : JsonConfigurationJob
+    public class Job : AzureSearchJob<Auxiliary2AzureSearchCommand>
     {
         private const string ConfigurationSectionName = "Auxiliary2AzureSearch";
 
-        public override async Task Run()
-        {
-            ServicePointManager.DefaultConnectionLimit = 64;
-            ServicePointManager.MaxServicePointIdleTime = 10000;
-
-            await _serviceProvider
-                .GetRequiredService<Auxiliary2AzureSearchCommand>()
-                .ExecuteAsync();
-        }
-
-        protected override void ConfigureAutofacServices(ContainerBuilder containerBuilder)
-        {
-            containerBuilder.AddAzureSearch();
-        }
-
         protected override void ConfigureJobServices(IServiceCollection services, IConfigurationRoot configurationRoot)
         {
-            services.AddAzureSearch();
+            base.ConfigureJobServices(services, configurationRoot);
 
             services.Configure<Auxiliary2AzureSearchConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));
             services.AddTransient<IOptionsSnapshot<IAuxiliaryDataStorageConfiguration>>(

diff --git a/src/NuGet.Jobs.Catalog2AzureSearch/Job.cs b/src/NuGet.Jobs.Catalog2AzureSearch/Job.cs
@@ -1,38 +1,20 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
-using System.Net;
-using System.Threading.Tasks;
-using Autofac;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
 using NuGet.Services.AzureSearch;
 using NuGet.Services.AzureSearch.Catalog2AzureSearch;
 
 namespace NuGet.Jobs
 {
-    public class Job : JsonConfigurationJob
+    public class Job : AzureSearchJob<Catalog2AzureSearchCommand>
     {
         private const string ConfigurationSectionName = "Catalog2AzureSearch";
 
-        public override async Task Run()
-        {
-            ServicePointManager.DefaultConnectionLimit = 64;
-            ServicePointManager.MaxServicePointIdleTime = 10000;
-
-            await _serviceProvider
-                .GetRequiredService<Catalog2AzureSearchCommand>()
-                .ExecuteAsync();
-        }
-
-        protected override void ConfigureAutofacServices(ContainerBuilder containerBuilder)
-        {
-            containerBuilder.AddAzureSearch();
-        }
-
         protected override void ConfigureJobServices(IServiceCollection services, IConfigurationRoot configurationRoot)
         {
-            services.AddAzureSearch();
+            base.ConfigureJobServices(services, configurationRoot);
 
             services.Configure<Catalog2AzureSearchConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));
             services.Configure<AzureSearchJobConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));

diff --git a/src/NuGet.Jobs.Db2AzureSearch/Job.cs b/src/NuGet.Jobs.Db2AzureSearch/Job.cs
@@ -1,9 +1,6 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
-using System.Net;
-using System.Threading.Tasks;
-using Autofac;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Options;
@@ -13,28 +10,13 @@
 
 namespace NuGet.Jobs
 {
-    public class Job : JsonConfigurationJob
+    public class Job : AzureSearchJob<Db2AzureSearchCommand>
     {
         private const string ConfigurationSectionName = "Db2AzureSearch";
 
-        public override async Task Run()
-        {
-            ServicePointManager.DefaultConnectionLimit = 64;
-            ServicePointManager.MaxServicePointIdleTime = 10000;
-
-            await _serviceProvider
-                .GetRequiredService<Db2AzureSearchCommand>()
-                .ExecuteAsync();
-        }
-
-        protected override void ConfigureAutofacServices(ContainerBuilder containerBuilder)
-        {
-            containerBuilder.AddAzureSearch();
-        }
-
         protected override void ConfigureJobServices(IServiceCollection services, IConfigurationRoot configurationRoot)
         {
-            services.AddAzureSearch();
+            base.ConfigureJobServices(services, configurationRoot);
 
             services.Configure<Db2AzureSearchConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));
             services.AddTransient<IOptionsSnapshot<IAuxiliaryDataStorageConfiguration>>(

diff --git a/src/NuGet.Jobs.Owners2AzureSearch/Job.cs b/src/NuGet.Jobs.Owners2AzureSearch/Job.cs
@@ -1,38 +1,20 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
-using System.Net;
-using System.Threading.Tasks;
-using Autofac;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
 using NuGet.Services.AzureSearch;
 using NuGet.Services.AzureSearch.Owners2AzureSearch;
 
 namespace NuGet.Jobs
 {
-    public class Job : JsonConfigurationJob
+    public class Job : AzureSearchJob<Owners2AzureSearchCommand>
     {
         private const string ConfigurationSectionName = "Owners2AzureSearch";
 
-        public override async Task Run()
-        {
-            ServicePointManager.DefaultConnectionLimit = 64;
-            ServicePointManager.MaxServicePointIdleTime = 10000;
-
-            await _serviceProvider
-                .GetRequiredService<Owners2AzureSearchCommand>()
-                .ExecuteAsync();
-        }
-
-        protected override void ConfigureAutofacServices(ContainerBuilder containerBuilder)
-        {
-            containerBuilder.AddAzureSearch();
-        }
-
         protected override void ConfigureJobServices(IServiceCollection services, IConfigurationRoot configurationRoot)
         {
-            services.AddAzureSearch();
+            base.ConfigureJobServices(services, configurationRoot);
 
             services.Configure<AzureSearchJobConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));
             services.Configure<AzureSearchConfiguration>(configurationRoot.GetSection(ConfigurationSectionName));

diff --git a/src/NuGet.Services.AzureSearch/Auxiliary2AzureSearch/Auxiliary2AzureSearchCommand.cs b/src/NuGet.Services.AzureSearch/Auxiliary2AzureSearch/Auxiliary2AzureSearchCommand.cs
@@ -18,7 +18,7 @@
 
 namespace NuGet.Services.AzureSearch.Auxiliary2AzureSearch
 {
-    public class Auxiliary2AzureSearchCommand
+    public class Auxiliary2AzureSearchCommand : IAzureSearchCommand
     {
         /// <summary>
         /// A package ID can result in one document per search filter if the there is a version that applies to each

diff --git a/src/NuGet.Services.AzureSearch/AzureSearchJob.cs b/src/NuGet.Services.AzureSearch/AzureSearchJob.cs
@@ -0,0 +1,45 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System.Net;
+using System.Threading.Tasks;
+using Autofac;
+using Microsoft.Extensions.Configuration;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Rest;
+using NuGet.Jobs;
+
+namespace NuGet.Services.AzureSearch
+{
+    public abstract class AzureSearchJob<T> : JsonConfigurationJob where T : IAzureSearchCommand
+    {
+        public override async Task Run()
+        {
+            ServicePointManager.DefaultConnectionLimit = 64;
+            ServicePointManager.MaxServicePointIdleTime = 10000;
+
+            var tracingInterceptor = _serviceProvider.GetRequiredService<IServiceClientTracingInterceptor>();
+            try
+            {
+                ServiceClientTracing.IsEnabled = true;
+                ServiceClientTracing.AddTracingInterceptor(tracingInterceptor);
+
+                await _serviceProvider.GetRequiredService<T>().ExecuteAsync();
+            }
+            finally
+            {
+                ServiceClientTracing.RemoveTracingInterceptor(tracingInterceptor);
+            }
+        }
+
+        protected override void ConfigureAutofacServices(ContainerBuilder containerBuilder)
+        {
+            containerBuilder.AddAzureSearch();
+        }
+
+        protected override void ConfigureJobServices(IServiceCollection services, IConfigurationRoot configurationRoot)
+        {
+            services.AddAzureSearch();
+        }
+    }
+}
diff --git a/src/NuGet.Services.AzureSearch/Catalog2AzureSearch/Catalog2AzureSearchCommand.cs b/src/NuGet.Services.AzureSearch/Catalog2AzureSearch/Catalog2AzureSearchCommand.cs
@@ -14,7 +14,7 @@
 
 namespace NuGet.Services.AzureSearch.Catalog2AzureSearch
 {
-    public class Catalog2AzureSearchCommand
+    public class Catalog2AzureSearchCommand : IAzureSearchCommand
     {
         public const string CursorRelativeUri = "cursor.json";
 

diff --git a/src/NuGet.Services.AzureSearch/Db2AzureSearch/Db2AzureSearchCommand.cs b/src/NuGet.Services.AzureSearch/Db2AzureSearch/Db2AzureSearchCommand.cs
@@ -18,7 +18,7 @@
 
 namespace NuGet.Services.AzureSearch.Db2AzureSearch
 {
-    public class Db2AzureSearchCommand
+    public class Db2AzureSearchCommand : IAzureSearchCommand
     {
         private readonly INewPackageRegistrationProducer _producer;
         private readonly IPackageEntityIndexActionBuilder _indexActionBuilder;

diff --git a/src/NuGet.Services.AzureSearch/DependencyInjectionExtensions.cs b/src/NuGet.Services.AzureSearch/DependencyInjectionExtensions.cs
@@ -9,6 +9,7 @@
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
+using Microsoft.Rest;
 using Microsoft.WindowsAzure.Storage;
 using Microsoft.WindowsAzure.Storage.Blob;
 using Microsoft.WindowsAzure.Storage.RetryPolicies;
@@ -287,6 +288,7 @@ public static IServiceCollection AddAzureSearch(this IServiceCollection services
             services.AddTransient<ISearchResponseBuilder, SearchResponseBuilder>();
             services.AddTransient<ISearchServiceClientWrapper, SearchServiceClientWrapper>();
             services.AddTransient<ISearchTextBuilder, SearchTextBuilder>();
+            services.AddTransient<IServiceClientTracingInterceptor, ServiceClientTracingLogger>();
             services.AddTransient<ISimpleHttpClient, SimpleHttpClient>();
             services.AddTransient<ISystemTime, SystemTime>();
             services.AddTransient<ITelemetryService, TelemetryService>();

diff --git a/src/NuGet.Services.AzureSearch/IAzureSearchCommand.cs b/src/NuGet.Services.AzureSearch/IAzureSearchCommand.cs
@@ -0,0 +1,12 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System.Threading.Tasks;
+
+namespace NuGet.Services.AzureSearch
+{
+    public interface IAzureSearchCommand
+    {
+        Task ExecuteAsync();
+    }
+}
diff --git a/src/NuGet.Services.AzureSearch/NuGet.Services.AzureSearch.csproj b/src/NuGet.Services.AzureSearch/NuGet.Services.AzureSearch.csproj
@@ -61,12 +61,14 @@
     <Compile Include="AuxiliaryFiles\IVerifiedPackagesDataClient.cs" />
     <Compile Include="AuxiliaryFiles\StringCache.cs" />
     <Compile Include="AuxiliaryFiles\VerifiedPackagesDataClient.cs" />
+    <Compile Include="AzureSearchJob.cs" />
     <Compile Include="AzureSearchScoringConfiguration.cs" />
     <Compile Include="BaseDocumentBuilder.cs" />
     <Compile Include="DatabaseOwnerFetcher.cs" />
     <Compile Include="Db2AzureSearch\InitialAuxiliaryData.cs" />
     <Compile Include="IAzureSearchTelemetryService.cs" />
     <Compile Include="IBaseDocumentBuilder.cs" />
+    <Compile Include="IAzureSearchCommand.cs" />
     <Compile Include="IDatabaseOwnerFetcher.cs" />
     <Compile Include="ISearchIndexActionBuilder.cs" />
     <Compile Include="JobOutcome.cs" />
@@ -192,6 +194,7 @@
     <Compile Include="SearchService\SearchTextBuilder.cs" />
     <Compile Include="AzureSearchTelemetryService.cs" />
     <Compile Include="SearchService\SecretRefresher.cs" />
+    <Compile Include="ServiceClientTracingLogger.cs" />
     <Compile Include="VersionList\Guard.cs" />
     <Compile Include="VersionList\HijackIndexChange.cs" />
     <Compile Include="VersionList\HijackIndexChangeType.cs" />

diff --git a/src/NuGet.Services.AzureSearch/Owners2AzureSearch/Owners2AzureSearchCommand.cs b/src/NuGet.Services.AzureSearch/Owners2AzureSearch/Owners2AzureSearchCommand.cs
@@ -13,7 +13,7 @@
 
 namespace NuGet.Services.AzureSearch.Owners2AzureSearch
 {
-    public class Owners2AzureSearchCommand
+    public class Owners2AzureSearchCommand : IAzureSearchCommand
     {
         private readonly IDatabaseOwnerFetcher _databaseOwnerFetcher;
         private readonly IOwnerDataClient _ownerDataClient;

diff --git a/src/NuGet.Services.AzureSearch/ServiceClientTracingLogger.cs b/src/NuGet.Services.AzureSearch/ServiceClientTracingLogger.cs
@@ -0,0 +1,60 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using System.Collections.Generic;
+using System.Net.Http;
+using Microsoft.Extensions.Logging;
+using Microsoft.Rest;
+
+namespace NuGet.Services.AzureSearch
+{
+    public class ServiceClientTracingLogger : IServiceClientTracingInterceptor
+    {
+        private const string Prefix = "ServiceClient ";
+        private readonly ILogger<ServiceClientTracingLogger> _logger;
+
+        public ServiceClientTracingLogger(ILogger<ServiceClientTracingLogger> logger)
+        {
+            _logger = logger ?? throw new ArgumentNullException(nameof(logger));
+        }
+
+        public void SendRequest(string invocationId, HttpRequestMessage request)
+        {
+            _logger.LogInformation(
+                Prefix + "invocation {InvocationId} sending request: {Method} {RequestUri}",
+                invocationId,
+                request.Method,
+                request.RequestUri);
+        }
+
+        public void ReceiveResponse(string invocationId, HttpResponseMessage response)
+        {
+            _logger.LogInformation(
+                Prefix + "invocation {InvocationId} received response: {StatusCode} {ReasonPhrase}",
+                invocationId,
+                (int)response.StatusCode,
+                response.ReasonPhrase);
+        }
+
+        public void Configuration(string source, string name, string value)
+        {
+        }
+
+        public void EnterMethod(string invocationId, object instance, string method, IDictionary<string, object> parameters)
+        {
+        }
+
+        public void ExitMethod(string invocationId, object returnValue)
+        {
+        }
+
+        public void Information(string message)
+        {
+        }
+
+        public void TraceError(string invocationId, Exception exception)
+        {
+        }
+    }
+}