logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ron Grabowski <rongrabow...@yahoo.com>
Subject RE: When to log, when to throw - Help!
Date Fri, 30 Jun 2006 20:14:55 GMT
Let's configure a basic ConsoleAppender and use a using() block to push
items onto the NDC from two loops:

 ConsoleAppender consoleAppender = new ConsoleAppender();
 consoleAppender.Layout = new PatternLayout(
  "MESSAGE [%message] NDC [%ndc] EXCEPTION [%exception]%newline");
 BasicConfigurator.Configure(consoleAppender);

 ILog log = LogManager.GetLogger(typeof(Class1));

 int[] oddNumbers = new int[5] {1, 3, 5, 7, 9};
 int[] evenNumbers = new int[5] {2, 4, 6, 8, 10};

 try
 {
  foreach (int oddNumber in oddNumbers)
  {
   using(NDC.Push("oddNumber: " + oddNumber))
   {
    foreach (int evenNumber in evenNumbers)
    {
     using(NDC.Push("evenNumber: " + evenNumber))
     {
      if (oddNumber == 7)
      {
       throw new ApplicationException("Oh no!");
      }
      log.DebugFormat("Sum: {0}", 
       oddNumber + evenNumber);
     }
    }
   }
  }
 }
 catch (Exception ex)
 {
  log.Fatal(
   "Unhandled exception. Cause: " + ex.Message, ex);
 }

That program produces the following output:

MESSAGE [Sum: 3] NDC [oddNumber: 1 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 5] NDC [oddNumber: 1 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 1 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 1 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 1 evenNumber: 10] EXCEPTION []
MESSAGE [Sum: 5] NDC [oddNumber: 3 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 3 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 3 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 3 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 13] NDC [oddNumber: 3 evenNumber: 10] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 5 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 5 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 5 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 13] NDC [oddNumber: 5 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 15] NDC [oddNumber: 5 evenNumber: 10] EXCEPTION []
MESSAGE [Unhandled exception. Cause: Oh no!] NDC [(null)] EXCEPTION
[System.ApplicationException: Oh no!
   at ConsoleApplication1.Class1.ndcPushWithUsing() in 
c:\consoleapplication1\class1.cs:line 45
]

I suspect your question is about the null NDC value when the exception
occurs. It would be better to show this information:

 NDC [oddNumber: 7 evenNumber: 2]

C#'s using() statement automatically calls Dispose() on its expression.
When you leave the try block and enter the catch block the objects in
the try block are disposed. In the case of NDC, the items are being
popped from the stack and the stack becomes empty.

There's nothing wrong with calling Pop() yourself:

 try
 {
  foreach (int oddNumber in oddNumbers)
  {
   NDC.Push("oddNumber: " + oddNumber);
   {
    foreach (int evenNumber in evenNumbers)
    {
     NDC.Push("evenNumber: " + evenNumber);
     {
      if (oddNumber == 7)
      {
       throw new ApplicationException("Oh no!");
      }
      log.DebugFormat("Sum: {0}", 
       oddNumber + evenNumber);
     }
     NDC.Pop();
    }
   }
   NDC.Pop();
  }
 }
 catch (Exception ex)
 {
 log.Fatal(
  "Unhandled exception. Cause: " + ex.Message, ex);
 }
 finally
 {
  NDC.Clear();
 }

That code produces the following output:

MESSAGE [Sum: 3] NDC [oddNumber: 1 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 5] NDC [oddNumber: 1 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 1 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 1 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 1 evenNumber: 10] EXCEPTION []
MESSAGE [Sum: 5] NDC [oddNumber: 3 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 3 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 3 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 3 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 13] NDC [oddNumber: 3 evenNumber: 10] EXCEPTION []
MESSAGE [Sum: 7] NDC [oddNumber: 5 evenNumber: 2] EXCEPTION []
MESSAGE [Sum: 9] NDC [oddNumber: 5 evenNumber: 4] EXCEPTION []
MESSAGE [Sum: 11] NDC [oddNumber: 5 evenNumber: 6] EXCEPTION []
MESSAGE [Sum: 13] NDC [oddNumber: 5 evenNumber: 8] EXCEPTION []
MESSAGE [Sum: 15] NDC [oddNumber: 5 evenNumber: 10] EXCEPTION []
MESSAGE [Unhandled exception. Cause: Oh no!] NDC [oddNumber: 7
evenNumber: 2] EXCEPTION [System.ApplicationException: Oh no!
   at ConsoleApplication1.Class1.ndcPushWithUsing() in 
c:\consoleapplication1\class1.cs:line 45
]

Is that an ok solution?

- Ron

--- Duncan Woods <duncan.woods@garradhassan.com> wrote:

> Hi Ron,
> 
> Thanks for reply.
> 
> >> I usually catch exceptions at higher levels (my user interface 
> >> or business layer) and let lower levels such as my data level 
> >> simple bubble the exceptions up.
> 
> Precisely what I do but almost all the error messages are unhelpful
> without context. The following example gives a bit more of a feel for
> the hierarchical multi part operations that include external plug-ins
> (which also use log4net):
> 
> try
> {
>   foreach (service in Services)
>   {
>     using(NDC.Push("Updating service " + service.Name))
>     {
>       foreach (model in service.models)
>       {
>         using(NDC.Push("Executing model " + model.Name))
>         {
>     	    foreach (input in model)
>           {
>             using(NDC.Push("Extracting input " + input.Name))
>             {
>                // db
>             }
> 	      using(NDC.Push("Calculate " + model.Name))
>             {
>                // external calc 
>             }
>           }
>         }		
>       }
>     }
>   }
> }
> catch (Exception e)
> {
>   log.Error("Unexpected error. Cause: " + ex.Message, ex);
> }
> 
> This works great for successful logging where each log message is
> qualified with its own context but every exception is fatal so there
> are
> few catch handlers. A typical framework exception like "Key not
> found"
> from a dictionary object is useless at the top level but with an NDC
> an
> error could be logged with:
> 
>  "Updating service Foo, Executing model Bar, Extracting Input Dingo".
> 
> which gives a chance to resolve the problem. If they are my own
> exceptions (lots are) then I could do this:
> 
> catch (NdcException e)
> {
>   using(NDC.Push(e.Ndc))
>   {
>     log.Error("Unexpected error. Cause: " + ex.Message, ex);
>   }  
> }
> 
> where e.Ndc is the state of the Ndc at the throw minus the ndc at the
> catch. I'd still have to wrap and rethrow non NdcExceptions at every
> level of the Ndc hierarchy. I suppose that when not using a logging
> framework I expect to catch, wrap and rethrow exceptions to give them
> context anyway but I'm not satisfied with that given that there is an
> Ndc sat there.
> 
> Thoughts?
> 
> http://logging.apache.org/log4net/release/manual/contexts.html
> 
> I need a thread context stack so I believe ndc is the best bet since
> its
> handled by tools like ChainSaw.
> 
> Thanks,
> Duncan

Mime
View raw message