DNNE icon indicating copy to clipboard operation
DNNE copied to clipboard

Question about IntPtr to managed object

Open DerekSMorin opened this issue 2 years ago • 7 comments

Hi, we have a "working" solution that allows native code to use managed logging with ILogger.

We are storing lots of function pointers and DNNE looks like a beautiful way to greatly simplify our code.

From the screenshots it looks like we pass the same IntPtr for the loggerHandle but when running the call with DNNE we get:

System.InvalidCastException: 'Unable to cast object of type 'Microsoft.Extensions.Logging.Logger' to type 'Microsoft.Extensions.Logging.ILogger'.'

Manually putting various casts into the watch window seem to work.

Examples: (ILogger?)handle.Target handle.Target as ILogger

Wondering if there are any ideas of what could be going on?

Here is the calling code with both the old and the new way with DNNE.

   void LoggerProxy::Log( Level level, std::wstring logMessage )
   {
      // This call seems to work for casting purposes?
      _loggerFunction( _logger->Handle(), (int) level, logMessage.c_str() );

      // Call use DNNE - from InfrastructureNE.h
      ::Log( (intptr_t) _logger->Handle(), (int32_t) level, (intptr_t) logMessage.c_str() );
   }

Here is the method we are calling into:

   [UnmanagedCallersOnly(CallConvs = new[] { typeof(CallConvCdecl) })]
   public static void Log(IntPtr loggerHandle, int loglevel, IntPtr message)
   {
      try
      {
         var handle = GCHandle.FromIntPtr(loggerHandle);

         var logmessagetemp = Marshal.PtrToStringUni(message); // move a copy of this up here, to verify it works before exception

         var logger = (ILogger?)handle.Target; // exception when using DNNE
         if (logger == null)
         {
            throw new ArgumentException("Unable to convert loggerHandle to ILogger");
         }
         var logmessage = Marshal.PtrToStringUni(message);
         logger.Log((LogLevel)loglevel, logmessage);
      }
      catch (Exception ex)
      {
         var logger = StaticLogging.CreateLogger(typeof(LoggerFactoryProxyService));
         logger.LogError($"Unable to write log from native code.  The log message will be lost.  Reason: {ex.Message}");
      }
   }

Screenshot of the "working" call:

image

Screenshot of the call with DNNE

image

DerekSMorin avatar Jul 27 '22 15:07 DerekSMorin

Can you please provide the Type Fullname of both calls of both the ILogger type and Logger type. Looks like there is a cast of Logger to ILogger from different assemblies.

var handle = GCHandle.FromIntPtr(loggerHandle);
Debug.WriteLine(handle.Target.GetType().Fullname);
Debug.WriteLine(typeof(ILogger).Fullname);

mwetzko avatar Jul 27 '22 16:07 mwetzko

@DerekSMorin This is likely related to confusion with AssemblyLoadContexts in the process. The problem is that there is a type A that is loaded in two different AssemblyLoadContext instances and they are not the same type according to the runtime - even though they come from the same assembly on disk. This can be confirmed using AssemblyLoadContext.GetLoadContext() with the ILogger types.

AaronRobinsonMSFT avatar Jul 27 '22 16:07 AaronRobinsonMSFT

Thanks for the speedy replies, @mwetzko and @AaronRobinsonMSFT .

I was able to get the assembly load context in both scenarios.

        var handleContext = System.Runtime.Loader.AssemblyLoadContext.GetLoadContext(handle.Target.GetType().Assembly);
        var iloggerContext = System.Runtime.Loader.AssemblyLoadContext.GetLoadContext(typeof(ILogger).Assembly);
        

In the working scenario ( our original PInvoke implementation ) both had:

{"Default" System.Runtime.Loader.DefaultAssemblyLoadContext #0}

In the DNNE scenario, the handleContext was:

{"IsolatedComponentLoadContext(C:\Development\Source\Bentley.Reliability\ReliabilityUpdateService\src\Bentley.OQ.APMUpdateService\bin\x64\Debug\net6.0\Infrastructure.dll)" Internal.Runtime.InteropServices.IsolatedComponentLoadContext #1}

DerekSMorin avatar Jul 27 '22 16:07 DerekSMorin

In the DNNE scenario, the handleContext was:

{"IsolatedComponentLoadContext(C:\Development\Source\Bentley.Reliability\ReliabilityUpdateService\src\Bentley.OQ.APMUpdateService\bin\x64\Debug\net6.0\Infrastructure.dll)" Internal.Runtime.InteropServices.IsolatedComponentLoadContext #1}

Right, this is the issue. There are likely two ILogger types available in your application and the one you are using is in a different context than the one that is implemented on the type in question. I'd need to know more about your application to provide guidance here, but this is a common issue with ALCs. A potential workaround here is to force your plug-in into the Default ALC, but that is rather complex and you are then trading one complexity for another.

@elinor-fung Do you have an idea on the easiest way to address this problem?

AaronRobinsonMSFT avatar Jul 27 '22 17:07 AaronRobinsonMSFT

In the DNNE scenario, the handleContext was:

{"IsolatedComponentLoadContext(C:\Development\Source\Bentley.Reliability\ReliabilityUpdateService\src\Bentley.OQ.APMUpdateService\bin\x64\Debug\net6.0\Infrastructure.dll)" Internal.Runtime.InteropServices.IsolatedComponentLoadContext https://github.com/AaronRobinsonMSFT/DNNE/issues/1}

And the iloggerContext AssemblyLoadContext (ALC) was still "Default"?

A potential workaround here is to force your plug-in into the Default ALC, but that is rather complex and you are then trading one complexity for another.

It is more getting shared dependencies (so probably Microsoft.Extensions.Logging in this case) loaded in the Default ALC, but not the isolated ALC created for the DNNE library. This is a similar idea to a managed app with plugins where the plugin needs to reference shared dependencies such that they don't get loaded into the ALC created for the plugin.

As @AaronRobinsonMSFT said, I think I'd need some more information about your application to provide better guidance. Some questions:

  • Where does _logger->Handle() come from?
  • Is the .NET runtime first loaded via DNNE? Or is it already loaded via some other mechanism (for example, a .NET application that calls into native code which then calls back into .NET via DNNE)?
    • From the callstack in your screenshot, it looks like the application is going from C# -> C++ -> (DNNE) C#
  • Is there just one assembly using DNNE or are there multiple?
    • Each assembly would be loaded into its own ALC

elinor-fung avatar Jul 27 '22 23:07 elinor-fung

The .NET runtime is first loaded by an ASP .NET Core application.

We currently use PInvoke to setup delegates to be able to create ILoggers from native code. We have a LoggerFactoryProxy which has delegates to create loggers, log a message, tell if a log category is enabled, beginscope. Every time we want to add a new function we end up having to setup more delegates. We want to use DNNE so we don't have to keep creating constructors with long lists of delegates. We have been using IntPtrs for handles to managed objects. The logger handle is something we store after creating an ILogger using PInvoke. This works in the purely PInvoke case, but when introducing DNNE the same handle gives us the InvalidCastException. I tested this by leaving the old log method to be called before the new log method.

So far we have just one dll using DNNE. We are just testing it out as a proof of concept at this point.

Is it possible that this would be resolved in .NET 7? I think it was going to stop using an IsolatedComponentLoad context? Or would DNNE still be using an IsolatedComponentLoad context? ( and sorry if any of these questions are getting ahead of myself )

DerekSMorin avatar Jul 28 '22 13:07 DerekSMorin

Is it possible that this would be resolved in .NET 7?

No at this point. The isolation of components actually makes things far less complicated for many scenarios. Since DNNE is being used with an existing activated runtime, this is a case where it does create annoyances.

I think it was going to stop using an IsolatedComponentLoad context? Or would DNNE still be using an IsolatedComponentLoad context? ( and sorry if any of these questions are getting ahead of myself )

The IsolatedComponentLoad is needed for many scenarios to help unloadability and to create a sane debugging experience. We are considering an option in the future, but that for .NET 8. See the C++/CLI approach, https://github.com/dotnet/runtime/issues/61105.

A potential solution here is to load an interface that is loaded into the Default ALC for the application and used by the DNNE generated component.

AaronRobinsonMSFT avatar Aug 05 '22 16:08 AaronRobinsonMSFT

I had a similar issue where my assemblies are loaded twice: Once by the native exports and once by COM into the same process. My solution to communication between the two was to set it up as RPC using StreamJsonRpc. That way client and server use normal .NET interfaces to communicate no need to worry about AssemblyLoadContext.

roboz0r avatar Nov 16 '22 05:11 roboz0r

@roboz0r That is a great solution. Thank you for sharing. If you have an example project to share that would be most helpful.

AaronRobinsonMSFT avatar Nov 16 '22 05:11 AaronRobinsonMSFT

My project isn't open source but I can share the relevant parts for RPC. Code is in F# but it shouldn't be too difficult to turn back into C# if required.

type IServer = // Define your interface

module Transport = 
    let serverPipe pipeName = 
        new NamedPipeServerStream(
            pipeName, 
            PipeDirection.InOut, 
            NamedPipeServerStream.MaxAllowedServerInstances, 
            PipeTransmissionMode.Byte, 
            PipeOptions.Asynchronous)
      
    let clientPipe pipeName = 
        new NamedPipeClientStream(".", pipeName, PipeDirection.InOut, PipeOptions.Asynchronous)

    let formatter () : IJsonRpcMessageFormatter = new JsonMessageFormatter()

module RPCServer =

    open System
    open StreamJsonRpc
    
    /// Creates a background thread to handle incoming connections to the server. 
    /// 'T should be the interface type that specifies the server data contract.
    let createRPCServer<'T when 'T: not struct> (server:'T) pipeName = 
        
        let rec loop () = async {
            // A new pipe must be created for each request
            let pipe = Transport.serverPipe pipeName
            do! pipe.WaitForConnectionAsync() |> Async.AwaitTask
            let handler = new HeaderDelimitedMessageHandler(pipe, pipe, Transport.formatter())
            
            use rpc = new JsonRpc(handler)
            rpc.ExceptionStrategy <- ExceptionProcessing.ISerializable
            rpc.AddLocalRpcTarget<'T>(server, JsonRpcTargetOptions())
            rpc.StartListening() 
            // No need to await completion, just loop and prepare new pipe for next request
            let _ = rpc.Completion
            return! loop()
        }
        loop ()
        |> Async.Start

module RPCClient =

    open System
    open StreamJsonRpc

    /// Returns a proxy interface to the server once the connection has been established.
    /// 'T should be the interface type that specifies the server data contract.
    let getClientProxy<'T when 'T: not struct> pipeName = 
        async {
            let! tok = Async.CancellationToken
            let pipe = Transport.clientPipe pipeName
            let handler = new HeaderDelimitedMessageHandler(pipe, pipe, Transport.formatter())
            // Client pipe must be connected before returning interface
            do! pipe.ConnectAsync(tok) |> Async.AwaitTask
            return JsonRpc.Attach<'T>(handler)
        }    

roboz0r avatar Nov 16 '22 06:11 roboz0r