diff --git a/ReleaseHistory.md b/ReleaseHistory.md index b14a2676d..d54a5bddc 100644 --- a/ReleaseHistory.md +++ b/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) diff --git a/src/Sarif.Driver/Sdk/MultithreadedAnalyzeCommandBase.cs b/src/Sarif.Driver/Sdk/MultithreadedAnalyzeCommandBase.cs index 5a0b00e91..697be1532 100644 --- a/src/Sarif.Driver/Sdk/MultithreadedAnalyzeCommandBase.cs +++ b/src/Sarif.Driver/Sdk/MultithreadedAnalyzeCommandBase.cs @@ -542,7 +542,9 @@ private async Task EnumerateTargetsAsync(TContext context) this._fileContextsCount = 0; this._fileContexts = new ConcurrentDictionary(); + DriverEventSource.Log.EnumerateTargetsStart(); await EnumerateFilesFromArtifactsProvider(context); + DriverEventSource.Log.EnumerateTargetsStop(); } finally { @@ -560,7 +562,7 @@ private async Task EnumerateTargetsAsync(TContext context) continue; } - Notes.LogEmptyFileSkipped(context, artifact.Uri.GetFilePath()); + Notes.LogEmptyFileSkipped(context, artifact.Uri.GetFileName()); } } @@ -597,6 +599,8 @@ private async Task 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> skimmers, ISet 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> skimmers, ISet disabledSkimmers) @@ -1103,7 +1109,9 @@ public static void AnalyzeTargetHelper(TContext context, IEnumerable + /// EventSource is an ETW EventSource for Microsoft.CodeAnalysis.Sarif.PatternMatcher events, allowing performance tracing. + /// + [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); + } + + } +} diff --git a/src/Sarif/EnumeratedArtifact.cs b/src/Sarif/EnumeratedArtifact.cs index a9a3f8aba..841bd7a6f 100644 --- a/src/Sarif/EnumeratedArtifact.cs +++ b/src/Sarif/EnumeratedArtifact.cs @@ -7,8 +7,8 @@ namespace Microsoft.CodeAnalysis.Sarif { - // TBD: this class should probably be a generic, with EnumeratedArtifact - // being a commonly utilized thing. + // TBD: this class should probably be a generic, with + // EnumeratedArtifact 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) diff --git a/src/Test.UnitTests.Sarif.Driver/Sdk/AnalyzeCommandBaseTests.cs b/src/Test.UnitTests.Sarif.Driver/Sdk/AnalyzeCommandBaseTests.cs index 015b2b360..9f0b414fe 100644 --- a/src/Test.UnitTests.Sarif.Driver/Sdk/AnalyzeCommandBaseTests.cs +++ b/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 { diff --git a/src/Test.UnitTests.Sarif/NotesTests.cs b/src/Test.UnitTests.Sarif/NotesTests.cs index 1dab712ca..852182ca8 100644 --- a/src/Test.UnitTests.Sarif/NotesTests.cs +++ b/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)