Merge branch 'logs-refactoring' into openssl

Config.cpp

@@ -110,7 +110,7 @@ namespace config {
       ("conf",      value<std::string>()->default_value(""),     "Path to main i2pd config file (default: try ~/.i2pd/i2p.conf or /var/lib/i2pd/i2p.conf)")
       ("tunconf",   value<std::string>()->default_value(""),     "Path to config with tunnels list and options (default: try ~/.i2pd/tunnels.cfg or /var/lib/i2pd/tunnels.cfg)")
       ("pidfile",   value<std::string>()->default_value(""),     "Path to pidfile (default: ~/i2pd/i2pd.pid or /var/lib/i2pd/i2pd.pid)")
-      ("log",       value<std::string>()->default_value(""),     "Logs destination: stdout, file (stdout if not set, file - otherwise, for compatibility)")
+      ("log",       value<std::string>()->default_value(""),     "Logs destination: stdout, file, syslog (stdout if not set)")
       ("logfile",   value<std::string>()->default_value(""),     "Path to logfile (stdout if not set, autodetect if daemon)")
       ("loglevel",  value<std::string>()->default_value("info"), "Set the minimal level of log messages (debug, info, warn, error)")
 	  ("family",    value<std::string>()->default_value(""),     "Specify a family, router belongs to")

Daemon.cpp

@@ -79,17 +79,38 @@ namespace i2p
 			i2p::config::ParseConfig(config);
 			i2p::config::Finalize();
 
-			i2p::crypto::InitCrypto ();
-			i2p::context.Init ();
-
 			i2p::config::GetOption("daemon", isDaemon);
 
-			// TODO: move log init here
+			std::string logs     = ""; i2p::config::GetOption("log",      logs);
+			std::string logfile  = ""; i2p::config::GetOption("logfile",  logfile);
+			std::string loglevel = ""; i2p::config::GetOption("loglevel", loglevel);
+
+			/* setup logging */
+			if (isDaemon && (logs == "" || logs == "stdout"))
+				logs = "file";
+
+			i2p::log::Logger().SetLogLevel(loglevel);
+			if (logs == "file") {
+				if (logfile == "")
+					logfile = i2p::fs::DataDirPath("i2pd.log");
+				LogPrint(eLogInfo, "Log: will send messages to ", logfile);
+				i2p::log::Logger().SendTo (logfile);
+#ifndef _WIN32
+			} else if (logs == "syslog") {
+				LogPrint(eLogInfo, "Log: will send messages to syslog");
+				i2p::log::Logger().SendTo("i2pd", LOG_DAEMON);
+#endif
+			} else {
+				// use stdout -- default
+			}
 
 			LogPrint(eLogInfo,  "i2pd v", VERSION, " starting");
 			LogPrint(eLogDebug, "FS: main config file: ", config);
 			LogPrint(eLogDebug, "FS: data directory: ", datadir);
 
+			i2p::crypto::InitCrypto ();
+			i2p::context.Init ();
+
 			uint16_t port; i2p::config::GetOption("port", port);
 			if (!i2p::config::IsDefault("port"))
 			{	
@@ -152,26 +173,6 @@ namespace i2p
 			
 		bool Daemon_Singleton::start()
 		{
-			std::string logs     = ""; i2p::config::GetOption("log",      logs);
-			std::string logfile  = ""; i2p::config::GetOption("logfile",  logfile);
-			std::string loglevel = ""; i2p::config::GetOption("loglevel", loglevel);
-
-			if (isDaemon && (logs == "" || logs == "stdout"))
-				logs = "file";
-
-			if (logs == "syslog") {
-				// use syslog only no stdout
-				StartSyslog();
-			} else if (logs == "file") {
-				if (logfile == "")
-					logfile = i2p::fs::DataDirPath("i2pd.log");
-				StartLog (logfile);
-			} else {
-				// use stdout
-				StartLog ("");
-			}
-			SetLogLevel(loglevel);
-			
 			bool http; i2p::config::GetOption("http.enabled", http);
 			if (http) {
 				std::string httpAddr; i2p::config::GetOption("http.address", httpAddr);
@@ -236,7 +237,6 @@ namespace i2p
 				d.m_I2PControlService = nullptr;
 			}	
 			i2p::crypto::TerminateCrypto ();
-			StopLog ();
 
 			return true;
 		}

DaemonLinux.cpp

@@ -19,7 +19,7 @@ void handle_signal(int sig)
 	{
 	case SIGHUP:
 		LogPrint(eLogInfo, "Daemon: Got SIGHUP, reopening log...");
-		ReopenLogFile ();
+		i2p::log::Logger().Reopen ();
 	break;
 	case SIGABRT:
 	case SIGTERM:

DaemonWin32.cpp

@@ -75,7 +75,7 @@ namespace i2p
             i2p::config::SetOption("log", std::string ("file"));
 #endif
 			bool ret = Daemon_Singleton::start();
-			if (ret && IsLogToFile ())
+			if (ret && i2p::log::Logger().GetLogType() == eLogFile)
 			{
 				// TODO: find out where this garbage to console comes from
 				SetStdHandle(STD_OUTPUT_HANDLE, INVALID_HANDLE_VALUE);

Log.cpp

@@ -1,133 +1,160 @@
-#include <boost/date_time/posix_time/posix_time.hpp>
+/*
+* Copyright (c) 2013-2016, The PurpleI2P Project
+*
+* This file is part of Purple i2pd project and licensed under BSD3
+*
+* See full license text in LICENSE file at top of project tree
+*/
+
 #include "Log.h"
 
-Log * g_Log = nullptr;
+namespace i2p {
-
+namespace log {
-static const char * g_LogLevelStr[eNumLogLevels] =
+	Log logger;
-{
+	/**
-	"error", // eLogError
+	 * @enum Maps our loglevel to their symbolic name
-	"warn",  // eLogWarning
+	 */
-	"info",  // eLogInfo
+	static const char * g_LogLevelStr[eNumLogLevels] =
-	"debug"	 // eLogDebug 
-};
-#ifndef _WIN32
-/** convert LogLevel enum to syslog priority level */
-static int ToSyslogLevel(LogLevel lvl)
-{
-  switch (lvl) {
-  case eLogError:
-    return LOG_ERR;
-  case eLogWarning:
-    return LOG_WARNING;
-  case eLogInfo:
-    return LOG_INFO;
-  case eLogDebug:
-    return LOG_DEBUG;
-  default:
-    // WTF? invalid log level?
-    return LOG_CRIT;
-  }
-}
-#endif
-
-void LogMsg::Process()
-{
-#ifndef _WIN32
-  if (log && log->SyslogEnabled()) {
-    // only log to syslog
-    syslog(ToSyslogLevel(level), "%s", s.str().c_str());
-    return;
-  }
-#endif
-	auto stream = log ? log->GetLogStream () : nullptr;
-	auto& output = stream ? *stream : std::cout;	
-	if (log)	
-		output << log->GetTimestamp ();
-	else
-		output << boost::posix_time::second_clock::local_time().time_of_day ();
-	output << "/" << g_LogLevelStr[level] << " - ";
-	output << s.str();
-}
-
-const std::string& Log::GetTimestamp ()
-{
-#if (__GNUC__ == 4) && (__GNUC_MINOR__ <= 6) && !defined(__clang__)	
-	auto ts = std::chrono::monotonic_clock::now ();	
-#else	
-	auto ts = std::chrono::steady_clock::now ();	
-#endif	
-	if (ts > m_LastTimestampUpdate + std::chrono::milliseconds (500)) // 0.5 second
 	{
-		m_LastTimestampUpdate = ts;
+		"error", // eLogError
-		m_Timestamp = boost::posix_time::to_simple_string (boost::posix_time::second_clock::local_time().time_of_day ());
+		"warn",  // eLogWarn
-	}		
+		"info",  // eLogInfo
-	return m_Timestamp;
+		"debug"	 // eLogDebug
-}
+	};
 
-void Log::Flush ()
-{
-	if (m_LogStream)
-		m_LogStream->flush();
-}
-
-void Log::SetLogFile (const std::string& fullFilePath, bool truncate)
-{
-	m_FullFilePath = fullFilePath;	
-	auto mode = std::ofstream::out | std::ofstream::binary;
-	mode |= truncate ? std::ofstream::trunc : std::ofstream::app;
-	auto logFile = std::make_shared<std::ofstream> (fullFilePath, mode);
-	if (logFile->is_open ())
-	{
-		SetLogStream (logFile);
-		LogPrint(eLogInfo, "Log: will send messages to ",  fullFilePath);
-	}	
-}
-
-void Log::ReopenLogFile ()
-{
-	if (m_FullFilePath.length () > 0)
-	{
-		SetLogFile (m_FullFilePath, false); // don't truncate
-		LogPrint(eLogInfo, "Log: file ", m_FullFilePath,  " reopen");
-	}
-}
-
-
-void Log::SetLogLevel (const std::string& level)
-{
-  if      (level == "error") { m_MinLevel = eLogError; }
-  else if (level == "warn")  { m_MinLevel = eLogWarning;  }
-  else if (level == "info")  { m_MinLevel = eLogInfo;  }
-  else if (level == "debug") { m_MinLevel = eLogDebug; }
-  else {
-		LogPrint(eLogError, "Log: Unknown loglevel: ", level);
-		return;
-  }
-  LogPrint(eLogInfo, "Log: min msg level set to ", level);
-}
-
-void Log::SetLogStream (std::shared_ptr<std::ostream> logStream)
-{
-	m_LogStream = logStream;
-}
-
-void Log::StartSyslog(const std::string & ident, const int facility)
-{
 #ifndef _WIN32
-	m_Ident = ident;
+	/**
-	openlog(m_Ident.c_str(), LOG_PID, facility);
+	 * @brief  Maps our log levels to syslog one
+	 * @return syslog priority LOG_*, as defined in syslog.h
+	 */
+	static inline int GetSyslogPrio (enum LogLevel l) {
+		int priority = LOG_DEBUG;
+		switch (l) {
+			case eLogError   : priority = LOG_ERR;     break;
+			case eLogWarning : priority = LOG_WARNING; break;
+			case eLogInfo    : priority = LOG_INFO;    break;
+			case eLogDebug   : priority = LOG_DEBUG;   break;
+			default          : priority = LOG_DEBUG;   break;
+		}
+		return priority;
+	}
 #endif
-}
 
-void Log::StopSyslog()
+	Log::Log():
-{
+	m_Destination(eLogStdout), m_MinLevel(eLogInfo),
+	m_LogStream (nullptr), m_Logfile(""), m_IsReady(false)
+	{
+	}
+
+	Log::~Log ()
+	{
+		switch (m_Destination) {
 #ifndef _WIN32
-	closelog();
+			case eLogSyslog :
-	m_Ident.clear();
+				closelog();
+				break;
 #endif
-}
+			case eLogFile:
+			case eLogStream:
+				m_LogStream->flush();
+				break;
+			default:
+				/* do nothing */
+				break;
+		}
+		Process();
+	}
 
-bool Log::SyslogEnabled()
+	void Log::SetLogLevel (const std::string& level) {
-{
+		if      (level == "error") { m_MinLevel = eLogError; }
-	return m_Ident.size() > 0;
+		else if (level == "warn")  { m_MinLevel = eLogWarning; }
-}
+		else if (level == "info")  { m_MinLevel = eLogInfo;  }
+		else if (level == "debug") { m_MinLevel = eLogDebug; }
+		else {
+			LogPrint(eLogError, "Log: unknown loglevel: ", level);
+			return;
+		}
+		LogPrint(eLogInfo, "Log: min messages level set to ", level);
+	}
+	
+	const char * Log::TimeAsString(std::time_t t) {
+		if (t != m_LastTimestamp) {
+			strftime(m_LastDateTime, sizeof(m_LastDateTime), "%H:%M:%S", localtime(&t));
+			m_LastTimestamp = t;
+		}
+		return m_LastDateTime;
+	}
+
+	/**
+	 * @note This function better to be run in separate thread due to disk i/o.
+	 * Unfortunately, with current startup process with late fork() this
+	 * will give us nothing but pain. Maybe later. See in NetDb as example.
+	 */
+	void Log::Process() {
+		std::unique_lock<std::mutex> l(m_OutputLock);
+		while (1) {
+			auto msg = m_Queue.GetNextWithTimeout (1);
+			if (!msg)
+				break;
+			switch (m_Destination) {
+#ifndef _WIN32
+				case eLogSyslog:
+					syslog(GetSyslogPrio(msg->level), "%s", msg->text.c_str());
+					break;
+#endif
+				case eLogFile:
+				case eLogStream:
+					*m_LogStream << TimeAsString(msg->timestamp) << "/" << g_LogLevelStr[msg->level] << " - " << msg->text << std::endl;
+					break;
+				default:
+					std::cout    << TimeAsString(msg->timestamp) << "/" << g_LogLevelStr[msg->level] << " - " << msg->text << std::endl;
+					break;
+			} // switch
+		} // while
+	}
+
+	void Log::Append(std::shared_ptr<i2p::log::LogMsg> & msg) {
+		m_Queue.Put(msg);
+		if (!m_IsReady)
+			return;
+		Process();
+	}
+
+	void Log::SendTo (const std::string& path) {
+		auto flags = std::ofstream::out | std::ofstream::app;
+		auto os = std::make_shared<std::ofstream> (path, flags);
+		if (os->is_open ()) {
+			m_Logfile = path;
+			m_Destination = eLogFile;
+			m_LogStream = os;
+			m_IsReady = true;
+			return;
+		}
+		LogPrint(eLogError, "Log: can't open file ", path);
+	}
+
+	void Log::SendTo (std::shared_ptr<std::ostream> os) {
+		m_Destination = eLogStream;
+		m_IsReady = true;
+		m_LogStream = os;
+	}
+
+#ifndef _WIN32
+	void Log::SendTo(const char *name, int facility) {
+		m_Destination = eLogSyslog;
+		m_LogStream = nullptr;
+		m_IsReady = true;
+		openlog(name, LOG_CONS | LOG_PID, facility);
+	}
+#endif
+
+	void Log::Reopen() {
+		if (m_Destination == eLogFile)
+			SendTo(m_Logfile);
+	}
+
+	Log & Logger() {
+		return logger;
+	}
+} // log
+} // i2p

Log.h

@@ -1,11 +1,19 @@
+/*
+* Copyright (c) 2013-2016, The PurpleI2P Project
+*
+* This file is part of Purple i2pd project and licensed under BSD3
+*
+* See full license text in LICENSE file at top of project tree
+*/
+
 #ifndef LOG_H__
 #define LOG_H__
 
+#include <ctime>
 #include <string>
 #include <iostream>
-#include <sstream>
 #include <fstream>
-#include <functional>
+#include <sstream>
 #include <chrono>
 #include <memory>
 #include "Queue.h"
@@ -23,129 +31,126 @@ enum LogLevel
 	eNumLogLevels
 };
 
-class Log;
+enum LogType {
-struct LogMsg
+	eLogStdout = 0,
-{
+	eLogStream,
-	std::stringstream s;
+	eLogFile,
-	Log * log;	
-	LogLevel level;
-
-	LogMsg (Log * l = nullptr, LogLevel lv = eLogInfo): log (l), level (lv) {};
-	
-	void Process();
-};
-
-class Log: public i2p::util::MsgQueue<LogMsg>
-{
-	public:
-
-		Log () { SetOnEmpty (std::bind (&Log::Flush, this)); };
-		~Log () {};
-
-		void SetLogFile (const std::string& fullFilePath, bool truncate = true);
-		void ReopenLogFile ();
-		void SetLogLevel (const std::string& level);
-		void SetLogStream (std::shared_ptr<std::ostream> logStream);
-		std::shared_ptr<std::ostream> GetLogStream () const { return m_LogStream; };	
-		const std::string& GetTimestamp ();
-		LogLevel GetLogLevel () { return m_MinLevel; };
-	 	const std::string& GetFullFilePath () const { return m_FullFilePath; };
-		/** start logging to syslog */
-		void StartSyslog(const std::string & ident, const int facility);
-		/** stop logging to syslog */
-		void StopSyslog();
-		/** are we logging to syslog right now? */
-		bool SyslogEnabled();
-	private:
-
-		void Flush ();
-
-	private:
-
-		std::string m_FullFilePath; // empty if stream
-		std::shared_ptr<std::ostream> m_LogStream;
-		enum LogLevel m_MinLevel;
-		std::string m_Timestamp;
-#if (__GNUC__ == 4) && (__GNUC_MINOR__ <= 6) && !defined(__clang__) // gcc 4.6
-		std::chrono::monotonic_clock::time_point m_LastTimestampUpdate;
-#else		
-		std::chrono::steady_clock::time_point m_LastTimestampUpdate;	
-#endif
-		std::string m_Ident;
-};
-
-extern Log * g_Log;
-
-inline void StartLog (const std::string& fullFilePath)
-{
-	if (!g_Log)
-	{	
-		auto log = new Log ();
-		if (fullFilePath.length () > 0)
-			log->SetLogFile (fullFilePath);
-		g_Log = log;
-	}	
-}
-
-inline void StartLog (std::shared_ptr<std::ostream> s)
-{
-	if (!g_Log)
-	{	
-		auto log = new Log ();
-		if (s)
-			log->SetLogStream (s);
-		g_Log = log;
-	}	
-}
-
-inline void StopLog ()
-{
-	if (g_Log)
-	{
-		auto log = g_Log;
-		g_Log = nullptr;
-		log->Stop ();
-		delete log;
-	}		
-}
-
-inline void SetLogLevel (const std::string& level)
-{
-	if (g_Log)	
-		g_Log->SetLogLevel(level);
-}
-
-inline void ReopenLogFile ()
-{
-	if (g_Log)	
-		g_Log->ReopenLogFile ();
-}
-
-inline bool IsLogToFile ()
-{
-	return g_Log ? !g_Log->GetFullFilePath ().empty () : false;
-}	
-
-inline void StartSyslog()
-{
-	StartLog("");
 #ifndef _WIN32
-	g_Log->StartSyslog("i2pd", LOG_USER);
+	eLogSyslog,
 #endif
-}
+};
 
-inline void StopSyslog()
+namespace i2p {
-{
+namespace log {
-	if(g_Log)
+	struct LogMsg; /* forward declaration */
-		g_Log->StopSyslog();
-}
 
+	class Log
+	{
+		private:
+
+			enum LogType  m_Destination;
+			enum LogLevel m_MinLevel;
+			std::shared_ptr<std::ostream> m_LogStream;
+			std::string m_Logfile;
+			std::time_t m_LastTimestamp;
+			char m_LastDateTime[64];
+			i2p::util::Queue<std::shared_ptr<LogMsg> > m_Queue;
+			volatile bool m_IsReady;
+			mutable std::mutex m_OutputLock;
+
+		private:
+
+			/** prevent making copies */
+			Log (const Log &);
+			const Log& operator=(const Log&);
+
+			/**
+			 * @brief process stored messages in queue
+			 */
+			void Process ();
+
+			/**
+			 * @brief Makes formatted string from unix timestamp
+			 * @param ts  Second since epoch
+			 *
+			 * This function internally caches the result for last provided value
+			 */
+			const char * TimeAsString(std::time_t ts);
+
+		public:
+
+			Log ();
+			~Log ();
+
+			LogType  GetLogType  () { return m_Destination; };
+			LogLevel GetLogLevel () { return m_MinLevel; };
+
+			/**
+			 * @brief  Sets minimal alloed level for log messages
+			 * @param  level  String with wanted minimal msg level
+			 */
+			void     SetLogLevel (const std::string& level);
+
+			/**
+			 * @brief Sets log destination to logfile
+			 * @param path  Path to logfile
+			 */
+			void SendTo (const std::string &path);
+
+			/**
+			 * @brief Sets log destination to given output stream
+			 * @param os  Output stream
+			 */
+			void SendTo (std::shared_ptr<std::ostream> s);
+
+	#ifndef _WIN32
+			/**
+			 * @brief Sets log destination to syslog
+			 * @param name     Wanted program name
+			 * @param facility Wanted log category
+			 */
+			void SendTo (const char *name, int facility);
+	#endif
+
+			/**
+			 * @brief  Format log message and write to output stream/syslog
+			 * @param  msg  Pointer to processed message
+			 */
+			void Append(std::shared_ptr<i2p::log::LogMsg> &);
+
+			/** @brief  Flushes the output log stream */
+			void Flush();
+
+			/** @brief  Reopen log file */
+			void Reopen();
+	};
+
+	/**
+	 * @struct Log message container
+	 *
+	 * We creating it somewhere with LogPrint(),
+	 * then put in MsgQueue for later processing.
+	 */
+	struct LogMsg {
+		std::time_t timestamp;
+		std::string text; /**< message text as single string */
+		LogLevel level;   /**< message level */
+
+		LogMsg (LogLevel lvl, std::time_t ts, const std::string & txt): timestamp(ts), text(txt), level(lvl) {};
+	};
+
+	Log & Logger();
+} // log
+} // i2p
+
+/** internal usage only -- folding args array to single string */
 template<typename TValue>
 void LogPrint (std::stringstream& s, TValue arg)
 {
 	s << arg;
 }
 
+/** internal usage only -- folding args array to single string */
 template<typename TValue, typename... TArgs>
 void LogPrint (std::stringstream& s, TValue arg, TArgs... args)
 {
@@ -153,20 +158,24 @@ void LogPrint (std::stringstream& s, TValue arg, TArgs... args)
 	LogPrint (s, args...);
 }
 
+/**
+ * @brief Create log message and send it to queue
+ * @param level Message level (eLogError, eLogInfo, ...)
+ * @param args Array of message parts
+ */
 template<typename... TArgs>
 void LogPrint (LogLevel level, TArgs... args)
 {
-	if (g_Log && level > g_Log->GetLogLevel ())
+	i2p::log::Log &log = i2p::log::Logger();
+	if (level > log.GetLogLevel ())
 		return;
-	LogMsg * msg = new LogMsg (g_Log, level);
+
-	LogPrint (msg->s, args...);
+	// fold message to single string
-	msg->s << std::endl;
+	std::stringstream ss("");
-	if (g_Log) {
+	LogPrint (ss, args ...);
-		g_Log->Put (msg);
+
-	} else {
+	auto msg = std::make_shared<i2p::log::LogMsg>(level, std::time(nullptr), ss.str());
-		msg->Process ();
+	log.Append(msg);
-		delete msg;
-	}
 }
 
-#endif
+#endif // LOG_H__

Queue.h

@@ -117,52 +117,6 @@ namespace util
 			std::mutex m_QueueMutex;
 			std::condition_variable m_NonEmpty;
 	};	
-
-	template<class Msg>
-	class MsgQueue: public Queue<Msg *>
-	{
-		public:
-
-			typedef std::function<void()> OnEmpty;
-
-			MsgQueue (): m_IsRunning (true), m_Thread (std::bind (&MsgQueue<Msg>::Run, this))  {};
-			~MsgQueue () { Stop (); };
-			void Stop()
-			{
-				if (m_IsRunning)
-				{
-					m_IsRunning = false;
-					Queue<Msg *>::WakeUp ();					
-					m_Thread.join();
-				}
-			}
-
-			void SetOnEmpty (OnEmpty const & e) { m_OnEmpty = e; };
-
-		private:
-
-			void Run ()
-			{
-				while (m_IsRunning)
-				{
-					while (auto msg = Queue<Msg *>::Get ())
-					{
-						msg->Process ();
-						delete msg;
-					}
-					if (m_OnEmpty != nullptr)
-						m_OnEmpty ();
-					if (m_IsRunning)
-						Queue<Msg *>::Wait ();
-				}	
-			}	
-			
-		private:
-			
-			volatile bool m_IsRunning;
-			OnEmpty m_OnEmpty;
-			std::thread m_Thread;	
-	};	
 }		
 }	
 

api.cpp

@@ -40,9 +40,9 @@ namespace api
 	void StartI2P (std::shared_ptr<std::ostream> logStream)
 	{
 		if (logStream)
-			StartLog (logStream);
+			i2p::log::Logger().SendTo (logStream);
 		else
-			StartLog (i2p::fs::DataDirPath (i2p::fs::GetAppName () + ".log"));
+			i2p::log::Logger().SendTo (i2p::fs::DataDirPath (i2p::fs::GetAppName () + ".log"));
 		LogPrint(eLogInfo, "API: starting NetDB");
 		i2p::data::netdb.Start();
 		LogPrint(eLogInfo, "API: starting Transports");
@@ -60,7 +60,6 @@ namespace api
 		i2p::transport::transports.Stop();
 		LogPrint(eLogInfo, "API: stopping NetDB");
 		i2p::data::netdb.Stop();
-		StopLog ();
 	}
 
 	void RunPeerTest ()