Discussion about usage and installation of the log4cxx library

Christopher Nagel | 18 May 2012 21:14

Using NDC?

I had the following code at the beginning of every method of an object:

log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, "Doing whatever!") ;

m_loggingContext was set in an init method to be like "Chan 4 / Dev 3".

This worked OK but eventually, if one method called another, I'd get NDC's in the log (pattern = "<%t>") that were concatenated duplicates, e.g.,

... <Chan 4 / Dev 3 Chan 4 / Dev 3> ... Doing whatever!

Not good.

So, I changed the code to this:

if( log4cxx::NDC::empty() )
log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, " Doing whatever!") ;

Now, the logs all show <null> for ALL NDC's, everywhere.

What is the correct way to avoid duplicate NDC's but also get some output?

Thanks,
Chris

headers

Christopher Nagel | 18 May 2012 21:23

Re: Using NDC?

BTW, I should also note that in stepping through the code, NDC::empty() returns true so the new NDC is then instantiated.

Could it be that the scope of the IF statement causes it to pop() as soon as it's push()ed by the ctor?

Chris

On Fri, May 18, 2012 at 3:14 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

I had the following code at the beginning of every method of an object:

log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, "Doing whatever!") ;

m_loggingContext was set in an init method to be like "Chan 4 / Dev 3".

This worked OK but eventually, if one method called another, I'd get NDC's in the log (pattern = "<%t>") that were concatenated duplicates, e.g.,

... <Chan 4 / Dev 3 Chan 4 / Dev 3> ... Doing whatever!

Not good.

So, I changed the code to this:

if( log4cxx::NDC::empty() )
log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, " Doing whatever!") ;

Now, the logs all show <null> for ALL NDC's, everywhere.

What is the correct way to avoid duplicate NDC's but also get some output?

Thanks,
Chris

headers

Christopher Nagel | 22 May 2012 21:27

Re: Using NDC?

Just to be a good citizen, I thought I'd offer the solution I am using:

if( log4cxx::NDC::getDepth() == 0 )

log4cxx::NDC ndc(m_loggingContext);

Chris

On Fri, May 18, 2012 at 3:23 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

BTW, I should also note that in stepping through the code, NDC::empty() returns true so the new NDC is then instantiated.

Could it be that the scope of the IF statement causes it to pop() as soon as it's push()ed by the ctor?

Chris

On Fri, May 18, 2012 at 3:14 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

I had the following code at the beginning of every method of an object:

log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, "Doing whatever!") ;

m_loggingContext was set in an init method to be like "Chan 4 / Dev 3".

This worked OK but eventually, if one method called another, I'd get NDC's in the log (pattern = "<%t>") that were concatenated duplicates, e.g.,

... <Chan 4 / Dev 3 Chan 4 / Dev 3> ... Doing whatever!

Not good.

So, I changed the code to this:

if( log4cxx::NDC::empty() )
log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, " Doing whatever!") ;

Now, the logs all show <null> for ALL NDC's, everywhere.

What is the correct way to avoid duplicate NDC's but also get some output?

Thanks,
Chris

headers

Christopher Nagel | 23 May 2012 00:32

Re: Using NDC?

OMG, Well, unfortunately although this worked fine in debug mode I'm afraid it is just different at runtime outside GDB: the pop() is, as confirmed by log entries, happening at the tail end of the IF branch!! Yet, across function calls in other parts of the code, I get TWO NDC's.

At this point, I am thinking this is actually several bugs:

This is just baffling me. I really doubt the thing would pop()

On Tue, May 22, 2012 at 3:27 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

Just to be a good citizen, I thought I'd offer the solution I am using:

if( log4cxx::NDC::getDepth() == 0 )

log4cxx::NDC ndc(m_loggingContext);

Chris

On Fri, May 18, 2012 at 3:23 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:
BTW, I should also note that in stepping through the code, NDC::empty() returns true so the new NDC is then instantiated.

Could it be that the scope of the IF statement causes it to pop() as soon as it's push()ed by the ctor?

Chris

On Fri, May 18, 2012 at 3:14 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

I had the following code at the beginning of every method of an object:

log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, "Doing whatever!") ;

m_loggingContext was set in an init method to be like "Chan 4 / Dev 3".

This worked OK but eventually, if one method called another, I'd get NDC's in the log (pattern = "<%t>") that were concatenated duplicates, e.g.,

... <Chan 4 / Dev 3 Chan 4 / Dev 3> ... Doing whatever!

Not good.

So, I changed the code to this:

if( log4cxx::NDC::empty() )
log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, " Doing whatever!") ;

Now, the logs all show <null> for ALL NDC's, everywhere.

What is the correct way to avoid duplicate NDC's but also get some output?

Thanks,
Chris

headers

Christopher Nagel | 23 May 2012 00:41

Re: Using NDC?

Sorry - I forget that when using GMAIL suddenly the TAB and SPACE keys are dangerous nuclear weapons ( <at> #$! <at> #%!#2 browser based society...)

1. NDC should not auto-pop() until a functional boundary is reached - in other words, IF branches should not cause pop() but new functions should.

2. Identical NDC strings should be merged (as would keys in an MDC). Or, it should be a class setting - NDC::setCoalescesDuplicateStrings(bool);

3. (Enhancement): Allow NDC to be created as an instance variable of an object and printed with that object's logging messages (e.g., allow them to be object based, not thread-based)

4. NDC documentation is sorely in need of updating, as it's still a hacked copy of the Java version

Chris

On Tue, May 22, 2012 at 6:32 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

OMG, Well, unfortunately although this worked fine in debug mode I'm afraid it is just different at runtime outside GDB: the pop() is, as confirmed by log entries, happening at the tail end of the IF branch!! Yet, across function calls in other parts of the code, I get TWO NDC's.

At this point, I am thinking this is actually several bugs:

This is just baffling me. I really doubt the thing would pop()

On Tue, May 22, 2012 at 3:27 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:
Just to be a good citizen, I thought I'd offer the solution I am using:

if( log4cxx::NDC::getDepth() == 0 )

log4cxx::NDC ndc(m_loggingContext);

Chris

On Fri, May 18, 2012 at 3:23 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:
BTW, I should also note that in stepping through the code, NDC::empty() returns true so the new NDC is then instantiated.

Could it be that the scope of the IF statement causes it to pop() as soon as it's push()ed by the ctor?

Chris

On Fri, May 18, 2012 at 3:14 PM, Christopher Nagel <cnagel.com <at> gmail.com> wrote:

I had the following code at the beginning of every method of an object:

log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, "Doing whatever!") ;

m_loggingContext was set in an init method to be like "Chan 4 / Dev 3".

This worked OK but eventually, if one method called another, I'd get NDC's in the log (pattern = "<%t>") that were concatenated duplicates, e.g.,

... <Chan 4 / Dev 3 Chan 4 / Dev 3> ... Doing whatever!

Not good.

So, I changed the code to this:

if( log4cxx::NDC::empty() )
log4cxx::NDC ndc( m_loggingContext );
LOG4CXX_TRACE(logger, " Doing whatever!") ;

Now, the logs all show <null> for ALL NDC's, everywhere.

What is the correct way to avoid duplicate NDC's but also get some output?

Thanks,
Chris

headers

Jacob L. Anawalt | 23 May 2012 01:58

Re: Using NDC?

On 2012-05-22 16:41, Christopher Nagel wrote:
> 1. NDC should not auto-pop() until a functional boundary is reached - in other
> words, IF branches should not cause pop() but new functions should.

I appreciate the scoped (RAII) behavior of the constructor based NDC push/pop, 
as documented in the API docs under NDC Constructor & Destructor Documentation.

http://logging.apache.org/log4cxx/apidocs/classlog4cxx_1_1_n_d_c.html

If you don't want an if statement to push/pop, don't create new stack based 
instances within the if scope. Instead consider using the static push and pop 
methods. Eg:

if( some condition )
	log4cxx::NDC::push(m_loggingContext);

http://wiki.apache.org/logging-log4cxx/NestedDiagnosticContexts

--

-- 
Jacob Anawalt
Gecko Software, Inc.
janawalt <at> geckosoftware.com
435-752-8026