core: use Boost.Log for logging
This makes the logging backend asynchronous
Change-Id: Ib3417e2ae424c5ae7237c071dc4698ca9769a33c
Refs: #2513
diff --git a/core/logger-factory.cpp b/core/logger-factory.cpp
index a463b94..aae7795 100644
--- a/core/logger-factory.cpp
+++ b/core/logger-factory.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -26,6 +26,8 @@
#include "logger-factory.hpp"
#include <boost/range/adaptor/map.hpp>
+#include <boost/log/core.hpp>
+#include <boost/log/expressions.hpp>
#ifdef HAVE_CUSTOM_LOGGER
#error "This file should not be compiled when custom logger is used"
@@ -53,6 +55,21 @@
m_levelNames["DEBUG"] = LOG_DEBUG;
m_levelNames["TRACE"] = LOG_TRACE;
m_levelNames["ALL"] = LOG_ALL;
+
+ auto backend = boost::make_shared<boost::log::sinks::text_ostream_backend>();
+ backend->auto_flush(true);
+ backend->add_stream(boost::shared_ptr<std::ostream>(&std::clog, bind([]{})));
+
+ m_sink = boost::make_shared<Sink>(backend);
+ m_sink->set_formatter(boost::log::expressions::stream << boost::log::expressions::message);
+ boost::log::core::get()->add_sink(m_sink);
+}
+
+LoggerFactory::~LoggerFactory()
+{
+ boost::log::core::get()->remove_sink(m_sink);
+ m_sink->stop();
+ m_sink->flush();
}
void
@@ -173,6 +190,12 @@
}
}
+void
+LoggerFactory::flushBackend()
+{
+ m_sink->flush();
+}
+
Logger&
LoggerFactory::create(const std::string& moduleName)
{
diff --git a/core/logger-factory.hpp b/core/logger-factory.hpp
index 606ac1c..e61d60f 100644
--- a/core/logger-factory.hpp
+++ b/core/logger-factory.hpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -35,6 +35,9 @@
#include "config-file.hpp"
#include "logger.hpp"
+#include <boost/log/sinks.hpp>
+#include <mutex>
+
namespace nfd {
class LoggerFactory : noncopyable
@@ -77,10 +80,15 @@
void
setDefaultLevel(LogLevel level);
+ void
+ flushBackend();
+
private:
LoggerFactory();
+ ~LoggerFactory();
+
Logger&
createLogger(const std::string& moduleName);
@@ -104,6 +112,9 @@
mutable std::mutex m_loggersGuard;
LogLevel m_defaultLevel;
+
+ typedef boost::log::sinks::asynchronous_sink<boost::log::sinks::text_ostream_backend> Sink;
+ boost::shared_ptr<Sink> m_sink;
};
inline LogLevel
diff --git a/core/logger.cpp b/core/logger.cpp
index 3a9da61..7803dfc 100644
--- a/core/logger.cpp
+++ b/core/logger.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -36,25 +36,23 @@
namespace nfd {
-std::mutex g_logMutex;
-
Logger::Logger(const std::string& name, LogLevel level)
: m_moduleName(name)
, m_enabledLogLevel(level)
{
}
-const char*
-Logger::now()
+std::ostream&
+operator<<(std::ostream& os, const LoggerTimestamp&)
{
using namespace ndn::time;
static const microseconds::rep ONE_SECOND = 1000000;
microseconds::rep microsecondsSinceEpoch = duration_cast<microseconds>(
- system_clock::now().time_since_epoch()).count();
+ system_clock::now().time_since_epoch()).count();
// 10 (whole seconds) + '.' + 6 (fraction) + '\0'
- static char buffer[10 + 1 + 6 + 1];
+ char buffer[10 + 1 + 6 + 1];
BOOST_ASSERT_MSG(microsecondsSinceEpoch / ONE_SECOND <= 9999999999L,
"whole seconds cannot fit in 10 characters");
@@ -66,9 +64,7 @@
microsecondsSinceEpoch / ONE_SECOND,
microsecondsSinceEpoch % ONE_SECOND);
- // It's okay to return a statically allocated buffer, because Logger::now() is invoked
- // only once per log macro.
- return buffer;
+ return os << buffer;
}
} // namespace nfd
diff --git a/core/logger.hpp b/core/logger.hpp
index 54af7cb..853a922 100644
--- a/core/logger.hpp
+++ b/core/logger.hpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -31,8 +31,8 @@
#ifdef HAVE_CUSTOM_LOGGER
#include "custom-logger.hpp"
#else
-
-#include <mutex>
+#include <boost/log/common.hpp>
+#include <boost/log/sources/logger.hpp>
namespace nfd {
@@ -84,12 +84,8 @@
m_moduleName = name;
}
- /** \return string representation of time since epoch: seconds.microseconds
- * \warning Return value is in a statically allocated buffer,
- * which subsequent calls will overwrite.
- */
- static const char*
- now();
+public:
+ boost::log::sources::logger boostLogger;
private:
std::string m_moduleName;
@@ -103,6 +99,20 @@
return output;
}
+/**
+ * \brief a tag that writes a timestamp upon stream output
+ */
+struct LoggerTimestamp
+{
+};
+
+/**
+ * \brief write a timestamp to \p os
+ * \note This function is thread-safe.
+ */
+std::ostream&
+operator<<(std::ostream& os, const LoggerTimestamp&);
+
} // namespace nfd
#include "core/logger-factory.hpp"
@@ -130,16 +140,15 @@
template<> \
nfd::Logger& cls<s1, s2>::g_logger = nfd::LoggerFactory::create(name)
-extern std::mutex g_logMutex;
+#define NFD_LOG_LINE(msg, expression) \
+LoggerTimestamp{} << " "#msg": " << "[" << g_logger << "] " << expression
-#define NFD_LOG(level, msg, expression) \
-do { \
- if (g_logger.isEnabled(::nfd::LOG_##level)) { \
- std::lock_guard<std::mutex> lock(::nfd::g_logMutex); \
- std::clog << ::nfd::Logger::now() << " "#msg": " \
- << "[" << g_logger << "] " << expression << "\n"; \
- } \
-} while (false)
+#define NFD_LOG(level, msg, expression) \
+ do { \
+ if (g_logger.isEnabled(::nfd::LOG_##level)) { \
+ BOOST_LOG(g_logger.boostLogger) << NFD_LOG_LINE(msg, expression); \
+ } \
+ } while (false)
#define NFD_LOG_TRACE(expression) NFD_LOG(TRACE, TRACE, expression)
#define NFD_LOG_DEBUG(expression) NFD_LOG(DEBUG, DEBUG, expression)
diff --git a/daemon/face/udp-factory.cpp b/daemon/face/udp-factory.cpp
index cc60a63..e905a0b 100644
--- a/daemon/face/udp-factory.cpp
+++ b/daemon/face/udp-factory.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -110,7 +110,7 @@
"endpoint is already allocated for a UDP multicast face"));
}
- channel = make_shared<UdpChannel>(endpoint, timeout);
+ channel = std::make_shared<UdpChannel>(endpoint, timeout);
m_channels[endpoint] = channel;
prohibitEndpoint(endpoint);
diff --git a/daemon/table/strategy-info-host.hpp b/daemon/table/strategy-info-host.hpp
index 84c0c63..7afe50d 100644
--- a/daemon/table/strategy-info-host.hpp
+++ b/daemon/table/strategy-info-host.hpp
@@ -1,12 +1,12 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014, Regents of the University of California,
- * Arizona Board of Regents,
- * Colorado State University,
- * University Pierre & Marie Curie, Sorbonne University,
- * Washington University in St. Louis,
- * Beijing Institute of Technology,
- * The University of Memphis
+ * Copyright (c) 2014-2016, Regents of the University of California,
+ * Arizona Board of Regents,
+ * Colorado State University,
+ * University Pierre & Marie Curie, Sorbonne University,
+ * Washington University in St. Louis,
+ * Beijing Institute of Technology,
+ * The University of Memphis.
*
* This file is part of NFD (Named Data Networking Forwarding Daemon).
* See AUTHORS.md for complete list of NFD authors and contributors.
@@ -108,7 +108,7 @@
shared_ptr<T> item = this->getStrategyInfo<T>();
if (!static_cast<bool>(item)) {
- item = make_shared<T>(std::forward<A>(args)...);
+ item = std::make_shared<T>(std::forward<A>(args)...);
this->setStrategyInfo(item);
}
return item;
diff --git a/tests/core/logger.t.cpp b/tests/core/logger.t.cpp
index 5dafadb..51dd2d2 100644
--- a/tests/core/logger.t.cpp
+++ b/tests/core/logger.t.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/**
- * Copyright (c) 2014-2015, Regents of the University of California,
+ * Copyright (c) 2014-2016, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -92,6 +92,8 @@
microseconds::rep after =
duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -203,6 +205,8 @@
microseconds::rep after =
duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -328,6 +332,8 @@
microseconds::rep after =
duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -424,6 +430,8 @@
const size_t N_EXPECTED = sizeof(EXPECTED) / sizeof(std::string);
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -513,6 +521,8 @@
microseconds::rep after =
duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
const size_t firstSpace = buffer.find(" ");
@@ -619,6 +629,8 @@
const size_t N_EXPECTED = sizeof(EXPECTED) / sizeof(string);
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -729,6 +741,8 @@
const size_t N_EXPECTED = sizeof(EXPECTED) / sizeof(string);
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
@@ -812,6 +826,8 @@
const size_t N_EXPECTED = sizeof(EXPECTED) / sizeof(string);
+ LoggerFactory::getInstance().flushBackend();
+
const string buffer = m_buffer.str();
std::vector<string> components;
diff --git a/tests/daemon/fw/topology-tester.cpp b/tests/daemon/fw/topology-tester.cpp
index 7b035eb..b1eeb6a 100644
--- a/tests/daemon/fw/topology-tester.cpp
+++ b/tests/daemon/fw/topology-tester.cpp
@@ -129,7 +129,7 @@
std::initializer_list<TopologyNode> forwarders,
bool forceMultiAccessFace)
{
- auto link = make_shared<TopologyLink>(delay);
+ auto link = std::make_shared<TopologyLink>(delay);
FaceUri remoteUri("topology://link/" + label);
ndn::nfd::LinkType linkType = (forceMultiAccessFace || forwarders.size() > 2) ?
ndn::nfd::LINK_TYPE_MULTI_ACCESS :
diff --git a/wscript b/wscript
index 1f1904b..5d1b35d 100644
--- a/wscript
+++ b/wscript
@@ -1,7 +1,7 @@
# -*- Mode: python; py-indent-offset: 4; indent-tabs-mode: nil; coding: utf-8; -*-
"""
-Copyright (c) 2014-2015, Regents of the University of California,
+Copyright (c) 2014-2016, Regents of the University of California,
Arizona Board of Regents,
Colorado State University,
University Pierre & Marie Curie, Sorbonne University,
@@ -101,7 +101,7 @@
conf.check_cxx(header_name='ifaddrs.h', mandatory=False)
- boost_libs = 'system chrono program_options random thread'
+ boost_libs = 'system chrono program_options random thread log log_setup'
if conf.options.with_tests:
conf.env['WITH_TESTS'] = 1
conf.define('WITH_TESTS', 1);
@@ -110,7 +110,7 @@
if conf.options.with_other_tests:
conf.env['WITH_OTHER_TESTS'] = 1
- conf.check_boost(lib=boost_libs)
+ conf.check_boost(lib=boost_libs, mt=True)
if conf.env.BOOST_VERSION_NUMBER < 105400:
Logs.error("Minimum required boost version is 1.54.0")
Logs.error("Please upgrade your distribution or install custom boost libraries" +