From 9d9a955e9412a196717bc7e5b39eda71e8d669bc Mon Sep 17 00:00:00 2001
From: gabime <galim120@bezeqint.net>
Date: Sat, 15 Mar 2014 21:05:11 +0200
Subject: [PATCH] default format_time performance improvement

---
 example/example.cpp                  |  2 +-
 include/c11log/details/fast_oss.h    |  6 ++-
 include/c11log/details/line_logger.h |  4 +-
 include/c11log/formatter.h           | 59 +++++++++++++++++-----------
 4 files changed, 42 insertions(+), 29 deletions(-)

diff --git a/example/example.cpp b/example/example.cpp
index c8a84cd9..0ee78dd0 100644
--- a/example/example.cpp
+++ b/example/example.cpp
@@ -33,7 +33,7 @@ int main(int argc, char* argv[])
 
     auto start = system_clock::now();
 
-    const unsigned int howmany = 5000000;
+    const unsigned int howmany = 15000000;
     for(unsigned int i = 0; i < howmany ; i++)
         my_logger.info() << "Hello logger " << i;
 
diff --git a/include/c11log/details/fast_oss.h b/include/c11log/details/fast_oss.h
index ccd07eb8..9cfb7371 100644
--- a/include/c11log/details/fast_oss.h
+++ b/include/c11log/details/fast_oss.h
@@ -27,7 +27,7 @@ public:
         return _str;
     }
 
-    void clear()
+    void reset_str()
     {
         _str.clear();
     }
@@ -68,6 +68,10 @@ public:
     {
         return _dev.str_ref();
     }
+	void reset_str()
+	{
+		_dev.reset_str();
+	}
 
 private:
     str_devicebuf _dev;
diff --git a/include/c11log/details/line_logger.h b/include/c11log/details/line_logger.h
index 6a650e63..80c044c8 100644
--- a/include/c11log/details/line_logger.h
+++ b/include/c11log/details/line_logger.h
@@ -42,9 +42,7 @@ public:
         // The move ctor should only be called on start of logging line,
         // where no logging happened yet for this line so no need to copy the string from the other
         _oss(),
-        _level(other._level)
-    {
-    };
+        _level(other._level) {};
 
 
     ~line_logger()
diff --git a/include/c11log/formatter.h b/include/c11log/formatter.h
index 8132ce21..b0bf1863 100644
--- a/include/c11log/formatter.h
+++ b/include/c11log/formatter.h
@@ -6,9 +6,11 @@
 #include <sstream>
 #include <iomanip>
 #include <thread>
+#include <cstdlib>
 
 #include "common_types.h"
 #include "details/os.h"
+#include "details/fast_oss.h"
 
 namespace c11log
 {
@@ -35,7 +37,7 @@ public:
     {
         _format_time(tp, dest);
         if(!logger_name.empty())
-            dest << " [" <<  logger_name << ":" << c11log::level::to_str(level) << "] ";
+            dest << " [" <<  logger_name << ':' << c11log::level::to_str(level) << "] ";
         else
             dest << " [" << c11log::level::to_str(level) << "] ";
 
@@ -48,35 +50,44 @@ private:
 } //namespace c11log
 
 
-
+// Format datetime like this: [2014-03-14 17:15:22]
 inline void c11log::formatters::default_formatter::_format_time(const log_clock::time_point& tp, std::ostream &dest)
 {
+	using namespace c11log::details::os;
+	using namespace std::chrono;
 
 #ifdef _MSC_VER
-    __declspec(thread) static std::tm last_tm = { 0, 0, 0, 0, 0, 0, 0, 0, 0};
-    __declspec(thread) static char last_time_str[64];
+    __declspec(thread) static std::tm s_last_tm = { 0, 0, 0, 0, 0, 0, 0, 0, 0};
+    __declspec(thread) static details::fast_oss s_time_oss;
 #else
-    thread_local static std::tm last_tm = { 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0};
-    thread_local static char last_time_str[64];
+
+	thread_local static details::fast_oss s_time_oss;
+	thread_local static std::time_t s_cache_time_t = 0;
 #endif
 
-    auto tm_now = details::os::localtime(log_clock::to_time_t(tp));
-    using namespace c11log::details::os;
-    if(last_tm != tm_now)
-    {
-#ifdef _MSC_VER
-        ::sprintf_s
-#else
-        ::snprintf
-#endif
-        (last_time_str, sizeof(last_time_str), "[%d-%02d-%02d %02d:%02d:%02d]",
-         tm_now.tm_year + 1900,
-         tm_now.tm_mon + 1,
-         tm_now.tm_mday,
-         tm_now.tm_hour,
-         tm_now.tm_min,
-         tm_now.tm_sec);
-        last_tm = tm_now;
+
+	std::time_t tp_time_t = log_clock::to_time_t(tp);
+
+
+	//Cache every second
+	if(tp_time_t != s_cache_time_t)
+    {		
+		auto tm_now = details::os::localtime(tp_time_t);
+		s_time_oss.reset_str();
+		s_time_oss.fill('0');
+		s_time_oss << '[' << tm_now.tm_year + 1900 << '-';
+		s_time_oss.width(2);
+		s_time_oss << tm_now.tm_mon + 1 << '-';
+		s_time_oss.width(2);
+		s_time_oss << tm_now.tm_mday << ' ';
+		s_time_oss.width(2);
+		s_time_oss << tm_now.tm_hour << ':';
+		s_time_oss.width(2);
+		s_time_oss << tm_now.tm_min << ':';
+		s_time_oss.width(2);
+		s_time_oss << tm_now.tm_sec << ']';		
+		s_cache_time_t = tp_time_t;
     }
-    dest << last_time_str;
+	const std::string &s = s_time_oss.str_ref();
+	dest.write(s.c_str(), s.size());
 }