You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-user@logging.apache.org by Duncan Woods <du...@garradhassan.com> on 2006/07/01 00:34:04 UTC
RE: When to log, when to throw - Help!
Hiya Ron,
Thanks for the response. You certainly understand my intention.
>> There's nothing wrong with calling Pop() yourself:
Oh but there is!
An important attraction of thread context is the automatic clear up that makes it impossible to screw-up. Forget one pop however and your context is misleading for the rest of the lifetime of the application. This may not be due to direct omission but by exceptions that are caught and handled or by different exit points from a function. Its a load of coding overhead and a disaster waiting to happen.
Thanks for the suggestion, its the right output but not quite there!
Thanks,
Duncan
-----Original Message-----
From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
Sent: Fri 6/30/2006 9:14 PM
To: Log4NET User
Subject: RE: When to log, when to throw - Help!
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 <du...@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
RE: When to log, when to throw - Help!
Posted by Duncan Woods <du...@garradhassan.com>.
>> DisposeReason might contain values like
>> ExplicitDisposeCall, ExitingTryBlock,...
Yes I can see that being useful. Similarly in-vain mechanisms that have crossed my mind are:
1. A means to append information to the current stack frame that persists into Exception.StackTrace
2. An event or system interrupt that triggers when any .Net exception is thrown
3. C++ style preprocessor/compiler directives
4. A means to extend functionality of System.Exception (and therefore all ex derived from it)
Do any of these exist?
thanks,
Duncan
-----Original Message-----
From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
Sent: Mon 7/3/2006 6:44 PM
To: Log4NET User
Subject: RE: When to log, when to throw - Help!
Isn't the automatic clean-up more a feature of the using statement
rather than the ThreadContext? In VB.Net, you'd need to call Push and
Pop yourself.
If it were easy to define new language constructs perhaps a
Dispose(DisposeReason) could be added to explain why the object was
being disposed. DisposeReason might contain values like
ExplicitDisposeCall, ExitingTryBlock, ExitingTryBlockWithException,
etc. Then you could choose whether or not to pop values from the NDC
based on how the using block was being disposed. I'm not a language
designer so I don't know how practical that would be. ASP.Net does
something similiar when an item is being removed from the cache but
object disposition occurs much more frequently that removing items from
a cache.
Anyway, I can't think of a simple way to ensure that values don't get
popped when the NDC's Dispose method is called. I'll think about it
somemore...
--- Duncan Woods <du...@garradhassan.com> wrote:
> Hiya Ron,
>
> Thanks for the response. You certainly understand my intention.
>
> >> There's nothing wrong with calling Pop() yourself:
>
> Oh but there is!
>
> An important attraction of thread context is the automatic clear up
> that makes it impossible to screw-up. Forget one pop however and your
> context is misleading for the rest of the lifetime of the
> application. This may not be due to direct omission but by exceptions
> that are caught and handled or by different exit points from a
> function. Its a load of coding overhead and a disaster waiting to
> happen.
>
> Thanks for the suggestion, its the right output but not quite there!
>
> Thanks,
> Duncan
>
>
> -----Original Message-----
> From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
> Sent: Fri 6/30/2006 9:14 PM
> To: Log4NET User
> Subject: RE: When to log, when to throw - Help!
>
> 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 <du...@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))
> > {
>
=== message truncated ===
RE: When to log, when to throw - Help!
Posted by Duncan Woods <du...@garradhassan.com>.
Ron,
>> Isn't the automatic clean-up more a feature of the
>> using statement rather than the ThreadContext?
Sorry if I wasn't clear. I consider them intertwined because I wouldn't use explicit (push/pop) ThreadContext without automatic clear-up. Too error prone.
I have tried to work out a scheme for anonymous delegates to provide context safe exceptions but sadly there is too much dang strong typing so either you have to declare a delegate type for anything you wish to execute contextually or do what I attach below which is ugly in so many different ways! Basically it requires that each level of context is a separate method, which is perfectly acceptable (and often the case anyway), and then call it as a delegate but sadly passing arguments requires filthy casting and its broken for ref, out, value-types and return values.
I post it to see if it sparks the creativity of anyone else to find a more effective scheme that is simpler and type-safe.
On a related note - the NDC Method 'CloneStack' doesn't work as I expected - it doesn't return a copy but a reference that is manipulated without consent plus the contained items are classes internal to log4net that don't have a sensible ToString so you can't do diddly with them. This is why I had to pop and re-push the ndc to copy it in NdcException. Doesn't FxCop warn about this?
anyway... on to the ugliness, believe it or not, it is functionally the same example Ron gave before:
using System;
using System.Collections.Generic;
using System.Text;
using log4net;
using log4net.Appender;
using log4net.Config;
using log4net.Layout;
namespace ConsoleApplication
{
public delegate void ExecuteInContext(params object[] p);
// execute code passed as an anonymous delegate with context safe exceptions
public abstract class Context
{
public static void Execute(string context, ExecuteInContext call, params object[] p)
{
using (NDC.Push(context))
{
try
{
call(p);
}
catch (Exception e)
{
if (!(e is NdcException)) throw new NdcException(e);
else throw;
}
}
}
}
// Wrap a normal exception and append the ndc stack - requires more effort than it should
public class NdcException : Exception
{
public NdcException(Exception e)
: base(e.Message, e)
{
Stack<string> stack = new Stack<string>();
StringBuilder sb = new StringBuilder("Exception : ");
while (NDC.Depth > 0)
{
stack.Push(NDC.Pop());
}
while (stack.Count > 0)
{
string s = stack.Pop();
sb.AppendFormat("{0} ", s);
NDC.Push(s);
}
Ndc = sb.ToString();
}
public string Ndc;
}
class Program
{
static ConsoleAppender consoleAppender;
static ILog log;
static void Main(string[] args)
{
consoleAppender = new ConsoleAppender();
consoleAppender.Layout = new PatternLayout("MESSAGE [%message] NDC [%ndc]%newline");
BasicConfigurator.Configure(consoleAppender);
log = LogManager.GetLogger(typeof(Program));
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)
{
Context.Execute(
"oddNumber: " + oddNumber,
delegate(object[] p) {EachEven((int) p[0], (int[]) p[1]);},
oddNumber, evenNumbers);
}
}
// Provide a contextual exception message
catch (NdcException ex)
{
using (NDC.Push(ex.Ndc))
{
log.Fatal(ex.Message);
}
}
catch (Exception ex)
{
log.Fatal("Should never happen: " + ex.Message, ex);
}
}
public static void EachEven(int oddNumber, int[] evenNumbers)
{
foreach (int evenNumber in evenNumbers)
{
Context.Execute(
"evenNumber: " + evenNumber,
delegate(object[] p) {TestOdd((int) p[0], (int) p[1]);},
oddNumber, evenNumber);
}
}
public static void TestOdd(int oddNumber, int evenNumber)
{
if (oddNumber == 7)
{
throw new ApplicationException("Oh no!");
}
log.DebugFormat("Sum: {0}", oddNumber + evenNumber);
}
}
}
Thanks,
Duncan
RE: When to log, when to throw - Help!
Posted by Duncan Woods <du...@garradhassan.com>.
Hi there,
I have come up with a solution which I think works well enough for me.
It is to store the deepest level of context reached and instead of
popping off each level as the context goes out of scope, it is only
updated when a new context block is started.
The only drawback is that if an exception is thrown /after/ a context
block then it will be misleading. In the code below, if you throw at
XXX, then the NDC will be for the preceding block. I'll simply have to
treat this as part of the coding standards to only apply context to
entire levels of scope.
Any better suggestions?
Thanks,
Duncan
using System;
using System.Collections.Generic;
using System.Text;
using log4net;
using log4net.Appender;
using log4net.Layout;
using log4net.Config;
using System.Diagnostics;
namespace ConsoleApplication1
{
class Program
{
static ConsoleAppender consoleAppender;
static ILog log;
static void Main(string[] args)
{
consoleAppender = new ConsoleAppender();
consoleAppender.Layout = new PatternLayout("MESSAGE
[%message] NDC [%ndc]%newline");
BasicConfigurator.Configure(consoleAppender);
log = LogManager.GetLogger(typeof(Program));
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 (Context.Push("oddNumber: " + oddNumber))
{
foreach (int evenNumber in evenNumbers)
{
using (Context.Push("evenNumber: " +
evenNumber))
{
if (oddNumber == 7)
{
throw new ApplicationException("Oh
no!");
}
log.DebugFormat("Sum: {0}", oddNumber +
evenNumber);
}
// XXX
}
}
}
}
catch (Exception ex)
{
Context.LogException(log, "Unhandled exception '" +
ex.Message + "'", ex);
}
}
/// <summary>
///
/// </summary>
public class Context : IDisposable
{
public static Context Push(string s)
{
return new Context(s);
}
// Log the exception with the deepest ndc reached
public static void LogException(ILog log, string message,
Exception e)
{
Stack<string> ndc = new Stack<string>();
while (NDC.Depth > 0)
{
ndc.Push(NDC.Pop());
}
NDC.Push(DeepestNdc);
log.Error(message, e);
NDC.Pop();
while (ndc.Count > 0)
{
NDC.Push(ndc.Pop());
}
}
// Convert the deepest ndc to a string
public static string DeepestNdc
{
get
{
int i =
System.Threading.Thread.CurrentThread.ManagedThreadId;
Stack<string> context;
if (!deepest.TryGetValue(i, out context))
{
return "";
}
Stack<string> temp = new Stack<string>();
StringBuilder sb = new StringBuilder();
while (context.Count > 0)
{
temp.Push(context.Pop());
}
while (temp.Count > 0)
{
string ndc = temp.Pop();
sb.AppendFormat("{0} ", ndc);
context.Push(ndc);
}
return sb.ToString();
}
}
// Reset the deepest context to the current NDC value
public Context(string s)
{
int i =
System.Threading.Thread.CurrentThread.ManagedThreadId;
Stack<string> context;
if (!deepest.TryGetValue(i, out context))
{
context = new Stack<string>();
deepest[i] = context;
}
while (context.Count > NDC.Depth)
{
context.Pop();
}
context.Push(s);
NDC.Push(s);
}
public void Dispose()
{
NDC.Pop();
}
static Dictionary<int, Stack<string>> deepest = new
Dictionary<int, Stack<string>>();
}
}
}
RE: When to log, when to throw - Help!
Posted by Ron Grabowski <ro...@yahoo.com>.
Isn't the automatic clean-up more a feature of the using statement
rather than the ThreadContext? In VB.Net, you'd need to call Push and
Pop yourself.
If it were easy to define new language constructs perhaps a
Dispose(DisposeReason) could be added to explain why the object was
being disposed. DisposeReason might contain values like
ExplicitDisposeCall, ExitingTryBlock, ExitingTryBlockWithException,
etc. Then you could choose whether or not to pop values from the NDC
based on how the using block was being disposed. I'm not a language
designer so I don't know how practical that would be. ASP.Net does
something similiar when an item is being removed from the cache but
object disposition occurs much more frequently that removing items from
a cache.
Anyway, I can't think of a simple way to ensure that values don't get
popped when the NDC's Dispose method is called. I'll think about it
somemore...
--- Duncan Woods <du...@garradhassan.com> wrote:
> Hiya Ron,
>
> Thanks for the response. You certainly understand my intention.
>
> >> There's nothing wrong with calling Pop() yourself:
>
> Oh but there is!
>
> An important attraction of thread context is the automatic clear up
> that makes it impossible to screw-up. Forget one pop however and your
> context is misleading for the rest of the lifetime of the
> application. This may not be due to direct omission but by exceptions
> that are caught and handled or by different exit points from a
> function. Its a load of coding overhead and a disaster waiting to
> happen.
>
> Thanks for the suggestion, its the right output but not quite there!
>
> Thanks,
> Duncan
>
>
> -----Original Message-----
> From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
> Sent: Fri 6/30/2006 9:14 PM
> To: Log4NET User
> Subject: RE: When to log, when to throw - Help!
>
> 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 <du...@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))
> > {
>
=== message truncated ===