More logging for downloads service. (#9361)

Author: agr

src/GitHubVulnerabilities2Db/Gallery/ThrowingTelemetryService.cs

@@ -400,5 +400,13 @@ public IDisposable TrackAsyncSqlConnectionCreationDuration()
         {
             throw new NotImplementedException();
         }
+
+        public void TrackDownloadJsonTotalPackageIds(int totalPackageIds) {
+            throw new NotImplementedException();
+        }
+
+        public void TrackDownloadJsonTotalPackageVersions(int totalPackageVersions) {
+            throw new NotImplementedException();
+        }
     }
 }

src/NuGetGallery.Services/Telemetry/ITelemetryService.cs

@@ -18,6 +18,10 @@ public interface ITelemetryService
 
         void TrackDownloadJsonRefreshDuration(TimeSpan duration);
 
+        void TrackDownloadJsonTotalPackageIds(int totalPackageIds);
+
+        void TrackDownloadJsonTotalPackageVersions(int totalPackageVersions);
+
         void TrackDownloadCountDecreasedDuringRefresh(string packageId, string packageVersion, long oldCount, long newCount);
 
         void TrackPackageDownloadCountDecreasedFromGallery(string packageId, string packageVersion, long galleryCount, long jsonCount);

src/NuGetGallery.Services/Telemetry/TelemetryService.cs

@@ -39,6 +39,8 @@ public static class Events
             public const string GalleryDownloadGreaterThanJsonForPackageRegistration = "GalleryDownloadGreaterThanJsonForPackageRegistration";
             public const string GetPackageDownloadCountFailed = "GetPackageDownloadCountFailed";
             public const string GetPackageRegistrationDownloadCountFailed = "GetPackageRegistrationDownloadCountFailed";
+            public const string DownloadJsonTotalPackageIds = "DownloadJsonTotalPackageIds";
+            public const string DownloadJsonTotalPackageVersions = "DownloadJsonTotalPackageVersions";
             public const string UserPackageDeleteCheckedAfterHours = "UserPackageDeleteCheckedAfterHours";
             public const string UserPackageDeleteExecuted = "UserPackageDeleteExecuted";
             public const string UserMultiFactorAuthenticationEnabled = "UserMultiFactorAuthenticationEnabled";
@@ -279,6 +281,16 @@ public void TrackDownloadJsonRefreshDuration(TimeSpan duration)
             TrackMetric(Events.DownloadJsonRefreshDuration, duration.TotalMilliseconds, properties => { });
         }
 
+        public void TrackDownloadJsonTotalPackageIds(int totalPackageIds)
+        {
+            TrackMetric(Events.DownloadJsonTotalPackageIds, totalPackageIds, properties => { });
+        }
+
+        public void TrackDownloadJsonTotalPackageVersions(int totalPackageVersions)
+        {
+            TrackMetric(Events.DownloadJsonTotalPackageVersions, totalPackageVersions, properties => { });
+        }
+
         public void TrackDownloadCountDecreasedDuringRefresh(string packageId, string packageVersion, long oldCount, long newCount)
         {
             TrackMetric(Events.DownloadCountDecreasedDuringRefresh, 1, properties =>

src/NuGetGallery/App_Start/DefaultDependenciesModule.cs

@@ -778,7 +778,8 @@ private static void RegisterStatisticsServices(ContainerBuilder builder, IGaller
                 {
                     var cloudBlobClientFactory = c.ResolveKeyed<Func<ICloudBlobClient>>(BindingKeys.FeatureFlaggedStatisticsKey);
                     var telemetryService = c.Resolve<ITelemetryService>();
-                    var downloadCountService = new CloudDownloadCountService(telemetryService, cloudBlobClientFactory);
+                    var downloadCountServiceLogger = c.Resolve<ILogger<CloudDownloadCountService>>();
+                    var downloadCountService = new CloudDownloadCountService(telemetryService, cloudBlobClientFactory, downloadCountServiceLogger);
 
                     var dlCountInterceptor = new DownloadCountObjectMaterializedInterceptor(downloadCountService, telemetryService);
                     ObjectMaterializedInterception.AddInterceptor(dlCountInterceptor);

src/NuGetGallery/Services/CloudDownloadCountService.cs

@@ -9,6 +9,7 @@
 using System.Net;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 using Microsoft.WindowsAzure.Storage;
 using Microsoft.WindowsAzure.Storage.Blob;
 using Microsoft.WindowsAzure.Storage.RetryPolicies;
@@ -29,6 +30,7 @@ public class CloudDownloadCountService : IDownloadCountService
 
         private readonly ITelemetryService _telemetryService;
         private readonly Func<ICloudBlobClient> _cloudBlobClientFactory;
+        private readonly ILogger<CloudDownloadCountService> _logger;
 
         private readonly object _refreshLock = new object();
         private bool _isRefreshing;
@@ -38,10 +40,12 @@ private readonly ConcurrentDictionary<string, ConcurrentDictionary<string, long>
 
         public CloudDownloadCountService(
             ITelemetryService telemetryService,
-            Func<ICloudBlobClient> cloudBlobClientFactory)
+            Func<ICloudBlobClient> cloudBlobClientFactory,
+            ILogger<CloudDownloadCountService> logger)
         {
             _telemetryService = telemetryService ?? throw new ArgumentNullException(nameof(telemetryService));
             _cloudBlobClientFactory = cloudBlobClientFactory ?? throw new ArgumentNullException(nameof(cloudBlobClientFactory));
+            _logger = logger ?? throw new ArgumentNullException(nameof(logger));
         }
 
         public bool TryGetDownloadCountForPackageRegistration(string id, out long downloadCount)
@@ -158,6 +162,9 @@ private async Task RefreshCoreAsync()
         {
             try
             {
+                int totalIds = 0;
+                int totalVersions = 0;
+
                 // The data in downloads.v1.json will be an array of Package records - which has Id, Array of Versions and download count.
                 // Sample.json : [["AutofacContrib.NSubstitute",["2.4.3.700",406],["2.5.0",137]],["Assman.Core",["2.0.7",138]]....
                 using (var blobStream = await GetBlobStreamAsync())
@@ -189,6 +196,8 @@ private async Task RefreshCoreAsync()
                                             continue;
                                         }
 
+                                        ++totalIds;
+
                                         var versions = _downloadCounts.GetOrAdd(
                                             id,
                                             _ => new ConcurrentDictionary<string, long>(StringComparer.OrdinalIgnoreCase));
@@ -199,6 +208,7 @@ private async Task RefreshCoreAsync()
                                             {
                                                 var version = token[0].ToString();
                                                 var downloadCount = token[1].ToObject<long>();
+                                                ++totalVersions;
 
                                                 if (versions.ContainsKey(version) && downloadCount < versions[version])
                                                 {
@@ -232,6 +242,9 @@ private async Task RefreshCoreAsync()
                         }
                     }
                 }
+
+                _telemetryService.TrackDownloadJsonTotalPackageIds(totalIds);
+                _telemetryService.TrackDownloadJsonTotalPackageVersions(totalVersions);
             }
             catch (Exception ex)
             {
@@ -250,6 +263,8 @@ private ISimpleCloudBlob GetBlobReference()
             var container = blobClient.GetContainerReference(StatsContainerName);
             var blob = container.GetBlobReference(DownloadCountBlobName);
 
+            _logger.LogInformation("Cloud download statistics source: {BlobUri}", blob.Uri);
+
             return blob;
         }
     }

src/VerifyMicrosoftPackage/Fakes/FakeTelemetryService.cs

@@ -402,5 +402,13 @@ public IDisposable TrackAsyncSqlConnectionCreationDuration()
         {
             throw new NotImplementedException();
         }
+
+        public void TrackDownloadJsonTotalPackageIds(int totalPackageIds) {
+            throw new NotImplementedException();
+        }
+
+        public void TrackDownloadJsonTotalPackageVersions(int totalPackageVersions) {
+            throw new NotImplementedException();
+        }
     }
 }

tests/NuGetGallery.Facts/Services/CloudDownloadCountServiceFacts.cs

@@ -10,6 +10,7 @@
 using System.Text;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 using Moq;
 using NuGetGallery.Services;
 using Xunit;
@@ -173,7 +174,10 @@ public class TestableCloudDownloadCountService : CloudDownloadCountService
             private readonly BaseFacts _baseFacts;
 
             public TestableCloudDownloadCountService(BaseFacts baseFacts)
-                    : base(baseFacts._telemetryService.Object, () => baseFacts._cloudBlobClientMock.Object)
+                    : base(
+                          baseFacts._telemetryService.Object,
+                          () => baseFacts._cloudBlobClientMock.Object,
+                          Mock.Of<ILogger<CloudDownloadCountService>>())
             {
                 _baseFacts = baseFacts;
             }