Adding logging to your objects without changing them (much)! Using MarshalByRefObject and RealProxy.
I was attempting to add very detailed logging (tracing) to my application. In order to do that, I had to change hundreds of objects. That wouldn't do. Fortunately, .NET has a nice feature called RealProxy. Let's see a quick and dirty example:class Program
{
static void Main(string[] args)
{
JsonConvert.DefaultSettings = () => new JsonSerializerSettings
{
ReferenceLoopHandling = ReferenceLoopHandling.Ignore,
NullValueHandling = NullValueHandling.Ignore,
Formatting = Formatting.Indented
};
Test test = new Test();
test.field = "test";
test.Property = "Test";
string outObject;
string refObject = "ref";
var result = test.Method("test1", "test2", ref refObject, out outObject);
Console.WriteLine(JsonConvert.SerializeObject(new object[] {
test,
result,
refObject,
outObject
})
);
Console.ReadKey();
}
}
class Test
{
public string field;
public string Property { get; set; }
public string Method(string parameter1, string parameter2,
ref string refObject, out string outObject)
{
if (parameter1 == null)
throw new ArgumentNullException("Parameter one cannot be null");
refObject += " reffed";
outObject = "outed";
return $"{parameter1} : {parameter2}";
}
}
So I defined an object with a field, a property and a method. That's what my application does. It then displays the object and the result of the method call. Here is the result:
[
{
"field": "test",
"Property": "Test"
},
"test1 : test2",
"ref reffed",
"outed"
]
I would like to log everything that happens with my Test object. Well, as such I can't do anything, I need to change the code a bit, like this:
class Program
{
static void Main(string[] args)
{
JsonConvert.DefaultSettings = ()=>new JsonSerializerSettings
{
ReferenceLoopHandling = ReferenceLoopHandling.Ignore,
NullValueHandling = NullValueHandling.Ignore,
Formatting = Formatting.Indented
};
Test test = (Test)new LoggingProxy(new Test()).GetTransparentProxy();
test.field = "test";
test.Property = "Test";
string outObject;
string refObject = "ref";
var result = test.Method("test1", "test2", ref refObject, out outObject);
Console.WriteLine(JsonConvert.SerializeObject(new object[] {
test,
result,
refObject,
outObject
})
);
Console.ReadKey();
}
}
class Test: MarshalByRefObject
{
public string field;
public string Property { get; set; }
public string Method(string parameter1, string parameter2,
ref string refObject, out string outObject)
{
if (parameter1 == null)
throw new ArgumentNullException("Parameter one cannot be null");
refObject += " reffed";
outObject = "outed";
return $"{parameter1} : {parameter2}";
}
}
class LoggingProxy : RealProxy
{
private readonly object _target;
public LoggingProxy(object obj) : base(obj?.GetType())
{
_target = obj;
}
public override IMessage Invoke(IMessage msg)
{
if (msg is IMethodCallMessage methodCall)
{
var arguments = methodCall.Args.ToArray();
var result = methodCall.MethodBase.Invoke(_target, arguments);
return new ReturnMessage(
result,
arguments,
arguments.Length,
methodCall.LogicalCallContext,
methodCall);
}
return null;
}
}
So this is what I did above:
- I've inherited my Test class from MarshalByRefObject
- I've created a LoggingProxy class that inherits from RealProxy and implements the Invoke method
- I've replaced new Test(); with (Test)new LoggingProxy(new Test()).GetTransparentProxy();
Running it we get the same result.
Time to add some logging. I will write stuff on the Console, too, for this demo. Here are the changes to the LoggingProxy class:
class LoggingProxy : RealProxy
{
private readonly object _target;
public LoggingProxy(object obj) : base(obj?.GetType())
{
_target = obj;
}
public override IMessage Invoke(IMessage msg)
{
if (msg is IMethodCallMessage methodCall)
{
var arguments = methodCall.Args.ToArray();
string typeName;
try
{
typeName = Type.GetType(methodCall.TypeName).Name;
}
catch
{
typeName = methodCall.TypeName;
}
try
{
Console.WriteLine($"Called {typeName}.{methodCall.MethodName}" +
$"({JsonConvert.SerializeObject(arguments)})");
var result = methodCall.MethodBase.Invoke(_target, arguments);
Console.WriteLine($"Success for {typeName}.{methodCall.MethodName}" +
$"({JsonConvert.SerializeObject(arguments)}): " +
$"{JsonConvert.SerializeObject(result)}");
return new ReturnMessage(
result,
arguments,
arguments.Length,
methodCall.LogicalCallContext,
methodCall);
}
catch (Exception exception)
{
Console.WriteLine($"Error for {typeName}.{methodCall.MethodName}" +
$"({JsonConvert.SerializeObject(arguments)}): " +
$"{exception}");
return new ReturnMessage(exception, methodCall);
}
}
return null;
}
}
It's the same as before, but with a try/catch block and some extra Console.WriteLines. Here is the output:
Called Object.FieldSetter([
"RealProxyTests2.Test",
"field",
"test"
])
Success for Object.FieldSetter([
"RealProxyTests2.Test",
"field",
"test"
]): null
Called Test.set_Property([
"Test"
])
Success for Test.set_Property([
"Test"
]): null
Called Test.Method([
"test1",
"test2",
"ref",
null
])
Success for Test.Method([
"test1",
"test2",
"ref reffed",
"outed"
]): "test1 : test2"
Called Object.GetType([])
Success for Object.GetType([]): "RealProxyTests2.Test, RealProxyTests2, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null"
Called Object.FieldGetter([
"RealProxyTests2.Test",
"field",
null
])
Success for Object.FieldGetter([
"RealProxyTests2.Test",
"field",
"test"
]): null
Called Test.get_Property([])
Success for Test.get_Property([]): "Test"
[
{
"field": "test",
"Property": "Test"
},
"test1 : test2",
"ref reffed",
"outed"
]
A bounty of information. The first lines are the setting of the field, Property and the execution of Method. But then there are a GetType, a field getter and a Property getter. What's that about? That's JsonConvert, serializing the Test proxy.
Warning: I've copied methodCall.Args into a local property called arguments. At first glance it might appear superfluous, but methodCall.Args is not really an array of object, even if it appears that way in the debugger. It is read-only, changing any of its items has no effect.
Remember how we defined the proxy in Program.Main? We can use a method in our proxy object, let's call it Wrap:
public static T Wrap<T>(T obj)
{
if (obj is MarshalByRefObject marshalByRefObject)
{
return (T)new LoggingProxy(marshalByRefObject).GetTransparentProxy();
}
return obj;
}
Conclusion:
While this works, there are a series of issues related to it:
- RealProxy is only available for .NET Framework, not .NET Core (see DispatchProxy for that)
- Serialization is not so straightforward as in this demo (see my blog post about Newtonsoft serialization
- You need to inherit from MarshalByRefObject, so this solution doesn't work for classes that already have a base class
- Performance wise you should make sure you are not logging or executing anything unless the correct log level is set (something like logger.LogTrace(JsonConvert(...)) would not work because the JSON serialization occurs no matter before executing LogTrace)
- Also, this wrapping is not free. With a simple proxy that did nothing than execute the code it took 43 times more time to run. Of course, that's because the actual execution of setting properties or returning a string is basically zero. When I added a Thread.Sleep(1) in the method, it took almost the same amount of time. Just don't use it in performance sensitive applications
Final thoughts: in the same namespace with RealProxy there is a ProxyAttribute class that at first glance seems to be even better: you just decorate a class with the attribute and BANG! instant AOP. But it's not that simple. First of all it works only on object that inherit from ContextBoundObject which itself inherit from MarshalByRefObject. And while it seems like a good idea to just replace MarshalByRefObject with ContextBoundObject in the code above, know that no generic class can inherit from it. There might be other restrictions, too. If you make Test inherit ContextBoundObject, the debugger will already show new Test() as being a transparent proxy, without wrapping it with any code. It might still be usable in certain conditions, though.
