14

With the help of AOP, I can remove the logging code from my business logic. But I think it can only be used to log simple things (i.e. logging method entry/exit and parameter values).

However, what if I need to log something in my business logic? e.g.

public void SomeDomainMethod(string id)
{
   //Get user by Id
   User user = Users.Get(id);
   if (user == null)
   {
      Log.Warn("user is not existed");        //<----------------- Log A
      throw new InvalidOperationException("user is not existed");
   }

   //Step 1 
   while(true)
   {
       //do something
   }
   Log.Info("Step 1 is completed");            //<----------------- Log B

   //Step 2
   while(true)
   {
       //do something
   }
   Log.Info("Step 2 is completed");            //<----------------- Log C

}

The above sample method may not be clear enough, what I want to show here is that the method should be treated as the smallest unit from the domain point of view. It shouldn't be divided into smaller pieces.

Is it possible to move above 3 logging code out of the method? What's best practice for such situation?

Charlie
  • 251
  • 2
  • 6
  • I am pretty sure your example's "Step1" and "Step2" logs should be part of a business logic audit trail and the first one a technical logging. I would first sort this... – tofro Mar 16 '17 at 07:53

8 Answers8

10

Sure, you can easily use AOP for this. Simply refactor the parts

  • Get user by Id
  • step 1
  • step 2

into separate methods (as you should have done either to make your code cleaner). Now you can easily configure your AOP framework to log the method calls of your choice (like shown here). The exception can be logged directly by the caller, no need to use AOP for getting this out of the business logic.

To your edit:

I want to show here is that the method should be treated as the smallest unit from the domain point of view. It shouldn't be divided into smaller pieces

By why shouldn't it? If, in a "business logic context", you want to log "something" which is worth logging, and if this "something" can be given a sensible name, in most cases it will make sense to refactor the code into a method on its own. If you want to use AOP, it will require you to structure your code in a way you probably should have structured it regardless of the logging requirement. You can interpret this as a disadvantage of AOP, or you can interpret this as a benefit, since it gives you a feedback where your code structure can be improved.

Doc Brown
  • 199,015
  • 33
  • 367
  • 565
  • It's my bad that my example is not clear enough. What I actually want to show in the example is that the method is the smallest unit from the domain point of view which shouldn't be divided into smaller pieces. – Charlie Mar 17 '17 at 11:45
  • @Charlie: the example is perfectly clear. Your misconception here is probably you think it might be a good idea to have larger methods than steps. And that is IMHO wrong, it is not a good idea. Having different steps worth logging is a clear sign these steps should have an abstraction, a name on its own, therefore a method on its own. – Doc Brown Mar 17 '17 at 12:21
  • @Charlie nothing stop you from doing 3 private method being called by your unit or work. This way from outside it stayed the same but now you have the required abstraction for your logging. – Rémi Mar 17 '17 at 12:43
  • This approach is fine if you want to drive your code structure by logging concerns. Sometimes you want to drive it by something else, though. – John Wu Mar 17 '17 at 12:56
  • @JohnWu: the code structure should reflect the different concerns/steps, regardless of the logging requirement. **That** is what drives the code structure here. Once this problem is solved, logging can be done by AOP, that is more a "side effect" of giving the code a better structure. So I think it is not the logging concern which drives the code structure, it is more that the requirement of using AOP for logging makes it more transparent that the code misses some structure which it should have either. – Doc Brown Mar 17 '17 at 13:44
  • Sounds sort of ivory tower to me, my friend. What you are saying is only true if you are assume either that logging drives structure or that logging must correspond to the structure. There are obvious cases where this is false-- e.g. post hoc logging after a problem is found. In that case, restructuring the code could cause the problem to move or change. If we limited ourselves to logging through AOP, it would not be possible to further diagnostic efforts through enhanced logging. – John Wu Mar 17 '17 at 15:30
  • @JohnWu: well, if I got this right, the "post hoc logging" situation is something like the "exception" from the example above, right? But that is easily solved by logging at "catch" side instead of the throw side, so nothing which requires restructuring the code, or AOP, at all. – Doc Brown Mar 17 '17 at 16:04
  • ... but don't get me wrong, I am just questioning the assumption of the OP that AOP can only be used for "simple things". I do not say it is the ideal solution for any kind of logging requirement. – Doc Brown Mar 17 '17 at 16:08
  • @Doc "Post hoc logging" is any logging that is added post hoc. Hopefully any experienced developer would think to log uncaught exceptions pre hoc. – John Wu Mar 17 '17 at 17:25
4

Sure!

But in my experience, there are two general types of useful logging:

Everything logs: Logs built through profiling API's. Good for identifying performance issues and reporting exceptions. Very noisy.

Business event logs: Logs invoked in business logic. Anything the business might care about. Minimal noise. Just notable, logical, "business" events. Good for auditing and KPI's...

So, I would highly suggest two things. Firstly, do what other monitoring tools do, like New Relic, and use the .NET profiling API1. Secondly, log logical business events in your business logic. Keeping a record of certain events is business logic.

And, I wouldn't normally suggest AOP for either sort of logging2. In my experience, you either want everything, which means you're using a profiler, or you you want logical/business events. And in the latter case, I think it's more straightforward to just invoke the logger in the business logic.

1. But seriously, save yourself thousands of hours in effort and just use an existing profiler tool...

2. Of course, this assumes that you share my opinion that an aspect isn't a great place to hide business rules!

svidgen
  • 13,414
  • 2
  • 34
  • 60
  • I'm quite agree on the "Business event logs", and just like others' answers, I will keep the log code in the business logic. And for "Everything logs" part, I'm prefer to using AOP solution as it'll follow the SRP and not pollute my business logic. Anyway, I'll take a look at the profiling API firstly. – Charlie Mar 22 '17 at 02:01
3

Unless Logging stuff is part of the business requirements then its best, as you say, to keep it completely out of your code.

That means you really don't want to log stuff like "step 1 complete". Although it might be initially useful for debugging, in production its just going to generate gigabytes of rubbish that you will never look at.

If Step1Complete is a some sort of business event which requires further action then it can be exposed through a good old fashioned event without forcing you to inject a ILogger or similar into your class

Ewan
  • 70,664
  • 5
  • 76
  • 161
  • That's what I was thinking. I can't come up with a reasonable case for logging within a domain/business model POCO. Logging is something that tends to naturally fit in outside of the core business models, IMO. – jleach Mar 17 '17 at 14:13
2

By aid of some common pattern you can pull out logging code from your business logic. However you may not find it worth doing so

For example, by use of listener (handcraft one or using event bus etc), your code will look like

public void SomeDomainMethod(string id)
{
   //Get user by Id
   User user = Users.Get(id);
   if (user == null)
   {
      listener.OnUserNotFound(userId);
      throw new InvalidOperationException("user is not existed");
   }

   //Step 1 
   while(true)
   {
       //do something
   }
   listener.OnStep1Finished(......);

   ...

}

By implementing the logging in the listener, logging logic is no longer in your business logic.

However you may find this is not always realistic as you may not always be able to define meaningful event of your logic.

Another approach is through mechanism like Dtrace in Solaris which allow you to inject into running processes (I believe there are way to do similar thing in C#?) so logging and statistic gatherings can be defined on runtime. Still there are other drawbacks.

Adrian Shum
  • 1,095
  • 7
  • 11
  • One problem AOP is trying to solve is the problem of code becoming unreadable of non-business code (like logging calls) interweaved with "business code" . Replacing a "logger" by a "listener" does not solve this, the readability of the code is not changed, – Doc Brown Mar 17 '17 at 17:11
2

Another approach is to put business logging and technical logging apart. Then we can call business logging "Audit" and apply a specific set of business rules like storage term and processing rules like Business Activity Monitoring.

On the other hand, technical logging, or simply "Logging", is a means of last resort to leave a trace of technical problem. It should be async, fast, tolerant to failure to persist log message. Also, log messages should pass through the least number of proxies possible to be close to the source of the trouble.

Logic of The Logging is quite variable and is tightly coupled with implementation, so do you really need to separate it from code?

Logic of The Audit should be considered a domain logic and handled accordingly.

For example, in Hexagonal Architecture there might be Audit port along with Clients, Storage and MQ (and, possibly, Metrics and Control) ports. It would be secondary port, i.e. activity on this port is triggered by the business core, rather than by external systems.

iTollu
  • 315
  • 2
  • 8
  • I very agreed on you that there're two kinds of logging. But I don't get _Logic of The Logging is quite variable and is tightly coupled with implementation_ , do you mean technical logging here? For technical logging, I think it's used to log method entry/exit and parameter values which is better to sit outside the method. – Charlie Mar 17 '17 at 12:26
  • @Charlie Yes, by "The Logging" I mean technical logging. Entry/exit/parameter values logging is sufficient in the case of pure functions. Then, or course, you could use an aspect or Logger monad. But pure functions are great in that they are testable. So, issues, the logger is supposed to trace, are likely to be solved during dev/debug. With impure functions, where tech logging is of most use, you'd want to log every side-effectful call params/result, every exception. – iTollu Mar 17 '17 at 12:35
1

Ways to avoid logging directly in a class or method:

  1. Throw an exception, and do your logging in a catch block farther up the call tree. If you need to capture a log level, you can throw a custom exception.

  2. Make calls to methods that are already instrumented for logging.

Robert Harvey
  • 198,589
  • 55
  • 464
  • 673
1

Is it really needed to separate your logging from your business logic? Logging being done is in correspondence to the business logic written and hence makes sense to be in the same class/function. More importantly, it aids easier readability of the code.

However, in case you really want to segregate logging from your business logic, you should consider throwing custom exceptions and handing those exceptions for logging.

user88748
  • 61
  • 2
0

No, not in c#

OP, the answer to your specific question is no, not in c#. There may be other, more natively AOP languages out there, but all the approaches to AOP in c# that I have seen can only apply aspected behaviors in the context of a join point, meaning there has to be flow of control between one code block and another. Aspected behaviors will not execute in the middle of a method, except of course by calling another method.

You could "apsect-ize" certain bits of logging

That being said, you could extract certain concerns involved in logging, just not log writing. For example, a cutpoint that executed on entry to a method could set up a logging context and output all the input parameters, and on exit could catch exceptions or commit a log to permanent storage, that sort of thing.

Log writing isn't an aspect, anyway

I would add that log writing isn't really a cross-cutting concern, anyway. At least not debug logging. My evidence for this is that you could not write a cross-cutting requirement that fully explains what this aspect would do-- it is specific for each and every case, because the purpose of writing the log is to reflect what is going on with the logic, and the logic in each method ought to be reasonably unique (see DRY).

In other words, there is an inextricable logical dependency between log writing and the stuff being written about. You can't generalize it.

But auditing is

If you have some sort of functional logging requirement (e.g. audit logging in support of a non-repudiation requirement) then some would argue (and I would agree) that if you find yourself needing to execute these log writes in the middle of a method, you have not structured your code in a manner that is consistent with aspect-oriented thinking. If this occurs, you should extract code into separate methods until you get the level of granularity you need.

Community
  • 1
John Wu
  • 26,032
  • 10
  • 63
  • 84