Introduction

Aspect Oriented Programming (AOP) is a very powerful approach to avoid boilerplate code and achieve better modularity. The main idea is to add behavior (advice) to the existing code without making any changes in the code itself. In Java, this idea is implemented in AspectJ and Spring frameworks. There are PostSharp (not free), NConcern, and some other frameworks (not very popular and easy to use) to do almost the same in .NET.

It is also possible to use RealProxy class to implement AOP. You can find some examples on how to do it here,

Example1: Aspect-Oriented Programming : Aspect-Oriented Programming with the RealProxy Class

Example2: MSDN.

Unfortunately, these examples have some significant drawbacks. Example1 does not support out parameters. Example2 has limitation. Decorated class should be inherited from MarshalByRefObject (it could be a problem if it is not your class). Also, both examples do not support asynchronous functions. Ok, technically it is supported. But I’m expecting “after” code execution AFTER task completion, and if “after” code tries to get value of Result property from Task object (for example during result serialization) it makes asynchronous code synchronous (not cool ☹).

I tried to fix first example.

Before continue reading

This article is how to fix some problems in solution, provided by Bruno Sonnino (Example1). That article has great explanation how code is supposed to work and what kind of problems it solves. Please read Aspect-Oriented Programming : Aspect-Oriented Programming with the RealProxy Class first.

Solution

This solution is an example of logging implementation. Code could be found here.

Differences with original code:

  1. Extension method GetDescription was added to log Exception data (Extensions.cs).
  2. DynamicProxy class was renamed to LoggingAdvice.
  3. Constructor was made private. Static function Create creates class instance and returns TransparentProxy (LoggingAdvice.cs - lines 35-41). It makes impossible to create instance of LoggingAdvice class, because only proxy, created by this class, is going to be used.
  4. LoggingAdvice receives actions to log function calls and errors, and function to serialize complex type values as parameters (LoggingAdvice.cs - lines 19-20).
  5. TaskScheduler was added as an optional parameter to support task results logging using different task scheduler. TaskScheduler.FromCurrentSynchronizationContext() will be used by default (LoggingAdvice.cs - line 36).
  6. Functions LogException, LogBefore and LogAfrer were added to log corresponding data (LoggingAdvice.cs - lines 150-209).
  7. Try/catch blocks were added to handle situation when logInfo function throws an exception (LoggingAdvice.cs - lines 53-61, 99-107).
  8. If result value of the function is Task, execution result will be logged after task completion (LoggingAdvice.cs - lines 69-96).
  9. Added output parameters support (LoggingAdvice.cs - lines 63, 110-111).
Extension to log exception (Extensions.cs)
  1. using System;
  2. using System.Text;
  4. namespace AOP
  5. {
  6. public static class Extensions
  7. {
  8. public static string GetDescription(this Exception e)
  9. {
  10. var builder = new StringBuilder();
  11. AddException(builder, e);
  13. return builder.ToString();
  14. }
  16. private static void AddException(StringBuilder builder, Exception e)
  17. {
  18. builder.AppendLine($"Message: {e.Message}");
  19. builder.AppendLine($"Stack Trace: {e.StackTrace}");
  20. if (e.InnerException != null)
  21. {
  22. builder.AppendLine("Inner Exception");
  23. AddException(builder, e.InnerException);
  24. }
  25. }
  26. }
  27. }
Logging Advice (LoggingAdvice.cs)
  1. using System;
  2. using System.Linq;
  3. using System.Reflection;
  4. using System.Runtime.Remoting.Messaging;
  5. using System.Runtime.Remoting.Proxies;
  6. using System.Text;
  7. using System.Threading.Tasks;
  9. namespace AOP
  10. {
  11. public class LoggingAdvice<T> : RealProxy
  12. {
  13. private readonly T _decorated;
  14. private readonly Action<string> _logInfo;
  15. private readonly Action<string> _logError;
  16. private readonly Func<object, string> _serializeFunction;
  17. private readonly TaskScheduler _loggingScheduler;
  19. private LoggingAdvice(T decorated, Action<string> logInfo, Action<string> logError,
  20. Func<object, string> serializeFunction, TaskScheduler loggingScheduler)
  21. : base(typeof(T))
  22. {
  23. if (decorated == null)
  24. {
  25. throw new ArgumentNullException(nameof(decorated));
  26. }
  28. _decorated = decorated;
  29. _logInfo = logInfo;
  30. _logError = logError;
  31. _serializeFunction = serializeFunction;
  32. _loggingScheduler = loggingScheduler ?? TaskScheduler.FromCurrentSynchronizationContext();
  33. }
  35. public static T Create(T decorated, Action<string> logInfo, Action<string> logError,
  36. Func<object, string> serializeFunction, TaskScheduler loggingScheduler = null)
  37. {
  38. var advice = new LoggingAdvice<T>(decorated, logInfo, logError, serializeFunction, loggingScheduler);
  40. return (T)advice.GetTransparentProxy();
  41. }
  43. public override IMessage Invoke(IMessage msg)
  44. {
  45. var methodCall = msg as IMethodCallMessage;
  46. if (methodCall != null)
  47. {
  48. var methodInfo = methodCall.MethodBase as MethodInfo;
  49. if (methodInfo != null)
  50. {
  51. try
  52. {
  53. try
  54. {
  55. LogBefore(methodCall, methodInfo);
  56. }
  57. catch (Exception ex)
  58. {
  59. //Do not stop method execution if exception
  60. LogException(ex);
  61. }
  63. var args = methodCall.Args;
  65. var result = typeof(T).InvokeMember(
  66. methodCall.MethodName,
  67. BindingFlags.InvokeMethod | BindingFlags.Public | BindingFlags.Instance, null, _decorated, args);
  69. if (result is Task)
  70. {
  71. ((Task)result).ContinueWith(task =>
  72. {
  73. if (task.Exception != null)
  74. {
  75. LogException(task.Exception.InnerException ?? task.Exception, methodCall);
  76. }
  77. else
  78. {
  79. object taskResult = null;
  81. if (task.GetType().IsGenericType && task.GetType().GetGenericTypeDefinition() == typeof(Task<>))
  82. {
  83. var property = task.GetType().GetProperties()
  84. .FirstOrDefault(p => p.Name == "Result");
  86. if (property != null)
  87. {
  88. taskResult = property.GetValue(task);
  89. }
  90. }
  92. LogAfter(methodCall, methodCall.Args, methodInfo, taskResult);
  93. }
  94. },
  95. _loggingScheduler);
  96. }
  97. else
  98. {
  99. try
  100. {
  101. LogAfter(methodCall, args, methodInfo, result);
  102. }
  103. catch (Exception ex)
  104. {
  105. //Do not stop method execution if exception
  106. LogException(ex);
  107. }
  108. }
  110. return new ReturnMessage(result, args, args.Length,
  111. methodCall.LogicalCallContext, methodCall);
  112. }
  113. catch (Exception ex)
  114. {
  115. if (ex is TargetInvocationException)
  116. {
  117. LogException(ex.InnerException ?? ex, methodCall);
  119. return new ReturnMessage(ex.InnerException ?? ex, methodCall);
  120. }
  121. }
  122. }
  123. }
  125. throw new ArgumentException(nameof(msg));
  126. }
  128. private string GetStringValue(object obj)
  129. {
  130. if (obj == null)
  131. {
  132. return "null";
  133. }
  135. if (obj.GetType().IsPrimitive || obj.GetType().IsEnum || obj is string)
  136. {
  137. return obj.ToString();
  138. }
  140. try
  141. {
  142. return _serializeFunction?.Invoke(obj) ?? obj.ToString();
  143. }
  144. catch
  145. {
  146. return obj.ToString();
  147. }
  148. }
  150. private void LogException(Exception exception, IMethodCallMessage methodCall = null)
  151. {
  152. try
  153. {
  154. var errorMessage = new StringBuilder();
  155. errorMessage.AppendLine($"Class {_decorated.GetType().FullName}");
  156. errorMessage.AppendLine($"Method {methodCall?.MethodName} threw exception");
  157. errorMessage.AppendLine(exception.GetDescription());
  159. _logError?.Invoke(errorMessage.ToString());
  160. }
  161. catch (Exception)
  162. {
  163. // ignored
  164. //Method should return original exception
  165. }
  166. }
  168. private void LogAfter(IMethodCallMessage methodCall, object[] args, MethodInfo methodInfo, object result)
  169. {
  170. var afterMessage = new StringBuilder();
  171. afterMessage.AppendLine($"Class {_decorated.GetType().FullName}");
  172. afterMessage.AppendLine($"Method {methodCall.MethodName} executed");
  173. afterMessage.AppendLine("Output:");
  174. afterMessage.AppendLine(GetStringValue(result));
  175. var parameters = methodInfo.GetParameters();
  176. if (parameters.Any())
  177. {
  178. afterMessage.AppendLine("Parameters:");
  179. for (var i = 0; i < parameters.Length; i++)
  180. {
  181. var parameter = parameters[i];
  182. var arg = args[i];
  183. afterMessage.AppendLine($"{parameter.Name}:{GetStringValue(arg)}");
  184. }
  185. }
  187. _logInfo?.Invoke(afterMessage.ToString());
  188. }
  190. private void LogBefore(IMethodCallMessage methodCall, MethodInfo methodInfo)
  191. {
  192. var beforeMessage = new StringBuilder();
  193. beforeMessage.AppendLine($"Class {_decorated.GetType().FullName}");
  194. beforeMessage.AppendLine($"Method {methodCall.MethodName} executing");
  195. var parameters = methodInfo.GetParameters();
  196. if (parameters.Any())
  197. {
  198. beforeMessage.AppendLine("Parameters:");
  199. for (var i = 0; i < parameters.Length; i++)
  200. {
  201. var parameter = parameters[i];
  202. var arg = methodCall.Args[i];
  203. beforeMessage.AppendLine($"{parameter.Name}:{GetStringValue(arg)}");
  204. }
  205. }
  207. _logInfo?.Invoke(beforeMessage.ToString());
  208. }
  209. }
  210. }

How to use

  1. var decoratedInstance = LoggingAdvice<IInstanceInteface>.Create(
  2. instance,
  3. s => Console.WriteLine(“Info:” + s),
  4. s => Console.WriteLine(“Error:” + s),
  5. o => o?.ToString());

Example

Let assume that we are going to implement calculator which adds and subtracts integer numbers.
  1. namespace AOP.Example
  2. {
  3. public interface ICalculator
  4. {
  5. int Add(int a, int b);
  6. int Subtract(int a, int b);
  7. }
  8. }
  1. namespace AOP.Example
  2. {
  3. public class Calculator : ICalculator
  4. {
  5. public int Add(int a, int b)
  6. {
  7. return a + b;
  8. }
  10. public int Subtract(int a, int b)
  11. {
  12. return a - b;
  13. }
  14. }
  15. }

Is is easy. Each method has only one responsiblility.

One day some users start complaining that sometimes Add(2, 2) returns 4. You don't understand what's going on and decide to add logging.

  1. namespace AOP.Example
  2. {
  3. public class CalculatorWithoutAop: ICalculator
  4. {
  5. private readonly ILogger _logger;
  7. public CalculatorWithoutAop(ILogger logger)
  8. {
  9. _logger = logger;
  10. }
  12. public int Add(int a, int b)
  13. {
  14. _logger.Log($"Adding {a} + {b}");
  15. var result = a + b;
  16. _logger.Log($"Result is {result}");
  18. return result;
  19. }
  21. public int Subtract(int a, int b)
  22. {
  23. _logger.Log($"Subtracting {a} - {b}");
  24. var result = a - b;
  25. _logger.Log($"Result is {result}");
  27. return result;
  28. }
  30. }
  31. }

There are 3 problems with this solution.

  1. Calculator class coupled with logging. Loosely coupled (because ILoger it is an interface), but coupled. Every time you make changes in this interface it affects Calculator.
  2. Code become more complex.
  3. It breaks Single Responsibility principle. Add function don't just add numbers. It logs input values, add values and logs result. The same for Subtract.
  4. Code in this article allows you don't touch Calculator class at all.

You just need to change creation of the class.

  1. namespace AOP.Example
  2. {
  3. public class CalculatorFactory
  4. {
  5. private readonly ILogger _logger;
  7. public CalculatorFactory(ILogger logger)
  8. {
  9. _logger = logger;
  10. }
  12. public ICalculator CreateCalculator()
  13. {
  14. return LoggingAdvice <ICalculator >.Create(
  15. new Calculator(),
  16. s => _logger.Log("Info:" + s),
  17. s => _logger.Log("Error:" + s),
  18. o => o?.ToString());
  19. }
  20. }
  21. }

Tests

NUnit and NSubstitute are used to write Unit Tests.

CurrentThreadTaskScheduler allows scheduling the tasks in current thread in test project.
  1. using System;
  2. using System.Collections.Generic;
  3. using System.Threading;
  4. using System.Threading.Tasks;
  5. using NSubstitute;
  6. using NUnit.Framework;
  8. namespace AOP.Tests
  9. {
  10. public interface ITestClass2
  11. {
  12. void Method();
  14. void MethodWithException();
  16. Task AsyncMethodWithException();
  17. }
  19. public class TestClass2 : ITestClass2
  20. {
  21. public void Method()
  22. {
  24. }
  26. public void MethodWithException()
  27. {
  28. throw new Exception();
  29. }
  31. public Task AsyncMethodWithException()
  32. {
  33. return Task.Factory.StartNew(() => { throw new Exception(); });
  34. }
  35. }
  37. [TestFixture]
  38. public class LoggingAdviceTests
  39. {
  40. private TaskScheduler _taskScheduler;
  42. public class Data
  43. {
  44. public string Prop { get; set; }
  45. }
  47. public interface ITestClass
  48. {
  49. string Property { get; set; }
  51. void MethodWithVoidResult();
  53. string MethodWithStringResultAndIntParameter(int intParam);
  55. Data MethodWithClassResultAndClassParameter(Data dataParam);
  57. int MethodWithOutParameter(out string stringParam);
  59. int MethodWithRefParameter(ref string stringParam);
  61. int MethodWithOutParameter(out int intParam);
  63. int MethodWithRefParameter(ref int intParam);
  65. int MethodWithMixedParameter(ref int refParam, out string outParam, bool param);
  67. Task MethodWithTaskResult();
  69. Task<string> MethodWithTaskStringResult();
  70. }
  72. [SetUp]
  73. public void SetUp()
  74. {
  75. SynchronizationContext.SetSynchronizationContext(new SynchronizationContext());
  76. _taskScheduler = new CurrentThreadTaskScheduler();
  77. }
  79. [Test]
  80. public void ThrowException_WhenDecoratedClassNull()
  81. {
  82. Assert.Throws<ArgumentNullException>(() =>
  83. {
  84. var decorated = LoggingAdvice<ITestClass>.Create(
  85. null,
  86. s => { },
  87. s => { },
  88. o => o?.ToString());
  89. });
  90. }
  92. [Test]
  93. public void LogInfo()
  94. {
  95. var testClass = Substitute.For<ITestClass>();
  96. var errorMassages = new List<string>();
  97. var infoMassages = new List<string>();
  98. var decorated = LoggingAdvice<ITestClass>.Create(
  99. testClass,
  100. s => infoMassages.Add(s),
  101. s => errorMassages.Add(s),
  102. o => o?.ToString());
  104. decorated.MethodWithVoidResult();
  106. testClass.Received().MethodWithVoidResult();
  107. Assert.AreEqual(2, infoMassages.Count);
  108. Assert.IsTrue(infoMassages[0].Contains("MethodWithVoidResult"));
  109. Assert.IsTrue(infoMassages[1].Contains("MethodWithVoidResult"));
  110. Assert.AreEqual(0, errorMassages.Count);
  111. }
  113. [Test]
  114. public void DoNotStop_WhenLogInfoThrowsException()
  115. {
  116. var testClass = Substitute.For<ITestClass>();
  117. var errorMassages = new List<string>();
  118. var decorated = LoggingAdvice<ITestClass>.Create(
  119. testClass,
  120. s => { throw new Exception(); },
  121. s => errorMassages.Add(s),
  122. o => o?.ToString());
  124. decorated.MethodWithVoidResult();
  126. testClass.Received().MethodWithVoidResult();
  127. Assert.AreEqual(2, errorMassages.Count);
  128. }
  130. [Test]
  131. public void LogInfo_WhenClassResultAndClassParameter()
  132. {
  133. var testClass = Substitute.For<ITestClass>();
  134. testClass.MethodWithClassResultAndClassParameter(Arg.Any<Data>()).Returns(new Data { Prop = "Result12345" });
  135. var errorMassages = new List<string>();
  136. var infoMassages = new List<string>();
  137. var decorated = LoggingAdvice<ITestClass>.Create(
  138. testClass,
  139. s => infoMassages.Add(s),
  140. s => errorMassages.Add(s),
  141. o => ((Data)o).Prop);
  143. var result = decorated.MethodWithClassResultAndClassParameter(new Data { Prop = "Parameter12345"});
  145. testClass.Received().MethodWithClassResultAndClassParameter(Arg.Any<Data>());
  146. Assert.AreEqual("Result12345", result.Prop);
  147. Assert.AreEqual(2, infoMassages.Count);
  148. Assert.IsTrue(infoMassages[0].Contains("dataParam:Parameter12345"));
  149. Assert.IsTrue(infoMassages[1].Contains("dataParam:Parameter12345"));
  150. Assert.IsTrue(infoMassages[1].Contains("Result12345"));
  151. Assert.AreEqual(0, errorMassages.Count);
  152. }
  154. [Test]
  155. public void LogInfo_WhenParameters()
  156. {
  157. var testClass = Substitute.For<ITestClass>();
  158. testClass.MethodWithStringResultAndIntParameter(Arg.Any<int>()).Returns("Result12345");
  159. var errorMassages = new List<string>();
  160. var infoMassages = new List<string>();
  161. var decorated = LoggingAdvice<ITestClass>.Create(
  162. testClass,
  163. s => infoMassages.Add(s),
  164. s => errorMassages.Add(s),
  165. o => o?.ToString());
  167. var result = decorated.MethodWithStringResultAndIntParameter(12345);
  169. testClass.Received().MethodWithStringResultAndIntParameter(Arg.Any<int>());
  170. Assert.AreEqual("Result12345", result);
  171. Assert.AreEqual(2, infoMassages.Count);
  172. Assert.IsTrue(infoMassages[0].Contains("intParam:12345"));
  173. Assert.IsTrue(infoMassages[1].Contains("Result12345"));
  174. Assert.IsTrue(infoMassages[1].Contains("intParam:12345"));
  175. Assert.AreEqual(0, errorMassages.Count);
  176. }
  178. [Test]
  179. public void DoNotStop_WhenSerializerThrowsException()
  180. {
  181. var testClass = Substitute.For<ITestClass>();
  182. testClass.MethodWithClassResultAndClassParameter(Arg.Any<Data>()).Returns(new Data { Prop = "Result12345" });
  183. var errorMassages = new List<string>();
  184. var infoMassages = new List<string>();
  185. var decorated = LoggingAdvice<ITestClass>.Create(
  186. testClass,
  187. s => infoMassages.Add(s),
  188. s => errorMassages.Add(s),
  189. o => { throw new Exception();});
  190. Data result = null;
  192. Assert.DoesNotThrow(() => result = decorated.MethodWithClassResultAndClassParameter(new Data { Prop = "Parameter12345"}));
  193. testClass.Received().MethodWithClassResultAndClassParameter(Arg.Any<Data>());
  194. Assert.AreEqual("Result12345", result?.Prop);
  195. Assert.AreEqual(2, infoMassages.Count);
  196. Assert.IsTrue(infoMassages[0].Contains("Data"));
  197. Assert.IsTrue(infoMassages[1].Contains("Data"));
  198. Assert.AreEqual(0, errorMassages.Count);
  199. }
  201. [Test]
  202. public void LogError()
  203. {
  204. var testClass = Substitute.For<ITestClass>();
  205. testClass.When(t => t.MethodWithVoidResult()).Do(info => { throw new Exception(); });
  206. var errorMassages = new List<string>();
  207. var infoMassages = new List<string>();
  208. var decorated = LoggingAdvice<ITestClass>.Create(
  209. testClass,
  210. s => infoMassages.Add(s),
  211. s => errorMassages.Add(s),
  212. o => o?.ToString());
  214. Assert.Throws<Exception>(() => decorated.MethodWithVoidResult());
  215. testClass.Received().MethodWithVoidResult();
  216. Assert.AreEqual(1, infoMassages.Count);
  217. Assert.IsTrue(infoMassages[0].Contains("MethodWithVoidResult"));
  218. Assert.AreEqual(1, errorMassages.Count);
  219. Assert.IsTrue(errorMassages[0].Contains("MethodWithVoidResult"));
  220. }
  222. [Test]
  223. public void DoNotStop_WhenLogErrorThrowsException()
  224. {
  225. var testClass = Substitute.For<ITestClass>();
  226. testClass.When(t => t.MethodWithVoidResult()).Do(info => { throw new Exception(); });
  227. var infoMassages = new List<string>();
  228. var decorated = LoggingAdvice<ITestClass>.Create(
  229. testClass,
  230. s => infoMassages.Add(s),
  231. s => { throw new ArgumentNullException(); },
  232. o => o?.ToString());
  234. Assert.Throws<Exception>(() => decorated.MethodWithVoidResult());
  236. testClass.Received().MethodWithVoidResult();
  237. Assert.AreEqual(1, infoMassages.Count);
  238. }
  240. [Test]
  241. public void LogInfo_WhenTaskMethodCall()
  242. {
  243. var testClass = Substitute.For<ITestClass>();
  244. testClass.MethodWithTaskResult().Returns(Task.CompletedTask);
  245. var errorMassages = new List<string>();
  246. var infoMassages = new List<string>();
  247. var decorated = LoggingAdvice<ITestClass>.Create(
  248. testClass,
  249. s => infoMassages.Add(s),
  250. s => errorMassages.Add(s),
  251. o => o?.ToString(),
  252. _taskScheduler);
  254. decorated.MethodWithTaskResult().Wait();
  255. ReleaseContext();
  257. testClass.Received().MethodWithTaskResult();
  258. Assert.AreEqual(2, infoMassages.Count);
  259. Assert.AreEqual(0, errorMassages.Count);
  260. }
  262. [Test]
  263. public void LogInfo_WhenTaskMethodCallWithException()
  264. {
  265. var testClass = Substitute.For<ITestClass>();
  266. testClass.MethodWithTaskResult().Returns(Task.FromException(new Exception("ERROR!!!!")));
  267. var errorMassages = new List<string>();
  268. var infoMassages = new List<string>();
  269. var decorated = LoggingAdvice<ITestClass>.Create(
  270. testClass,
  271. s => infoMassages.Add(s),
  272. s => errorMassages.Add(s),
  273. o => o?.ToString(),
  274. _taskScheduler);
  276. Assert.Throws<AggregateException>(() => decorated.MethodWithTaskResult().Wait());
  277. ReleaseContext();
  279. testClass.Received().MethodWithTaskResult();
  280. Assert.AreEqual(1, infoMassages.Count);
  281. Assert.AreEqual(1, errorMassages.Count);
  282. Assert.IsTrue(errorMassages[0].Contains("ERROR!!!!"));
  283. }
  285. [Test]
  286. public void LogInfo_WhenTaskHasResult()
  287. {
  288. var testClass = Substitute.For<ITestClass>();
  289. testClass.MethodWithTaskStringResult().Returns("String result");
  290. var errorMassages = new List<string>();
  291. var infoMassages = new List<string>();
  292. var decorated = LoggingAdvice<ITestClass>.Create(
  293. testClass,
  294. s => infoMassages.Add(s),
  295. s => errorMassages.Add(s),
  296. o => o?.ToString(),
  297. _taskScheduler);
  299. var result = decorated.MethodWithTaskStringResult().Result;
  300. ReleaseContext();
  302. Assert.AreEqual("String result", result);
  303. testClass.Received().MethodWithTaskStringResult();
  304. Assert.AreEqual(2, infoMassages.Count);
  305. Assert.IsTrue(infoMassages[1].Contains("String result"));
  306. Assert.AreEqual(0, errorMassages.Count);
  307. }
  309. [Test]
  310. public void LogInfo_WhenTaskWithResultThrowException()
  311. {
  312. var testClass = Substitute.For<ITestClass>();
  313. testClass.MethodWithTaskStringResult().Returns(Task.FromException<string>(new Exception("ERROR!!!!")));
  314. var errorMassages = new List<string>();
  315. var infoMassages = new List<string>();
  316. var decorated = LoggingAdvice<ITestClass>.Create(
  317. testClass,
  318. s => infoMassages.Add(s),
  319. s => errorMassages.Add(s),
  320. o => o?.ToString(),
  321. _taskScheduler);
  323. Assert.Throws<AggregateException>(() => decorated.MethodWithTaskStringResult().Wait());
  324. ReleaseContext();
  326. testClass.Received().MethodWithTaskStringResult();
  327. Assert.AreEqual(1, infoMassages.Count);
  328. Assert.AreEqual(1, errorMassages.Count);
  329. Assert.IsTrue(errorMassages[0].Contains("ERROR!!!!"));
  330. }
  332. [Test]
  333. public void LogInfo_WhenOutParameter()
  334. {
  335. var testClass = Substitute.For<ITestClass>();
  336. var val = "s2";
  337. testClass.MethodWithOutParameter(out val)
  338. .Returns(x =>
  339. {
  340. x[0] = "s5";
  342. return 25;
  343. });
  345. var errorMassages = new List<string>();
  346. var infoMassages = new List<string>();
  347. var decorated = LoggingAdvice<ITestClass>.Create(
  348. testClass,
  349. s => infoMassages.Add(s),
  350. s => errorMassages.Add(s),
  351. o => o?.ToString());
  353. var result = decorated.MethodWithOutParameter(out val);
  355. var val2 = "s2";
  356. testClass.Received().MethodWithOutParameter(out val2);
  357. Assert.AreEqual(0, errorMassages.Count);
  358. Assert.AreEqual(2, infoMassages.Count);
  359. Assert.AreEqual(25, result);
  360. Assert.AreEqual("s5", val);
  361. Assert.IsTrue(infoMassages[1].Contains("25"));
  362. Assert.IsTrue(infoMassages[1].Contains("stringParam:s5"));
  363. }
  365. [Test]
  366. public void LogInfo_WhenRefParameter()
  367. {
  368. var testClass = Substitute.For<ITestClass>();
  369. var val = "s2";
  370. testClass.MethodWithRefParameter(ref val)
  371. .Returns(x =>
  372. {
  373. x[0] = "s5";
  375. return 25;
  376. });
  378. var errorMassages = new List<string>();
  379. var infoMassages = new List<string>();
  380. var decorated = LoggingAdvice<ITestClass>.Create(
  381. testClass,
  382. s => infoMassages.Add(s),
  383. s => errorMassages.Add(s),
  384. o => o?.ToString());
  386. var result = decorated.MethodWithRefParameter(ref val);
  388. var val2 = "s2";
  389. testClass.Received().MethodWithRefParameter(ref val2);
  390. Assert.AreEqual(0, errorMassages.Count);
  391. Assert.AreEqual(2, infoMassages.Count);
  392. Assert.AreEqual(25, result);
  393. Assert.AreEqual("s5", val);
  394. Assert.IsTrue(infoMassages[0].Contains("stringParam:s2"));
  395. Assert.IsTrue(infoMassages[1].Contains("25"));
  396. Assert.IsTrue(infoMassages[1].Contains("stringParam:s5"));
  397. }
  399. [Test]
  400. public void LogInfo_WhenOutParameterOfValueType()
  401. {
  402. var testClass = Substitute.For<ITestClass>();
  403. var val = 2;
  404. testClass.MethodWithOutParameter(out val)
  405. .Returns(x =>
  406. {
  407. x[0] = 5;
  409. return 25;
  410. });
  412. var errorMassages = new List<string>();
  413. var infoMassages = new List<string>();
  414. var decorated = LoggingAdvice<ITestClass>.Create(
  415. testClass,
  416. s => infoMassages.Add(s),
  417. s => errorMassages.Add(s),
  418. o => o?.ToString());
  420. var result = decorated.MethodWithOutParameter(out val);
  422. var val2 = 2;
  423. testClass.Received().MethodWithOutParameter(out val2);
  424. Assert.AreEqual(0, errorMassages.Count);
  425. Assert.AreEqual(2, infoMassages.Count);
  426. Assert.AreEqual(25, result);
  427. Assert.AreEqual(5, val);
  428. Assert.IsTrue(infoMassages[1].Contains("25"));
  429. Assert.IsTrue(infoMassages[1].Contains("intParam:5"));
  430. }
  432. [Test]
  433. public void LogInfo_WhenRefParameterOfValueType()
  434. {
  435. var testClass = Substitute.For<ITestClass>();
  436. var val = 2;
  437. testClass.MethodWithRefParameter(ref val)
  438. .Returns(x =>
  439. {
  440. x[0] = 5;
  442. return 25;
  443. });
  445. var errorMassages = new List<string>();
  446. var infoMassages = new List<string>();
  447. var decorated = LoggingAdvice<ITestClass>.Create(
  448. testClass,
  449. s => infoMassages.Add(s),
  450. s => errorMassages.Add(s),
  451. o => o?.ToString());
  453. var result = decorated.MethodWithRefParameter(ref val);
  455. var val2 = 2;
  456. testClass.Received().MethodWithRefParameter(ref val2);
  457. Assert.AreEqual(0, errorMassages.Count);
  458. Assert.AreEqual(2, infoMassages.Count);
  459. Assert.AreEqual(25, result);
  460. Assert.AreEqual(5, val);
  461. Assert.IsTrue(infoMassages[0].Contains("intParam:2"));
  462. Assert.IsTrue(infoMassages[1].Contains("25"));
  463. Assert.IsTrue(infoMassages[1].Contains("intParam:5"));
  464. }
  466. [Test]
  467. public void LogInfo_WhenMixedParameters()
  468. {
  469. var testClass = Substitute.For<ITestClass>();
  470. var refParam = 0;
  471. var outParam = "s2";
  472. testClass.MethodWithMixedParameter(ref refParam, out outParam, true)
  473. .Returns(x =>
  474. {
  475. x[0] = 5;
  476. x[1] = "s5";
  478. return 25;
  479. });
  481. var errorMassages = new List<string>();
  482. var infoMassages = new List<string>();
  483. var decorated = LoggingAdvice<ITestClass>.Create(
  484. testClass,
  485. s => infoMassages.Add(s),
  486. s => errorMassages.Add(s),
  487. o => o?.ToString());
  489. var result = decorated.MethodWithMixedParameter(ref refParam, out outParam, true);
  491. var refParam2 = 0;
  492. var outParam2 = "s2";
  493. testClass.Received().MethodWithMixedParameter(ref refParam2, out outParam2, true);
  494. Assert.AreEqual(0, errorMassages.Count);
  495. Assert.AreEqual(2, infoMassages.Count);
  496. Assert.AreEqual(25, result);
  497. Assert.AreEqual(5, refParam);
  498. Assert.AreEqual("s5", outParam);
  499. Assert.IsTrue(infoMassages[0].Contains("refParam:0"));
  500. Assert.IsTrue(infoMassages[0].Contains("outParam:s2"));
  501. Assert.IsTrue(infoMassages[0].Contains("param:True"));
  502. Assert.IsTrue(infoMassages[1].Contains("25"));
  503. Assert.IsTrue(infoMassages[1].Contains("refParam:5"));
  504. Assert.IsTrue(infoMassages[1].Contains("outParam:s5"));
  505. Assert.IsTrue(infoMassages[1].Contains("param:True"));
  506. }
  508. [Test]
  509. public void LogInfoWithProperClassName()
  510. {
  511. var testClass = new TestClass2();
  512. var errorMassages = new List<string>();
  513. var infoMassages = new List<string>();
  514. var decorated = LoggingAdvice<ITestClass2>.Create(
  515. testClass,
  516. s => infoMassages.Add(s),
  517. s => errorMassages.Add(s),
  518. o => o?.ToString());
  520. decorated.Method();
  522. Assert.AreEqual(2, infoMassages.Count);
  523. Assert.IsTrue(infoMassages[0].Contains("Class AOP.Tests.TestClass2"));
  524. Assert.IsTrue(infoMassages[1].Contains("Class AOP.Tests.TestClass2"));
  525. Assert.AreEqual(0, errorMassages.Count);
  526. }
  528. [Test]
  529. public void LogInfoWithProperStackTrace()
  530. {
  531. var testClass = new TestClass2();
  532. var errorMassages = new List<string>();
  533. var infoMassages = new List<string>();
  534. var decorated = LoggingAdvice<ITestClass2>.Create(
  535. testClass,
  536. s => infoMassages.Add(s),
  537. s => errorMassages.Add(s),
  538. o => o?.ToString());
  540. Assert.Throws<Exception>(() => decorated.MethodWithException());
  542. Assert.AreEqual(1, infoMassages.Count);
  543. Assert.IsTrue(infoMassages[0].Contains("Class AOP.Tests.TestClass2"));
  544. Assert.AreEqual(1, errorMassages.Count);
  545. Assert.IsTrue(errorMassages[0].Contains("Class AOP.Tests.TestClass2"));
  546. //Only original Exception should be logged
  547. Assert.IsFalse(errorMassages[0].Contains("LoggingAdvice.cs"));
  548. Assert.IsTrue(errorMassages[0].Contains("LoggingAdviceTests.cs"));
  549. }
  551. [Test]
  552. public void LogInfoWithProperStackTrace_WhenTask()
  553. {
  554. var testClass = new TestClass2();
  555. var errorMassages = new List<string>();
  556. var infoMassages = new List<string>();
  557. var decorated = LoggingAdvice<ITestClass2>.Create(
  558. testClass,
  559. s => infoMassages.Add(s),
  560. s => errorMassages.Add(s),
  561. o => o?.ToString(),
  562. _taskScheduler);
  564. Assert.Throws<AggregateException>(() => decorated.AsyncMethodWithException().Wait());
  566. Assert.AreEqual(1, infoMassages.Count);
  567. Assert.IsTrue(infoMassages[0].Contains("Class AOP.Tests.TestClass2"));
  568. Assert.AreEqual(1, errorMassages.Count);
  569. Assert.IsTrue(errorMassages[0].Contains("Class AOP.Tests.TestClass2"));
  570. //Only original Exception should be logged
  571. Assert.IsFalse(errorMassages[0].Contains("LoggingAdvice.cs"));
  572. Assert.IsTrue(errorMassages[0].Contains("LoggingAdviceTests.cs"));
  573. }
  575. [Test]
  576. public void LogInfo_WhenPropertySet()
  577. {
  578. var testClass = Substitute.For<ITestClass>();
  579. var errorMassages = new List<string>();
  580. var infoMassages = new List<string>();
  581. var decorated = LoggingAdvice<ITestClass>.Create(
  582. testClass,
  583. s => infoMassages.Add(s),
  584. s => errorMassages.Add(s),
  585. o => o?.ToString());
  587. decorated.Property = "Str1";
  589. testClass.Received().Property = "Str1";
  590. Assert.AreEqual(2, infoMassages.Count);
  591. Assert.IsTrue(infoMassages[0].Contains("set_Property"));
  592. Assert.IsTrue(infoMassages[1].Contains("set_Property"));
  593. Assert.AreEqual(0, errorMassages.Count);
  594. }
  596. [Test]
  597. public void LogInfo_WhenPropertyGet()
  598. {
  599. var testClass = Substitute.For<ITestClass>();
  600. testClass.Property.Returns("Str1");
  601. var errorMassages = new List<string>();
  602. var infoMassages = new List<string>();
  603. var decorated = LoggingAdvice<ITestClass>.Create(
  604. testClass,
  605. s => infoMassages.Add(s),
  606. s => errorMassages.Add(s),
  607. o => o?.ToString());
  609. var value = decorated.Property;
  611. var tmp = testClass.Received().Property;
  612. Assert.AreEqual("Str1", value);
  613. Assert.AreEqual(2, infoMassages.Count);
  614. Assert.IsTrue(infoMassages[0].Contains("get_Property"));
  615. Assert.IsTrue(infoMassages[1].Contains("get_Property"));
  616. Assert.AreEqual(0, errorMassages.Count);
  617. }
  619. /// <summary>
  620. /// Call to process scheduled tasks
  621. /// </summary>
  622. protected void ReleaseContext()
  623. {
  624. Task.Delay(1).Wait();
  625. }
  626. }
  627. }

Image title
Conclusion

This code works for my cases. If you have any examples about when this code does not work or how this code could be improved, please feel free to contact me.

That's it — enjoy!