Details
-
Type:
Bug
-
Status: Done
-
Resolution: Done
-
Fix Version/s: None
-
Labels:
-
Story Points:2
-
Epic Link:
-
Team:Alert Production
Description
There are two bugs in the log package:
log.info("%s") results in:
TypeError: not enough arguments for format string
|
this is because Log._log is defined with this line:
self.log(level, os.path.split(frame.f_code.co_filename)[1],
|
inspect.stack()[2][3], frame.f_lineno, fmt % args)
|
and in this case args is an empty tuple. A trivial fix is to replace this with:
msg = fmt % args if args else fmt
|
self.log(level, os.path.split(frame.f_code.co_filename)[1],
|
inspect.stack()[2][3], frame.f_lineno, msg)
|
However, doing so exposes another bug. The following will segfault:
log.log(2000, "foo", "bar", 5, "%s")
|
This is because Log.log is extended in logLib.i as follows:
void log(int level, std::string const& filename,
|
std::string const& funcname, unsigned int lineno,
|
std::string const& msg) {
|
self->log(log4cxx::Level::toLevel(level),
|
log4cxx::spi::LocationInfo(filename.c_str(), funcname.c_str(), lineno),
|
msg.c_str());
|
and the version of Log.log it calls expects additional format arguments. In general the log package seems to use logMsg when no %s formatting is wanted, and log when such formatting is wanted, so I propose to fix this using:
void logMsg(int level, std::string const& filename,
|
std::string const& funcname, unsigned int lineno,
|
std::string const& msg) {
|
self->logMsg(log4cxx::Level::toLevel(level),
|
log4cxx::spi::LocationInfo(filename.c_str(), funcname.c_str(), lineno),
|
msg.c_str());
|
In addition, this requires the first fix to be changed to call logMsg instead of log
Attachments
Activity
I have one remaining concern: is C++ logging subject to the same segfault, e.g. if one provides a format string with a mis-matched number of data arguments? If so, is there some way to raise an exception, instead? I suspect our code contains many log messages that will rarely or never be printed, and I'd hate to have those able to cause a segfault.
In C++, LOGL_WARN(logger, "This is WARN %s"); gives
unknown location:0: fatal error: in "log_stream": memory access violation at address: 0xfffffff0: no mapping at fault address
But to log something with % in the string, one can use the iostream-style formatting.
e.g. LOGLS_WARN(logger, "This is WARN " << "%s"); is fine.
Hsin-Fang Chiang
added a comment - In C++, LOGL_WARN(logger, "This is WARN %s"); gives
unknown location:0: fatal error: in "log_stream": memory access violation at address: 0xfffffff0: no mapping at fault address
But to log something with % in the string, one can use the iostream-style formatting.
e.g. LOGLS_WARN(logger, "This is WARN " << "%s"); is fine.
Your changes look fine to me, with some comments from Tim Jenness on the PR (indentation, the binary tests/testLog, etc). I agree with using logMsg as doing string interpolation more than once really does not make sense. Thanks for fixing it.
I added a commit to log through the logger in the newly added test.
lsst.log.info("this logs to the default root logger") |
is fine but I find logging to a logger less confusing as a logger is available in that test.
Hsin-Fang Chiang
added a comment - Your changes look fine to me, with some comments from Tim Jenness on the PR (indentation, the binary tests/testLog, etc). I agree with using logMsg as doing string interpolation more than once really does not make sense. Thanks for fixing it.
I added a commit to log through the logger in the newly added test.
lsst.log.info( "this logs to the default root logger" )
is fine but I find logging to a logger less confusing as a logger is available in that test. Thank you to Hsin-Fang Chiang and Tim Jenness for the fast review, and on a 3 day weekend no less!
I cleaned up the indentation issues noted by Tim Jenness and rebased the commits (including Hsin-Fang Chiang's test improvement) so that:
- The test for logging messages containing "%s" is part of the same commit that fixes the bugs
- Removed a test result file that I accidentally added
- Updated .gitignore to hide tests/testLog and remove an obsolete entry
I will merge to master after a final successful Jenkins run.
Regarding Jenkins, I think that there must be only one place that uses %s in a log message using the new logger and that test is skipped on Jenkins because Jenkins does not know how to connect to lsst-db.