5

I have the following classes :

class Task
{
    public void DoSomething()
    { 
        var s = new Service();
        s.First();
        s.Second();
        s.Third();
    }
}

class Service
{
    public void First() {};
    public void Second() {};
    public void Third() {};
}

If I want to add logging, should I put logging statements like this :

    public void DoSomething()
    { 
        Log("new");
        var s = new Service();

        Log("First");
        s.First();

        Log("Second");
        s.Second();

        Log("Third");
        s.Third();
    }

Or should I put each statement inside the called methods of Service class ?

I know it is quite subjective, and won't change a lot of things, but I'm curious about the pros and cons of each approach.

Update : I'm not asking about verbosity or level, just about placement of the logging statements.

  • 1
    For me a general rule is to place a logging statement where it will better serve an additional documenting purpose. Which, of course, depends on context. – SK-logic Apr 6 '11 at 11:55
8

It is indeed subjective. Every project and every situation requires its own level and verbosity of logging.

Personally, I would put the statements inside the methods they refer to. This is more foolproof, as it logs any calls to these methods, not just the ones inside doSomething(). This may help you spot subtle bugs in the long run, if the methods are called when it's not appropriate.

Nevertheless, I don't put entry/exit log statements into code by default, as they create too much noise. Only specific cases justify them, e.g. when analysing a complex module or hunting down a tricky bug (such as a concurrency issue).

1

This strongly depends on what you need it for. Without knowing about your situation I would suggest that you consider the following:

  • Use a logging framework that allows for one message being more important than another. Typically you are interested in ERROR (really bad), INFO (like a pulse) and DEBUG (ok, what did actually happen here). Also log statements are time stamped.
  • All exceptions need to be logged at ERROR level.
  • The things you need to see to be convinced that things are working nicely should be logged at INFO level. You do not necessarily want a lot here. Just enough to see that things run smoothly.
  • The things you need to see to figure out where things go slow or incorrect log at DEBUG level. This can be very verbose as you only activate it when you need to see problems.
  • Make the messages self-standing if at all possible. This allows you to read the log files more quickly.

In this case I would consider

public void DoSomething()
{ 
    Log.info("DoSomething()");
    var s = new Service();

    Log.debug("First");
    s.First();

    Log.debug("Second");
    s.Second();

    Log.debug("Third");
    s.Third();
}

But you are the only one to know what you will need to know to debug an issue. Much of this knowledge unfortunately comes from having been in situations where you didn't have it. Hopefully this will avoid some of them.

Good luck.

0

There are no fixed rules on this as Peter has written, I would do both - put some inside each individual method as well as before it.

In the current code example, if there is an exception in First(), you would probably know it when you don't see the logger before calling Second()

However, you could log something in First() to ensure that First() did it's task successfully and then move on to Second() and so on

0

Yep, fairly subjective. What I do:

  • Log entry to a public method (with param values).
  • Log exit from the same (with return value if there is one).
  • Log exceptions (with appropriate details).

Personally I have found that doing more than this adds more noise for less value. E.g. I rarely log entry/exit in private methods, I occassionaly log unexpected paths that may be errors but are not exceptions, but this is very rare. If I were writing your code above I would remove the Log("First") etc, and put logging inside the First() method (if it were public).

0

Update : I'm not asking about verbosity or level, just about placement of the logging statements

Sorry, but that's the wrong attitude. If you don't think about what you're logging, then where you log doesn't matter. In fact, you can place your logging statements wherever you like, because they'll not add much value.

Taking an example from your code:

class Task
{
    public void DoSomething()
    { 
        var s = new Service();
        s.First();
        s.Second();
        s.Third();
    }
}

DoSomething has no decision points, so there's no good reason to log between each statement. If any of the method calls fail, of course, it's important to log that. However, that typically gets handled via a catch block.

On the other hand, it's critically important to know what task is being processed, and what context surrounds that task (I'm assuming a unique task ID and user here):

class Task
{
    public void DoSomething()
    { 
        log("DoSomething: task " + getId() + " invoked by " + getUser());
        var s = new Service();
  • I knew what to log in the specific case that made me wonder where to put statements. It was too speecific to turn it into a question. But you have a good point on the verbosity. – mathieu Apr 6 '11 at 11:47
0

I prefer to separate logging from my code. This gives each class a single reason to change. The logging class changes when a troubleshooting dev needs more info. The actual code changes with its stakeholder's requirements. So I would create a LoggableService that would look like this (in C#).

public class LoggableService : Service 
{
  private Logger _logger

  public LoggableService(Args args, Logger logger) : base(args)
  {
    _logger = logger;
  }

  public override void First() {
  {
    LogStart(MethodBase.GetCurrentMethod().Name);
    base.First();
    LogSuccess(MethodBase.GetCurrentMethod().Name);
  }

  public override void Second() {
  {
    LogStart(MethodBase.GetCurrentMethod().Name);
    base.Second();
    LogSuccess(MethodBase.GetCurrentMethod().Name);
  }

  public override void Third() {
  {
    LogStart(MethodBase.GetCurrentMethod().Name);
    base.Third();
    LogSuccess(MethodBase.GetCurrentMethod().Name);
  }    

  private void LogStart(string method)
  {
    _logger.Info($"{method}: STARTED");
  }      

  private void LogSuccess(string method)
  {
    _logger.Info($"{method}: SUCCESS");
  }

}

So when LoggableService.First is called, the log will show a First: STARTED and First: SUCCESS. DoSomething will look like this.

public void DoSomething()
{
  var s = new LoggableService();
  s.First();
  s.Second();
  s.Third();
}

The log will look like this.

First: STARTED
First: SUCCESS
Second: STARTED
Second: SUCCESS
Third: STARTED
Third: SUCCESS

protected by gnat Aug 31 '18 at 13:27

Thank you for your interest in this question. Because it has attracted low-quality or spam answers that had to be removed, posting an answer now requires 10 reputation on this site (the association bonus does not count).

Would you like to answer one of these unanswered questions instead?

Not the answer you're looking for? Browse other questions tagged or ask your own question.