Skip to content

Commit

Permalink
Adding logging down the stack
Browse files Browse the repository at this point in the history
  • Loading branch information
aaronpowell committed Aug 9, 2024
1 parent 7aa14be commit 06d3f9a
Show file tree
Hide file tree
Showing 11 changed files with 106 additions and 25 deletions.
1 change: 1 addition & 0 deletions src/CSnakes.Runtime.Tests/CSnakes.Runtime.Tests.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@
<PackageReference Include="python" Version="3.12.4" />
<PackageReference Include="xunit" Version="2.5.3" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.5.3" />
<PackageReference Include="MartinCostello.Logging.XUnit" Version="0.4.0" />
</ItemGroup>

<ItemGroup>
Expand Down
3 changes: 3 additions & 0 deletions src/CSnakes.Runtime.Tests/Converter/ConverterTestBase.cs
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;

namespace CSnakes.Runtime.Tests.Converter;
public class ConverterTestBase : IDisposable
Expand All @@ -16,6 +17,8 @@ public ConverterTestBase()
pb.WithHome(Environment.CurrentDirectory);

pb.FromNuGet("3.12.4").FromMacOSInstallerLocator("3.12").FromEnvironmentVariable("Python3_ROOT_DIR", "3.12.4");

services.AddLogging(builder => builder.AddXUnit());
})
.Build();

Expand Down
3 changes: 3 additions & 0 deletions src/CSnakes.Runtime/IPythonEnvironment.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using CSnakes.Runtime.CPython;
using Microsoft.Extensions.Logging;

namespace CSnakes.Runtime;

Expand All @@ -11,4 +12,6 @@ public string Version
return CPythonAPI.Py_GetVersion() ?? "No version available";
}
}

public ILogger<IPythonEnvironment> Logger { get; }
}
4 changes: 3 additions & 1 deletion src/CSnakes.Runtime/IServiceCollectionExtensions.cs
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
using CSnakes.Runtime.Locators;
using CSnakes.Runtime.PackageManagement;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

namespace CSnakes.Runtime;
/// <summary>
Expand All @@ -24,10 +25,11 @@ public static IPythonEnvironmentBuilder WithPython(this IServiceCollection servi
var envBuilder = sp.GetRequiredService<IPythonEnvironmentBuilder>();
var locators = sp.GetServices<PythonLocator>();
var installers = sp.GetServices<IPythonPackageInstaller>();
var logger = sp.GetRequiredService<ILogger<IPythonEnvironment>>();

var options = envBuilder.GetOptions();

return PythonEnvironment.GetPythonEnvironment(locators, installers, options);
return PythonEnvironment.GetPythonEnvironment(locators, installers, options, logger);
});

return pythonBuilder;
Expand Down
2 changes: 2 additions & 0 deletions src/CSnakes.Runtime/PackageManagement/PipInstaller.cs
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ private void InstallPackagesWithPip(string home, string? virtualEnvironmentLocat

if (virtualEnvironmentLocation is not null)
{
logger.LogInformation("Using virtual environment at {VirtualEnvironmentLocation} to install packages with pip.", virtualEnvironmentLocation);
string venvScriptPath = Path.Combine(virtualEnvironmentLocation, RuntimeInformation.IsOSPlatform(OSPlatform.Windows) ? "Scripts" : "bin");
startInfo.FileName = Path.Combine(venvScriptPath, pipBinaryName);
startInfo.EnvironmentVariables["PATH"] = $"{venvScriptPath};{Environment.GetEnvironmentVariable("PATH")}";
Expand Down Expand Up @@ -66,6 +67,7 @@ private void InstallPackagesWithPip(string home, string? virtualEnvironmentLocat

if (process.ExitCode != 0)
{
logger.LogError("Failed to install packages.");
throw new InvalidOperationException("Failed to install packages.");
}
}
Expand Down
69 changes: 56 additions & 13 deletions src/CSnakes.Runtime/PythonEnvironment.cs
Original file line number Diff line number Diff line change
@@ -1,46 +1,58 @@
using CSnakes.Runtime.CPython;
using CSnakes.Runtime.Locators;
using CSnakes.Runtime.PackageManagement;
using Microsoft.Extensions.Logging;
using System.Diagnostics;
using System.Runtime.InteropServices;

namespace CSnakes.Runtime;

internal class PythonEnvironment : IPythonEnvironment
{
public ILogger<IPythonEnvironment> Logger { get; private set; }

private readonly CPythonAPI api;
private bool disposedValue;

private static IPythonEnvironment? pythonEnvironment;
private readonly static object locker = new();

public static IPythonEnvironment GetPythonEnvironment(IEnumerable<PythonLocator> locators, IEnumerable<IPythonPackageInstaller> packageInstallers, PythonEnvironmentOptions options)
public static IPythonEnvironment GetPythonEnvironment(IEnumerable<PythonLocator> locators, IEnumerable<IPythonPackageInstaller> packageInstallers, PythonEnvironmentOptions options, Microsoft.Extensions.Logging.ILogger<IPythonEnvironment> logger)
{
if (pythonEnvironment is null)
if (pythonEnvironment is null)
{
lock (locker)
{
lock(locker)
{
pythonEnvironment ??= new PythonEnvironment(locators, packageInstallers, options);
}
pythonEnvironment ??= new PythonEnvironment(locators, packageInstallers, options, logger);
}
return pythonEnvironment;
}
return pythonEnvironment;
}

private PythonEnvironment(
IEnumerable<PythonLocator> locators,
IEnumerable<IPythonPackageInstaller> packageInstallers,
PythonEnvironmentOptions options)
PythonEnvironmentOptions options,
ILogger<IPythonEnvironment> logger)
{
Logger = logger;

var location = locators
.Where(locator => locator.IsSupported())
.Select(locator => locator.LocatePython())
.FirstOrDefault(loc => loc is not null)
?? throw new InvalidOperationException("Python installation not found.");
.FirstOrDefault(loc => loc is not null);

if (location is null)
{
logger.LogError("Python installation not found. There were {LocatorCount} locators registered.", locators.Count());
throw new InvalidOperationException("Python installation not found.");
}

string home = options.Home;

if (!Directory.Exists(home))
{
logger.LogError("Python home directory does not exist: {Home}", home);
throw new DirectoryNotFoundException("Python home directory does not exist.");
}

Expand All @@ -49,6 +61,8 @@ private PythonEnvironment(
EnsureVirtualEnvironment(location, options.VirtualEnvironmentPath);
}

logger.LogInformation("Setting up Python environment from {PythonLocation} using home of {Home}", location.Folder, home);

foreach (var installer in packageInstallers)
{
installer.InstallPackages(home, options.VirtualEnvironmentPath);
Expand All @@ -68,33 +82,58 @@ private PythonEnvironment(

if (options.ExtraPaths is { Length: > 0 })
{
logger.LogInformation("Adding extra paths to PYTHONPATH: {ExtraPaths}", options.ExtraPaths);
api.PythonPath = api.PythonPath + sep + string.Join(sep, options.ExtraPaths);
}
api.Initialize();
}

private static void EnsureVirtualEnvironment(PythonLocationMetadata pythonLocation, string? venvPath)
private void EnsureVirtualEnvironment(PythonLocationMetadata pythonLocation, string? venvPath)
{
if (venvPath is null)
{
Logger.LogError("Virtual environment location is not set but it was requested to be created.");
throw new ArgumentNullException(nameof(venvPath), "Virtual environment location is not set.");
}

if (!Directory.Exists(venvPath))
{
Logger.LogInformation("Creating virtual environment at {VirtualEnvPath}", venvPath);

ProcessStartInfo startInfo = new()
{
WorkingDirectory = pythonLocation.Folder,
FileName = "python",
Arguments = $"-m venv {venvPath}"
};
startInfo.RedirectStandardError = true;
startInfo.RedirectStandardOutput = true;

using Process process = new() { StartInfo = startInfo };
process.OutputDataReceived += (sender, e) =>
{
if (!string.IsNullOrEmpty(e.Data))
{
Logger.LogInformation("{Data}", e.Data);
}
};

process.ErrorDataReceived += (sender, e) =>
{
if (!string.IsNullOrEmpty(e.Data))
{
Logger.LogError("{Data}", e.Data);
}
};

process.Start();
process.BeginErrorReadLine();
process.BeginOutputReadLine();
process.WaitForExit();
}
}

private static CPythonAPI SetupStandardLibrary(PythonLocationMetadata pythonLocationMetadata, string versionPath, string majorVersion, char sep)
private CPythonAPI SetupStandardLibrary(PythonLocationMetadata pythonLocationMetadata, string versionPath, string majorVersion, char sep)
{
string pythonDll = string.Empty;
string pythonPath = string.Empty;
Expand Down Expand Up @@ -129,6 +168,10 @@ private static CPythonAPI SetupStandardLibrary(PythonLocationMetadata pythonLoca
{
throw new PlatformNotSupportedException("Unsupported platform.");
}

Logger.LogInformation("Python DLL: {PythonDLL}", pythonDll);
Logger.LogInformation("Python path: {PythonPath}", pythonPath);

var api = new CPythonAPI(pythonDll)
{
PythonPath = pythonPath
Expand All @@ -152,7 +195,7 @@ protected virtual void Dispose(bool disposing)
api.Dispose();
if (pythonEnvironment is not null)
{
lock(locker)
lock (locker)
{
if (pythonEnvironment is not null)
{
Expand Down
2 changes: 2 additions & 0 deletions src/CSnakes.Tests/BasicSmokeTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
using Microsoft.CodeAnalysis;
using Microsoft.CodeAnalysis.CSharp;
using Microsoft.CodeAnalysis.Text;
using Microsoft.Extensions.Logging;
using PythonSourceGenerator.Parser;
using PythonSourceGenerator.Reflection;
using System.ComponentModel;
Expand Down Expand Up @@ -54,6 +55,7 @@ public void TestGeneratedSignature(string code, string expected)
.AddReferences(MetadataReference.CreateFromFile(typeof(TypeConverter).Assembly.Location))
.AddReferences(MetadataReference.CreateFromFile(typeof(IReadOnlyDictionary<,>).Assembly.Location))
.AddReferences(MetadataReference.CreateFromFile(typeof(IPythonEnvironmentBuilder).Assembly.Location))
.AddReferences(MetadataReference.CreateFromFile(typeof(ILogger<>).Assembly.Location))
.AddReferences(MetadataReference.CreateFromFile(AppDomain.CurrentDomain.GetAssemblies().Single(a => a.GetName().Name == "netstandard").Location)) // TODO: (track) Ensure 2.0
.AddReferences(MetadataReference.CreateFromFile(AppDomain.CurrentDomain.GetAssemblies().Single(a => a.GetName().Name == "System.Runtime").Location))
.AddReferences(MetadataReference.CreateFromFile(AppDomain.CurrentDomain.GetAssemblies().Single(a => a.GetName().Name == "System.Collections").Location))
Expand Down
21 changes: 15 additions & 6 deletions src/CSnakes/PythonStaticGenerator.cs
Original file line number Diff line number Diff line change
Expand Up @@ -28,8 +28,6 @@ public void Initialize(IncrementalGeneratorInitializationContext context)

// Convert snakecase to pascal case
var pascalFileName = string.Join("", fileName.Split('_').Select(s => char.ToUpperInvariant(s[0]) + s.Substring(1)));

IEnumerable<MethodDefinition> methods;
// Read the file
var code = file.GetText(sourceContext.CancellationToken);

Expand All @@ -45,8 +43,8 @@ public void Initialize(IncrementalGeneratorInitializationContext context)
sourceContext.ReportDiagnostic(Diagnostic.Create(new DiagnosticDescriptor("PSG004", "PythonStaticGenerator", error.Message, "PythonStaticGenerator", DiagnosticSeverity.Error, true), errorLocation));
}

if (result) {
methods = ModuleReflection.MethodsFromFunctionDefinitions(functions, fileName);
if (result) {
IEnumerable<MethodDefinition> methods = ModuleReflection.MethodsFromFunctionDefinitions(functions, fileName);
string source = FormatClassFromMethods(@namespace, pascalFileName, methods, fileName);
sourceContext.AddSource($"{pascalFileName}.py.cs", source);
sourceContext.ReportDiagnostic(Diagnostic.Create(new DiagnosticDescriptor("PSG002", "PythonStaticGenerator", $"Generated {pascalFileName}.py.cs", "PythonStaticGenerator", DiagnosticSeverity.Info, true), Location.None));
Expand All @@ -70,14 +68,20 @@ public static string FormatClassFromMethods(string @namespace, string pascalFile
using System.Collections.Generic;
using System.ComponentModel;
using Microsoft.Extensions.Logging;
namespace {{@namespace}}
{
public static class {{pascalFileName}}Extensions
{
private static readonly I{{pascalFileName}} instance = new {{pascalFileName}}Internal();
private static I{{pascalFileName}}? instance;
public static I{{pascalFileName}} {{pascalFileName}}(this IPythonEnvironment env)
{
if (instance is null)
{
instance = new {{pascalFileName}}Internal(env.Logger);
}
return instance;
}
Expand All @@ -87,16 +91,21 @@ private class {{pascalFileName}}Internal : I{{pascalFileName}}
private readonly PyObject module;
internal {{pascalFileName}}Internal()
private readonly ILogger<IPythonEnvironment> logger;
internal {{pascalFileName}}Internal(ILogger<IPythonEnvironment> logger)
{
this.logger = logger;
using (GIL.Acquire())
{
logger.LogInformation("Importing module {ModuleName}", "{{fileName}}");
module = Import.ImportModule("{{fileName}}");
}
}
public void Dispose()
{
logger.LogInformation("Disposing module {ModuleName}", "{{fileName}}");
module.Dispose();
}
Expand Down
20 changes: 16 additions & 4 deletions src/CSnakes/Reflection/MethodReflection.cs
Original file line number Diff line number Diff line change
Expand Up @@ -141,11 +141,23 @@ public static MethodDefinition FromMethod(PythonFunctionDefinition function, str
SyntaxKind.SimpleMemberAccessExpression,
IdentifierName("__underlyingPythonFunc"),
IdentifierName("Call")),
ArgumentList(
SeparatedList(pythonCastArguments))))))))
.WithUsingKeyword(
Token(SyntaxKind.UsingKeyword));
ArgumentList(SeparatedList(pythonCastArguments))))))))
.WithUsingKeyword(Token(SyntaxKind.UsingKeyword));
StatementSyntax[] statements = [
ExpressionStatement(
InvocationExpression(
MemberAccessExpression(
SyntaxKind.SimpleMemberAccessExpression,
IdentifierName("logger"),
IdentifierName("LogInformation")))
.WithArgumentList(
ArgumentList(
SeparatedList(
[
Argument(LiteralExpression(SyntaxKind.StringLiteralExpression, Literal("Invoking Python function: {FunctionName}"))),
Argument(LiteralExpression(SyntaxKind.StringLiteralExpression, Literal(function.Name)))
])))
),
moduleDefinition,
.. pythonConversionStatements,
callStatement,
Expand Down
1 change: 1 addition & 0 deletions src/Integration.Tests/Integration.Tests.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,7 @@
<PackageReference Include="xunit" Version="2.5.3" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.5.3" />
<PackageReference Include="python" Version="3.12.4" />
<PackageReference Include="MartinCostello.Logging.XUnit" Version="0.4.0" />
</ItemGroup>

<ItemGroup>
Expand Down
5 changes: 4 additions & 1 deletion src/Integration.Tests/IntegrationTestBase.cs
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;

namespace Integration.Tests;
public class IntegrationTestBase : IDisposable
Expand All @@ -15,7 +16,9 @@ public IntegrationTestBase()
var pb = services.WithPython();
pb.WithHome(Path.Join(Environment.CurrentDirectory, "python"));

pb.FromNuGet("3.12.4").FromMacOSInstallerLocator("3.12").FromEnvironmentVariable("Python3_ROOT_DIR", "3.12.4");
pb.FromNuGet("3.12.4").FromMacOSInstallerLocator("3.12").FromEnvironmentVariable("Python3_ROOT_DIR", "3.12.4");

services.AddLogging(builder => builder.AddXUnit());
})
.Build();

Expand Down

0 comments on commit 06d3f9a

Please sign in to comment.