diff options
-rw-r--r-- | src/dbus/server/main.cpp | 9 | ||||
-rw-r--r-- | src/dbus/server/server.cpp | 116 | ||||
-rw-r--r-- | src/dbus/server/server.h | 34 | ||||
-rw-r--r-- | src/dbus/server/session-helper.cpp | 122 | ||||
-rw-r--r-- | src/dbus/server/session-helper.h | 12 | ||||
-rw-r--r-- | src/dbus/server/session.cpp | 80 | ||||
-rw-r--r-- | src/dbus/server/session.h | 10 | ||||
-rw-r--r-- | src/dbus/server/sync-helper.cpp | 11 | ||||
-rw-r--r-- | src/syncevo/Cmdline.cpp | 6 | ||||
-rw-r--r-- | src/syncevo/ForkExec.cpp | 9 | ||||
-rw-r--r-- | src/syncevo/LocalTransportAgent.cpp | 74 | ||||
-rw-r--r-- | src/syncevo/LogRedirect.cpp | 82 | ||||
-rw-r--r-- | src/syncevo/LogRedirect.h | 22 | ||||
-rw-r--r-- | src/syncevo/LogSyslog.cpp | 2 | ||||
-rw-r--r-- | src/syncevo/LogSyslog.h | 2 | ||||
-rw-r--r-- | src/syncevo/Logging.cpp | 259 | ||||
-rw-r--r-- | src/syncevo/Logging.h | 205 | ||||
-rw-r--r-- | src/syncevo/SuspendFlags.h | 1 | ||||
-rw-r--r-- | src/syncevo/SyncContext.cpp | 240 | ||||
-rw-r--r-- | src/syncevo/syncevo.am | 4 | ||||
-rw-r--r-- | src/syncevolution.cpp | 2 | ||||
-rw-r--r-- | test/client-test-main.cpp | 12 |
22 files changed, 848 insertions, 466 deletions
diff --git a/src/dbus/server/main.cpp b/src/dbus/server/main.cpp index ed424efd..a8d8c6d9 100644 --- a/src/dbus/server/main.cpp +++ b/src/dbus/server/main.cpp @@ -152,9 +152,9 @@ int main(int argc, char **argv, char **envp) setvbuf(stdout, NULL, _IONBF, 0); // Redirect output and optionally log to syslog. - LogRedirect redirect(true); - redirect.setLevel(stdoutEnabled ? level : Logger::NONE); - std::auto_ptr<Logger> syslogger; + PushLogger<LogRedirect> redirect(new LogRedirect(LogRedirect::STDERR_AND_STDOUT)); + redirect->setLevel(stdoutEnabled ? level : Logger::NONE); + PushLogger<LoggerSyslog> syslogger; if (syslogEnabled && level > Logger::NONE) { syslogger.reset(new LoggerSyslog(execName)); syslogger->setLevel(level); @@ -206,6 +206,9 @@ int main(int argc, char **argv, char **envp) SE_LOG_DEBUG(NULL, "flushing D-Bus connection"); conn.flush(); conn.reset(); + SE_LOG_INFO(NULL, "terminating, closing logging"); + syslogger.reset(); + redirect.reset(); SE_LOG_INFO(NULL, "terminating"); return 0; } catch ( const std::exception &ex ) { diff --git a/src/dbus/server/server.cpp b/src/dbus/server/server.cpp index 4f885d6e..da96c860 100644 --- a/src/dbus/server/server.cpp +++ b/src/dbus/server/server.cpp @@ -48,6 +48,87 @@ static void logIdle(bool idle) SE_LOG_DEBUG(NULL, "server is %s", idle ? "idle" : "not idle"); } +class ServerLogger : public Logger +{ + Logger::Handle m_parentLogger; + // Currently a strong reference. Would be a weak reference + // if we had proper reference counting for Server. + boost::shared_ptr<Server> m_server; + +public: + ServerLogger(const boost::shared_ptr<Server> &server) : + m_parentLogger(Logger::instance()), + m_server(server) + { + } + + virtual void remove() throw () + { + // Hold the Logger mutex while cutting our connection to the + // server. The code using m_server below does the same and + // holds the mutex while logging. That way we prevent threads + // from holding onto the server while it tries to shut down. + // + // This is important because the server's live time is not + // really controlled via the boost::shared_ptr, it may + // destruct while there are still references. See + // Server::m_logger instantiation below. + RecMutex::Guard guard = lock(); + m_server.reset(); + } + + virtual void messagev(const MessageOptions &options, + const char *format, + va_list args) + { + // Ensure that remove() cannot proceed while we have the + // server in use. + RecMutex::Guard guard = lock(); + Server *server = m_server.get(); + message2DBus(server, + options, + format, + args, + server ? server->getPath() : "", + getProcessName()); + } + + /** + * @param server may be NULL, in which case logging only goes to parent + */ + void message2DBus(Server *server, + const MessageOptions &options, + const char *format, + va_list args, + const std::string &dbusPath, + const std::string &procname) + { + // Keeps logging consistent: otherwise thread A might log to + // parent, thread B to parent and D-Bus, then thread A + // finishes its logging via D-Bus. The order of log messages + // would then not be the same in the parent and D-Bus. + RecMutex::Guard guard = lock(); + + // iterating over args in messagev() is destructive, must make a copy first + va_list argsCopy; + va_copy(argsCopy, args); + m_parentLogger.messagev(options, format, args); + + if (server) { + try { + if (options.m_level <= server->getDBusLogLevel()) { + string log = StringPrintfV(format, argsCopy); + server->logOutput(dbusPath, options.m_level, log, procname); + } + } catch (...) { + remove(); + // Give up on server logging silently. + } + } + va_end(argsCopy); + } +}; + void Server::clientGone(Client *c) { for (Clients_t::iterator it = m_clients.begin(); @@ -282,7 +363,11 @@ Server::Server(GMainLoop *loop, m_logOutputSignal(*this, "LogOutput"), m_autoTerm(m_loop, m_shutdownRequested, duration), m_dbusLogLevel(Logger::INFO), - m_parentLogger(Logger::instance()) + // TODO (?): turn Server into a proper reference counted instance. + // This would help with dangling references to it when other threads + // use it for logging, see ServerLogger. However, with mutex locking + // in ServerLogger that shouldn't be a problem. + m_logger(new ServerLogger(boost::shared_ptr<Server>(this, NopDestructor()))) { struct timeval tv; gettimeofday(&tv, NULL); @@ -327,8 +412,9 @@ void Server::activate() // out object isn't visible to it yet. GDBusCXX::DBusObjectHelper::activate(); - Logger::pushLogger(this); - setLevel(Logger::DEBUG); + // Push ourselves as logger for the time being. + m_logger->setLevel(Logger::DEBUG); + m_pushLogger.reset(m_logger); m_presence.reset(new PresenceStatus(*this)); @@ -363,7 +449,9 @@ Server::~Server() m_connman.reset(); m_networkManager.reset(); m_presence.reset(); - Logger::popLogger(); + + m_pushLogger.reset(); + m_logger.reset(); } bool Server::shutdown() @@ -909,24 +997,16 @@ void Server::updateDevice(const string &deviceId, } } -void Server::messagev(const MessageOptions &options, - const char *format, - va_list args, - const std::string &dbusPath, - const std::string &procname) +void Server::message2DBus(const Logger::MessageOptions &options, + const char *format, + va_list args, + const std::string &dbusPath, + const std::string &procname) { - // iterating over args in messagev() is destructive, must make a copy first - va_list argsCopy; - va_copy(argsCopy, args); - m_parentLogger.messagev(options, format, args); // prefix is used to set session path // for general server output, the object path field is dbus server // the object path can't be empty for object paths prevent using empty string. - if (options.m_level <= m_dbusLogLevel) { - string log = StringPrintfV(format, argsCopy); - logOutput(dbusPath, options.m_level, log, procname); - } - va_end(argsCopy); + m_logger->message2DBus(this, options, format, args, dbusPath, procname); } void Server::logOutput(const GDBusCXX::DBusObject_t &path, diff --git a/src/dbus/server/server.h b/src/dbus/server/server.h index 95163331..673958b4 100644 --- a/src/dbus/server/server.h +++ b/src/dbus/server/server.h @@ -53,14 +53,15 @@ class NetworkManagerClient; // TODO: avoid polluting namespace using namespace std; +class ServerLogger; + /** * Implements the main org.syncevolution.Server interface. * * The Server class is responsible for listening to clients and * spinning of sync sessions as requested by clients. */ -class Server : public GDBusCXX::DBusObjectHelper, - public Logger +class Server : public GDBusCXX::DBusObjectHelper { GMainLoop *m_loop; bool &m_shutdownRequested; @@ -391,9 +392,10 @@ class Server : public GDBusCXX::DBusObjectHelper, // The level of detail for D-Bus logging signals. Logger::Level m_dbusLogLevel; - //records the parent logger, dbus server acts as logger to - //send signals to clients and put logs in the parent logger. - Logger &m_parentLogger; + // Created in constructor and captures parent logger there, + // then pushed as default logger in activate(). + boost::shared_ptr<ServerLogger> m_logger; + PushLogger<ServerLogger> m_pushLogger; /** * All active timeouts created by addTimeout(). @@ -653,23 +655,11 @@ public: */ bool notificationsEnabled(); - /** - * implement virtual method from LogStdout. - * Not only print the message in the console - * but also send them as signals to clients - */ - virtual void messagev(const MessageOptions &options, - const char *format, - va_list args) { - messagev(options, format, args, - getPath(), - getProcessName()); - } - void messagev(const MessageOptions &options, - const char *format, - va_list args, - const std::string &dbusPath, - const std::string &procname); + void message2DBus(const Logger::MessageOptions &options, + const char *format, + va_list args, + const std::string &dbusPath, + const std::string &procname); }; // extensions to the D-Bus server, created dynamically by main() diff --git a/src/dbus/server/session-helper.cpp b/src/dbus/server/session-helper.cpp index cffd8e52..0df0004b 100644 --- a/src/dbus/server/session-helper.cpp +++ b/src/dbus/server/session-helper.cpp @@ -30,10 +30,82 @@ SE_BEGIN_CXX +static void dumpString(const std::string &output) +{ + fputs(output.c_str(), stdout); +} + +/** + * Same logging approach as in Server class: pretend that we + * have reference counting for the SessionHelper class and + * use mutex locking to prevent dangling pointers. + */ +class SessionHelperLogger : public Logger +{ + boost::shared_ptr<LogRedirect> m_parentLogger; + boost::shared_ptr<SessionHelper> m_helper; + +public: + SessionHelperLogger(const boost::shared_ptr<LogRedirect> &parentLogger, + const boost::shared_ptr<SessionHelper> &helper): + m_parentLogger(parentLogger), + m_helper(helper) + { + } + + virtual void remove() throw () + { + RecMutex::Guard guard = lock(); + m_helper.reset(); + } + + virtual void messagev(const MessageOptions &options, + const char *format, + va_list args) + { + RecMutex::Guard guard = lock(); + static bool dbg = getenv("SYNCEVOLUTION_DEBUG"); + + if (dbg) { + // let parent LogRedirect or utility function handle the output *in addition* to + // logging via D-Bus + va_list argsCopy; + va_copy(argsCopy, args); + if (m_parentLogger) { + m_parentLogger->messagev(options, format, argsCopy); + } else { + formatLines(options.m_level, DEBUG, + options.m_processName, + options.m_prefix, + format, argsCopy, + boost::bind(dumpString, _1)); + } + va_end(argsCopy); + } else if (m_parentLogger) { + // Only flush parent logger, to capture output sent to + // stdout/stderr by some library and send it via D-Bus + // (recursively!) before printing out own, new output. + m_parentLogger->flush(); + } + + if (m_helper) { + // send to parent + string log = StringPrintfV(format, args); + string strLevel = Logger::levelToStr(options.m_level); + try { + m_helper->emitLogOutput(strLevel, log, options.m_processName ? *options.m_processName : getProcessName()); + } catch (...) { + // Give up forwarding output. + m_helper.reset(); + } + } + } +}; + SessionHelper::SessionHelper(GMainLoop *loop, const GDBusCXX::DBusConnectionPtr &conn, const boost::shared_ptr<ForkExecChild> &forkexec, - LogRedirect *parentLogger) : + const boost::shared_ptr<LogRedirect> &parentLogger) : GDBusCXX::DBusObjectHelper(conn, SessionCommon::HELPER_PATH, SessionCommon::HELPER_IFACE, @@ -42,7 +114,7 @@ SessionHelper::SessionHelper(GMainLoop *loop, m_loop(loop), m_conn(conn), m_forkexec(forkexec), - m_parentLogger(parentLogger), + m_logger(new SessionHelperLogger(parentLogger, boost::shared_ptr<SessionHelper>(this, NopDestructor()))), emitLogOutput(*this, "LogOutput"), emitSyncProgress(*this, "SyncProgress"), emitSourceProgress(*this, "SourceProgress"), @@ -68,52 +140,18 @@ SessionHelper::SessionHelper(GMainLoop *loop, add(emitPasswordRequest); add(emitMessage); add(emitShutdown); - activate(); - Logger::pushLogger(this); -} - -SessionHelper::~SessionHelper() -{ - Logger::popLogger(); } -static void dumpString(const std::string &output) +void SessionHelper::activate() { - fputs(output.c_str(), stdout); + GDBusCXX::DBusObjectHelper::activate(); + m_pushLogger.reset(m_logger); } -void SessionHelper::messagev(const MessageOptions &options, - const char *format, - va_list args) +SessionHelper::~SessionHelper() { - static bool dbg = getenv("SYNCEVOLUTION_DEBUG"); - - if (dbg) { - // let parent LogRedirect or utility function handle the output *in addition* to - // logging via D-Bus - va_list argsCopy; - va_copy(argsCopy, args); - if (m_parentLogger) { - m_parentLogger->messagev(options, format, argsCopy); - } else { - formatLines(options.m_level, DEBUG, - options.m_processName, - options.m_prefix, - format, argsCopy, - boost::bind(dumpString, _1)); - } - va_end(argsCopy); - } else { - // Only flush parent logger, to capture output sent to - // stdout/stderr by some library and send it via D-Bus - // (recursively!) before printing out own, new output. - m_parentLogger->flush(); - } - - // send to parent - string log = StringPrintfV(format, args); - string strLevel = Logger::levelToStr(options.m_level); - emitLogOutput(strLevel, log, options.m_processName ? *options.m_processName : getProcessName()); + m_pushLogger.reset(); + m_logger.reset(); } void SessionHelper::run() diff --git a/src/dbus/server/session-helper.h b/src/dbus/server/session-helper.h index 380ff209..e06b28fd 100644 --- a/src/dbus/server/session-helper.h +++ b/src/dbus/server/session-helper.h @@ -43,14 +43,14 @@ class ForkExecChild; * traditional syncevo-dbus-server did. */ class SessionHelper : public GDBusCXX::DBusObjectHelper, - private Logger, private boost::noncopyable { GMainLoop *m_loop; GDBusCXX::DBusConnectionPtr m_conn; boost::shared_ptr<ForkExecChild> m_forkexec; - LogRedirect *m_parentLogger; boost::function<bool ()> m_operation; + boost::shared_ptr<Logger> m_logger; + PushLogger<Logger> m_pushLogger; /** valid during doSync() */ boost::scoped_ptr<DBusSync> m_sync; @@ -81,18 +81,14 @@ class SessionHelper : public GDBusCXX::DBusObjectHelper, /** SessionHelper.PasswordResponse */ void passwordResponse(bool timedOut, bool aborted, const std::string &password); - // Logger implementation -> output via D-Bus emitLogOutput - virtual void messagev(const MessageOptions &options, - const char *format, - va_list args); - public: SessionHelper(GMainLoop *loop, const GDBusCXX::DBusConnectionPtr &conn, const boost::shared_ptr<ForkExecChild> &forkexec, - LogRedirect *parentLogger); + const boost::shared_ptr<LogRedirect> &parentLogger); ~SessionHelper(); + void activate(); void run(); GMainLoop *getLoop() const { return m_loop; } diff --git a/src/dbus/server/session.cpp b/src/dbus/server/session.cpp index 64819b63..acae499c 100644 --- a/src/dbus/server/session.cpp +++ b/src/dbus/server/session.cpp @@ -204,7 +204,7 @@ void Session::setNamedConfig(const std::string &configName, bool update, bool temporary, const ReadOperations::Config_t &config) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation != SessionCommon::OP_NULL) { string msg = StringPrintf("%s started, cannot change configuration at this time", runOpToString(m_runOperation).c_str()); SE_THROW_EXCEPTION(InvalidCall, msg); @@ -323,7 +323,7 @@ void Session::setNamedConfig(const std::string &configName, void Session::initServer(SharedBuffer data, const std::string &messageType) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); m_serverMode = true; m_initialMessage = data; m_initialMessageType = messageType; @@ -331,7 +331,7 @@ void Session::initServer(SharedBuffer data, const std::string &messageType) void Session::sync(const std::string &mode, const SessionCommon::SourceModes_t &sourceModes) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation == SessionCommon::OP_SYNC) { string msg = StringPrintf("%s started, cannot start again", runOpToString(m_runOperation).c_str()); SE_THROW_EXCEPTION(InvalidCall, msg); @@ -352,7 +352,7 @@ void Session::sync(const std::string &mode, const SessionCommon::SourceModes_t & void Session::sync2(const std::string &mode, const SessionCommon::SourceModes_t &sourceModes) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (!m_forkExecParent || !m_helper) { SE_THROW("syncing cannot continue, helper died"); } @@ -415,7 +415,7 @@ void Session::sync2(const std::string &mode, const SessionCommon::SourceModes_t void Session::abort() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation != SessionCommon::OP_SYNC && m_runOperation != SessionCommon::OP_CMDLINE) { SE_THROW_EXCEPTION(InvalidCall, "sync not started, cannot abort at this time"); } @@ -436,7 +436,7 @@ void Session::abort() void Session::suspend() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation != SessionCommon::OP_SYNC && m_runOperation != SessionCommon::OP_CMDLINE) { SE_THROW_EXCEPTION(InvalidCall, "sync not started, cannot suspend at this time"); } @@ -453,7 +453,7 @@ void Session::suspend() void Session::abortAsync(const SimpleResult &result) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (!m_forkExecParent) { result.done(); } else { @@ -470,7 +470,7 @@ void Session::getStatus(std::string &status, uint32_t &error, SourceStatuses_t &sources) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); status = syncStatusToString(m_syncStatus); if (m_stepIsWaiting) { status += ";waiting"; @@ -483,14 +483,14 @@ void Session::getStatus(std::string &status, void Session::getProgress(int32_t &progress, SourceProgresses_t &sources) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); progress = m_progData.getProgress(); sources = m_sourceProgress; } void Session::fireStatus(bool flush) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); std::string status; uint32_t error; SourceStatuses_t sources; @@ -507,7 +507,7 @@ void Session::fireStatus(bool flush) void Session::fireProgress(bool flush) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); int32_t progress; SourceProgresses_t sources; @@ -595,13 +595,13 @@ Session::Session(Server &server, void Session::passwordRequest(const std::string &descr, const ConfigPasswordKey &key) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); m_passwordRequest = m_server.passwordRequest(descr, key, m_me); } void Session::dbusResultCb(const std::string &operation, bool success, const std::string &error) throw() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { SE_LOG_DEBUG(NULL, "%s helper call completed, %s", operation.c_str(), @@ -625,7 +625,7 @@ void Session::dbusResultCb(const std::string &operation, bool success, const std void Session::failureCb() throw() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { if (m_status == SESSION_DONE) { // ignore errors that happen after session already closed, @@ -666,7 +666,7 @@ void Session::failureCb() throw() void Session::doneCb(bool success) throw() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { if (m_status == SESSION_DONE) { return; @@ -730,7 +730,7 @@ static void raiseChildTermError(int status, const SimpleResult &result) void Session::runOperationAsync(SessionCommon::RunOperation op, const SuccessCb_t &helperReady) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); m_server.addSyncSession(this); m_runOperation = op; m_status = SESSION_RUNNING; @@ -743,7 +743,7 @@ void Session::runOperationAsync(SessionCommon::RunOperation op, void Session::useHelperAsync(const SimpleResult &result) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { if (m_helper) { // exists already, invoke callback directly @@ -810,9 +810,9 @@ void Session::messagev(const MessageOptions &options, { // log with session path and empty process name, // just like the syncevo-dbus-helper does - m_server.messagev(options, - format, args, - getPath(), ""); + m_server.message2DBus(options, + format, args, + getPath(), ""); } static void Logging2Server(Server &server, @@ -829,7 +829,7 @@ static void Logging2Server(Server &server, void Session::useHelper2(const SimpleResult &result, const boost::signals2::connection &c) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { // helper is running, don't call result.failed() when it quits // sometime in the future @@ -872,7 +872,7 @@ void Session::useHelper2(const SimpleResult &result, const boost::signals2::conn void Session::onConnect(const GDBusCXX::DBusConnectionPtr &conn) throw () { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { SE_LOG_DEBUG(NULL, "helper has connected"); m_helper.reset(new SessionProxy(conn)); @@ -891,7 +891,7 @@ void Session::onConnect(const GDBusCXX::DBusConnectionPtr &conn) throw () void Session::onQuit(int status) throw () { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { SE_LOG_DEBUG(NULL, "helper quit with return code %d, was %s", status, @@ -936,7 +936,7 @@ void Session::onQuit(int status) throw () void Session::onFailure(SyncMLStatus status, const std::string &explanation) throw () { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { SE_LOG_DEBUG(NULL, "helper failed, status code %d = %s, %s", status, @@ -949,7 +949,7 @@ void Session::onFailure(SyncMLStatus status, const std::string &explanation) thr void Session::onOutput(const char *buffer, size_t length) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); // treat null-bytes inside the buffer like line breaks size_t off = 0; do { @@ -960,7 +960,7 @@ void Session::onOutput(const char *buffer, size_t length) void Session::activateSession() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_status != SESSION_IDLE) { SE_THROW("internal error, session changing from non-idle to active"); } @@ -981,7 +981,7 @@ void Session::activateSession() void Session::passwordResponse(bool timedOut, bool aborted, const std::string &password) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_helper) { // Ignore communicaton failures with helper here, // we'll notice that elsewhere @@ -994,7 +994,7 @@ void Session::passwordResponse(bool timedOut, bool aborted, const std::string &p void Session::syncProgress(sysync::TProgressEventEnum type, int32_t extra1, int32_t extra2, int32_t extra3) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); switch(type) { case sysync::PEV_CUSTOM_START: m_cmdlineOp = (RunOperation)extra1; @@ -1047,7 +1047,7 @@ void Session::sourceProgress(sysync::TProgressEventEnum type, SyncMode sourceSyncMode, int32_t extra1, int32_t extra2, int32_t extra3) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); // a command line operation can be many things, helper must have told us SessionCommon::RunOperation op = m_runOperation == SessionCommon::OP_CMDLINE ? m_cmdlineOp : @@ -1165,7 +1165,7 @@ void Session::sourceProgress(sysync::TProgressEventEnum type, bool Session::setFilters(SyncConfig &config) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); /** apply temporary configs to config */ config.setConfigFilter(true, "", m_syncFilter); // set all sources in the filter to config @@ -1177,7 +1177,7 @@ bool Session::setFilters(SyncConfig &config) void Session::setWaiting(bool isWaiting) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); // if stepInfo doesn't change, then ignore it to avoid duplicate status info if(m_stepIsWaiting != isWaiting) { m_stepIsWaiting = isWaiting; @@ -1187,7 +1187,7 @@ void Session::setWaiting(bool isWaiting) void Session::restore(const string &dir, bool before, const std::vector<std::string> &sources) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation == SessionCommon::OP_RESTORE) { string msg = StringPrintf("restore started, cannot restore again"); SE_THROW_EXCEPTION(InvalidCall, msg); @@ -1207,7 +1207,7 @@ void Session::restore(const string &dir, bool before, const std::vector<std::str void Session::restore2(const string &dir, bool before, const std::vector<std::string> &sources) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (!m_forkExecParent || !m_helper) { SE_THROW("syncing cannot continue, helper died"); } @@ -1219,7 +1219,7 @@ void Session::restore2(const string &dir, bool before, const std::vector<std::st void Session::execute(const vector<string> &args, const map<string, string> &vars) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (m_runOperation == SessionCommon::OP_CMDLINE) { SE_THROW_EXCEPTION(InvalidCall, "cmdline started, cannot start again"); } else if (m_runOperation != SessionCommon::OP_NULL) { @@ -1238,7 +1238,7 @@ void Session::execute(const vector<string> &args, const map<string, string> &var void Session::execute2(const vector<string> &args, const map<string, string> &vars) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); if (!m_forkExecParent || !m_helper) { SE_THROW("syncing cannot continue, helper died"); } @@ -1251,7 +1251,7 @@ void Session::execute2(const vector<string> &args, const map<string, string> &va /*Implementation of Session.CheckPresence */ void Session::checkPresence (string &status) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); vector<string> transport; m_server.checkPresence(m_configName, status, transport); } @@ -1260,7 +1260,7 @@ void Session::sendViaConnection(const DBusArray<uint8_t> buffer, const std::string &type, const std::string &url) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { boost::shared_ptr<Connection> connection = m_connection.lock(); @@ -1279,7 +1279,7 @@ void Session::sendViaConnection(const DBusArray<uint8_t> buffer, void Session::shutdownConnection() { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); try { boost::shared_ptr<Connection> connection = m_connection.lock(); @@ -1299,7 +1299,7 @@ void Session::shutdownConnection() void Session::storeMessage(const DBusArray<uint8_t> &message, const std::string &type) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); // ignore errors if (m_helper) { m_helper->m_storeMessage.start(message, type, @@ -1309,7 +1309,7 @@ void Session::storeMessage(const DBusArray<uint8_t> &message, void Session::connectionState(const std::string &error) { - Session::LoggingGuard guard(this); + PushLogger<Logger> guard(m_me); // ignore errors if (m_helper) { m_helper->m_connectionState.start(error, diff --git a/src/dbus/server/session.h b/src/dbus/server/session.h index c7053e69..f2062eb8 100644 --- a/src/dbus/server/session.h +++ b/src/dbus/server/session.h @@ -351,16 +351,6 @@ private: const char *format, va_list args); - class LoggingGuard { - public: - LoggingGuard(Session *session) { - Logger::pushLogger(session); - } - ~LoggingGuard() { - Logger::popLogger(); - } - }; - public: enum { PRI_CMDLINE = -10, diff --git a/src/dbus/server/sync-helper.cpp b/src/dbus/server/sync-helper.cpp index fc7d4fae..5ad57516 100644 --- a/src/dbus/server/sync-helper.cpp +++ b/src/dbus/server/sync-helper.cpp @@ -44,11 +44,12 @@ namespace { } void onConnect(const DBusConnectionPtr &conn, - LogRedirect *parentLogger, + const boost::shared_ptr<LogRedirect> &parentLogger, const boost::shared_ptr<ForkExecChild> &forkexec, boost::shared_ptr<SessionHelper> &helper) { helper.reset(new SessionHelper(loop, conn, forkexec, parentLogger)); + helper->activate(); } void onAbort() @@ -87,9 +88,11 @@ int main(int argc, char **argv, char **envp) // which are unaware of the SyncEvolution logging system. // Redirecting is useful to get such output into our // sync logfile, once we have one. - boost::scoped_ptr<LogRedirect> redirect; + boost::shared_ptr<LogRedirect> redirect; + PushLogger<LogRedirect> pushRedirect; if (!debug) { - redirect.reset(new LogRedirect(true)); + redirect.reset(new LogRedirect(LogRedirect::STDERR_AND_STDOUT)); + pushRedirect.reset(redirect); } setvbuf(stderr, NULL, _IONBF, 0); setvbuf(stdout, NULL, _IONBF, 0); @@ -110,7 +113,7 @@ int main(int argc, char **argv, char **envp) boost::shared_ptr<SessionHelper> helper; bool failed = false; - forkexec->m_onConnect.connect(boost::bind(onConnect, _1, redirect.get(), + forkexec->m_onConnect.connect(boost::bind(onConnect, _1, redirect, boost::cref(forkexec), boost::ref(helper))); forkexec->m_onFailure.connect(boost::bind(onFailure, _2, boost::ref(failed))); diff --git a/src/syncevo/Cmdline.cpp b/src/syncevo/Cmdline.cpp index b0e1cda1..63afdfef 100644 --- a/src/syncevo/Cmdline.cpp +++ b/src/syncevo/Cmdline.cpp @@ -4362,9 +4362,9 @@ private: * vararg constructor with NULL termination, * out and error stream into stringstream members */ - class TestCmdline : private Logger { + class TestCmdline : public Logger { void init() { - pushLogger(this); + addLogger(boost::shared_ptr<Logger>(this, NopDestructor())); m_argv.reset(new const char *[m_argvstr.size() + 1]); m_argv[0] = "client-test"; @@ -4398,7 +4398,7 @@ private: } ~TestCmdline() { - popLogger(); + removeLogger(this); } boost::shared_ptr<SyncContext> parse() diff --git a/src/syncevo/ForkExec.cpp b/src/syncevo/ForkExec.cpp index 649b5b0c..46cd1d67 100644 --- a/src/syncevo/ForkExec.cpp +++ b/src/syncevo/ForkExec.cpp @@ -128,14 +128,7 @@ void ForkExecParent::forked(gpointer data) throw() // any output is printed directly, instead of going through // the parent's output processing in LogRedirect. if (getenv("SYNCEVOLUTION_DEBUG")) { - int index = Logger::numLoggers(); - LogRedirect *redirect = NULL; - while (--index >= 0 && - !(redirect = dynamic_cast<LogRedirect *>(Logger::loggerAt(index)))) { - } - if (redirect) { - redirect->reset(); - } + LogRedirect::removeRedirect(); } if (me->m_mergedStdoutStderr) { diff --git a/src/syncevo/LocalTransportAgent.cpp b/src/syncevo/LocalTransportAgent.cpp index 08b20d45..179c0ea9 100644 --- a/src/syncevo/LocalTransportAgent.cpp +++ b/src/syncevo/LocalTransportAgent.cpp @@ -550,7 +550,42 @@ public: true /* ignore transmission failures */> m_logOutput; }; -class LocalTransportAgentChild : public TransportAgent, private Logger +class ChildLogger : public Logger +{ + std::auto_ptr<LogRedirect> m_parentLogger; + boost::weak_ptr<LocalTransportChildImpl> m_child; + +public: + ChildLogger(const boost::shared_ptr<LocalTransportChildImpl> &child) : + m_parentLogger(new LogRedirect(LogRedirect::STDERR_AND_STDOUT)), + m_child(child) + {} + ~ChildLogger() + { + m_parentLogger.reset(); + } + + /** + * Write message into our own log and send to parent. + */ + virtual void messagev(const MessageOptions &options, + const char *format, + va_list args) + { + m_parentLogger->process(); + boost::shared_ptr<LocalTransportChildImpl> child = m_child.lock(); + if (child) { + // prefix is used to set session path + // for general server output, the object path field is dbus server + // the object path can't be empty for object paths prevent using empty string. + string strLevel = Logger::levelToStr(options.m_level); + string log = StringPrintfV(format, args); + child->m_logOutput(strLevel, log); + } + } +}; + +class LocalTransportAgentChild : public TransportAgent { /** final return code of our main(): non-zero indicates that we need to shut down */ int m_ret; @@ -576,7 +611,7 @@ class LocalTransportAgentChild : public TransportAgent, private Logger /** * our D-Bus interface, created in onConnect() */ - boost::scoped_ptr<LocalTransportChildImpl> m_child; + boost::shared_ptr<LocalTransportChildImpl> m_child; /** * sync context, created in Sync() D-Bus call @@ -834,36 +869,13 @@ class LocalTransportAgentChild : public TransportAgent, private Logger } } - /** - * Write message into our own log and send to parent. - */ - virtual void messagev(const MessageOptions &options, - const char *format, - va_list args) - { - if (m_parentLogger) { - m_parentLogger->process(); - } - if (m_child) { - // prefix is used to set session path - // for general server output, the object path field is dbus server - // the object path can't be empty for object paths prevent using empty string. - string strLevel = Logger::levelToStr(options.m_level); - string log = StringPrintfV(format, args); - m_child->m_logOutput(strLevel, log); - } - } - public: LocalTransportAgentChild() : m_ret(0), - m_parentLogger(new LogRedirect(true)), // redirect all output via D-Bus m_forkexec(SyncEvo::ForkExecChild::create()), m_reportSent(false), m_status(INACTIVE) { - Logger::pushLogger(this); - m_forkexec->m_onConnect.connect(boost::bind(&LocalTransportAgentChild::onConnect, this, _1)); m_forkexec->m_onFailure.connect(boost::bind(&LocalTransportAgentChild::onFailure, this, _1, _2)); // When parent quits, we need to abort whatever we do and shut @@ -880,9 +892,9 @@ public: m_forkexec->connect(); } - ~LocalTransportAgentChild() + boost::shared_ptr<ChildLogger> createLogger() { - Logger::popLogger(); + return boost::shared_ptr<ChildLogger>(new ChildLogger(m_child)); } void run() @@ -1125,8 +1137,16 @@ int LocalTransportMain(int argc, char **argv) Logger::setProcessName("syncevo-local-sync"); boost::shared_ptr<LocalTransportAgentChild> child(new LocalTransportAgentChild); + PushLogger<Logger> logger; + // Temporary handle is necessary to avoid compiler issue with + // clang (ambiguous brackets). + { + Logger::Handle handle(child->createLogger()); + logger.reset(handle); + } child->run(); int ret = child->getReturnCode(); + logger.reset(); child.reset(); return ret; } catch ( const std::exception &ex ) { diff --git a/src/syncevo/LogRedirect.cpp b/src/syncevo/LogRedirect.cpp index 89475c7f..65ced69b 100644 --- a/src/syncevo/LogRedirect.cpp +++ b/src/syncevo/LogRedirect.cpp @@ -57,8 +57,11 @@ void LogRedirect::abortHandler(int sig) throw() // SE_LOG_ERROR(NULL, "caught signal %d, shutting down", sig); // shut down redirection, also flushes to log - if (m_redirect) { - m_redirect->restore(); + { + RecMutex::Guard guard = lock(); + if (m_redirect) { + m_redirect->restore(); + } } // Raise same signal again. Because our handler @@ -103,13 +106,13 @@ void LogRedirect::init() m_knownErrors.insert("Qt: Session management error: None of the authentication protocols specified are supported"); } -LogRedirect::LogRedirect(bool both, const char *filename) throw() +LogRedirect::LogRedirect(Mode mode, const char *filename) { init(); m_processing = true; if (!getenv("SYNCEVOLUTION_DEBUG")) { redirect(STDERR_FILENO, m_stderr); - if (both) { + if (mode == STDERR_AND_STDOUT) { redirect(STDOUT_FILENO, m_stdout); m_out = filename ? fopen(filename, "w") : @@ -132,7 +135,12 @@ LogRedirect::LogRedirect(bool both, const char *filename) throw() fileno(m_out) : m_stderr.m_copy), "w"); } - Logger::pushLogger(this); + + // Modify process state while holding the Logger mutex. + RecMutex::Guard guard = lock(); + if (m_redirect) { + SE_LOG_WARNING(NULL, "LogRedirect already instantiated?!"); + } m_redirect = this; if (!getenv("SYNCEVOLUTION_DEBUG")) { @@ -158,6 +166,8 @@ LogRedirect::LogRedirect(ExecuteFlags flags) { init(); + // This instance does not modify process state and + // doesn't have to be thread-safe. m_streams = true; if (!(flags & EXECUTE_NO_STDERR)) { redirect(STDERR_FILENO, m_stderr); @@ -169,10 +179,12 @@ LogRedirect::LogRedirect(ExecuteFlags flags) LogRedirect::~LogRedirect() throw() { - bool pop = false; + RecMutex::Guard guard; + if (!m_streams) { + guard = lock(); + } if (m_redirect == this) { m_redirect = NULL; - pop = true; } process(); restore(); @@ -186,28 +198,36 @@ LogRedirect::~LogRedirect() throw() if (m_buffer) { free(m_buffer); } - if (pop) { - Logger::popLogger(); - } } -void LogRedirect::redoRedirect() throw() +void LogRedirect::remove() throw() { - bool doStdout = m_stdout.m_copy >= 0; - bool doStderr = m_stderr.m_copy >= 0; + restore(); +} - if (doStdout) { - restore(m_stdout); - redirect(STDOUT_FILENO, m_stdout); - } - if (doStderr) { - restore(m_stderr); - redirect(STDERR_FILENO, m_stderr); +void LogRedirect::removeRedirect() throw() +{ + if (m_redirect) { + // We were forked. Ignore mutex (might be held by thread which was not + // forked) and restore the forked process' state to the one it was + // before setting up redirection. + // + // Do the minimal amount of work possible in restore(), i.e., + // suppress the processing of streams. + m_redirect->m_streams = false; + + m_redirect->restore(m_redirect->m_stdout); + m_redirect->restore(m_redirect->m_stderr); } } void LogRedirect::restore() throw() { + RecMutex::Guard guard; + if (!m_streams) { + guard = lock(); + } + if (m_processing) { return; } @@ -223,6 +243,8 @@ void LogRedirect::messagev(const MessageOptions &options, const char *format, va_list args) { + RecMutex::Guard guard = lock(); + // check for other output first process(); // Choose output channel: SHOW goes to original stdout, @@ -524,6 +546,8 @@ bool LogRedirect::ignoreError(const std::string &text) void LogRedirect::process() { + RecMutex::Guard guard; + if (m_streams) { // iterate until both sockets are closed by peer while (true) { @@ -589,6 +613,8 @@ void LogRedirect::process() break; } } + } else { + guard = lock(); } if (m_processing) { @@ -613,6 +639,8 @@ void LogRedirect::process() void LogRedirect::flush() throw() { + RecMutex::Guard guard = lock(); + process(); if (!m_stdoutData.empty()) { std::string buffer; @@ -645,17 +673,17 @@ class LogRedirectTest : public CppUnit::TestFixture { { public: std::stringstream m_streams[DEBUG + 1]; - LogRedirect *m_redirect; + PushLogger<LogRedirect> m_redirect; - LogBuffer(bool both = true) + LogBuffer(LogRedirect::Mode mode = LogRedirect::STDERR_AND_STDOUT) { - m_redirect = new LogRedirect(both); - pushLogger(this); + m_redirect.reset(new LogRedirect(mode)); + addLogger(boost::shared_ptr<Logger>(this, NopDestructor())); } ~LogBuffer() { - popLogger(); - delete m_redirect; + removeLogger(this); + m_redirect.reset(); } virtual void messagev(const MessageOptions &options, @@ -746,7 +774,7 @@ public: orig_stdout = dup(STDOUT_FILENO); dup2(new_stdout, STDOUT_FILENO); - LogBuffer buffer(false); + LogBuffer buffer(LogRedirect::STDERR); fprintf(stdout, "normal message stdout\n"); fflush(stdout); diff --git a/src/syncevo/LogRedirect.h b/src/syncevo/LogRedirect.h index 5b762ab4..65f7498f 100644 --- a/src/syncevo/LogRedirect.h +++ b/src/syncevo/LogRedirect.h @@ -132,6 +132,11 @@ class LogRedirect : public LoggerStdout void init(); public: + enum Mode { + STDERR_AND_STDOUT, + STDERR + }; + /** * Redirect both stderr and stdout or just stderr, * using UDP so that we don't block when not reading @@ -140,16 +145,23 @@ class LogRedirect : public LoggerStdout * messagev() only writes messages to the previous stdout * or the optional file which pass the filtering (relevant, * suppress known errors, ...). + * + * May only be called when there is no other active LogRedirect + * instance. Not thread-safe, in contrast to the actual logging + * method and redirect handling. + * + * Does not add or remove the logger from the logger stack. + * That must be done by the caller. */ - LogRedirect(bool both = true, const char *filename = NULL) throw(); + LogRedirect(Mode mode, const char *filename = NULL); ~LogRedirect() throw(); + virtual void remove() throw(); + /** - * re-initialize redirection after a fork: - * - closes inherited file descriptors, except for the original output file descriptor - * - sets up new sockets + * Remove redirection (if any) after a fork and before an exec. */ - void redoRedirect() throw(); + static void removeRedirect() throw(); /** * Meant to be used for redirecting output of a specific command diff --git a/src/syncevo/LogSyslog.cpp b/src/syncevo/LogSyslog.cpp index a24d7737..2b178171 100644 --- a/src/syncevo/LogSyslog.cpp +++ b/src/syncevo/LogSyslog.cpp @@ -35,13 +35,11 @@ LoggerSyslog::LoggerSyslog(const std::string &processName) : // valgrind tells us that openlog() does not copy the string. // Must provide pointer to a permanent copy. openlog(m_processName.c_str(), LOG_CONS | LOG_NDELAY | LOG_PID, LOG_USER); - Logger::pushLogger(this); } LoggerSyslog::~LoggerSyslog() { closelog(); - Logger::popLogger(); } static void printToSyslog(int sysloglevel, std::string &chunk, size_t expectedTotal) diff --git a/src/syncevo/LogSyslog.h b/src/syncevo/LogSyslog.h index 3f72132c..9e8f3c9a 100644 --- a/src/syncevo/LogSyslog.h +++ b/src/syncevo/LogSyslog.h @@ -35,7 +35,7 @@ SE_BEGIN_CXX class LoggerSyslog : public Logger { const std::string m_processName; - Logger &m_parentLogger; + Handle m_parentLogger; public: /** diff --git a/src/syncevo/Logging.cpp b/src/syncevo/Logging.cpp index 82a063a5..01794f8a 100644 --- a/src/syncevo/Logging.cpp +++ b/src/syncevo/Logging.cpp @@ -27,7 +27,32 @@ #include <syncevo/declarations.h> SE_BEGIN_CXX -std::string Logger::m_processName; +static RecMutex logMutex; +/** + * POD to have it initialized without relying on a constructor to run. + */ +static std::string *logProcessName; + +void Logger::setProcessName(const std::string &name) +{ + RecMutex::Guard guard = logMutex.lock(); + if (!logProcessName) { + logProcessName = new std::string(name); + } else { + *logProcessName = name; + } +} + +std::string Logger::getProcessName() +{ + RecMutex::Guard guard = logMutex.lock(); + return logProcessName ? *logProcessName : ""; +} + +RecMutex::Guard Logger::lock() +{ + return logMutex.lock(); +} Logger::Logger() : m_level(INFO) @@ -38,53 +63,55 @@ Logger::~Logger() { } -static std::vector<Logger *> &loggers() +/** + * Create (if necessary) and return the logger stack. + * It has at least one entry. + * + * logMutex must be locked when calling this. + */ +static std::vector<Logger::Handle> &LoggersSingleton() { // allocate array once and never free it because it might be needed till // the very end of the application life cycle - static std::vector<Logger *> *loggers = new std::vector<Logger *>; + static std::vector<Logger::Handle> *loggers; + if (!loggers) { + loggers = new std::vector<Logger::Handle>; + // Ensure that the array is never empty. + boost::shared_ptr<Logger> logger(new LoggerStdout); + loggers->push_back(logger); + } return *loggers; } -Logger &Logger::instance() +Logger::Handle Logger::instance() { - // prevent destructing this instance as part of the executable's - // shutdown by allocating it dynamically, because it may be - // needed by other instances that get destructed later - // (order of global instance construction/destruction is - // undefined) - static LoggerStdout *DefaultLogger = new LoggerStdout; - if (!loggers().empty()) { - return *loggers()[loggers().size() - 1]; - } else { - return *DefaultLogger; - } + RecMutex::Guard guard = logMutex.lock(); + std::vector<Handle> &loggers = LoggersSingleton(); + return loggers.back(); } -void Logger::pushLogger(Logger *logger) +void Logger::addLogger(const Handle &logger) { - loggers().push_back(logger); -} + RecMutex::Guard guard = logMutex.lock(); + std::vector<Handle> &loggers = LoggersSingleton(); -void Logger::popLogger() -{ - if (loggers().empty()) { - throw "too many popLogger() calls"; - } else { - loggers().pop_back(); - } + loggers.push_back(logger); } -int Logger::numLoggers() +void Logger::removeLogger(Logger *logger) { - return (int)loggers().size(); -} + RecMutex::Guard guard = logMutex.lock(); + std::vector<Handle> &loggers = LoggersSingleton(); -Logger *Logger::loggerAt(int index) -{ - return index < 0 || index >= (int)loggers().size() ? - NULL : - loggers()[index]; + for (ssize_t i = loggers.size() - 1; + i >= 0; + --i) { + if (loggers[i] == logger) { + loggers[i].remove(); + loggers.erase(loggers.begin() + i); + break; + } + } } void Logger::formatLines(Level msglevel, @@ -101,56 +128,69 @@ void Logger::formatLines(Level msglevel, if (msglevel != SHOW) { std::string reltime; std::string procname; - const std::string *realProcname; + std::string firstLine; - if (processName) { - realProcname = processName; - } else { - realProcname = &m_processName; - } - if (!realProcname->empty()) { - procname.reserve(realProcname->size() + 1); - procname += " "; - procname += *realProcname; - } + // Run non-blocking operations on shared data while + // holding the mutex. + { + RecMutex::Guard guard = logMutex.lock(); + const std::string *realProcname; - if (outputlevel >= DEBUG) { - // add relative time stamp - Timespec now = Timespec::monotonic(); - if (!m_startTime) { - // first message, start counting time - m_startTime = now; - time_t nowt = time(NULL); - struct tm tm_gm, tm_local; - char buffer[2][80]; - gmtime_r(&nowt, &tm_gm); - localtime_r(&nowt, &tm_local); - reltime = " 00:00:00"; - strftime(buffer[0], sizeof(buffer[0]), - "%a %Y-%m-%d %H:%M:%S", - &tm_gm); - strftime(buffer[1], sizeof(buffer[1]), - "%H:%M %z %Z", - &tm_local); - std::string line = - StringPrintf("[DEBUG%s%s] %s UTC = %s\n", - procname.c_str(), - reltime.c_str(), - buffer[0], - buffer[1]); - print(line, 1); + if (processName) { + realProcname = processName; } else { - if (now >= m_startTime) { - Timespec delta = now - m_startTime; - reltime = StringPrintf(" %02ld:%02ld:%02ld", - delta.tv_sec / (60 * 60), - (delta.tv_sec % (60 * 60)) / 60, - delta.tv_sec % 60); + if (!logProcessName) { + logProcessName = new std::string; + } + realProcname = logProcessName; + } + if (!realProcname->empty()) { + procname.reserve(realProcname->size() + 1); + procname += " "; + procname += *realProcname; + } + + if (outputlevel >= DEBUG) { + // add relative time stamp + Timespec now = Timespec::monotonic(); + if (!m_startTime) { + // first message, start counting time + m_startTime = now; + time_t nowt = time(NULL); + struct tm tm_gm, tm_local; + char buffer[2][80]; + gmtime_r(&nowt, &tm_gm); + localtime_r(&nowt, &tm_local); + reltime = " 00:00:00"; + strftime(buffer[0], sizeof(buffer[0]), + "%a %Y-%m-%d %H:%M:%S", + &tm_gm); + strftime(buffer[1], sizeof(buffer[1]), + "%H:%M %z %Z", + &tm_local); + std::string line = + StringPrintf("[DEBUG%s%s] %s UTC = %s\n", + procname.c_str(), + reltime.c_str(), + buffer[0], + buffer[1]); } else { - reltime = " ??:??:??"; + if (now >= m_startTime) { + Timespec delta = now - m_startTime; + reltime = StringPrintf(" %02ld:%02ld:%02ld", + delta.tv_sec / (60 * 60), + (delta.tv_sec % (60 * 60)) / 60, + delta.tv_sec % 60); + } else { + reltime = " ??:??:??"; + } } } } + + if (!firstLine.empty()) { + print(firstLine, 1); + } tag = StringPrintf("[%s%s%s] %s%s", levelToStr(msglevel), procname.c_str(), @@ -224,41 +264,68 @@ Logger::MessageOptions::MessageOptions(Level level, { } -void Logger::message(Level level, - const std::string *prefix, - const char *file, - int line, - const char *function, - const char *format, - ...) +Logger::Handle::Handle() throw () +{ +} + +Logger::Handle::Handle(Logger *logger) throw () +{ + m_logger.reset(logger); +} + +Logger::Handle::Handle(const Handle &other) throw () +{ + m_logger = other.m_logger; +} + +Logger::Handle & Logger::Handle::operator = (const Handle &other) throw () +{ + if (this != &other) { + m_logger = other.m_logger; + } + return *this; +} + +Logger::Handle::~Handle() throw () +{ + m_logger.reset(); +} + +void Logger::Handle::message(Level level, + const std::string *prefix, + const char *file, + int line, + const char *function, + const char *format, + ...) { va_list args; va_start(args, format); - messagev(MessageOptions(level, prefix, file, line, function), format, args); + m_logger->messagev(MessageOptions(level, prefix, file, line, function), format, args); va_end(args); } -void Logger::message(Level level, - const std::string &prefix, - const char *file, - int line, - const char *function, - const char *format, - ...) +void Logger::Handle::message(Level level, + const std::string &prefix, + const char *file, + int line, + const char *function, + const char *format, + ...) { va_list args; va_start(args, format); - messagev(MessageOptions(level, &prefix, file, line, function), format, args); + m_logger->messagev(MessageOptions(level, &prefix, file, line, function), format, args); va_end(args); } -void Logger::messageWithOptions(const MessageOptions &options, - const char *format, - ...) +void Logger::Handle::messageWithOptions(const MessageOptions &options, + const char *format, + ...) { va_list args; va_start(args, format); - messagev(options, format, args); + m_logger->messagev(options, format, args); va_end(args); } diff --git a/src/syncevo/Logging.h b/src/syncevo/Logging.h index 283efa8d..dde9e325 100644 --- a/src/syncevo/Logging.h +++ b/src/syncevo/Logging.h @@ -33,8 +33,11 @@ #endif #include <syncevo/Timespec.h> +#include <syncevo/ThreadSupport.h> #include <boost/function.hpp> +#include <boost/shared_ptr.hpp> +#include <boost/noncopyable.hpp> #include <syncevo/declarations.h> SE_BEGIN_CXX @@ -130,8 +133,17 @@ class Logger * * Included by LoggerStdout in the [INFO/DEBUG/...] tag. */ - static void setProcessName(const std::string &name) { m_processName = name; } - static std::string getProcessName() { return m_processName; } + static void setProcessName(const std::string &name); + static std::string getProcessName(); + + /** + * Obtains the recursive logging mutex. + * + * All calls offered by the Logger class already lock that mutex + * internally, but sometimes it may be necessary to protect a larger + * region of logging related activity. + */ + static RecMutex::Guard lock(); #ifdef HAVE_GLIB /** @@ -161,6 +173,15 @@ class Logger virtual ~Logger(); /** + * Prepare logger for removal from logging stack. May be called + * multiple times. + * + * The logger should stop doing anything right away and just pass + * on messages until it gets deleted eventually. + */ + virtual void remove() throw () {} + + /** * Collects all the parameters which may get passed to * messagev. */ @@ -199,36 +220,69 @@ class Logger const char *format, va_list args) = 0; - /** redirect into messagev() */ - void message(Level level, - const std::string *prefix, - const char *file, - int line, - const char *function, - const char *format, - ...) + /** + * A convenience and backwards-compatibility class which allows + * calling some methods of the underlying pointer directly similar + * to the Logger reference returned in previous SyncEvolution + * releases. + */ + class Handle + { + boost::shared_ptr<Logger> m_logger; + + public: + Handle() throw (); + Handle(Logger *logger) throw (); + template<class L> Handle(const boost::shared_ptr<L> &logger) throw () : m_logger(logger) {} + template<class L> Handle(const boost::weak_ptr<L> &logger) throw () : m_logger(logger.lock()) {} + Handle(const Handle &other) throw (); + Handle &operator = (const Handle &other) throw (); + ~Handle() throw (); + + operator bool () const { return m_logger; } + bool operator == (Logger *logger) const { return m_logger.get() == logger; } + Logger *get() const { return m_logger.get(); } + + void messagev(const MessageOptions &options, + const char *format, + va_list args) + { + m_logger->messagev(options, format, args); + } + + void message(Level level, + const std::string *prefix, + const char *file, + int line, + const char *function, + const char *format, + ...) #ifdef __GNUC__ - __attribute__((format(printf, 7, 8))) + __attribute__((format(printf, 7, 8))) #endif - ; - void message(Level level, - const std::string &prefix, - const char *file, - int line, - const char *function, - const char *format, - ...) + ; + void message(Level level, + const std::string &prefix, + const char *file, + int line, + const char *function, + const char *format, + ...) #ifdef __GNUC__ - __attribute__((format(printf, 7, 8))) + __attribute__((format(printf, 7, 8))) #endif - ; - void messageWithOptions(const MessageOptions &options, - const char *format, - ...) + ; + void messageWithOptions(const MessageOptions &options, + const char *format, + ...) #ifdef __GNUC__ - __attribute__((format(printf, 3, 4))) + __attribute__((format(printf, 3, 4))) #endif - ; + ; + void setLevel(Level level) { m_logger->setLevel(level); } + Level getLevel() { return m_logger->getLevel(); } + void remove() throw () { m_logger->remove(); } + }; /** * Grants access to the singleton which implements logging. @@ -236,31 +290,25 @@ class Logger * class itself is platform specific: if no Log instance * has been set yet, then this call has to create one. */ - static Logger &instance(); + static Handle instance(); /** - * Overrides the default Logger implementation. The Logger class - * itself will never delete the active logger. + * Overrides the current default Logger implementation. * * @param logger will be used for all future logging activities */ - static void pushLogger(Logger *logger); + static void addLogger(const Handle &logger); /** - * Remove the current logger and restore previous one. - * Must match a pushLogger() call. - */ - static void popLogger(); - - /** total number of active loggers */ - static int numLoggers(); - - /** - * access to active logger - * @param index 0 for oldest (inner-most) logger - * @return pointer or NULL for invalid index + * Remove the specified logger. + * + * Note that the logger might still be in use afterwards, for + * example when a different thread currently uses it. Therefore + * loggers should be small stub classes. If they need access to + * more expensive classes to do their work, they shold hold weak + * reference to those and only lock them when logging. */ - static Logger *loggerAt(int index); + static void removeLogger(Logger *logger); virtual void setLevel(Level level) { m_level = level; } virtual Level getLevel() { return m_level; } @@ -288,7 +336,6 @@ class Logger boost::function<void (std::string &chunk, size_t expectedTotal)> print); private: - static std::string m_processName; Level m_level; /** @@ -299,6 +346,76 @@ class Logger Timespec m_startTime; }; +/** + * Takes a logger and adds it to the stack + * as long as the instance exists. + */ +template<class L> class PushLogger : boost::noncopyable +{ + Logger::Handle m_logger; + + public: + PushLogger() {} + /** + * Can use Handle directly here. + */ + PushLogger(const Logger::Handle &logger) : m_logger(logger) + { + if (m_logger) { + Logger::addLogger(m_logger); + } + } + /** + * Take any type that a Handle constructor accepts, then use it as + * Handle. + */ + template <class M> PushLogger(M logger) : m_logger(Logger::Handle(logger)) + { + if (m_logger) { + Logger::addLogger(m_logger); + } + } + ~PushLogger() throw () + { + if (m_logger) { + Logger::removeLogger(m_logger.get()); + } + } + + operator bool () const { return m_logger; } + + void reset(const Logger::Handle &logger) + { + if (m_logger) { + Logger::removeLogger(m_logger.get()); + } + m_logger = logger; + if (m_logger) { + Logger::addLogger(m_logger); + } + } + template<class M> void reset(M logger) + { + if (m_logger) { + Logger::removeLogger(m_logger.get()); + } + m_logger = Logger::Handle(logger); + if (m_logger) { + Logger::addLogger(m_logger); + } + } + + void reset() + { + if (m_logger) { + Logger::removeLogger(m_logger.get()); + } + m_logger = Logger::Handle(); + } + + L *get() { return static_cast<L *>(m_logger.get()); } + L * operator -> () { return get(); } +}; /** * Wraps Logger::message() in the current default logger. diff --git a/src/syncevo/SuspendFlags.h b/src/syncevo/SuspendFlags.h index f527dfa4..a45c1154 100644 --- a/src/syncevo/SuspendFlags.h +++ b/src/syncevo/SuspendFlags.h @@ -21,6 +21,7 @@ #define INCL_SUSPENDFLAGS #include <signal.h> +#include <stdint.h> #include <boost/smart_ptr.hpp> #include <boost/function.hpp> #include <boost/signals2.hpp> diff --git a/src/syncevo/SyncContext.cpp b/src/syncevo/SyncContext.cpp index fe8e9183..9624c383 100644 --- a/src/syncevo/SyncContext.cpp +++ b/src/syncevo/SyncContext.cpp @@ -267,12 +267,30 @@ public: } }; -// this class owns the logging directory and is responsible +class LogDir; + +/** + * Helper class for LogDir: acts as proxy for logging into + * the LogDir's reports and log file. + */ +class LogDirLogger : public Logger +{ + Logger::Handle m_parentLogger; /**< the logger which was active before we started to intercept messages */ + boost::weak_ptr<LogDir> m_logdir; /**< grants access to report and Synthesis engine */ + +public: + LogDirLogger(const boost::weak_ptr<LogDir> &logdir); + virtual void remove() throw (); + virtual void messagev(const MessageOptions &options, + const char *format, + va_list args); +}; + +// This class owns the logging directory. It is responsible // for redirecting output at the start and end of sync (even -// in case of exceptions thrown!) -class LogDir : public Logger, private boost::noncopyable, private LogDirNames { +// in case of exceptions thrown!). +class LogDir : private boost::noncopyable, private LogDirNames { SyncContext &m_client; - Logger &m_parentLogger; /**< the logger which was active before we started to intercept messages */ string m_logdir; /**< configured backup root dir */ int m_maxlogdirs; /**< number of backup dirs to preserve, 0 if unlimited */ string m_prefix; /**< common prefix of backup dirs */ @@ -286,11 +304,18 @@ class LogDir : public Logger, private boost::noncopyable, private LogDirNames { that this class still is the central point to ask for the name of the log file. */ boost::scoped_ptr<SafeConfigNode> m_info; /**< key/value representation of sync information */ + + // Access to m_report and m_client must be thread-safe as soon as + // LogDirLogger is active, because they are shared between main + // thread and any thread which might log errors. + friend class LogDirLogger; bool m_readonly; /**< m_info is not to be written to */ SyncReport *m_report; /**< record start/end times here */ -public: - LogDir(SyncContext &client) : m_client(client), m_parentLogger(Logger::instance()), m_info(NULL), m_readonly(false), m_report(NULL) + boost::weak_ptr<LogDir> m_self; + PushLogger<LogDirLogger> m_logger; /**< active logger */ + + LogDir(SyncContext &client) : m_client(client), m_info(NULL), m_readonly(false), m_report(NULL) { // Set default log directory. This will be overwritten with a user-specified // location later on, if one was selected by the user. SyncEvolution >= 0.9 alpha @@ -312,6 +337,14 @@ public: setLogdir(path); } +public: + static boost::shared_ptr<LogDir> create(SyncContext &client) + { + boost::shared_ptr<LogDir> logdir(new LogDir(client)); + logdir->m_self = logdir; + return logdir; + } + /** * Finds previous log directories for context. Reports errors via exceptions. * @@ -512,35 +545,36 @@ public: } // update log level of default logger and our own replacement - Level level; + Logger::Level level; switch (logLevel) { case 0: // default for console output - level = INFO; + level = Logger::INFO; break; case 1: - level = ERROR; + level = Logger::ERROR; break; case 2: - level = INFO; + level = Logger::INFO; break; default: if (m_logfile.empty() || getenv("SYNCEVOLUTION_DEBUG")) { // no log file or user wants to see everything: // print all information to the console - level = DEBUG; + level = Logger::DEBUG; } else { // have log file: avoid excessive output to the console, // full information is in the log file - level = INFO; + level = Logger::INFO; } break; } if (mode != SESSION_USE_PATH) { Logger::instance().setLevel(level); } - setLevel(level); - Logger::pushLogger(this); + boost::shared_ptr<Logger> logger(new LogDirLogger(m_self)); + logger->setLevel(level); + m_logger.reset(logger); time_t start = time(NULL); if (m_report) { @@ -710,6 +744,7 @@ public: if (!m_readonly) { writeTimestamp("end", end); if (m_report) { + RecMutex::Guard guard = Logger::lock(); writeReport(*m_report); } m_info->flush(); @@ -718,11 +753,9 @@ public: } } - // remove redirection of logging (safe for destructor) + // Remove redirection of logging. void restore() { - if (&Logger::instance() == this) { - Logger::popLogger(); - } + m_logger.reset(); } ~LogDir() { @@ -730,47 +763,6 @@ public: } - virtual void messagev(const MessageOptions &options, - const char *format, - va_list args) - { - // always to parent first (usually stdout): - // if the parent is a LogRedirect instance, then - // it'll flush its own output first, which ensures - // that the new output comes later (as desired) - { - va_list argscopy; - va_copy(argscopy, args); - m_parentLogger.messagev(options, format, argscopy); - va_end(argscopy); - } - - if (m_report && - options.m_level <= ERROR && - m_report->getError().empty()) { - va_list argscopy; - va_copy(argscopy, args); - string error = StringPrintfV(format, argscopy); - va_end(argscopy); - - m_report->setError(error); - } - - if (m_client.getEngine().get()) { - va_list argscopy; - va_copy(argscopy, args); - // once to Synthesis log, with full debugging - m_client.getEngine().doDebug(options.m_level, - options.m_prefix ? options.m_prefix->c_str() : NULL, - options.m_file, - options.m_line, - options.m_function, - format, - argscopy); - va_end(argscopy); - } - } - #if 0 /** * A quick check for level = SHOW text dumps whether the text dump @@ -933,6 +925,67 @@ private: } }; +LogDirLogger::LogDirLogger(const boost::weak_ptr<LogDir> &logdir) : + m_parentLogger(Logger::instance()), + m_logdir(logdir) +{ +} + +void LogDirLogger::remove() throw () +{ + // Forget reference to LogDir. This prevents accessing it in + // future messagev() calls. + RecMutex::Guard guard = Logger::lock(); + m_logdir.reset(); +} + +void LogDirLogger::messagev(const MessageOptions &options, + const char *format, + va_list args) +{ + // Protects ordering of log messages and access to shared + // variables like m_report and m_engine. + RecMutex::Guard guard = Logger::lock(); + + // always to parent first (usually stdout): + // if the parent is a LogRedirect instance, then + // it'll flush its own output first, which ensures + // that the new output comes later (as desired) + va_list argscopy; + va_copy(argscopy, args); + m_parentLogger.messagev(options, format, argscopy); + va_end(argscopy); + + boost::shared_ptr<LogDir> logdir = m_logdir.lock(); + if (logdir) { + if (logdir->m_report && + options.m_level <= ERROR && + logdir->m_report->getError().empty()) { + va_list argscopy; + va_copy(argscopy, args); + string error = StringPrintfV(format, argscopy); + va_end(argscopy); + + logdir->m_report->setError(error); + } + + if (logdir->m_client.getEngine().get()) { + va_list argscopy; + va_copy(argscopy, args); + // once to Synthesis log, with full debugging + logdir->m_client.getEngine().doDebug(options.m_level, + options.m_prefix ? options.m_prefix->c_str() : NULL, + options.m_file, + options.m_line, + options.m_function, + format, + argscopy); + va_end(argscopy); + } + } +} + + const char* const LogDirNames::DIR_PREFIX = "SyncEvolution-"; /** @@ -1001,7 +1054,7 @@ public: private: VirtualSyncSources_t m_virtualSources; /**< all configured virtual data sources (aka Synthesis <superdatastore>) */ - LogDir m_logdir; /**< our logging directory */ + boost::shared_ptr<LogDir> m_logdir; /**< our logging directory */ SyncContext &m_client; /**< the context in which we were instantiated */ set<string> m_prepared; /**< remember for which source we dumped databases successfully */ string m_intro; /**< remembers the dumpLocalChanges() intro and only prints it again @@ -1015,7 +1068,7 @@ private: /** create name in current (if set) or previous logdir */ string databaseName(SyncSource &source, const string suffix, string logdir = "") { if (!logdir.size()) { - logdir = m_logdir.getLogdir(); + logdir = m_logdir->getLogdir(); } return logdir + "/" + source.getName() + "." + suffix; @@ -1076,9 +1129,9 @@ public: // to search for previous backups of each source, if // necessary. SyncContext context(m_client.getContextName()); - LogDir logdir(context); + boost::shared_ptr<LogDir> logdir(LogDir::create(context)); vector<string> dirs; - logdir.previousLogdirs(dirs); + logdir->previousLogdirs(dirs); BOOST_FOREACH(SyncSource *source, *this) { if ((!excludeSource.empty() && excludeSource != source->getName()) || @@ -1150,7 +1203,7 @@ public: } SourceList(SyncContext &client, bool doLogging) : - m_logdir(client), + m_logdir(LogDir::create(client)), m_client(client), m_doLogging(doLogging), m_reportTodo(true), @@ -1160,37 +1213,37 @@ public: // call as soon as logdir settings are known void startSession(const string &logDirPath, int maxlogdirs, int logLevel, SyncReport *report) { - m_logdir.setLogdir(logDirPath); - m_previousLogdir = m_logdir.previousLogdir(); + m_logdir->setLogdir(logDirPath); + m_previousLogdir = m_logdir->previousLogdir(); if (m_doLogging) { - m_logdir.startSession(logDirPath, LogDir::SESSION_CREATE, maxlogdirs, logLevel, report); + m_logdir->startSession(logDirPath, LogDir::SESSION_CREATE, maxlogdirs, logLevel, report); } else { // Run debug session without paying attention to // the normal logdir handling. The log level here // refers to stdout. The log file will be as complete // as possible. - m_logdir.startSession(logDirPath, LogDir::SESSION_USE_PATH, 0, 1, report); + m_logdir->startSession(logDirPath, LogDir::SESSION_USE_PATH, 0, 1, report); } } /** read-only access to existing session, identified in logDirPath */ void accessSession(const string &logDirPath) { - m_logdir.setLogdir(logDirPath); - m_previousLogdir = m_logdir.previousLogdir(); - m_logdir.startSession(logDirPath, LogDir::SESSION_READ_ONLY, 0, 0, NULL); + m_logdir->setLogdir(logDirPath); + m_previousLogdir = m_logdir->previousLogdir(); + m_logdir->startSession(logDirPath, LogDir::SESSION_READ_ONLY, 0, 0, NULL); } /** return log directory, empty if not enabled */ const string &getLogdir() { - return m_logdir.getLogdir(); + return m_logdir->getLogdir(); } /** return previous log dir found in startSession() */ const string &getPrevLogdir() const { return m_previousLogdir; } /** set directory for database files without actually redirecting the logging */ - void setPath(const string &path) { m_logdir.setPath(path); } + void setPath(const string &path) { m_logdir->setPath(path); } /** * If possible (directory to compare against available) and enabled, @@ -1214,7 +1267,7 @@ public: vector<string> dirs; if (oldSession.empty()) { - m_logdir.previousLogdirs(dirs); + m_logdir->previousLogdirs(dirs); } BOOST_FOREACH(SyncSource *source, *this) { @@ -1237,10 +1290,10 @@ public: it != dirs.rend(); ++it) { const string &sessiondir = *it; - LogDir oldsession(m_client); - oldsession.openLogdir(sessiondir); + boost::shared_ptr<LogDir> oldsession(LogDir::create(m_client)); + oldsession->openLogdir(sessiondir); SyncReport report; - oldsession.readReport(report); + oldsession->readReport(report); if (report.find(source->getName()) != report.end()) { // source was active in that session, use dump // made there @@ -1283,7 +1336,7 @@ public: return; } - if (m_logdir.getLogfile().size() && + if (m_logdir->getLogfile().size() && m_doLogging && (m_client.getDumpData() || m_client.getPrintChanges())) { // dump initial databases @@ -1340,17 +1393,17 @@ public: } // ensure that stderr is seen again - m_logdir.restore(); + m_logdir->restore(); // write out session status - m_logdir.endSession(); + m_logdir->endSession(); if (m_reportTodo) { // haven't looked at result of sync yet; // don't do it again m_reportTodo = false; - string logfile = m_logdir.getLogfile(); + string logfile = m_logdir->getLogfile(); if (status == STATUS_OK) { SE_LOG_SHOW(NULL, "\nSynchronization successful."); } else if (logfile.size()) { @@ -1380,7 +1433,7 @@ public: // compare databases? if (m_client.getPrintChanges()) { - dumpLocalChanges(m_logdir.getLogdir(), + dumpLocalChanges(m_logdir->getLogdir(), "before", "after", "", StringPrintf("\nData modified %s during synchronization:\n", m_client.isLocalSync() ? m_client.getContextName().c_str() : "locally"), @@ -1388,12 +1441,12 @@ public: } // now remove some old logdirs - m_logdir.expire(); + m_logdir->expire(); } } else { // finish debug session - m_logdir.restore(); - m_logdir.endSession(); + m_logdir->restore(); + m_logdir->endSession(); } } @@ -4136,16 +4189,15 @@ void SyncContext::restore(const string &dirname, RestoreDatabase database) void SyncContext::getSessions(vector<string> &dirs) { - LogDir logging(*this); - logging.previousLogdirs(dirs); + LogDir::create(*this)->previousLogdirs(dirs); } string SyncContext::readSessionInfo(const string &dir, SyncReport &report) { - LogDir logging(*this); - logging.openLogdir(dir); - logging.readReport(report); - return logging.getPeerNameFromLogdir(dir); + boost::shared_ptr<LogDir> logging(LogDir::create(*this)); + logging->openLogdir(dir); + logging->readReport(report); + return logging->getPeerNameFromLogdir(dir); } #ifdef ENABLE_UNIT_TESTS @@ -4157,7 +4209,7 @@ string SyncContext::readSessionInfo(const string &dir, SyncReport &report) * With that setup and a fake SyncContext it is possible to simulate * sessions and test the resulting logdirs. */ -class LogDirTest : public CppUnit::TestFixture, private SyncContext, private Logger +class LogDirTest : public CppUnit::TestFixture, private SyncContext, public Logger { public: LogDirTest() : @@ -4165,11 +4217,11 @@ public: m_maxLogDirs(10) { // suppress output by redirecting into m_out - pushLogger(this); + addLogger(boost::shared_ptr<Logger>(this, NopDestructor())); } ~LogDirTest() { - popLogger(); + removeLogger(this); } void setUp() { diff --git a/src/syncevo/syncevo.am b/src/syncevo/syncevo.am index 6b027df1..cc2e30cb 100644 --- a/src/syncevo/syncevo.am +++ b/src/syncevo/syncevo.am @@ -36,7 +36,7 @@ src_syncevo_sources = \ src/syncevo/eds_abi_wrapper.cpp \ src/syncevo/GLibSupport.h \ src/syncevo/GLibSupport.cpp \ - src/syncevo/ThreadingSupport.h \ + src/syncevo/ThreadSupport.h \ \ src/syncevo/SyncML.h \ src/syncevo/SyncML.cpp \ @@ -150,7 +150,7 @@ src_syncevo_libsyncevolution_include_HEADERS = \ src/syncevo/Cmdline.h \ src/syncevo/ConfigFilter.h \ src/syncevo/GLibSupport.h \ - src/syncevo/ThreadingSupport.h \ + src/syncevo/ThreadSupport.h \ src/syncevo/TrackingSyncSource.h \ src/syncevo/MapSyncSource.h \ src/syncevo/LogRedirect.h \ diff --git a/src/syncevolution.cpp b/src/syncevolution.cpp index ab077a15..801a5cf9 100644 --- a/src/syncevolution.cpp +++ b/src/syncevolution.cpp @@ -421,7 +421,7 @@ int main( int argc, char **argv ) // stdout is printed normally. Deconstructing it when // leaving main() does one final processing of pending // output. - LogRedirect redirect(false); + PushLogger<LogRedirect> redirect(new LogRedirect(LogRedirect::STDERR)); setvbuf(stderr, NULL, _IONBF, 0); setvbuf(stdout, NULL, _IONBF, 0); diff --git a/test/client-test-main.cpp b/test/client-test-main.cpp index b68317c7..6685aa02 100644 --- a/test/client-test-main.cpp +++ b/test/client-test-main.cpp @@ -123,9 +123,7 @@ public: } ~ClientListener() { - if (&Logger::instance() == m_logger.get()) { - Logger::popLogger(); - } + m_logger.reset(); } void addAllowedFailures(string allowedFailures) { @@ -138,9 +136,8 @@ public: if (!getenv("SYNCEVOLUTION_DEBUG")) { string logfile = m_currentTest + ".log"; simplifyFilename(logfile); - m_logger.reset(new LogRedirect(true, logfile.c_str())); + m_logger.reset(new LogRedirect(LogRedirect::STDERR_AND_STDOUT, logfile.c_str())); m_logger->setLevel(Logger::DEBUG); - Logger::pushLogger(m_logger.get()); } SE_LOG_DEBUG(NULL, "*** starting %s ***", m_currentTest.c_str()); m_failures.reset(); @@ -192,9 +189,6 @@ public: if (!failure.empty()) { SE_LOG_ERROR(NULL, "%s", failure.c_str()); } - if (&Logger::instance() == m_logger.get()) { - Logger::popLogger(); - } m_logger.reset(); string logfile = m_currentTest + ".log"; @@ -245,7 +239,7 @@ private: bool m_failed, m_testFailed; string m_currentTest; int m_alarmSeconds; - auto_ptr<Logger> m_logger; + PushLogger<Logger> m_logger; CppUnit::TestResultCollector m_failures; static void alarmTriggered(int signal) { |