You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4cxx-user@logging.apache.org by Anita Banerji <An...@postgrad.manchester.ac.uk> on 2007/10/18 10:10:34 UTC
level problem
Hi,
I wish to print out variable values within my code at the various
different logging levels. However, debug level statements are printed
when there are also info level statements within the same function. I'd
appreciate any advice on how to prevent this happening.
With the level set to INFO in the config file:
log4j.logger.ImageVolume=INFO I would not expect to see the debug level
output: "generateImage: xMax: ok".
Thank you,
Anita
Output:
INFO ImageVolume - creating a new image volume
INFO ImageVolume - generateImage: no noise added
INFO ImageVolume - generateImage: mapping to image
INFO ImageVolume - generateImage: xMax: okgenerateImage: complete
In ImageVolume.h
class ImageVolume
{
static log4cxx::LoggerPtr logger;
shared_ptr<logstream> outstream;
...
};
In ImageVolume.cc
LoggerPtr ImageVolume::logger(Logger::getLogger("ImageVolume"));
ImageVolume::ImageVolume(shared_ptr<TissueToVoxelMap> tissueToVoxelMap)
{
shared_ptr<logstream> log(new logstream(logger,
Level::OFF));
outstream= log;
*outstream << Level::INFO << "creating a new image volume "
<< LOG4CXX_ENDMSG;
...
}
void ImageVolume::generateImage(shared_ptr<SignalProduction>
signalProduction,
shared_ptr<TissueToVoxelMap> tissueToVoxelMap, shared_ptr<Noise> noise)
{
*(outstream.get()) << Level::INFO << "generateImage: no
noise added " << LOG4CXX_ENDMSG;
shared_ptr< map<TISSUETYPE, SIGNAL_INTENSITY> >
tissueToSignalMap= signalProduction->generateSignalForAllTissues();
unsigned xMax= image->getDimX();
unsigned yMax= image->getDimY();
unsigned zMax= image->getDimZ();
*(outstream.get()) << Level::INFO << "generateImage: mapping
to image" << LOG4CXX_ENDMSG;
*outstream << Level::DEBUG << "generateImage: xMax: " <<
xMax << " ok" << LOG4CXX_ENDMSG;
...
*(outstream.get()) << Level::INFO << "generateImage:
complete" << LOG4CXX_ENDMSG;
}
Re: level problem
Posted by Curt Arnold <ca...@apache.org>.
On Nov 9, 2007, at 5:54 AM, Anita Banerji wrote:
> Thanks for the help.
>
> I've checked out the svn head to get the macros that allow me to
> use the
> insertion operator so that I can follow your advice. However, the
> install fails. Any help would be greatly appreciated.
>
> Interestingly I checked out yesterday and twice today in order to
> try a
> couple of times and I got different failure from yesterdays check out.
>
> Thanks,
>
> Anita
>
Logged issue as LOGCXX-206 and temporarily disabled the offending
tests. Won't be able to work on log4cxx until Monday.
Re: level problem
Posted by Curt Arnold <ca...@apache.org>.
On Nov 9, 2007, at 5:54 AM, Anita Banerji wrote:
> Thanks for the help.
>
> I've checked out the svn head to get the macros that allow me to
> use the
> insertion operator so that I can follow your advice. However, the
> install fails. Any help would be greatly appreciated.
>
> Interestingly I checked out yesterday and twice today in order to
> try a
> couple of times and I got different failure from yesterdays check out.
>
> Thanks,
>
> Anita
>
Thanks for the report. Gump is seeing the same thing:
http://vmgump.apache.org/gump/public/logging-log4cxx/logging-log4cxx-
ant/gump_work/build_logging-log4cxx_logging-log4cxx-ant.html
I but I haven't seen it on when running the tests locally. I don't
know why Gump hasn't been nagging. Its last successful run was over
a week ago. Will investigate.
I've recently rewritten the logstream code and would appreciate any
performance comparisons or observations you could provide between the
old code and the new code and the new code and using insertion
operators.
RE: level problem
Posted by Anita Banerji <An...@postgrad.manchester.ac.uk>.
Thanks for the help.
I've checked out the svn head to get the macros that allow me to use the
insertion operator so that I can follow your advice. However, the
install fails. Any help would be greatly appreciated.
Interestingly I checked out yesterday and twice today in order to try a
couple of times and I got different failure from yesterdays check out.
Thanks,
Anita
My system:
uname -a
Linux linux-lfns 2.6.16.13-4-smp #1 SMP Wed May 3 04:53:23 UTC 2006 i686
i686 i386 GNU/Linux
ant -version
Apache Ant version 1.7.0 compiled on December 13 2006
java -version
java version "1.6.0_01"
The last part of the output from the install:
[exec] !!!FAILURES!!!
[exec] Test Results:
[exec] Run: 307 Failures: 5 Errors: 4
[exec]
[exec]
[exec] 1) test: TimeBasedRollingTest::test1 (E)
[exec] uncaught exception of type log4cxx::helpers::IOException
[exec] - IO Exception : status code = 2
[exec]
[exec]
[exec] 2) test: TimeBasedRollingTest::test2 (E)
[exec] uncaught exception of type log4cxx::helpers::IOException
[exec] - IO Exception : status code = 2
[exec]
[exec]
[exec] 3) test: TimeBasedRollingTest::test3 (F) line: 244
/usr/local/src/apache-log4cxx/src/test/cpp/rolling/timebasedrollingtest.
cpp
[exec] equality assertion failed
[exec] - Expected: 1
[exec] - Actual : 0
[exec]
[exec]
[exec] 4) test: TimeBasedRollingTest::test4 (E)
[exec] uncaught exception of type log4cxx::helpers::IOException
[exec] - IO Exception : status code = 2
[exec]
[exec]
[exec] 5) test: TimeBasedRollingTest::test5 (E)
[exec] uncaught exception of type log4cxx::helpers::IOException
[exec] - IO Exception : status code = 2
[exec]
[exec]
[exec] 6) test: TimeBasedRollingTest::test6 (F) line: 413
/usr/local/src/apache-log4cxx/src/test/cpp/rolling/timebasedrollingtest.
cpp
[exec] equality assertion failed
[exec] - Expected: 1
[exec] - Actual : 0
[exec]
[exec]
[exec] 7) test: AsyncAppenderTestCase::closeTest (F) line: 155
/usr/local/src/apache-log4cxx/src/test/cpp/asyncappendertestcase.cpp
[exec] equality assertion failed
[exec] - Expected: 1
[exec] - Actual : 0
[exec]
[exec]
[exec] 8) test: AsyncAppenderTestCase::test2 (F) line: 175
/usr/local/src/apache-log4cxx/src/test/cpp/asyncappendertestcase.cpp
[exec] equality assertion failed
[exec] - Expected: 1
[exec] - Actual : 0
[exec]
[exec]
[exec] 9) test: AsyncAppenderTestCase::test3 (F) line: 199
/usr/local/src/apache-log4cxx/src/test/cpp/asyncappendertestcase.cpp
[exec] equality assertion failed
[exec] - Expected: 200
[exec] - Actual : 0
[exec]
[exec]
[exec] ..............
BUILD FAILED
/usr/local/src/apache-log4cxx/build.xml:1030: exec returned: 1
-----Original Message-----
From: Curt Arnold [mailto:carnold@apache.org]
Sent: 02 November 2007 17:44
To: Log4CXX User
Subject: Re: level problem
On Nov 2, 2007, at 9:49 AM, Anita Banerji wrote:
> I am also finding a significant performance penalty when including
> DEBUG level statements even though this level is not enabled, and
> therefore have to comment out log4cxx code out of frequently run
> areas.
>
> Any ideas on how I can fix this?
>
> Thanks.
If you are using logstream, I believe it had a pretty high overhead
on some platforms as the base std::basic_ostream<> constructor was
surprisingly expensive. However, if you attempted to base logstream
on something other than std::basic_ostream, then you could not match
all of the basic_ostream semantics. Likely logstream will be pulled
from the distribution before release since it was hard to get just
right. It is only just one header file and if you want to keep using
it, you would be free to continue.
Recently, the LOG4CXX_INFO and similar macros were reworked to
restore use of insertion operators within the message parameter to
the macro like:
LOG4CXX_INFO(logger, "Hello" << ", World");
The current implementation doesn't compile with VC6 (no problem with
VC 2008 or gcc, haven't checked VC 7, 7.1 or 8) due to a compiler bug/
limitation.
If you are using logstream (and not using VC6), I'd suggest modifying
the code to use the LOG4CXX_INFO macros and testing the performance.
If you are using the LOG4CXX_INFO macros and are still seeing
performance issues, please create a sample program and attach it to a
bug report and I'll profile it and see if there is something biting us.
RE: level problem
Posted by Anita Banerji <An...@postgrad.manchester.ac.uk>.
Hi Curt,
I've updated to the SVN head and this has solved both my problems. The
performance is now much improved and I only get the messages from the
selected level appearing.
Thanks for your help,
Anita
-----Original Message-----
From: Curt Arnold [mailto:carnold@apache.org]
Sent: 02 November 2007 17:44
To: Log4CXX User
Subject: Re: level problem
On Nov 2, 2007, at 9:49 AM, Anita Banerji wrote:
> I am also finding a significant performance penalty when including
> DEBUG level statements even though this level is not enabled, and
> therefore have to comment out log4cxx code out of frequently run
> areas.
>
> Any ideas on how I can fix this?
>
> Thanks.
If you are using logstream, I believe it had a pretty high overhead
on some platforms as the base std::basic_ostream<> constructor was
surprisingly expensive. However, if you attempted to base logstream
on something other than std::basic_ostream, then you could not match
all of the basic_ostream semantics. Likely logstream will be pulled
from the distribution before release since it was hard to get just
right. It is only just one header file and if you want to keep using
it, you would be free to continue.
Recently, the LOG4CXX_INFO and similar macros were reworked to
restore use of insertion operators within the message parameter to
the macro like:
LOG4CXX_INFO(logger, "Hello" << ", World");
The current implementation doesn't compile with VC6 (no problem with
VC 2008 or gcc, haven't checked VC 7, 7.1 or 8) due to a compiler bug/
limitation.
If you are using logstream (and not using VC6), I'd suggest modifying
the code to use the LOG4CXX_INFO macros and testing the performance.
If you are using the LOG4CXX_INFO macros and are still seeing
performance issues, please create a sample program and attach it to a
bug report and I'll profile it and see if there is something biting us.
Re: level problem
Posted by Curt Arnold <ca...@apache.org>.
On Nov 2, 2007, at 9:49 AM, Anita Banerji wrote:
> I am also finding a significant performance penalty when including
> DEBUG level statements even though this level is not enabled, and
> therefore have to comment out log4cxx code out of frequently run
> areas.
>
> Any ideas on how I can fix this?
>
> Thanks.
If you are using logstream, I believe it had a pretty high overhead
on some platforms as the base std::basic_ostream<> constructor was
surprisingly expensive. However, if you attempted to base logstream
on something other than std::basic_ostream, then you could not match
all of the basic_ostream semantics. Likely logstream will be pulled
from the distribution before release since it was hard to get just
right. It is only just one header file and if you want to keep using
it, you would be free to continue.
Recently, the LOG4CXX_INFO and similar macros were reworked to
restore use of insertion operators within the message parameter to
the macro like:
LOG4CXX_INFO(logger, "Hello" << ", World");
The current implementation doesn't compile with VC6 (no problem with
VC 2008 or gcc, haven't checked VC 7, 7.1 or 8) due to a compiler bug/
limitation.
If you are using logstream (and not using VC6), I'd suggest modifying
the code to use the LOG4CXX_INFO macros and testing the performance.
If you are using the LOG4CXX_INFO macros and are still seeing
performance issues, please create a sample program and attach it to a
bug report and I'll profile it and see if there is something biting us.
level problem
Posted by Anita Banerji <An...@postgrad.manchester.ac.uk>.
I am also finding a significant performance penalty when including DEBUG
level statements even though this level is not enabled, and therefore
have to comment out log4cxx code out of frequently run areas.
Any ideas on how I can fix this?
Thanks.
________________________________
From: Anita Banerji [mailto:Anita.Banerji@postgrad.manchester.ac.uk]
Sent: 18 October 2007 09:11
To: log4cxx-user@logging.apache.org
Subject: level problem
Hi,
I wish to print out variable values within my code at the various
different logging levels. However, debug level statements are printed
when there are also info level statements within the same function. I'd
appreciate any advice on how to prevent this happening.
With the level set to INFO in the config file:
log4j.logger.ImageVolume=INFO I would not expect to see the debug level
output: "generateImage: xMax: ok".
Thank you,
Anita
Output:
INFO ImageVolume - creating a new image volume
INFO ImageVolume - generateImage: no noise added
INFO ImageVolume - generateImage: mapping to image
INFO ImageVolume - generateImage: xMax: okgenerateImage: complete
In ImageVolume.h
class ImageVolume
{
static log4cxx::LoggerPtr logger;
shared_ptr<logstream> outstream;
...
};
In ImageVolume.cc
LoggerPtr ImageVolume::logger(Logger::getLogger("ImageVolume"));
ImageVolume::ImageVolume(shared_ptr<TissueToVoxelMap> tissueToVoxelMap)
{
shared_ptr<logstream> log(new logstream(logger,
Level::OFF));
outstream= log;
*outstream << Level::INFO << "creating a new image volume "
<< LOG4CXX_ENDMSG;
...
}
void ImageVolume::generateImage(shared_ptr<SignalProduction>
signalProduction,
shared_ptr<TissueToVoxelMap> tissueToVoxelMap, shared_ptr<Noise> noise)
{
*(outstream.get()) << Level::INFO << "generateImage: no
noise added " << LOG4CXX_ENDMSG;
shared_ptr< map<TISSUETYPE, SIGNAL_INTENSITY> >
tissueToSignalMap= signalProduction->generateSignalForAllTissues();
unsigned xMax= image->getDimX();
unsigned yMax= image->getDimY();
unsigned zMax= image->getDimZ();
*(outstream.get()) << Level::INFO << "generateImage: mapping
to image" << LOG4CXX_ENDMSG;
*outstream << Level::DEBUG << "generateImage: xMax: " <<
xMax << " ok" << LOG4CXX_ENDMSG;
...
*(outstream.get()) << Level::INFO << "generateImage:
complete" << LOG4CXX_ENDMSG;
}