Logging: avoid changing global process name

Changing the process' name, even temporarily, is not thread-safe
and needs to be avoided. Instead pass the additional parameter
explicitly via the MessageOptions container.

Logger::formatLines() and LogStdout::write() are passed the process
name as "const std::string *" pointer, with Logger::getProcessName()
acting as fallback for NULL. Calling that is delayed as long as possible,
to avoid making the string copy when not necessary.

The previous implementation of formatLines() used a std::string
reference, but only used the content to determine whether to include
the current process name - probably not what was intended, but harmless
because either the empty string or the current name were passed.
This commit is contained in:
Patrick Ohly 2013-04-08 20:59:32 +02:00
parent 30955bab34
commit ecfceb3f98
9 changed files with 67 additions and 44 deletions

View File

@ -96,8 +96,10 @@ void SessionHelper::messagev(const MessageOptions &options,
if (m_parentLogger) {
m_parentLogger->messagev(options, format, argsCopy);
} else {
formatLines(options.m_level, DEBUG, getProcessName(),
options.m_prefix, format, argsCopy,
formatLines(options.m_level, DEBUG,
options.m_processName,
options.m_prefix,
format, argsCopy,
boost::bind(dumpString, _1));
}
va_end(argsCopy);
@ -111,7 +113,7 @@ void SessionHelper::messagev(const MessageOptions &options,
// send to parent
string log = StringPrintfV(format, args);
string strLevel = Logger::levelToStr(options.m_level);
emitLogOutput(strLevel, log, getProcessName());
emitLogOutput(strLevel, log, options.m_processName ? *options.m_processName : getProcessName());
}
void SessionHelper::run()

View File

@ -175,8 +175,9 @@ class LocalTransportChild : public GDBusCXX::DBusRemoteObject
void LocalTransportAgent::logChildOutput(const std::string &level, const std::string &message)
{
ProcNameGuard guard(m_clientContext);
SE_LOG(NULL, Logger::strToLevel(level.c_str()), "%s", message.c_str());
Logger::MessageOptions options(Logger::strToLevel(level.c_str()));
options.m_processName = &m_clientContext;
SyncEvo::LoggerBase::instance().messageWithOptions(options, "%s", message.c_str());
}
void LocalTransportAgent::onChildConnect(const GDBusCXX::DBusConnectionPtr &conn)

View File

@ -232,6 +232,7 @@ void LogRedirect::messagev(const MessageOptions &options,
(m_err ? m_err : stderr),
options.m_level, getLevel(),
options.m_prefix,
options.m_processName,
format,
args);
}

View File

@ -62,6 +62,7 @@ void LoggerStdout::write(FILE *file,
Level msglevel,
Level filelevel,
const std::string *prefix,
const std::string *procname,
const char *format,
va_list args)
{
@ -70,7 +71,7 @@ void LoggerStdout::write(FILE *file,
// TODO: print debugging information, perhaps only in log file
std::string output;
formatLines(msglevel, filelevel,
m_processName,
procname,
prefix,
format, args,
boost::bind(appendOutput, boost::ref(output), _1, _2));
@ -85,6 +86,7 @@ void LoggerStdout::messagev(const MessageOptions &options,
{
write(m_file, options.m_level, getLevel(),
options.m_prefix,
options.m_processName,
format, args);
}

View File

@ -59,6 +59,7 @@ class LoggerStdout : public LoggerBase
Level msglevel,
Level filelevel,
const std::string *prefix,
const std::string *procname,
const char *format,
va_list args);
virtual void messagev(const MessageOptions &options,

View File

@ -82,8 +82,9 @@ void LoggerSyslog::messagev(const MessageOptions &options,
}
if (options.m_level <= getLevel()) {
const std::string none;
formatLines(options.m_level, getLevel(),
"", // process name is set when opening the syslog
&none, // Process name is set when opening the syslog, don't repeat it.
options.m_prefix,
format, args,
boost::bind(printToSyslog, getSyslogLevel(options.m_level), _1, _2));

View File

@ -80,7 +80,7 @@ LoggerBase *LoggerBase::loggerAt(int index)
void LoggerBase::formatLines(Level msglevel,
Level outputlevel,
const std::string &processName,
const std::string *processName,
const std::string *prefix,
const char *format,
va_list args,
@ -92,10 +92,17 @@ void LoggerBase::formatLines(Level msglevel,
if (msglevel != SHOW) {
std::string reltime;
std::string procname;
if (!processName.empty()) {
procname.reserve(processName.size() + 1);
const std::string *realProcname;
if (processName) {
realProcname = processName;
} else {
realProcname = &m_processName;
}
if (!realProcname->empty()) {
procname.reserve(realProcname->size() + 1);
procname += " ";
procname += m_processName;
procname += *realProcname;
}
if (outputlevel >= DEBUG) {
@ -184,6 +191,16 @@ void LoggerBase::formatLines(Level msglevel,
}
}
Logger::MessageOptions::MessageOptions(Level level) :
m_level(level),
m_prefix(NULL),
m_file(NULL),
m_line(0),
m_function(NULL),
m_processName(NULL)
{
}
Logger::MessageOptions::MessageOptions(Level level,
const std::string *prefix,
const char *file,
@ -193,7 +210,8 @@ Logger::MessageOptions::MessageOptions(Level level,
m_prefix(prefix),
m_file(file),
m_line(line),
m_function(function)
m_function(function),
m_processName(NULL)
{
}
@ -225,6 +243,16 @@ void Logger::message(Level level,
va_end(args);
}
void Logger::messageWithOptions(const MessageOptions &options,
const char *format,
...)
{
va_list args;
va_start(args, format);
messagev(options, format, args);
va_end(args);
}
const char *Logger::levelToStr(Level level)
{
switch (level) {

View File

@ -162,12 +162,15 @@ class Logger
/** inserted at beginning of each line, if non-NULL */
const std::string *m_prefix;
/** source file where message comes from, if non-NULL */
char *m_file;
const char *m_file;
/** source line number, if file is non-NULL */
int m_line;
/** surrounding function name, if non-NULL */
char *m_function;
const char *m_function;
/** name of the process which originally created the message, if different from current one */
const std::string *m_processName;
MessageOptions(Level level);
MessageOptions(Level level,
const std::string *prefix,
const char *file,
@ -208,6 +211,13 @@ class Logger
...)
#ifdef __GNUC__
__attribute__((format(printf, 7, 8)))
#endif
;
void messageWithOptions(const MessageOptions &options,
const char *format,
...)
#ifdef __GNUC__
__attribute__((format(printf, 3, 4)))
#endif
;
@ -222,33 +232,6 @@ class Logger
static std::string m_processName;
};
/**
* Changes the process name temporarily.
*/
class ProcNameGuard {
std::string m_oldProcName;
bool m_modified;
public:
ProcNameGuard(const std::string &procname) :
m_oldProcName(Logger::getProcessName())
{
if (m_oldProcName != procname) {
Logger::setProcessName(procname);
m_modified = true;
} else {
m_modified = false;
}
}
~ProcNameGuard()
{
if (m_modified) {
Logger::setProcessName(m_oldProcName);
}
}
};
/**
* Global logging, implemented as a singleton with one instance per
* process.
@ -305,10 +288,13 @@ class LoggerBase : public Logger
* Each chunk already includes the necessary line breaks (in
* particular after the last line when it contains the entire
* output). It may be modified by the callback.
*
* @param processName NULL means use the current process' name,
* empty means use none
*/
void formatLines(Level msglevel,
Level outputlevel,
const std::string &processName,
const std::string *processName,
const std::string *prefix,
const char *format,
va_list args,

View File

@ -1003,8 +1003,9 @@ void RemoteSession::interruptAsync(const char *operation)
void RemoteSession::logOutput(Logger::Level level, const string &log, const string &procname)
{
if(m_output) {
ProcNameGuard guard(procname);
SE_LOG(NULL, level, "%s", log.c_str());
Logger::MessageOptions options(level);
options.m_processName = &procname;
SyncEvo::LoggerBase::instance().messageWithOptions(options, "%s", log.c_str());
}
}