Added pattern formatter and updated related stuff

c11logtest/c11logtest/c11logtest.vcxproj

@@ -57,6 +57,7 @@
     <Link>
       <SubSystem>Console</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
+      <Profile>true</Profile>
     </Link>
   </ItemDefinitionGroup>
   <ItemDefinitionGroup Condition="'$(Configuration)|$(Platform)'=='Release|Win32'">
@@ -88,6 +89,7 @@
     <ClInclude Include="..\..\include\c11log\details\blocking_queue.h" />
     <ClInclude Include="..\..\include\c11log\details\fast_oss.h" />
     <ClInclude Include="..\..\include\c11log\details\flush_helper.h" />
+    <ClInclude Include="..\..\include\c11log\details\fast_istostr.h" />
     <ClInclude Include="..\..\include\c11log\details\line_logger.h" />
     <ClInclude Include="..\..\include\c11log\details\log_msg.h" />
     <ClInclude Include="..\..\include\c11log\details\null_mutex.h" />
@@ -96,6 +98,7 @@
     <ClInclude Include="..\..\include\c11log\factory.h" />
     <ClInclude Include="..\..\include\c11log\formatter.h" />
     <ClInclude Include="..\..\include\c11log\logger.h" />
+    <ClInclude Include="..\..\include\c11log\pattern_formatter.h" />
     <ClInclude Include="..\..\include\c11log\sinks\async_sink.h" />
     <ClInclude Include="..\..\include\c11log\sinks\base_sink.h" />
     <ClInclude Include="..\..\include\c11log\sinks\ostream_sink.h" />

c11logtest/c11logtest/c11logtest.vcxproj.filters

@@ -90,6 +90,12 @@
     <ClInclude Include="..\..\include\c11log\factory.h">
       <Filter>Header Files\c11log</Filter>
     </ClInclude>
+    <ClInclude Include="..\..\include\c11log\pattern_formatter.h">
+      <Filter>Header Files\c11log\sinks</Filter>
+    </ClInclude>
+    <ClInclude Include="..\..\include\c11log\details\fast_istostr.h">
+      <Filter>Header Files\c11log\details</Filter>
+    </ClInclude>
   </ItemGroup>
   <ItemGroup>
     <ClCompile Include="stdafx.cpp">

example/bench.cpp

@@ -2,6 +2,7 @@
 //
 #include <mutex>
 #include "c11log/logger.h"
+#include "c11log/pattern_formatter.h"
 #include "c11log/sinks/async_sink.h"
 #include "c11log/sinks/file_sinks.h"
 #include "c11log/sinks/stdout_sinks.h"
@@ -15,26 +16,27 @@ using namespace c11log;
 using namespace utils;
 
 
-int main2(int argc, char* argv[])
+int main(int argc, char* argv[])
 {
+    const unsigned int howmany = argc <= 1 ? 500000 : atoi(argv[1]);
 
-    const unsigned int howmany = argc <= 1 ? 1000000 : atoi(argv[1]);
+    std::string pattern = "%Y:%m:%d %H:%M:%S.%e [%n:%l] %t";
+    auto formatter1 = std::unique_ptr<formatters::formatter>(new formatters::pattern_formatter(pattern));
 
-    logger cout_logger("example", std::make_shared<sinks::stderr_sink_mt>());
+    logger cout_logger("bench",  std::make_shared<sinks::stderr_sink_mt>() , std::move(formatter1));
     cout_logger.info() << "Hello logger";
 
     auto nullsink = std::make_shared<sinks::null_sink<details::null_mutex>>();
 
 
-
-
-    logger my_logger("my_logger", nullsink);
-
+    auto formatter2 = std::unique_ptr<formatters::formatter>(new formatters::pattern_formatter(pattern));
+    logger my_logger("my_logger",  nullsink, std::move(formatter2));
+    //logger my_logger("my_logger", nullsink);
 
     auto start = system_clock::now();
     for (unsigned int i = 1; i <= howmany; ++i)
-        my_logger.info() << "Hello logger: msg #" << i << 1<<2<<3<<4<<5<<6<<7<<8<<9<<10<<11<<12<<13<<14<<15<<16<<17<<18<<19;
-    //my_logger.info("Hello logger: msg #",i,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19);
+        my_logger.info() << "Hello logger: msg #" << i;
+
 
 
     auto delta = system_clock::now() - start;

example/example.cpp

@@ -9,7 +9,7 @@
 #include "c11log/sinks/file_sinks.h"
 using namespace std;
 
-int main(int argc, char* argv[])
+int main2(int argc, char* argv[])
 {
 
     auto console = c11log::factory::stdout_logger();
@@ -30,6 +30,6 @@ int main(int argc, char* argv[])
     auto sink1= std::make_shared<c11log::sinks::stdout_sink_mt>();
     auto sink2 = std::make_shared<c11log::sinks::daily_file_sink_mt>("rotating", "txt");
     c11log::logger combined("combined", { sink1, sink2 });
-
+    return 0;
 }
 

include/c11log/details/fast_oss.h

@@ -5,8 +5,10 @@
 
 #include <ostream>
 #include <iomanip>
+#include "fast_istostr.h"
 #include "stack_buf.h"
 
+
 namespace c11log
 {
 namespace details
@@ -15,7 +17,7 @@ namespace details
 class stack_devicebuf :public std::streambuf
 {
 public:
-    static const unsigned short stack_size = 192;
+    static const unsigned short stack_size = 256;
     using stackbuf_t = stack_buf<stack_size>;
 
     stack_devicebuf() = default;
@@ -103,6 +105,29 @@ public:
         _dev.clear();
     }
 
+    // The following were added because they add significant boost to perfromance
+    void putc(char c)
+    {
+        _dev.sputc(c);
+    }
+
+
+    // put int and pad with zeroes if smalled than min_width
+    void put_int(int n, int min_width)
+    {
+        std::string s;
+        details::fast_itostr(n, s, min_width);
+        _dev.sputn(s.data(), s.size());
+        //sprintf_s(buf, "%d", n);
+        //_dev.sputn(buf, width);
+    }
+
+    void put_str(const std::string& str)
+    {
+        _dev.sputn(str.data(), str.size());
+    }
+
+
 private:
     stack_devicebuf _dev;
 };

include/c11log/details/line_logger.h

@@ -45,6 +45,7 @@ public:
         {
             _log_msg.logger_name = _callback_logger->name();
             _log_msg.time = log_clock::now();
+            _log_msg.tm_time = details::os::localtime(log_clock::to_time_t(_log_msg.time));
             _log_msg.raw = _oss.str();
             _callback_logger->_log_msg(_log_msg);
         }

include/c11log/details/log_msg.h

@@ -14,6 +14,7 @@ struct log_msg
         logger_name(),
         level(l),
         time(),
+        tm_time(),
         raw(),
         formatted() {}
 
@@ -21,6 +22,7 @@ struct log_msg
         logger_name(other.logger_name),
         level(other.level),
         time(other.time),
+        tm_time(other.tm_time),
         raw(other.raw),
         formatted(other.formatted) {}
 
@@ -35,6 +37,7 @@ struct log_msg
         swap(l.logger_name, r.logger_name);
         swap(l.level, r.level);
         swap(l.time, r.time);
+        swap(l.tm_time, r.tm_time);
         swap(l.raw, r.raw);
         swap(l.formatted, r.formatted);
     }
@@ -56,9 +59,11 @@ struct log_msg
     std::string logger_name;
     level::level_enum level;
     log_clock::time_point time;
+    std::tm tm_time;
     std::string raw;
     std::string formatted;
 
+
 };
 }
 }

include/c11log/formatter.h

@@ -33,7 +33,7 @@ public:
     void format(details::log_msg& msg) override
     {
         details::fast_oss oss;
-        _format_time(msg.time, oss);
+        _format_time(msg, oss);
 
         if(!msg.logger_name.empty())
             oss << " [" <<  msg.logger_name << ':' << c11log::level::to_str(msg.level) << "] ";
@@ -44,7 +44,7 @@ public:
         msg.formatted = oss.str();
     }
 private:
-    void _format_time(const log_clock::time_point& tp, std::ostream& output);
+    void _format_time(const details::log_msg& msg, std::ostream &output);
 
 };
 
@@ -53,44 +53,15 @@ 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 &output)
+inline void c11log::formatters::default_formatter::_format_time(const details::log_msg& msg, std::ostream &output)
 {
-    using namespace c11log::details::os;
-    using namespace std::chrono;
-
-#ifdef _WIN32 //VS2013 doesn't support yet thread_local keyword    
-    __declspec(thread) static char s_cache_timestr[128];
-    __declspec(thread) static int s_cache_timesize = 0;
-    __declspec(thread) static std::time_t s_cache_time_t = 0;
-#else
-    thread_local static char s_cache_timestr[128];
-    thread_local static int s_cache_timesize = 0;
-    thread_local static std::time_t s_cache_time_t = 0;
-#endif
-
-    //Cache every second
-    std::time_t tp_time_t = log_clock::to_time_t(tp);
-    if(tp_time_t != s_cache_time_t)
-    {
-        auto tm_now = details::os::localtime(tp_time_t);
-        std::ostringstream time_oss;
-        time_oss.fill('0');
-        time_oss << '[' << tm_now.tm_year + 1900 << '-';
-        time_oss.width(2);
-        time_oss << tm_now.tm_mon + 1 << '-';
-        time_oss.width(2);
-        time_oss << tm_now.tm_mday << ' ';
-        time_oss.width(2);
-        time_oss << tm_now.tm_hour << ':';
-        time_oss.width(2);
-        time_oss << tm_now.tm_min << ':';
-        time_oss.width(2);
-        time_oss << tm_now.tm_sec << ']';
-        //Cache the resulted string and its size
-        s_cache_time_t = tp_time_t;
-        const std::string s = time_oss.str();
-        s_cache_timesize = s.size();
-        std::memcpy(s_cache_timestr, s.c_str(), s_cache_timesize);
-    }
-    output.write(s_cache_timestr, s_cache_timesize);
+    output.fill('0');
+    output << '[' << msg.tm_time.tm_year + 1900 << '-';
+    output.width(2);
+    output << msg.tm_time.tm_mon + 1 << '-';
+    output << msg.tm_time.tm_mday << ' ';
+    output << msg.tm_time.tm_hour << ':';
+    output << msg.tm_time.tm_min << ':';
+    output << msg.tm_time.tm_sec << ']';
 }
+

include/c11log/pattern_formatter.h

+#pragma once
+
+#include <string>
+#include <chrono>
+#include <memory>
+#include <vector>
+
+#include "formatter.h"
+#include "details/log_msg.h"
+#include "details/fast_oss.h"
+
+
+namespace c11log
+{
+namespace details {
+class pattern_appender
+{
+public:
+    virtual void append(const details::log_msg& msg, details::fast_oss& oss) = 0;
+};
+
+// log name appender
+class name_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss << msg.logger_name;
+    }
+};
+
+// log level appender
+class level_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss << level::to_str(msg.level);
+    }
+};
+
+///////////////////////////////////////////////////////////////////////
+// Date time pattern appenders
+///////////////////////////////////////////////////////////////////////
+
+// year - 4 digit
+class Y_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_year+1900, 4);
+    }
+};
+
+// year - 2 digit
+class y_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_year, 2);
+    }
+};
+// month 1-12
+class m_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_mon + 1, 2);
+    }
+};
+
+
+// day of month 1-31
+class d_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_mday, 2);
+    }
+};
+
+// hours in 24 format  0-23
+class H_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_hour, 2);
+    }
+};
+
+// hours in 12 format  1-12
+class I_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int((msg.tm_time.tm_hour + 1) % 1, 2);
+    }
+};
+
+// ninutes 0-59
+class M_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_min, 2);
+    }
+};
+
+// seconds 0-59
+class S_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_int(msg.tm_time.tm_sec, 2);
+    }
+};
+
+// milliseconds
+class e_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        auto duration = msg.time.time_since_epoch();
+        auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(duration).count() % 1000;
+        oss.put_int(millis, 3);
+    }
+};
+
+
+class t_appender :public pattern_appender
+{
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.put_str(msg.raw);
+    }
+};
+
+class ch_appender :public pattern_appender
+{
+public:
+    explicit ch_appender(char ch) : _ch(ch)
+    {}
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss.putc( _ch);
+    }
+private:
+    char _ch;
+};
+
+
+class str_appender :public pattern_appender
+{
+public:
+    str_appender()
+    {}
+    void add_ch(char ch)
+    {
+        _str += ch;
+    }
+    void append(const details::log_msg& msg, details::fast_oss& oss) override
+    {
+        oss << _str;
+    }
+private:
+    std::string _str;
+};
+}
+
+
+namespace formatters
+{
+class pattern_formatter : public formatter
+{
+
+public:
+    explicit pattern_formatter(const std::string& pattern);
+    pattern_formatter(const pattern_formatter&) = delete;
+    void format(details::log_msg& msg) override;
+private:
+    const std::string _pattern;
+    std::vector<std::unique_ptr<details::pattern_appender>> _appenders;
+    void handle_flag(char flag);
+    void compile_pattern(const std::string& pattern);
+};
+}
+}
+
+
+c11log::formatters::pattern_formatter::pattern_formatter(const std::string& pattern)
+{
+    compile_pattern(pattern);
+}
+
+
+void c11log::formatters::pattern_formatter::compile_pattern(const std::string& pattern)
+{
+    auto end = pattern.end();
+    for (auto it = pattern.begin(); it != end; ++it)
+    {
+        if (*it == '%')
+        {
+            if (++it != end)
+                handle_flag(*it);
+            else
+                return;
+        }
+        else
+        {
+            // chars not following the % sign should be displayed as is
+            _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::ch_appender(*it)));
+        }
+    }
+
+}
+void c11log::formatters::pattern_formatter::handle_flag(char flag)
+{
+    switch (flag)
+    {
+    // logger name
+    case 'n':
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::name_appender()));
+        break;
+    // message log level
+    case 'l':
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::level_appender()));
+        break;
+    // message text
+    case('t') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::t_appender()));
+        break;
+    // year
+    case('Y') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::Y_appender()));
+        break;
+    // year 2 digits
+    case('y') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::y_appender()));
+        break;
+    // month
+    case('m') :
+        // minute
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::m_appender()));
+        break;
+    // day in month
+    case('d') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::d_appender()));
+        break;
+    // hour (24)
+    case('H') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::H_appender()));
+        break;
+    // hour (12)
+    case('I') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::I_appender()));
+        break;
+    // minutes
+    case('M') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::M_appender()));
+        break;
+    // seconds
+    case('S') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::S_appender()));
+        break;
+    // milliseconds part
+    case('e'):
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::e_appender()));
+        break;
+    // % sign
+    case('%') :
+        _appenders.push_back(std::unique_ptr<details::pattern_appender>(new details::ch_appender('%')));
+        break;
+    }
+
+}
+
+
+void c11log::formatters::pattern_formatter::format(details::log_msg& msg)
+{
+    details::fast_oss oss;
+    for (auto &appender : _appenders)
+    {
+        appender->append(msg, oss);
+    }
+    oss.write(details::os::eol(), details::os::eol_size());
+    msg.formatted = oss.str();
+}
\ No newline at end of file