Driver ETW events

ReleaseHistory.md

@@ -24,6 +24,7 @@
 * BUG: Generate `IAnalysisLogger.AnalyzingTarget` callbacks from `MulthreadedAnalyzeCommandBase`. [#2637](https://github.com/microsoft/sarif-sdk/pull/2637)
 * BUG: Persist `fileRegionsCache` parameter in `SarifLogger` to support retrieving hash data. [#2639](https://github.com/microsoft/sarif-sdk/pull/2639)
 * BUG: Allow override of `FailureLevels` and `ResultKinds` in context objects. [#2639](https://github.com/microsoft/sarif-sdk/pull/2639)
+* NEW: Provide new ETW telemetry for runtime behavior, provider `SarifDriver`, guid `c84480b4-a77f-421f-8a11-48210c1724d4`. https://github.com/microsoft/sarif-sdk/pull/2668
 * NEW: Provide convenience enumerator at the `SarifLog` level that iterates over all results in all runs in the log. [#2660](https://github.com/microsoft/sarif-sdk/pull/2660)
 * NEW: Provide `Notes.LogEmptyFileSkipped` helper for reporting zero-byte files skipped at scan time. [#2660](https://github.com/microsoft/sarif-sdk/pull/2660)
 * NEW: Add `MemoryStreamSarifLogger` (for in-memory SARIF generation). [#2655](https://github.com/microsoft/sarif-sdk/pull/2655)

src/Sarif.Driver/Sdk/MultithreadedAnalyzeCommandBase.cs

@@ -542,7 +542,9 @@ private async Task<bool> EnumerateTargetsAsync(TContext context)
                 this._fileContextsCount = 0;
                 this._fileContexts = new ConcurrentDictionary<uint, TContext>();
 
+                DriverEventSource.Log.EnumerateTargetsStart();
                 await EnumerateFilesFromArtifactsProvider(context);
+                DriverEventSource.Log.EnumerateTargetsStop();
             }
             finally
             {
@@ -560,7 +562,7 @@ private async Task<bool> EnumerateTargetsAsync(TContext context)
                         continue;
                     }
 
-                    Notes.LogEmptyFileSkipped(context, artifact.Uri.GetFilePath());
+                    Notes.LogEmptyFileSkipped(context, artifact.Uri.GetFileName());
                 }
             }
 
@@ -597,6 +599,8 @@ private async Task<bool> EnumerateFilesFromArtifactsProvider(TContext globalCont
                     //
                     // This call needs to be protected with a lock as the actual
                     // logging occurs on a separated thread.
+
+                    DriverEventSource.Log.ArtifactSizeInBytes(artifact.Uri.GetFilePath(), artifact.SizeInBytes.Value);
                     globalContext.Logger.AnalyzingTarget(fileContext);
                 }
 
@@ -1079,7 +1083,9 @@ internal static string GetFileNameFromUri(Uri uri)
 
         protected virtual void AnalyzeTarget(TContext context, IEnumerable<Skimmer<TContext>> skimmers, ISet<string> disabledSkimmers)
         {
+            DriverEventSource.Log.ScanTargetStart(context.CurrentTarget.Uri.GetFilePath());
             AnalyzeTargetHelper(context, skimmers, disabledSkimmers);
+            DriverEventSource.Log.ScanTargetStop(context.CurrentTarget.Uri.GetFilePath());
         }
 
         public static void AnalyzeTargetHelper(TContext context, IEnumerable<Skimmer<TContext>> skimmers, ISet<string> disabledSkimmers)
@@ -1103,7 +1109,9 @@ public static void AnalyzeTargetHelper(TContext context, IEnumerable<Skimmer<TCo
                         ? Stopwatch.StartNew()
                         : null;
 
+                    DriverEventSource.Log.RuleStart(context.CurrentTarget.Uri.GetFilePath(), skimmer.Id, skimmer.Name);
                     skimmer.Analyze(context);
+                    DriverEventSource.Log.RuleStop(context.CurrentTarget.Uri.GetFilePath(), skimmer.Id, skimmer.Name);
 
                     Uri uri = context.CurrentTarget.Uri;
 

src/Sarif/DriverEvent.cs

@@ -0,0 +1,27 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+namespace Microsoft.CodeAnalysis.Sarif
+{
+    public enum DriverEvent : int
+    {
+        EnumerateTargetsStart = 1,
+        EnumerateTargetsStop = 2,
+        ArtifactSizeInBytes = 3,
+        GetTargetStart = 4,
+        GetTargetStop = 5,
+        ScanTargetStart = 6,
+        ScanTargetStop = 7,
+        RuleStart = 8,
+        RuleStop = 9,
+        RuleFired = 10,
+        LogResultsStart = 11,
+        LogResultsEnd = 12,
+        RuleReserved = 13,
+        RuleReservedStart = 14,
+        RuleReservedStop = 15,
+        TargetReserved = 16,
+        TargetReservedStart = 17,
+        TargetReservedStop = 18,
+    }
+}

src/Sarif/DriverEventSource.cs

@@ -0,0 +1,108 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Diagnostics.Tracing;
+
+namespace Microsoft.CodeAnalysis.Sarif
+{
+    /// <summary>
+    ///  EventSource is an ETW EventSource for Microsoft.CodeAnalysis.Sarif.PatternMatcher events, allowing performance tracing.
+    /// </summary>
+    [EventSource(Name = "SarifDriver", Guid = "c84480b4-a77f-421f-8a11-48210c1724d4")]
+    public class DriverEventSource : EventSource
+    {
+        public static DriverEventSource Log = new DriverEventSource();
+
+        [Event((int)DriverEvent.GetTargetStart, Message = "Get contents: {0}")]
+        public void GetTargetStart(string filePath)
+        {
+            WriteEvent((int)DriverEvent.GetTargetStart, filePath);
+        }
+
+        [Event((int)DriverEvent.GetTargetStop, Message = "Contents retrieved: {0}")]
+        public void GetTargetStop(string filePath)
+        {
+            WriteEvent((int)DriverEvent.GetTargetStop, filePath);
+        }
+
+        [Event((int)DriverEvent.ScanTargetStart, Message = "Scan start: {0}")]
+        public void ScanTargetStart(string filePath)
+        {
+            WriteEvent((int)DriverEvent.ScanTargetStart, filePath);
+        }
+
+        [Event((int)DriverEvent.ScanTargetStop, Message = "Scan stop: {0}")]
+        public void ScanTargetStop(string filePath)
+        {
+            WriteEvent((int)DriverEvent.ScanTargetStop, filePath);
+        }
+
+        [Event((int)DriverEvent.RuleStart, Message = "'{1}.{2}' start: {0}")]
+        public void RuleStart(string filePath, string ruleId, string ruleName)
+        {
+            WriteEvent((int)DriverEvent.RuleStart, filePath, ruleId, ruleName);
+        }
+
+        [Event((int)DriverEvent.RuleStop, Message = "'{1}.{2}' stop: {0}")]
+        public void RuleStop(string filePath, string ruleId, string ruleName)
+        {
+            WriteEvent((int)DriverEvent.RuleStop, filePath, ruleId, ruleName);
+        }
+
+        [Event((int)DriverEvent.RuleFired, Message = "'{1}.{2}' fired with severity '{3}': {0}")]
+        public void RuleFired(string filePath, string ruleId, string ruleName, FailureLevel level)
+        {
+            WriteEvent((int)DriverEvent.RuleFired, filePath, ruleId, ruleName, level);
+        }
+
+        [Event((int)DriverEvent.ArtifactSizeInBytes, Message = "{0} : size {1} bytes.")]
+        public void ArtifactSizeInBytes(string filePath, ulong sizeInBytes)
+        {
+            WriteEvent((int)DriverEvent.ArtifactSizeInBytes, filePath, sizeInBytes);
+        }
+
+        [Event((int)DriverEvent.EnumerateTargetsStart, Message = "Target enumeration started.")]
+        public void EnumerateTargetsStart()
+        {
+            WriteEvent((int)DriverEvent.EnumerateTargetsStart);
+        }
+
+        [Event((int)DriverEvent.EnumerateTargetsStop, Message = "Target enumeration stopped.")]
+        public void EnumerateTargetsStop()
+        {
+            WriteEvent((int)DriverEvent.EnumerateTargetsStop);
+        }
+
+        [Event((int)DriverEvent.TargetReserved, Message = "'{0}': {1}")]
+        public void TargetReserved(string eventId, string filePath)
+        {
+            WriteEvent((int)DriverEvent.TargetReserved, eventId, filePath);
+        }
+
+        [Event((int)DriverEvent.TargetReservedStart, Message = "'{0}' start: {1}")]
+        public void TargetReservedStart(string eventId, string filePath)
+        {
+            WriteEvent((int)DriverEvent.TargetReservedStart, eventId, filePath);
+        }
+
+        [Event((int)DriverEvent.TargetReservedStop, Message = "'{0}' stop: {1}")]
+        public void TargetReservedStop(string eventId, string filePath)
+        {
+            WriteEvent((int)DriverEvent.TargetReservedStop, eventId, filePath);
+        }
+
+        [Event((int)DriverEvent.RuleReservedStart, Message = "'{2}.{3}' '{0}' start: {1}")]
+        public void RuleReservedStart(string eventId, string filePath, string ruleId, string ruleName)
+        {
+            WriteEvent((int)DriverEvent.RuleReservedStart, eventId, filePath, ruleId, ruleName);
+        }
+
+        [Event((int)DriverEvent.RuleReservedStop, Message = "'{2}.{3}' '{0}' stop: {1}")]
+        public void RuleReservedStop(string eventId, string filePath, string ruleId, string ruleName)
+        {
+            WriteEvent((int)DriverEvent.RuleReservedStop, eventId, filePath, ruleId, ruleName);
+        }
+
+    }
+}

src/Sarif/EnumeratedArtifact.cs

@@ -7,8 +7,8 @@
 
 namespace Microsoft.CodeAnalysis.Sarif
 {
-    // TBD: this class should probably be a generic, with EnumeratedArtifact<string>
-    // being a commonly utilized thing.
+    // TBD: this class should probably be a generic, with
+    // EnumeratedArtifact<string> being a commonly utilized thing.
     public class EnumeratedArtifact : IEnumeratedArtifact
     {
         public EnumeratedArtifact(IFileSystem fileSystem)
@@ -34,6 +34,10 @@ public string Contents
 
         private string GetContents()
         {
+            if (this.contents != null) { return this.contents; }
+
+            DriverEventSource.Log.GetTargetStart(this.Uri.GetFilePath());
+
             if (Stream == null && this.contents == null)
             {
                 // TBD we actually have no validation URI is non-null yet.
@@ -42,15 +46,16 @@ private string GetContents()
                     : null;
 
                 this.sizeInBytes = (ulong?)this.contents?.Length;
-
-                return contents;
+            }
+            else
+            {
+                if (Stream.CanSeek) { this.Stream.Seek(0, SeekOrigin.Begin); }
+                using var contentReader = new StreamReader(Stream);
+                this.contents = contentReader.ReadToEnd();
+                Stream = null;
             }
 
-            if (this.contents != null) { return this.contents; }
-            if (Stream.CanSeek) { this.Stream.Seek(0, SeekOrigin.Begin); }
-            using var contentReader = new StreamReader(Stream);
-            this.contents = contentReader.ReadToEnd();
-            Stream = null;
+            DriverEventSource.Log.GetTargetStop(this.Uri.GetFilePath());
             return this.contents;
         }
 
@@ -60,7 +65,15 @@ public ulong? SizeInBytes
         {
             get
             {
-                if (sizeInBytes != null) { return sizeInBytes.Value; };
+                if (this.sizeInBytes != null)
+                {
+                    return this.sizeInBytes.Value;
+                };
+
+                if (this.Contents != null)
+                {
+                    return (ulong?)this.Contents.Length;
+                }
 
                 this.sizeInBytes = Uri!.IsFile
                     ? (ulong)FileSystem.FileInfoLength(Uri.LocalPath)

src/Test.UnitTests.Sarif.Driver/Sdk/AnalyzeCommandBaseTests.cs

@@ -692,7 +692,7 @@ public void AnalyzeCommand_TracesInMemory()
                                                  levels: BaseLogger.ErrorWarningNote,
                                                  kinds: BaseLogger.Fail);
 
-                    var target = new EnumeratedArtifact(FileSystem.Instance) { Uri = uri, Contents = string.Empty };
+                    var target = new EnumeratedArtifact(FileSystem.Instance) { Uri = uri, Contents = "A" };
 
                     var context = new TestAnalysisContext
                     {

src/Test.UnitTests.Sarif/NotesTests.cs

@@ -24,6 +24,7 @@ public void NotesTests_LogEmptyFileSkipped()
             var oneCharacterFile = new EnumeratedArtifact(FileSystem.Instance)
             {
                 Uri = new Uri(@"c:\\nonemptyfile.txt"),
+                Contents = "A",
             };
 
             var emptyFile = new EnumeratedArtifact(FileSystem.Instance)