Typo-squatting: Log metrics (#6428)

* Finish log metrics

* Update

* update again

* update

* Refactor different metrics for different time costs

* Retry pushing

* Final update

Author: zhhyu

src/NuGetGallery/Services/ITelemetryService.cs

@@ -178,5 +178,41 @@ public interface ITelemetryService
         /// <param name="packageId">The id of the package that has the symbols uploaded.</param>
         /// <param name="packageVersion">The version of the package that has the symbols uploaded.</param>
         void TrackSymbolPackageFailedGalleryValidationEvent(string packageId, string packageVersion);
+
+        /// <summary>
+        /// The typosquatting check result and total time for the uploaded package.
+        /// </summary>
+        /// <param name="packageId">The Id of the uploaded package.</param>
+        /// <param name="totalTime">The total time for the typosquatting check logic</param>
+        /// <param name="wasUploadBlocked">Whether the uploaded package is blocked because of typosquatting check.</param>
+        /// <param name="collisionPackageIds">The list of collision package Ids for this uploaded package.</param>
+        /// <param name="checklistLength">The length of the checklist for typosquatting check</param>
+        void TrackMetricForTyposquattingCheckResultAndTotalTime(
+            string packageId,
+            TimeSpan totalTime,
+            bool wasUploadBlocked,
+            List<string> collisionPackageIds,
+            int checklistLength);
+
+        /// <summary>
+        /// The retrieval time to get the checklist for typosquatting check.
+        /// /// </summary>
+        /// <param name="packageId">The Id of the uploaded package.</param>
+        /// <param name="checklistRetrievalTime">The time used to retrieval the checklist from the database.</param>
+        void TrackMetricForTyposquattingChecklistRetrievalTime(string packageId, TimeSpan checklistRetrievalTime);
+
+        /// <summary>
+        /// The algorithm processing time for typosquatting check.
+        /// /// </summary>
+        /// <param name="packageId">The Id of the uploaded package.</param>
+        /// <param name="algorithmProcessingTime">The time used to finish the algorithm of typosquatting check.</param>
+        void TrackMetricForTyposquattingAlgorithmProcessingTime(string packageId, TimeSpan algorithmProcessingTime);
+
+        /// <summary>
+        /// The owners double check time for typosquatting check.
+        /// /// </summary>
+        /// <param name="packageId">The Id of the uploaded package.</param>
+        /// <param name ="ownersCheckTime">The time used to double check the owners of collision Ids</param>
+        void TrackMetricForTyposquattingOwnersCheckTime(string packageId, TimeSpan ownersCheckTime);
     }
 }

src/NuGetGallery/Services/TelemetryService.cs

@@ -55,6 +55,10 @@ internal class Events
             public const string PackageMetadataComplianceError = "PackageMetadataComplianceError";
             public const string PackageMetadataComplianceWarning = "PackageMetadataComplianceWarning";
             public const string PackageOwnershipAutomaticallyAdded = "PackageOwnershipAutomaticallyAdded";
+            public const string TyposquattingCheckResultAndTotalTimeInMs = "TyposquattingCheckResultAndTotalTimeInMs";
+            public const string TyposquattingChecklistRetrievalTimeInMs = "TyposquattingChecklistRetrievalTimeInMs";
+            public const string TyposquattingAlgorithmProcessingTimeInMs = "TyposquattingAlgorithmProcessingTimeInMs";
+            public const string TyposquattingOwnersCheckTimeInMs = "TyposquattingOwnersCheckTimeInMs";
         }
 
         private IDiagnosticsSource _diagnosticsSource;
@@ -65,7 +69,7 @@ internal class Events
             ReferenceLoopHandling = ReferenceLoopHandling.Ignore,
             Formatting = Formatting.None
         };
-
+        
         // ODataQueryFilter properties
         public const string CallContext = "CallContext";
         public const string IsEnabled = "IsEnabled";
@@ -132,6 +136,14 @@ internal class Events
 
         public const string ValueUnknown = "Unknown";
 
+        // Typosquatting check properties
+        private const int TyposquattingCollisionIdsMaxPropertyValue = 10;
+        public const string WasUploadBlocked = "WasUploadBlocked";
+        public const string CollisionPackageIds = "CollisionPackageIds";
+        public const string CollisionPackageIdsCount = "CollisionPackageIdsCount";
+        public const string CheckListLength = "CheckListLength";
+        public const string HasExtraCollisionPackageIds = "HasExtraCollisionPackageIds";
+
         public TelemetryService(IDiagnosticsService diagnosticsService, ITelemetryClient telemetryClient = null)
         {
             if (diagnosticsService == null)
@@ -681,6 +693,44 @@ public void TrackSendEmail(string smtpUri, DateTimeOffset startTime, TimeSpan du
             _telemetryClient.TrackDependency("SMTP", smtpUri, "SendMessage", null, startTime, duration, null, success, properties);
         }
 
+        public void TrackMetricForTyposquattingCheckResultAndTotalTime(
+            string packageId,
+            TimeSpan totalTime,
+            bool wasUploadBlocked,
+            List<string> collisionPackageIds,
+            int checklistLength)
+        {
+            TrackMetric(Events.TyposquattingCheckResultAndTotalTimeInMs, totalTime.TotalMilliseconds, properties => {
+                properties.Add(PackageId, packageId);
+                properties.Add(WasUploadBlocked, wasUploadBlocked.ToString());
+                properties.Add(CollisionPackageIds, string.Join(",", collisionPackageIds.Take(TyposquattingCollisionIdsMaxPropertyValue)));
+                properties.Add(CollisionPackageIdsCount, collisionPackageIds.Count.ToString());
+                properties.Add(CheckListLength, checklistLength.ToString());
+                properties.Add(HasExtraCollisionPackageIds, (collisionPackageIds.Count > TyposquattingCollisionIdsMaxPropertyValue).ToString());
+            });
+        }
+
+        public void TrackMetricForTyposquattingChecklistRetrievalTime(string packageId, TimeSpan checklistRetrievalTime)
+        {
+            TrackMetric(Events.TyposquattingChecklistRetrievalTimeInMs, checklistRetrievalTime.TotalMilliseconds, properties => {
+                properties.Add(PackageId, packageId);
+            });
+        }
+
+        public void TrackMetricForTyposquattingAlgorithmProcessingTime(string packageId, TimeSpan algorithmProcessingTime)
+        {
+            TrackMetric(Events.TyposquattingAlgorithmProcessingTimeInMs, algorithmProcessingTime.TotalMilliseconds, properties => {
+                properties.Add(PackageId, packageId);
+            });
+        }
+
+        public void TrackMetricForTyposquattingOwnersCheckTime(string packageId, TimeSpan ownersCheckTime)
+        {
+            TrackMetric(Events.TyposquattingOwnersCheckTimeInMs, ownersCheckTime.TotalMilliseconds, properties => {
+                properties.Add(PackageId, packageId);
+            });
+        }
+
         /// <summary>
         /// We use <see cref="ITelemetryClient.TrackMetric(string, double, IDictionary{string, string})"/> instead of
         /// <see cref="ITelemetryClient.TrackEvent(string, IDictionary{string, string}, IDictionary{string, double})"/>

src/NuGetGallery/Services/TyposquattingService.cs

@@ -6,6 +6,7 @@
 using System.Collections.Generic;
 using System.Threading.Tasks;
 using System.Linq;
+using System.Diagnostics;
 
 namespace NuGetGallery
 {
@@ -23,22 +24,25 @@ public class TyposquattingService : ITyposquattingService
         private readonly IContentObjectService _contentObjectService;
         private readonly IPackageService _packageService;
         private readonly IReservedNamespaceService _reservedNamespaceService;
+        private readonly ITelemetryService _telemetryService;
 
-        public TyposquattingService(IContentObjectService contentObjectService, IPackageService packageService, IReservedNamespaceService reservedNamespaceService)
+        public TyposquattingService(IContentObjectService contentObjectService, IPackageService packageService, IReservedNamespaceService reservedNamespaceService, ITelemetryService telemetryService)
         {
             _contentObjectService = contentObjectService ?? throw new ArgumentNullException(nameof(contentObjectService));
             _packageService = packageService ?? throw new ArgumentNullException(nameof(packageService));
             _reservedNamespaceService = reservedNamespaceService ?? throw new ArgumentNullException(nameof(reservedNamespaceService));
+            _telemetryService = telemetryService ?? throw new ArgumentNullException(nameof(telemetryService));
 
             TyposquattingCheckListLength = _contentObjectService.TyposquattingConfiguration.PackageIdChecklistLength;
         }
 
         public bool IsUploadedPackageIdTyposquatting(string uploadedPackageId, User uploadedPackageOwner, out List<string> typosquattingCheckCollisionIds)
         {
             typosquattingCheckCollisionIds = new List<string>();
+            var wasUploadBlocked = false;
             if (!_contentObjectService.TyposquattingConfiguration.IsCheckEnabled || _reservedNamespaceService.GetReservedNamespacesForId(uploadedPackageId).Any())
             {
-                return false;
+                return wasUploadBlocked;
             }
 
             if (uploadedPackageId == null)
@@ -51,14 +55,17 @@ public bool IsUploadedPackageIdTyposquatting(string uploadedPackageId, User uplo
                 throw new ArgumentNullException(nameof(uploadedPackageOwner));
             }
 
+            var checklistRetrievalStopwatch = Stopwatch.StartNew();
             var packageRegistrations = _packageService.GetAllPackageRegistrations();
             var packagesCheckList = packageRegistrations
                 .OrderByDescending(pr => pr.IsVerified)
                 .ThenByDescending(pr => pr.DownloadCount)
                 .Select(pr => pr.Id)
                 .Take(TyposquattingCheckListLength)
                 .ToList();
+            checklistRetrievalStopwatch.Stop();
 
+            var algorithmProcessingStopwatch = Stopwatch.StartNew();
             var threshold = GetThreshold(uploadedPackageId);
             uploadedPackageId = TyposquattingStringNormalization.NormalizeString(uploadedPackageId);
 
@@ -72,11 +79,25 @@ public bool IsUploadedPackageIdTyposquatting(string uploadedPackageId, User uplo
                 }
             });
 
+            algorithmProcessingStopwatch.Stop();
+
+            var totalTime = checklistRetrievalStopwatch.Elapsed.Add(algorithmProcessingStopwatch.Elapsed);
+            _telemetryService.TrackMetricForTyposquattingChecklistRetrievalTime(uploadedPackageId, checklistRetrievalStopwatch.Elapsed);
+            _telemetryService.TrackMetricForTyposquattingAlgorithmProcessingTime(uploadedPackageId, algorithmProcessingStopwatch.Elapsed);
+
             if (collisionIds.Count == 0)
             {
+                _telemetryService.TrackMetricForTyposquattingCheckResultAndTotalTime(
+                    uploadedPackageId,
+                    totalTime,
+                    wasUploadBlocked,
+                    typosquattingCheckCollisionIds,
+                    TyposquattingCheckListLength);
+
                 return false;
             }
 
+            var ownersCheckStopwatch = Stopwatch.StartNew();
             var collisionPackagesIdAndOwners = packageRegistrations
                 .Where(pr => collisionIds.Contains(pr.Id))
                 .Select(pr => new { Id = pr.Id, Owners = pr.Owners.Select(x => x.Key).ToList() })
@@ -99,7 +120,20 @@ public bool IsUploadedPackageIdTyposquatting(string uploadedPackageId, User uplo
             var isUserAllowedTyposquatting = collisionPackagesIdAndOwners
                 .Any(pio => pio.Owners.Any(k => k == uploadedPackageOwner.Key));
 
-            return _contentObjectService.TyposquattingConfiguration.IsBlockUsersEnabled && !isUserAllowedTyposquatting;
+            wasUploadBlocked = _contentObjectService.TyposquattingConfiguration.IsBlockUsersEnabled && !isUserAllowedTyposquatting;
+
+            ownersCheckStopwatch.Stop();
+
+            totalTime = totalTime.Add(ownersCheckStopwatch.Elapsed);
+            _telemetryService.TrackMetricForTyposquattingOwnersCheckTime(uploadedPackageId, ownersCheckStopwatch.Elapsed);
+            _telemetryService.TrackMetricForTyposquattingCheckResultAndTotalTime(
+                    uploadedPackageId,
+                    totalTime,
+                    wasUploadBlocked,
+                    typosquattingCheckCollisionIds,
+                    TyposquattingCheckListLength);
+
+            return wasUploadBlocked;
         }
 
         private static int GetThreshold(string packageId)
@@ -112,7 +146,7 @@ private static int GetThreshold(string packageId)
                 }
             }
 
-            throw new ArgumentException("There is no predefined typo-squatting threshold for this package Id: " + packageId);
+            throw new ArgumentException(String.Format("There is no predefined typo-squatting threshold for this package Id: {0}", packageId));
         }
     }
 

tests/NuGetGallery.Facts/Services/TelemetryServiceFacts.cs

@@ -203,6 +203,22 @@ public static IEnumerable<object[]> TrackMetricNames_Data
                     yield return new object[] { "PackageOwnershipAutomaticallyAdded",
                         (TrackAction)(s => s.TrackPackageOwnershipAutomaticallyAdded(fakes.Package.Id, package.NormalizedVersion))
                     };
+
+                    yield return new object[] { "TyposquattingCheckResultAndTotalTimeInMs",
+                        (TrackAction)(s => s.TrackMetricForTyposquattingCheckResultAndTotalTime(fakes.Package.Id, TimeSpan.FromMilliseconds(100), true, new List<string>{"newtonsoft-json" }, 10000))
+                    };
+
+                    yield return new object[] { "TyposquattingChecklistRetrievalTimeInMs",
+                        (TrackAction)(s => s.TrackMetricForTyposquattingChecklistRetrievalTime(fakes.Package.Id, TimeSpan.FromMilliseconds(100)))
+                    };
+
+                    yield return new object[] { "TyposquattingAlgorithmProcessingTimeInMs",
+                        (TrackAction)(s => s.TrackMetricForTyposquattingAlgorithmProcessingTime(fakes.Package.Id, TimeSpan.FromMilliseconds(100)))
+                    };
+
+                    yield return new object[] { "TyposquattingOwnersCheckTimeInMs",
+                        (TrackAction)(s => s.TrackMetricForTyposquattingOwnersCheckTime(fakes.Package.Id, TimeSpan.FromMilliseconds(100)))
+                    };
                 }
             }