From edc93dfeb747225990b756f4df609f2e7d8d4f7a Mon Sep 17 00:00:00 2001 From: Tamas Vajk Date: Tue, 19 Sep 2023 11:34:43 +0200 Subject: [PATCH] Add managed thread ID to extractor log messages --- .../Semmle.Autobuild.Shared/Autobuilder.cs | 2 +- .../Semmle.Autobuild.Shared/BuildActions.cs | 2 +- .../Semmle.Extraction.CIL.Driver/Program.cs | 2 +- .../DependencyManager.cs | 76 +++++++------------ .../DotNet.cs | 22 ++---- .../DotNetCliInvoker.cs | 14 ++-- .../IDotNet.cs | 6 +- .../Extractor.cs | 2 +- .../Options.cs | 5 +- .../Extractor/Extractor.cs | 4 +- .../Semmle.Extraction.Tests/DotNet.cs | 8 +- .../Semmle.Extraction.Tests/Runtime.cs | 18 +---- csharp/extractor/Semmle.Util/Logger.cs | 18 ++++- .../Semmle.Util/ProcessStartInfoExtensions.cs | 13 +++- 14 files changed, 85 insertions(+), 107 deletions(-) diff --git a/csharp/autobuilder/Semmle.Autobuild.Shared/Autobuilder.cs b/csharp/autobuilder/Semmle.Autobuild.Shared/Autobuilder.cs index 6bed39efe76..c6cf3e32b7e 100644 --- a/csharp/autobuilder/Semmle.Autobuild.Shared/Autobuilder.cs +++ b/csharp/autobuilder/Semmle.Autobuild.Shared/Autobuilder.cs @@ -267,7 +267,7 @@ namespace Semmle.Autobuild.Shared protected DiagnosticClassifier DiagnosticClassifier { get; } - private readonly ILogger logger = new ConsoleLogger(Verbosity.Info); + private readonly ILogger logger = new ConsoleLogger(Verbosity.Info, logThreadId: false); private readonly IDiagnosticsWriter diagnostics; diff --git a/csharp/autobuilder/Semmle.Autobuild.Shared/BuildActions.cs b/csharp/autobuilder/Semmle.Autobuild.Shared/BuildActions.cs index f917e3efc8a..d3988a2bc3e 100644 --- a/csharp/autobuilder/Semmle.Autobuild.Shared/BuildActions.cs +++ b/csharp/autobuilder/Semmle.Autobuild.Shared/BuildActions.cs @@ -237,7 +237,7 @@ namespace Semmle.Autobuild.Shared int IBuildActions.RunProcess(string cmd, string args, string? workingDirectory, IDictionary? environment, out IList stdOut) { var pi = GetProcessStartInfo(cmd, args, workingDirectory, environment, true); - return pi.ReadOutput(out stdOut); + return pi.ReadOutput(out stdOut, printToConsole: false); } void IBuildActions.DirectoryDelete(string dir, bool recursive) => Directory.Delete(dir, recursive); diff --git a/csharp/extractor/Semmle.Extraction.CIL.Driver/Program.cs b/csharp/extractor/Semmle.Extraction.CIL.Driver/Program.cs index 86450a91135..cb70bfe9c38 100644 --- a/csharp/extractor/Semmle.Extraction.CIL.Driver/Program.cs +++ b/csharp/extractor/Semmle.Extraction.CIL.Driver/Program.cs @@ -38,7 +38,7 @@ namespace Semmle.Extraction.CIL.Driver } var options = new ExtractorOptions(args); - using var logger = new ConsoleLogger(options.Verbosity); + using var logger = new ConsoleLogger(options.Verbosity, logThreadId: false); var actions = options.AssembliesToExtract .Select(asm => asm.Filename) diff --git a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DependencyManager.cs b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DependencyManager.cs index 718d90d529d..acac1dcb3ae 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DependencyManager.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DependencyManager.cs @@ -219,7 +219,7 @@ namespace Semmle.Extraction.CSharp.DependencyFetching } } - public DependencyManager(string srcDir) : this(srcDir, DependencyOptions.Default, new ConsoleLogger(Verbosity.Info)) { } + public DependencyManager(string srcDir) : this(srcDir, DependencyOptions.Default, new ConsoleLogger(Verbosity.Info, logThreadId: true)) { } private IEnumerable GetAllFiles() { @@ -430,8 +430,8 @@ namespace Semmle.Extraction.CSharp.DependencyFetching } - private bool RestoreProject(string project, out string stdout, string? pathToNugetConfig = null) => - dotnet.RestoreProjectToDirectory(project, packageDirectory.DirInfo.FullName, out stdout, pathToNugetConfig); + private bool RestoreProject(string project, string? pathToNugetConfig = null) => + dotnet.RestoreProjectToDirectory(project, packageDirectory.DirInfo.FullName, pathToNugetConfig); private bool RestoreSolution(string solution, out IEnumerable projects) => dotnet.RestoreSolutionToDirectory(solution, packageDirectory.DirInfo.FullName, out projects); @@ -454,25 +454,14 @@ namespace Semmle.Extraction.CSharp.DependencyFetching /// /// Executes `dotnet restore` on all projects in projects. /// This is done in parallel for performance reasons. - /// To ensure that output is not interleaved, the output of each - /// restore is collected and printed. /// /// A list of paths to project files. private void RestoreProjects(IEnumerable projects) { - var stdoutLines = projects - .AsParallel() - .WithDegreeOfParallelism(options.Threads) - .Select(project => - { - RestoreProject(project, out var stdout); - return stdout; - }) - .ToList(); - foreach (var line in stdoutLines) + Parallel.ForEach(projects, new ParallelOptions { MaxDegreeOfParallelism = options.Threads }, project => { - Console.WriteLine(line); - } + RestoreProject(project); + }); } private void DownloadMissingPackages(List allFiles) @@ -500,38 +489,29 @@ namespace Semmle.Extraction.CSharp.DependencyFetching .Select(d => Path.GetFileName(d).ToLowerInvariant()); var notYetDownloadedPackages = fileContent.AllPackages.Except(alreadyDownloadedPackages); - var stdoutLines = notYetDownloadedPackages - .AsParallel() - .WithDegreeOfParallelism(options.Threads) - .Select(package => - { - progressMonitor.NugetInstall(package); - using var tempDir = new TemporaryDirectory(ComputeTempDirectory(package)); - var success = dotnet.New(tempDir.DirInfo.FullName, out var stdout1); - if (!success) - { - return new[] { stdout1 }; - } - - success = dotnet.AddPackage(tempDir.DirInfo.FullName, package, out var stdout2); - if (!success) - { - return new[] { stdout1, stdout2 }; - } - - success = RestoreProject(tempDir.DirInfo.FullName, out var stdout3, nugetConfig); - // TODO: the restore might fail, we could retry with a prerelease (*-* instead of *) version of the package. - if (!success) - { - progressMonitor.FailedToRestoreNugetPackage(package); - } - return new[] { stdout1, stdout2, stdout3 }; - }) - .ToList(); - foreach (var line in stdoutLines.SelectMany(l => l)) + Parallel.ForEach(notYetDownloadedPackages, new ParallelOptions { MaxDegreeOfParallelism = options.Threads }, package => { - Console.WriteLine(line); - } + progressMonitor.NugetInstall(package); + using var tempDir = new TemporaryDirectory(ComputeTempDirectory(package)); + var success = dotnet.New(tempDir.DirInfo.FullName); + if (!success) + { + return; + } + + success = dotnet.AddPackage(tempDir.DirInfo.FullName, package); + if (!success) + { + return; + } + + success = RestoreProject(tempDir.DirInfo.FullName, nugetConfig); + // TODO: the restore might fail, we could retry with a prerelease (*-* instead of *) version of the package. + if (!success) + { + progressMonitor.FailedToRestoreNugetPackage(package); + } + }); } private void AnalyseSolutions(IEnumerable solutions) diff --git a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNet.cs b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNet.cs index 3e221a5a82e..8a5db9fed12 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNet.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNet.cs @@ -37,17 +37,10 @@ namespace Semmle.Extraction.CSharp.DependencyFetching } } - private bool RunCommand(string args, out string stdout) - { - var success = dotnetCliInvoker.RunCommand(args, out var output); - stdout = string.Join("\n", output); - return success; - } - private static string GetRestoreArgs(string projectOrSolutionFile, string packageDirectory) => $"restore --no-dependencies \"{projectOrSolutionFile}\" --packages \"{packageDirectory}\" /p:DisableImplicitNuGetFallbackFolder=true"; - public bool RestoreProjectToDirectory(string projectFile, string packageDirectory, out string stdout, string? pathToNugetConfig = null) + public bool RestoreProjectToDirectory(string projectFile, string packageDirectory, string? pathToNugetConfig = null) { var args = GetRestoreArgs(projectFile, packageDirectory); if (pathToNugetConfig != null) @@ -55,7 +48,7 @@ namespace Semmle.Extraction.CSharp.DependencyFetching args += $" --configfile \"{pathToNugetConfig}\""; } - return RunCommand(args, out stdout); + return dotnetCliInvoker.RunCommand(args); } public bool RestoreSolutionToDirectory(string solutionFile, string packageDirectory, out IEnumerable projects) @@ -76,16 +69,16 @@ namespace Semmle.Extraction.CSharp.DependencyFetching return false; } - public bool New(string folder, out string stdout) + public bool New(string folder) { var args = $"new console --no-restore --output \"{folder}\""; - return RunCommand(args, out stdout); + return dotnetCliInvoker.RunCommand(args); } - public bool AddPackage(string folder, string package, out string stdout) + public bool AddPackage(string folder, string package) { var args = $"add \"{folder}\" package \"{package}\" --no-restore"; - return RunCommand(args, out stdout); + return dotnetCliInvoker.RunCommand(args); } public IList GetListedRuntimes() => GetListed("--list-runtimes", "runtime"); @@ -94,9 +87,8 @@ namespace Semmle.Extraction.CSharp.DependencyFetching private IList GetListed(string args, string artifact) { - if (dotnetCliInvoker.RunCommand(args, out IList artifacts)) + if (dotnetCliInvoker.RunCommand(args, out var artifacts)) { - progressMonitor.LogInfo($"Found {artifact}s: {string.Join("\n", artifacts)}"); return artifacts; } return new List(); diff --git a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNetCliInvoker.cs b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNetCliInvoker.cs index 4a461e18f7b..3e1ca0fedb1 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNetCliInvoker.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/DotNetCliInvoker.cs @@ -19,23 +19,23 @@ namespace Semmle.Extraction.CSharp.DependencyFetching this.Exec = exec; } - private ProcessStartInfo MakeDotnetStartInfo(string args, bool redirectStandardOutput) + private ProcessStartInfo MakeDotnetStartInfo(string args) { var startInfo = new ProcessStartInfo(Exec, args) { UseShellExecute = false, - RedirectStandardOutput = redirectStandardOutput + RedirectStandardOutput = true }; // Set the .NET CLI language to English to avoid localized output. startInfo.EnvironmentVariables["DOTNET_CLI_UI_LANGUAGE"] = "en"; return startInfo; } - private bool RunCommandAux(string args, bool redirectStandardOutput, out IList output) + private bool RunCommandAux(string args, out IList output) { progressMonitor.RunningProcess($"{Exec} {args}"); - var pi = MakeDotnetStartInfo(args, redirectStandardOutput); - var exitCode = pi.ReadOutput(out output); + var pi = MakeDotnetStartInfo(args); + var exitCode = pi.ReadOutput(out output, true); if (exitCode != 0) { progressMonitor.CommandFailed(Exec, args, exitCode); @@ -45,9 +45,9 @@ namespace Semmle.Extraction.CSharp.DependencyFetching } public bool RunCommand(string args) => - RunCommandAux(args, redirectStandardOutput: false, out _); + RunCommandAux(args, out _); public bool RunCommand(string args, out IList output) => - RunCommandAux(args, redirectStandardOutput: true, out output); + RunCommandAux(args, out output); } } diff --git a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/IDotNet.cs b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/IDotNet.cs index 832f211293b..0612d772880 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/IDotNet.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.DependencyFetching/IDotNet.cs @@ -4,10 +4,10 @@ namespace Semmle.Extraction.CSharp.DependencyFetching { internal interface IDotNet { - bool RestoreProjectToDirectory(string project, string directory, out string stdout, string? pathToNugetConfig = null); + bool RestoreProjectToDirectory(string project, string directory, string? pathToNugetConfig = null); bool RestoreSolutionToDirectory(string solutionFile, string packageDirectory, out IEnumerable projects); - bool New(string folder, out string stdout); - bool AddPackage(string folder, string package, out string stdout); + bool New(string folder); + bool AddPackage(string folder, string package); IList GetListedRuntimes(); IList GetListedSdks(); bool Exec(string execArgs); diff --git a/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Extractor.cs b/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Extractor.cs index a9f43af2bea..0724ad88dfd 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Extractor.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Extractor.cs @@ -119,7 +119,7 @@ namespace Semmle.Extraction.CSharp.Standalone var stopwatch = new Stopwatch(); stopwatch.Start(); - using var logger = new ConsoleLogger(options.Verbosity); + using var logger = new ConsoleLogger(options.Verbosity, logThreadId: true); logger.Log(Severity.Info, "Running C# standalone extractor"); using var a = new Analysis(logger, options); var sourceFileCount = a.Extraction.Sources.Count; diff --git a/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Options.cs b/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Options.cs index 07c45e375de..09ef54e8d9c 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Options.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp.Standalone/Options.cs @@ -2,6 +2,7 @@ using System.IO; using Semmle.Util; using Semmle.Util.Logging; using Semmle.Extraction.CSharp.DependencyFetching; +using System; namespace Semmle.Extraction.CSharp.Standalone { @@ -64,7 +65,7 @@ namespace Semmle.Extraction.CSharp.Standalone var fi = new FileInfo(dependencies.SolutionFile); if (!fi.Exists) { - System.Console.WriteLine("Error: The solution {0} does not exist", fi.FullName); + System.Console.WriteLine($"[{Environment.CurrentManagedThreadId:D3}] Error: The solution {fi.FullName} does not exist"); Errors = true; } return true; @@ -72,7 +73,7 @@ namespace Semmle.Extraction.CSharp.Standalone public override void InvalidArgument(string argument) { - System.Console.WriteLine($"Error: Invalid argument {argument}"); + System.Console.WriteLine($"[{Environment.CurrentManagedThreadId:D3}] Error: Invalid argument {argument}"); Errors = true; } diff --git a/csharp/extractor/Semmle.Extraction.CSharp/Extractor/Extractor.cs b/csharp/extractor/Semmle.Extraction.CSharp/Extractor/Extractor.cs index 0eb29849b8d..33674808f90 100644 --- a/csharp/extractor/Semmle.Extraction.CSharp/Extractor/Extractor.cs +++ b/csharp/extractor/Semmle.Extraction.CSharp/Extractor/Extractor.cs @@ -71,9 +71,9 @@ namespace Semmle.Extraction.CSharp public static ILogger MakeLogger(Verbosity verbosity, bool includeConsole) { - var fileLogger = new FileLogger(verbosity, GetCSharpLogPath()); + var fileLogger = new FileLogger(verbosity, GetCSharpLogPath(), logThreadId: true); return includeConsole - ? new CombinedLogger(new ConsoleLogger(verbosity), fileLogger) + ? new CombinedLogger(new ConsoleLogger(verbosity, logThreadId: true), fileLogger) : (ILogger)fileLogger; } diff --git a/csharp/extractor/Semmle.Extraction.Tests/DotNet.cs b/csharp/extractor/Semmle.Extraction.Tests/DotNet.cs index 97aeff37c0b..f7ede993808 100644 --- a/csharp/extractor/Semmle.Extraction.Tests/DotNet.cs +++ b/csharp/extractor/Semmle.Extraction.Tests/DotNet.cs @@ -99,7 +99,7 @@ namespace Semmle.Extraction.Tests var dotnet = MakeDotnet(dotnetCliInvoker); // Execute - dotnet.RestoreProjectToDirectory("myproject.csproj", "mypackages", out var _); + dotnet.RestoreProjectToDirectory("myproject.csproj", "mypackages"); // Verify var lastArgs = dotnetCliInvoker.GetLastArgs(); @@ -114,7 +114,7 @@ namespace Semmle.Extraction.Tests var dotnet = MakeDotnet(dotnetCliInvoker); // Execute - dotnet.RestoreProjectToDirectory("myproject.csproj", "mypackages", out var _, "myconfig.config"); + dotnet.RestoreProjectToDirectory("myproject.csproj", "mypackages", "myconfig.config"); // Verify var lastArgs = dotnetCliInvoker.GetLastArgs(); @@ -164,7 +164,7 @@ namespace Semmle.Extraction.Tests var dotnet = MakeDotnet(dotnetCliInvoker); // Execute - dotnet.New("myfolder", out var _); + dotnet.New("myfolder"); // Verify var lastArgs = dotnetCliInvoker.GetLastArgs(); @@ -179,7 +179,7 @@ namespace Semmle.Extraction.Tests var dotnet = MakeDotnet(dotnetCliInvoker); // Execute - dotnet.AddPackage("myfolder", "mypackage", out var _); + dotnet.AddPackage("myfolder", "mypackage"); // Verify var lastArgs = dotnetCliInvoker.GetLastArgs(); diff --git a/csharp/extractor/Semmle.Extraction.Tests/Runtime.cs b/csharp/extractor/Semmle.Extraction.Tests/Runtime.cs index 6596fff55d9..2afd467f8d4 100644 --- a/csharp/extractor/Semmle.Extraction.Tests/Runtime.cs +++ b/csharp/extractor/Semmle.Extraction.Tests/Runtime.cs @@ -15,23 +15,11 @@ namespace Semmle.Extraction.Tests this.runtimes = runtimes; this.sdks = sdks; } - public bool AddPackage(string folder, string package, out string stdout) - { - stdout = ""; - return true; - } + public bool AddPackage(string folder, string package) => true; - public bool New(string folder, out string stdout) - { - stdout = ""; - return true; - } + public bool New(string folder) => true; - public bool RestoreProjectToDirectory(string project, string directory, out string stdout, string? pathToNugetConfig = null) - { - stdout = ""; - return true; - } + public bool RestoreProjectToDirectory(string project, string directory, string? pathToNugetConfig = null) => true; public bool RestoreSolutionToDirectory(string solution, string directory, out IEnumerable projects) { diff --git a/csharp/extractor/Semmle.Util/Logger.cs b/csharp/extractor/Semmle.Util/Logger.cs index 1182046f693..747d43368b8 100644 --- a/csharp/extractor/Semmle.Util/Logger.cs +++ b/csharp/extractor/Semmle.Util/Logger.cs @@ -59,10 +59,12 @@ namespace Semmle.Util.Logging { private readonly StreamWriter writer; private readonly Verbosity verbosity; + private readonly bool logThreadId; - public FileLogger(Verbosity verbosity, string outputFile) + public FileLogger(Verbosity verbosity, string outputFile, bool logThreadId) { this.verbosity = verbosity; + this.logThreadId = logThreadId; try { @@ -93,7 +95,10 @@ namespace Semmle.Util.Logging public void Log(Severity s, string text) { if (verbosity.Includes(s)) - writer.WriteLine(GetSeverityPrefix(s) + text); + { + var threadId = this.logThreadId ? $"[{Environment.CurrentManagedThreadId:D3}] " : ""; + writer.WriteLine(threadId + GetSeverityPrefix(s) + text); + } } } @@ -103,10 +108,12 @@ namespace Semmle.Util.Logging public sealed class ConsoleLogger : ILogger { private readonly Verbosity verbosity; + private readonly bool logThreadId; - public ConsoleLogger(Verbosity verbosity) + public ConsoleLogger(Verbosity verbosity, bool logThreadId) { this.verbosity = verbosity; + this.logThreadId = logThreadId; } public void Dispose() { } @@ -136,7 +143,10 @@ namespace Semmle.Util.Logging public void Log(Severity s, string text) { if (verbosity.Includes(s)) - GetConsole(s).WriteLine(GetSeverityPrefix(s) + text); + { + var threadId = this.logThreadId ? $"[{Environment.CurrentManagedThreadId:D3}] " : ""; + GetConsole(s).WriteLine(threadId + GetSeverityPrefix(s) + text); + } } } diff --git a/csharp/extractor/Semmle.Util/ProcessStartInfoExtensions.cs b/csharp/extractor/Semmle.Util/ProcessStartInfoExtensions.cs index 8c58fb1876b..3f2150c224e 100644 --- a/csharp/extractor/Semmle.Util/ProcessStartInfoExtensions.cs +++ b/csharp/extractor/Semmle.Util/ProcessStartInfoExtensions.cs @@ -1,4 +1,5 @@ -using System.Collections.Generic; +using System; +using System.Collections.Generic; using System.Diagnostics; namespace Semmle.Util @@ -7,9 +8,11 @@ namespace Semmle.Util { /// /// Runs this process, and returns the exit code, as well as the contents - /// of stdout in . + /// of stdout in . If + /// is true, then stdout is printed to the console and each line is prefixed + /// with the thread id. /// - public static int ReadOutput(this ProcessStartInfo pi, out IList stdout) + public static int ReadOutput(this ProcessStartInfo pi, out IList stdout, bool printToConsole) { stdout = new List(); using var process = Process.Start(pi); @@ -27,6 +30,10 @@ namespace Semmle.Util s = process.StandardOutput.ReadLine(); if (s is not null) { + if (printToConsole) + { + Console.WriteLine($"[{Environment.CurrentManagedThreadId:D3}] {s}"); + } stdout.Add(s); } }