Add support for logging via Mock

[tapika]

By default when you create new Mock object - it allows to record methods being called, by placing them into "Invocations" property.

I would prefer to operate in real time and perform logging of methods being called and their call arguments.

By brief check of Moq v4 - I've noticed that this is far not simple thing to be done, as Moq does use Castle.DynamicProxy.ProxyGenerator, but it does not allow end-user of Moq to override call with it's own interceptor.

What I've came up - is maybe I could just double proxy executing - so Moq would create one proxy and I would put second proxy on top of that one.

    public class LoggedMock<T>: Mock<T> where T: class
    {
        object logProxy;

        Castle.DynamicProxy.ProxyGenerator proxygenerator;
        string[] _methodsToIgnore;

        public LoggedMock(
            params string[] methodsToIgnore
        ) : base()
        {
            _methodsToIgnore = methodsToIgnore;
        }


        public override T Object
        {
            get
            {
                if (logProxy == null)
                {
                    if (proxygenerator == null)
                    { 
                        proxygenerator = new Castle.DynamicProxy.ProxyGenerator();
                    }

                    if (typeof(T).IsInterface)
                    {
                        logProxy = proxygenerator.CreateInterfaceProxyWithTarget(typeof(T), base.Object, new LoggedMockInterceptor(_methodsToIgnore));
                    }
                    else
                    { 
                        logProxy = proxygenerator.CreateClassProxyWithTarget(typeof(T), base.Object, new LoggedMockInterceptor(_methodsToIgnore));
                    }
                }

                return (T)logProxy;
            }
        }

This did work correctly, however - then I wanted to switch from Mock<interface> to Mock<abstract class> - and then noticed that Mock does support such method as As<TInterface>(), which in a turn woul create a new copy of Mock with different generic parameter.

To support all use cases as Mock does - it would require also mimic also class AsInterface<TInterface> : LoggedMock<TInterface>
class, which drags more complexity into whole story.

Moverover - then I've noticed that Moq v5 was not based anymore on Castle core, with it's own mechanisms for logging interception.

Also if interception is done via logging - it's possible also to override existing Mock behavior and not to update Invocations at all (as it would eat more performance).

Just to illustrate what kind of logging I want to achive - this is something coded with Castle.Core / Moq v4.

    public class LoggedMockInterceptor : IInterceptor
    {
        StringBuilder sb = new StringBuilder();
        string[] _methodsToIgnore;

        public LoggedMockInterceptor(string[] methodsToIgnore)
        {
            _methodsToIgnore = methodsToIgnore;
        }

        public void Intercept(IInvocation invocation)
        {
            string name = invocation.Method.Name;

            if (_methodsToIgnore.Contains(name))
            {
                //invocation.Proceed();
                return;
            }

            ParameterInfo[] parameters = invocation.Method.GetParameters();
            sb.Clear();

            object[] args = invocation.Arguments;
            sb.Append(name);
            sb.Append("(");

            for (int i = 0; i < parameters.Length; i++)
            {
                if (i != 0)
                {
                    sb.Append(",");
                }

                if (parameters[i].ParameterType == typeof(string))
                {
                    if (args[i] == null)
                    {
                        sb.Append("null");
                    }
                    else
                    { 
                        sb.Append("\"");
                        sb.Append(args[i].ToString());
                        sb.Append("\"");
                    }
                }
                else
                { 
                    sb.Append(args[i].ToString());
                }
            }
            
            sb.Append(")");
        
            LogService.GetInstance(false)._console.Info(sb.ToString());
            invocation.Proceed();
        }
    }

Would it be possible to add into Moq v5 logging support or just to provide some code on how this could be done.

[stakx]

Moq 4 bases its functionality on top of Castle DynamicProxy, but you should consider that an internal implementation detail. Moq 4 does not offer an easy way to have all invocations go through a common callback. (Not yet, anyway; see last paragraph below.)

I've seen your other issue about composite proxies (#72). In theory, you could switch things around: Use a DynamicProxy ProxyGenerator to generate a composite T proxy with a Mock<T>.Object as its target. Have the proxy use an interceptor that first logs the current invocation, then proceeds to the target (i.e. to the mock object).

It's not particularly elegant nor efficient, as you'll end up with two proxies, but it should work without a change to Moq 4.

Moq 5 uses a fairly different approach for invocation pipelines that we cannot retrofit in the same exact form onto Moq 4. I've in the past done some prototyping towards a more flexible invocation pipeline (see devlooped/moq#1002), and I've continued refactoring Moq 4's internals towards that goal, but we're still not quite there yet.

[stakx]

(Sorry, I totally misinterpreted this issue's original post as I was under the false assumption that this was posted at the moq4 repo. Please ignore my above post.)

[tapika]

Actually any input is welcomed. I think I will try maybe also to put ProxyGenerator's proxy > Mock proxy into same Mock<T>.instance - I think I will be able to access that field via reflection. This will probably solve the Moq v4 problem, and Moq v5 will have built-in support for logging - I guess devlooped/moq#1002 is quite close towards what needs to be achieved.

I have tried by myself to build Moq v5, but without success, I guess need to install newer C# compiler tools, maybe also re-configure Moq v5. I have checked also that Moq v5 nuget packages are not yet published - even not alpha / beta.

Would be interested to try out Moq v5 as well. (What is still not working in v5 ?)

[tapika]

It looks like for Moq v4 this code indeed works:

namespace Moq
{
    public static class MockExtensions
    {
        static Castle.DynamicProxy.ProxyGenerator proxygenerator;
        
        /// <summary>
        /// Enables logging of specific mock instance
        /// </summary>
        /// <param name="methodsToIgnore">Specifies method or property names to ignore when logging 
        /// (e.g. utility functions about which we don't care)</param>
        public static Mock<T> Logged<T>(this Mock<T> mock, params string[] methodsToIgnore) where T : class
        {
            object mockedObject = mock.Object;
            object proxy;

            if (proxygenerator == null)
            {
                proxygenerator = new Castle.DynamicProxy.ProxyGenerator();
            }

            if (typeof(T).IsInterface)
            {
                proxy = proxygenerator.CreateInterfaceProxyWithTarget(typeof(T), mockedObject, new LoggedMockInterceptor(methodsToIgnore));
            }
            else
            {
                proxy = proxygenerator.CreateClassProxyWithTarget(typeof(T), mockedObject, new LoggedMockInterceptor(methodsToIgnore));
            }

            var field = mock.GetType().GetField("instance", System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Instance);
            field.SetValue(mock, proxy);
            return mock;
        }
    }
}

Usage is quite trivial, something like this:

        protected Mock<DotNetFileSystemBase> fileSystem = new Mock<DotNetFileSystemBase>().Logged(
            nameof(IFileSystem.get_file_extension),
            nameof(IFileSystem.get_file_name),
            nameof(IFileSystem.get_directory_name),
            nameof(IFileSystem.combine_paths)
        );

Need to try out on bit wider scope.

[tapika]

Unrelated to ticket - here are some benchmarks of proxy creation versus calling:

https://github.com/mtamme/NProxy/blob/master/Documentation/BENCHMARKS.md

Maybe need to try out NProxy later on.