Merge pull request #15437 from tamasvajk/feature/log-verbosity

C#: Introduce log verbosity extractor option
This commit is contained in:
Tamás Vajk
2024-01-26 12:33:06 +01:00
committed by GitHub
16 changed files with 362 additions and 238 deletions

View File

@@ -267,7 +267,11 @@ namespace Semmle.Autobuild.Shared
protected DiagnosticClassifier DiagnosticClassifier { get; }
private readonly ILogger logger = new ConsoleLogger(Verbosity.Info, logThreadId: false);
private readonly ILogger logger = new ConsoleLogger(
VerbosityExtensions.ParseVerbosity(
Environment.GetEnvironmentVariable("CODEQL_VERBOSITY"),
logThreadId: false) ?? Verbosity.Info,
logThreadId: false);
private readonly IDiagnosticsWriter diagnostics;

View File

@@ -48,3 +48,21 @@ options:
The default is 'true'.
type: string
pattern: "^(false|true)$"
logging:
title: Options pertaining to logging.
type: object
properties:
verbosity:
title: Extractor logging verbosity level.
description: >
Controls the level of verbosity of the extractor.
The supported levels are (in order of increasing verbosity):
- off
- errors
- warnings
- info or progress
- debug or progress+
- trace or progress++
- progress+++
type: string
pattern: "^(off|errors|warnings|(info|progress)|(debug|progress\\+)|(trace|progress\\+\\+)|progress\\+\\+\\+)$"

View File

@@ -38,7 +38,7 @@ namespace Semmle.Extraction.CIL.Driver
}
var options = new ExtractorOptions(args);
using var logger = new ConsoleLogger(options.Verbosity, logThreadId: false);
using ILogger logger = new ConsoleLogger(options.Verbosity, logThreadId: false);
var actions = options.AssembliesToExtract
.Select(asm => asm.Filename)

View File

@@ -15,9 +15,6 @@ namespace Semmle.Extraction.CSharp.Standalone
{
switch (key)
{
case "silent":
Verbosity = value ? Verbosity.Off : Verbosity.Info;
return true;
case "help":
Help = true;
return true;

View File

@@ -27,7 +27,7 @@ namespace Semmle.Extraction.Tests
Assert.Null(options.CompilerName);
Assert.Empty(options.CompilerArguments);
Assert.True(options.Threads >= 1);
Assert.Equal(Verbosity.Info, options.Verbosity);
Assert.Equal(Verbosity.Info, options.LegacyVerbosity);
Assert.False(options.Console);
Assert.False(options.PDB);
Assert.False(options.Fast);
@@ -80,29 +80,60 @@ namespace Semmle.Extraction.Tests
public void VerbosityTests()
{
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbose" });
Assert.Equal(Verbosity.Debug, options.Verbosity);
Assert.Equal(Verbosity.Debug, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "0" });
Assert.Equal(Verbosity.Off, options.Verbosity);
Assert.Equal(Verbosity.Off, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "1" });
Assert.Equal(Verbosity.Error, options.Verbosity);
Assert.Equal(Verbosity.Error, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "2" });
Assert.Equal(Verbosity.Warning, options.Verbosity);
Assert.Equal(Verbosity.Warning, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "3" });
Assert.Equal(Verbosity.Info, options.Verbosity);
Assert.Equal(Verbosity.Info, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "4" });
Assert.Equal(Verbosity.Debug, options.Verbosity);
Assert.Equal(Verbosity.Debug, options.LegacyVerbosity);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "5" });
Assert.Equal(Verbosity.Trace, options.Verbosity);
Assert.Equal(Verbosity.Trace, options.LegacyVerbosity);
Assert.Throws<FormatException>(() => CSharp.Options.CreateWithEnvironment(new string[] { "--verbosity", "X" }));
}
private const string extractorVariableName = "CODEQL_EXTRACTOR_CSHARP_OPTION_LOGGING_VERBOSITY";
private const string cliVariableName = "CODEQL_VERBOSITY";
private void CheckVerbosity(string? extractor, string? cli, Verbosity expected)
{
var currentExtractorVerbosity = Environment.GetEnvironmentVariable(extractorVariableName);
var currentCliVerbosity = Environment.GetEnvironmentVariable(cliVariableName);
try
{
Environment.SetEnvironmentVariable(extractorVariableName, extractor);
Environment.SetEnvironmentVariable(cliVariableName, cli);
options = CSharp.Options.CreateWithEnvironment(new string[] { "--verbose" });
Assert.Equal(expected, options.Verbosity);
}
finally
{
Environment.SetEnvironmentVariable(extractorVariableName, currentExtractorVerbosity);
Environment.SetEnvironmentVariable(cliVariableName, currentCliVerbosity);
}
}
[Fact]
public void VerbosityTests_WithExtractorOption()
{
CheckVerbosity("progress+++", "progress++", Verbosity.All);
CheckVerbosity(null, "progress++", Verbosity.Trace);
CheckVerbosity(null, null, Verbosity.Debug);
}
[Fact]
public void Console()
{
@@ -142,7 +173,7 @@ namespace Semmle.Extraction.Tests
public void StandaloneOptions()
{
standaloneOptions = CSharp.Standalone.Options.Create(new string[] { "--silent" });
Assert.Equal(Verbosity.Off, standaloneOptions.Verbosity);
Assert.Equal(Verbosity.Off, standaloneOptions.LegacyVerbosity);
Assert.False(standaloneOptions.Errors);
Assert.False(standaloneOptions.Help);
}

View File

@@ -16,9 +16,39 @@ namespace Semmle.Extraction
public int Threads { get; private set; } = EnvironmentVariables.GetDefaultNumberOfThreads();
/// <summary>
/// The verbosity used in output and logging.
/// The verbosity used specified by the '--silent' or '--verbose' flags or the '--verbosity' option.
/// </summary>
public Verbosity Verbosity { get; protected set; } = Verbosity.Info;
public Verbosity LegacyVerbosity { get; protected set; } = Verbosity.Info;
private Verbosity? verbosity = null;
public Verbosity Verbosity
{
get
{
if (verbosity != null)
{
return verbosity.Value;
}
var envVarValue = EnvironmentVariables.GetExtractorOption("LOGGING_VERBOSITY");
verbosity = VerbosityExtensions.ParseVerbosity(envVarValue, logThreadId: true);
if (verbosity != null)
{
return verbosity.Value;
}
envVarValue = Environment.GetEnvironmentVariable("CODEQL_VERBOSITY");
verbosity = VerbosityExtensions.ParseVerbosity(envVarValue, logThreadId: true);
if (verbosity != null)
{
return verbosity.Value;
}
// This only works, because we already parsed the provided options, so `LegacyVerbosity` is already set (or it still has the default value).
verbosity = LegacyVerbosity;
return verbosity.Value;
}
}
/// <summary>
/// Whether to output to the console.
@@ -63,7 +93,7 @@ namespace Semmle.Extraction
Threads = int.Parse(value);
return true;
case "verbosity":
Verbosity = (Verbosity)int.Parse(value);
LegacyVerbosity = (Verbosity)int.Parse(value);
return true;
case "trap_compression":
if (Enum.TryParse<TrapWriter.CompressionMode>(value, true, out var mode))
@@ -87,11 +117,10 @@ namespace Semmle.Extraction
switch (flag)
{
case "silent":
if (value)
Verbosity = Verbosity.Off;
LegacyVerbosity = value ? Verbosity.Off : Verbosity.Info;
return true;
case "verbose":
Verbosity = value ? Verbosity.Debug : Verbosity.Error;
LegacyVerbosity = value ? Verbosity.Debug : Verbosity.Error;
return true;
case "console":
Console = value;

View File

@@ -1,217 +0,0 @@
using System;
using System.IO;
namespace Semmle.Util.Logging
{
/// <summary>
/// The severity of a log message.
/// </summary>
public enum Severity
{
Trace = 1,
Debug = 2,
Info = 3,
Warning = 4,
Error = 5
}
/// <summary>
/// Log verbosity level.
/// </summary>
public enum Verbosity
{
Off = 0,
Error = 1,
Warning = 2,
Info = 3,
Debug = 4,
Trace = 5,
All = 6
}
/// <summary>
/// A logger.
/// </summary>
public interface ILogger : IDisposable
{
/// <summary>
/// Log the given text with the given severity.
/// </summary>
void Log(Severity s, string text, int? threadId = null);
void LogError(string text, int? threadId = null) => Log(Severity.Error, text, threadId);
void LogWarning(string text, int? threadId = null) => Log(Severity.Warning, text, threadId);
void LogInfo(string text, int? threadId = null) => Log(Severity.Info, text, threadId);
void LogDebug(string text, int? threadId = null) => Log(Severity.Debug, text, threadId);
}
public static class LoggerExtensions
{
/// <summary>
/// Log the given text with the given severity.
/// </summary>
public static void Log(this ILogger logger, Severity s, string text, params object?[] args)
{
logger.Log(s, string.Format(text, args));
}
}
/// <summary>
/// A logger that outputs to a <code>csharp.log</code>
/// file.
/// </summary>
public sealed class FileLogger : ILogger
{
private readonly StreamWriter writer;
private readonly Verbosity verbosity;
private readonly bool logThreadId;
public FileLogger(Verbosity verbosity, string outputFile, bool logThreadId)
{
this.verbosity = verbosity;
this.logThreadId = logThreadId;
try
{
var dir = Path.GetDirectoryName(outputFile);
if (!string.IsNullOrEmpty(dir) && !System.IO.Directory.Exists(dir))
Directory.CreateDirectory(dir);
writer = new PidStreamWriter(
new FileStream(outputFile, FileMode.Append, FileAccess.Write, FileShare.ReadWrite, 8192));
}
catch (Exception ex) // lgtm[cs/catch-of-all-exceptions]
{
Console.Error.WriteLine("CodeQL: Couldn't initialise C# extractor output: " + ex.Message + "\n" + ex.StackTrace);
Console.Error.Flush();
throw;
}
}
public void Dispose()
{
writer.Dispose();
}
private static string GetSeverityPrefix(Severity s)
{
return "[" + s.ToString().ToUpper() + "] ";
}
public void Log(Severity s, string text, int? threadId = null)
{
if (verbosity.Includes(s))
{
threadId ??= Environment.CurrentManagedThreadId;
var prefix = this.logThreadId ? $"[{threadId:D3}] " : "";
writer.WriteLine(prefix + GetSeverityPrefix(s) + text);
}
}
}
/// <summary>
/// A logger that outputs to stdout/stderr.
/// </summary>
public sealed class ConsoleLogger : ILogger
{
private readonly Verbosity verbosity;
private readonly bool logThreadId;
public ConsoleLogger(Verbosity verbosity, bool logThreadId)
{
this.verbosity = verbosity;
this.logThreadId = logThreadId;
}
public void Dispose() { }
private static TextWriter GetConsole(Severity s)
{
return s == Severity.Error ? Console.Error : Console.Out;
}
private static string GetSeverityPrefix(Severity s)
{
switch (s)
{
case Severity.Trace:
case Severity.Debug:
case Severity.Info:
return "";
case Severity.Warning:
return "Warning: ";
case Severity.Error:
return "Error: ";
default:
throw new ArgumentOutOfRangeException(nameof(s));
}
}
public void Log(Severity s, string text, int? threadId = null)
{
if (verbosity.Includes(s))
{
threadId ??= Environment.CurrentManagedThreadId;
var prefix = this.logThreadId ? $"[{threadId:D3}] " : "";
GetConsole(s).WriteLine(prefix + GetSeverityPrefix(s) + text);
}
}
}
/// <summary>
/// A combined logger.
/// </summary>
public sealed class CombinedLogger : ILogger
{
private readonly ILogger logger1;
private readonly ILogger logger2;
public CombinedLogger(ILogger logger1, ILogger logger2)
{
this.logger1 = logger1;
this.logger2 = logger2;
}
public void Dispose()
{
logger1.Dispose();
logger2.Dispose();
}
public void Log(Severity s, string text, int? threadId = null)
{
logger1.Log(s, text, threadId);
logger2.Log(s, text, threadId);
}
}
internal static class VerbosityExtensions
{
/// <summary>
/// Whether a message with the given severity must be included
/// for this verbosity level.
/// </summary>
public static bool Includes(this Verbosity v, Severity s)
{
switch (s)
{
case Severity.Trace:
return v >= Verbosity.Trace;
case Severity.Debug:
return v >= Verbosity.Debug;
case Severity.Info:
return v >= Verbosity.Info;
case Severity.Warning:
return v >= Verbosity.Warning;
case Severity.Error:
return v >= Verbosity.Error;
default:
throw new ArgumentOutOfRangeException(nameof(s));
}
}
}
}

View File

@@ -0,0 +1,29 @@
namespace Semmle.Util.Logging
{
/// <summary>
/// A combined logger.
/// </summary>
public sealed class CombinedLogger : ILogger
{
private readonly ILogger logger1;
private readonly ILogger logger2;
public CombinedLogger(ILogger logger1, ILogger logger2)
{
this.logger1 = logger1;
this.logger2 = logger2;
}
public void Dispose()
{
logger1.Dispose();
logger2.Dispose();
}
public void Log(Severity s, string text, int? threadId = null)
{
logger1.Log(s, text, threadId);
logger2.Log(s, text, threadId);
}
}
}

View File

@@ -0,0 +1,55 @@
using System;
using System.IO;
namespace Semmle.Util.Logging
{
/// <summary>
/// A logger that outputs to stdout/stderr.
/// </summary>
public sealed class ConsoleLogger : ILogger
{
private readonly Verbosity verbosity;
private readonly bool logThreadId;
public ConsoleLogger(Verbosity verbosity, bool logThreadId)
{
this.verbosity = verbosity;
this.logThreadId = logThreadId;
}
public void Dispose() { }
private static TextWriter GetConsole(Severity s)
{
return s == Severity.Error ? Console.Error : Console.Out;
}
private static string GetSeverityPrefix(Severity s)
{
switch (s)
{
case Severity.Trace:
case Severity.Debug:
case Severity.Info:
return "";
case Severity.Warning:
return "Warning: ";
case Severity.Error:
return "Error: ";
default:
throw new ArgumentOutOfRangeException(nameof(s));
}
}
public void Log(Severity s, string text, int? threadId = null)
{
if (verbosity.Includes(s))
{
threadId ??= Environment.CurrentManagedThreadId;
var prefix = this.logThreadId ? $"[{threadId:D3}] " : "";
GetConsole(s).WriteLine(prefix + GetSeverityPrefix(s) + text);
}
}
}
}

View File

@@ -0,0 +1,58 @@
using System;
using System.IO;
namespace Semmle.Util.Logging
{
/// <summary>
/// A logger that outputs to a <code>csharp.log</code>
/// file.
/// </summary>
public sealed class FileLogger : ILogger
{
private readonly StreamWriter writer;
private readonly Verbosity verbosity;
private readonly bool logThreadId;
public FileLogger(Verbosity verbosity, string outputFile, bool logThreadId)
{
this.verbosity = verbosity;
this.logThreadId = logThreadId;
try
{
var dir = Path.GetDirectoryName(outputFile);
if (!string.IsNullOrEmpty(dir) && !System.IO.Directory.Exists(dir))
Directory.CreateDirectory(dir);
writer = new PidStreamWriter(
new FileStream(outputFile, FileMode.Append, FileAccess.Write, FileShare.ReadWrite, 8192));
}
catch (Exception ex) // lgtm[cs/catch-of-all-exceptions]
{
Console.Error.WriteLine("CodeQL: Couldn't initialise C# extractor output: " + ex.Message + "\n" + ex.StackTrace);
Console.Error.Flush();
throw;
}
}
public void Dispose()
{
writer.Dispose();
}
private static string GetSeverityPrefix(Severity s)
{
return "[" + s.ToString().ToUpper() + "] ";
}
public void Log(Severity s, string text, int? threadId = null)
{
if (verbosity.Includes(s))
{
threadId ??= Environment.CurrentManagedThreadId;
var prefix = this.logThreadId ? $"[{threadId:D3}] " : "";
writer.WriteLine(prefix + GetSeverityPrefix(s) + text);
}
}
}
}

View File

@@ -0,0 +1,25 @@
using System;
namespace Semmle.Util.Logging
{
/// <summary>
/// A logger.
/// </summary>
public interface ILogger : IDisposable
{
/// <summary>
/// Log the given text with the given severity.
/// </summary>
void Log(Severity s, string text, int? threadId = null);
void LogError(string text, int? threadId = null) => Log(Severity.Error, text, threadId);
void LogWarning(string text, int? threadId = null) => Log(Severity.Warning, text, threadId);
void LogInfo(string text, int? threadId = null) => Log(Severity.Info, text, threadId);
void LogDebug(string text, int? threadId = null) => Log(Severity.Debug, text, threadId);
void Log(Severity s, string text, params object?[] args) => Log(s, string.Format(text, args));
}
}

View File

@@ -1,7 +1,7 @@
using System.IO;
using System.Diagnostics;
namespace Semmle.Util
namespace Semmle.Util.Logging
{
/// <summary>
/// Utility stream writer that prefixes the current PID to some writes.

View File

@@ -0,0 +1,14 @@
namespace Semmle.Util.Logging
{
/// <summary>
/// The severity of a log message.
/// </summary>
public enum Severity
{
Trace = 1,
Debug = 2,
Info = 3,
Warning = 4,
Error = 5
}
}

View File

@@ -0,0 +1,16 @@
namespace Semmle.Util.Logging
{
/// <summary>
/// Log verbosity level.
/// </summary>
public enum Verbosity
{
Off = 0,
Error = 1,
Warning = 2,
Info = 3,
Debug = 4,
Trace = 5,
All = 6
}
}

View File

@@ -0,0 +1,59 @@
using System;
namespace Semmle.Util.Logging
{
public static class VerbosityExtensions
{
/// <summary>
/// Whether a message with the given severity must be included
/// for this verbosity level.
/// </summary>
public static bool Includes(this Verbosity v, Severity s)
{
switch (s)
{
case Severity.Trace:
return v >= Verbosity.Trace;
case Severity.Debug:
return v >= Verbosity.Debug;
case Severity.Info:
return v >= Verbosity.Info;
case Severity.Warning:
return v >= Verbosity.Warning;
case Severity.Error:
return v >= Verbosity.Error;
default:
throw new ArgumentOutOfRangeException(nameof(s));
}
}
public static Verbosity? ParseVerbosity(string? str, bool logThreadId)
{
if (str == null)
{
return null;
}
Verbosity? verbosity = str.ToLowerInvariant() switch
{
"off" => Verbosity.Off,
"errors" => Verbosity.Error,
"warnings" => Verbosity.Warning,
"info" or "progress" => Verbosity.Info,
"debug" or "progress+" => Verbosity.Debug,
"trace" or "progress++" => Verbosity.Trace,
"progress+++" => Verbosity.All,
_ => null
};
if (verbosity == null && str != null)
{
// We don't have a logger when this setting is parsed, so writing it to the console:
var prefix = logThreadId ? $"[{Environment.CurrentManagedThreadId:D3}] " : "";
Console.WriteLine($"{prefix}Error: Invalid verbosity level: '{str}'");
}
return verbosity;
}
}
}

View File

@@ -0,0 +1,6 @@
---
category: minorAnalysis
---
* The C# extractor now accepts an extractor option `logging.verbosity` that specifies the verbosity of the logs. The
option is added via `codeql database create --language=csharp -Ologging.verbosity=debug ...` or by setting the
corresponding environment variable `CODEQL_EXTRACTOR_CSHARP_OPTION_LOGGING_VERBOSITY`.