[Rgen] Add logging to the transformer.

src/rgen/Microsoft.Macios.Transformer/Main.cs

@@ -1,8 +1,16 @@
 using System.CommandLine;
 using Microsoft.CodeAnalysis.CSharp;
 using Microsoft.Macios.Transformer;
+using Serilog;
+using Serilog.Core;
+using Serilog.Events;
+using Serilog.Templates;
+using static System.Console;
 
 public class Program {
+	static internal readonly LoggingLevelSwitch LogLevelSwitch = new (LogEventLevel.Information);
+	public static ILogger logger = Log.ForContext<Program> ();
+
 	public static int Main (string [] args)
 	{
 		// Create options
@@ -31,19 +39,33 @@ public static int Main (string [] args)
 			"Absolute path to the sdk directory"
 		);
 
+		var verbosityOption = new Option<Verbosity> (["--verbosity", "-v"],
+			getDefaultValue: () => Verbosity.Normal) {
+			IsRequired = false,
+			Arity = ArgumentArity.ZeroOrOne,
+			Description = "Set the verbosity level"
+		};
+
 		// Create root command and add options
 		var rootCmd = new RootCommand ("command to convert outdated bindings to be rgen compatible") {
-			rspOption, destinationOption, forceOption, workingDirectoryOption, sdkPathOption
+			rspOption,
+			destinationOption,
+			forceOption,
+			workingDirectoryOption,
+			sdkPathOption,
+			verbosityOption
 		};
 
 		// If no arguments, show help and exit
 		if (args.Length == 0) {
-			rootCmd.InvokeAsync (new string [] { "--help" }).Wait ();
+			rootCmd.InvokeAsync (["--help"]).Wait ();
 			return 0;
 		}
 
 		// Set handler for parsing and executing
-		rootCmd.SetHandler (async (rspPath, destPath, workingDirectory, sdkPath, force) => {
+		rootCmd.SetHandler (async (rspPath, destPath, workingDirectory, sdkPath, force, verbosity) => {
+			WriteLine ($"Microsoft.Macios.Transformer v{typeof (Program).Assembly.GetName ().Version}, (c) Microsoft Corporation. All rights reserved.\n");
+
 			// Convert local to absolute, expand ~
 			rspPath = ToAbsolutePath (rspPath);
 			workingDirectory = ToAbsolutePath (workingDirectory);
@@ -53,14 +75,26 @@ public static int Main (string [] args)
 			ValidateRsp (rspPath);
 			ValidateSdk (sdkPath);
 			ValidateWorkingDirectory (workingDirectory);
+			ValidateVerbosity (verbosity);
 			PrepareDestination (destPath, force);
 
+			// logging options
+			Log.Logger = new LoggerConfiguration ()
+				.MinimumLevel.ControlledBy (LogLevelSwitch)
+				.Enrich.WithThreadName ()
+				.Enrich.WithThreadId ()
+				.Enrich.FromLogContext ()
+				.WriteTo.Console (new ExpressionTemplate (
+					"[{@t:HH:mm:ss} {@l:u3} {Substring(SourceContext, LastIndexOf(SourceContext, '.') + 1)} (Thread: {ThreadId})] {@m}\n"))
+				.CreateLogger ();
+
 			// Parse the .rsp file with Roslyn's CSharpCommandLineParser
-			var args = new string [] { $"@{rspPath}" };
+			var args = new [] { $"@{rspPath}" };
 			var parseResult = CSharpCommandLineParser.Default.Parse (args, workingDirectory, null);
-			Console.WriteLine ($"RSP parsed. Errors: {parseResult.Errors.Length}");
+			logger.Information ("RSP parsed. Errors: {ParserErrorLength}", parseResult.Errors.Length);
 			foreach (var resultError in parseResult.Errors) {
-				Console.WriteLine (resultError);
+				logger.Error ("{Error}", resultError);
+				WriteLine (resultError);
 			}
 
 			await Transformer.Execute (
@@ -70,7 +104,7 @@ await Transformer.Execute (
 				sdkDirectory: sdkPath
 			);
 		},
-			rspOption, destinationOption, workingDirectoryOption, sdkPathOption, forceOption
+			rspOption, destinationOption, workingDirectoryOption, sdkPathOption, forceOption, verbosityOption
 		);
 
 		// Invoke command
@@ -84,6 +118,7 @@ static string ToAbsolutePath (string path)
 			absolutePath = Path.GetFullPath (absolutePath);
 		return absolutePath;
 	}
+
 	static void ValidateRsp (string path)
 	{
 		if (string.IsNullOrWhiteSpace (path) || !File.Exists (path))
@@ -105,6 +140,18 @@ static void ValidateSdk (string path)
 			throw new DirectoryNotFoundException ("Working directory does not exist.");
 	}
 
+	static void ValidateVerbosity (Verbosity verbosity)
+	{
+		LogLevelSwitch.MinimumLevel = verbosity switch {
+			Verbosity.Quiet => LogEventLevel.Error,
+			Verbosity.Minimal => LogEventLevel.Error,
+			Verbosity.Normal => LogEventLevel.Information,
+			Verbosity.Detailed => LogEventLevel.Verbose,
+			Verbosity.Diagnostic => LogEventLevel.Verbose,
+			_ => LogEventLevel.Information,
+		};
+	}
+
 	static void PrepareDestination (string path, bool force)
 	{
 		if (Directory.Exists (path)) {

src/rgen/Microsoft.Macios.Transformer/Microsoft.Macios.Transformer.csproj

@@ -12,6 +12,11 @@
         <PackageReference Include="Marille" Version="0.5.3" />
         <PackageReference Include="Microsoft.CodeAnalysis.Common" Version="4.9.2" />
         <PackageReference Include="Microsoft.CodeAnalysis.CSharp" Version="4.9.2" />
+        <PackageReference Include="Serilog" Version="4.0.0" />
+        <PackageReference Include="Serilog.Enrichers.Thread" Version="4.0.0" />
+        <PackageReference Include="Serilog.Expressions" Version="4.0.0" />
+        <PackageReference Include="Serilog.Sinks.Console" Version="5.0.1" />
+        <PackageReference Include="Serilog.Sinks.Debug" Version="2.0.0" />
         <PackageReference Include="System.CommandLine" Version="2.0.0-beta4.22272.1" />
     </ItemGroup>
 

src/rgen/Microsoft.Macios.Transformer/Transformer.cs

@@ -10,6 +10,7 @@
 using Microsoft.Macios.Generator.Extensions;
 using Microsoft.Macios.Transformer.Extensions;
 using Microsoft.Macios.Transformer.Workers;
+using Serilog;
 
 namespace Microsoft.Macios.Transformer;
 
@@ -18,6 +19,7 @@ namespace Microsoft.Macios.Transformer;
 /// to be able to process the different transformations per binding type.
 /// </summary>
 class Transformer {
+	readonly static ILogger logger = Log.ForContext<Transformer> ();
 	readonly string destinationDirectory;
 	readonly Compilation compilation;
 	readonly HashSet<string>? namespaceFilter;
@@ -54,6 +56,7 @@ internal async Task<Hub> CreateHub ()
 		var configuration = new TopicConfiguration { Mode = ChannelDeliveryMode.AtLeastOnceSync };
 		foreach (var (topicName, transformer) in transformers) {
 			await hub.CreateAsync (topicName, configuration, transformer, transformer);
+			logger.Information ("Created new topic '{TopicName}'", topicName);
 		}
 
 		return hub;
@@ -63,38 +66,55 @@ internal async Task<Hub> CreateHub ()
 	{
 		// get the attrs, based on those return the correct topic to use
 		var attrs = symbol.GetAttributeData ();
+		logger.Debug ("Symbol '{SymbolName}' has [{Attributes}] attributes", symbol.Name, string.Join (", ", attrs.Keys));
+		logger.Debug ("Symbol '{SymbolName}' kind is '{SymbolKind}'", symbol.Name, symbol.TypeKind);
+
 		if (symbol.TypeKind == TypeKind.Enum) {
 			// simplest case, an error domain	
-			if (attrs.ContainsKey (AttributesNames.ErrorDomainAttribute))
+			if (attrs.ContainsKey (AttributesNames.ErrorDomainAttribute)) {
+				logger.Debug ("Symbol '{SymbolName}' is an error domain", symbol.Name);
 				return nameof (ErrorDomainTransformer);
+			}
 
 			// in this case, we need to check if the enum is a smart enum. 
 			// Smart enum: One of the enum members contains a FieldAttribute. Does NOT have to be ALL
 			var enumMembers = symbol.GetMembers ().OfType<IFieldSymbol> ().ToArray ();
 			foreach (var enumField in enumMembers) {
 				var fieldAttrs = enumField.GetAttributeData ();
 				if (fieldAttrs.ContainsKey (AttributesNames.FieldAttribute)) {
+					logger.Debug ("Symbol '{SymbolName}' is a smart enum", symbol.Name);
 					return nameof (SmartEnumTransformer);
 				}
 			}
 
 			// we have either a native enum of a regular enum, we will use the copy worker
+			logger.Debug ("Symbol '{SymbolName}' is a regular enum", symbol.Name);
 			return nameof (CopyTransformer);
 		}
 
 		if (attrs.ContainsKey (AttributesNames.BaseTypeAttribute)) {
 			// if can be a class or a protocol, check if the protocol attribute is present
 			if (attrs.ContainsKey (AttributesNames.ProtocolAttribute) ||
-				attrs.ContainsKey (AttributesNames.ModelAttribute))
+				attrs.ContainsKey (AttributesNames.ModelAttribute)) {
+				logger.Debug ("Symbol '{SymbolName}' is a protocol", symbol.Name);
 				return nameof (ProtocolTransformer);
-			if (attrs.ContainsKey (AttributesNames.CategoryAttribute))
+			}
+
+			if (attrs.ContainsKey (AttributesNames.CategoryAttribute)) {
+				logger.Debug ("Symbol '{SymbolName}' is a category", symbol.Name);
 				return nameof (CategoryTransformer);
+			}
+
+			logger.Debug ("Symbol '{SymbolName}' is a class", symbol.Name);
 			return nameof (ClassTransformer);
 		}
 
-		if (attrs.ContainsKey (AttributesNames.StrongDictionaryAttribute))
+		if (attrs.ContainsKey (AttributesNames.StrongDictionaryAttribute)) {
+			logger.Debug ("Symbol '{SymbolName}' is a strong dictionary", symbol.Name);
 			return nameof (StrongDictionaryTransformer);
+		}
 
+		logger.Warning ("Symbol '{SymbolName}' could not be matched to a transformer", symbol.Name);
 		return null;
 	}
 
@@ -108,8 +128,8 @@ internal bool Skip (SyntaxTree syntaxTree, ISymbol symbol, [NotNullWhen (false)]
 
 		if (namespaceFilter is not null && !namespaceFilter.Contains (symbolNamespace)) {
 			// TODO we could do this better by looking at the tree
-			Console.WriteLine (
-				$"Skipping {symbol.Name} because namespace {symbolNamespace} was not included in the transformation");
+			logger.Information ("Skipping '{SymbolName}' because namespace it was not included in the transformation",
+				symbol.Name, symbolNamespace);
 			// filtered out
 			return true;
 		}
@@ -140,26 +160,30 @@ internal async Task Execute ()
 				.DescendantNodes ()
 				.OfType<BaseTypeDeclarationSyntax> ().ToArray ();
 
-			Console.WriteLine ($"Found {declarations.Length} interfaces in {tree.FilePath}");
+			logger.Debug ("Found '{Declarations}' interfaces in '{FilePath}'", declarations.Length, tree.FilePath);
 
 			// loop over the declarations and send them to the hub
 			foreach (var declaration in declarations) {
 				var symbol = model.GetDeclaredSymbol (declaration);
 				if (symbol is null) {
 					// skip the transformation because the symbol is null
+					logger.Warning ("Could not get the symbol for '{Declaration}'", declaration.Identifier);
 					continue;
 				}
 
-				if (Skip (tree, symbol, out var outputDirectory))
+				if (Skip (tree, symbol, out var outputDirectory)) {
 					// matched the filter
+					logger.Information ("Skipping '{SymbolName}' because it was filtered out", symbol.Name);
 					continue;
+				}
 
 				// create the destination directory if needed, this is the only location we should be creating directories
 				Directory.CreateDirectory (outputDirectory);
 
 				var topicName = SelectTopic (symbol);
 				if (topicName is not null && transformers.TryGetValue (topicName, out var transformer)) {
 					await hub.PublishAsync (topicName, transformer.CreateMessage (tree, symbol));
+					logger.Information ("Published '{SymbolName}' to '{TopicName}'", symbol.Name, topicName);
 				}
 			}
 		}
@@ -172,7 +196,7 @@ internal async Task Execute ()
 	public static Task Execute (string destinationDirectory, string rspFile, string workingDirectory,
 		string sdkDirectory)
 	{
-		Console.WriteLine ("Executing transformation");
+		logger.Information ("Executing transformation");
 		// the transformation works as follows. We first need to parse the rsp file to create a compilation
 		// to do so we relay on the csharp compiler, there is not much we really need to do. If the parsing 
 		// is wrong, we throw an exception. 
@@ -190,7 +214,9 @@ public static Task Execute (string destinationDirectory, string rspFile, string
 			.WithDocumentationMode (DocumentationMode.None);
 
 		var references = parseResult.GetReferences (workingDirectory, sdkDirectory);
+		logger.Information ("References {References}", references.Length);
 		var parsedSource = parseResult.GetSourceFiles (updatedParseOptions);
+		logger.Information ("Parsed {Files} files", parsedSource.Length);
 
 		var compilation = CSharpCompilation.Create (
 			assemblyName: $"{parseResult.CompilationName}-transformer",
@@ -199,14 +225,15 @@ public static Task Execute (string destinationDirectory, string rspFile, string
 			options: parseResult.CompilationOptions);
 
 		var diagnostics = compilation.GetDiagnostics ();
-		Console.WriteLine ($"Diagnostics length {diagnostics.Length}");
+		logger.Debug ("Total diagnostics length {DiagnosticsLength}", diagnostics.Length);
 		// collect all the compilation errors, ignoring the warnings, if any error is found, we throw an exception
 		var errors = diagnostics.Where (d => d.Severity == DiagnosticSeverity.Error).ToArray ();
 		if (errors.Length > 0) {
 			var sb = new StringBuilder ();
 			foreach (var resultError in errors) {
 				sb.AppendLine ($"{resultError}");
 			}
+			logger.Error ("Error during workspace compilation: {Error}", sb);
 			throw new Exception ($"Error during workspace compilation: {sb}");
 		}
 

src/rgen/Microsoft.Macios.Transformer/Verbosity.cs

@@ -0,0 +1,13 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+namespace Microsoft.Macios.Transformer;
+
+enum Verbosity {
+	Quiet,
+	Minimal,
+	Normal,
+	Detailed,
+	Diagnostic
+}
+

src/rgen/Microsoft.Macios.Transformer/Workers/CategoryTransformer.cs

@@ -3,22 +3,27 @@
 
 using Marille;
 using Microsoft.CodeAnalysis;
+using Serilog;
 
 namespace Microsoft.Macios.Transformer.Workers;
 
 public class CategoryTransformer (string destinationDirectory) : ITransformer<(string Path, string SymbolName)> {
 
+	readonly static ILogger logger = Log.ForContext<CategoryTransformer> ();
 	public bool UseBackgroundThread { get => true; }
 
 	public Task ConsumeAsync ((string Path, string SymbolName) message, CancellationToken token = new ())
 	{
-		Console.WriteLine ($"CategoryTransformer: Transforming class {message.SymbolName} for path {message.Path} to {destinationDirectory}");
+		logger.Information ("Transforming {SymbolName} for path {Path} to {DestinationDirectory}",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.Delay (10);
 	}
 
 	public Task ConsumeAsync ((string Path, string SymbolName) message, Exception exception,
 		CancellationToken token = new CancellationToken ())
 	{
+		logger.Error (exception, "Error transforming {SymbolName} for path {Path} to {DestinationDirectory}:",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.CompletedTask;
 	}
 

src/rgen/Microsoft.Macios.Transformer/Workers/ClassTransformer.cs

@@ -3,21 +3,26 @@
 
 using Marille;
 using Microsoft.CodeAnalysis;
+using Serilog;
 
 namespace Microsoft.Macios.Transformer.Workers;
 
 public class ClassTransformer (string destinationDirectory) : ITransformer<(string Path, string SymbolName)> {
 
+	readonly static ILogger logger = Log.ForContext<ClassTransformer> ();
 	public ValueTask DisposeAsync () => ValueTask.CompletedTask;
 	public Task ConsumeAsync ((string Path, string SymbolName) message, CancellationToken token = new ())
 	{
-		Console.WriteLine ($"ClassTransformer: Transforming class {message.SymbolName} for path {message.Path} to {destinationDirectory}");
+		logger.Information ("Transforming {SymbolName} for path {Path} to {DestinationDirectory}",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.Delay (10);
 	}
 
 	public Task ConsumeAsync ((string Path, string SymbolName) message, Exception exception,
 		CancellationToken token = new CancellationToken ())
 	{
+		logger.Error (exception, "Error transforming {SymbolName} for path {Path} to {DestinationDirectory}:",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.CompletedTask;
 	}
 

src/rgen/Microsoft.Macios.Transformer/Workers/CopyTransformer.cs

@@ -3,22 +3,27 @@
 
 using Marille;
 using Microsoft.CodeAnalysis;
+using Serilog;
 
 namespace Microsoft.Macios.Transformer.Workers;
 
 public class CopyTransformer (string destinationDirectory) : ITransformer<(string Path, string SymbolName)> {
 
+	readonly static ILogger logger = Log.ForContext<CopyTransformer> ();
 	public bool UseBackgroundThread { get => true; }
 
 	public Task ConsumeAsync ((string Path, string SymbolName) message, CancellationToken token = new ())
 	{
-		Console.WriteLine ($"CopyTransformer: Transforming class {message.SymbolName} for path {message.Path} to {destinationDirectory}");
+		logger.Information ("Transforming {SymbolName} for path {Path} to {DestinationDirectory}",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.Delay (10);
 	}
 
 	public Task ConsumeAsync ((string Path, string SymbolName) message, Exception exception,
 		CancellationToken token = new CancellationToken ())
 	{
+		logger.Error (exception, "Error transforming {SymbolName} for path {Path} to {DestinationDirectory}:",
+			message.SymbolName, message.Path, destinationDirectory);
 		return Task.CompletedTask;
 	}