diff --git a/c11logtest/c11logtest/c11logtest.vcxproj b/c11logtest/c11logtest/c11logtest.vcxproj index eb84e605..a702e84b 100644 --- a/c11logtest/c11logtest/c11logtest.vcxproj +++ b/c11logtest/c11logtest/c11logtest.vcxproj @@ -57,6 +57,7 @@ Console true + true @@ -88,6 +89,7 @@ + @@ -96,6 +98,7 @@ + diff --git a/c11logtest/c11logtest/c11logtest.vcxproj.filters b/c11logtest/c11logtest/c11logtest.vcxproj.filters index 5110b219..959b0c9d 100644 --- a/c11logtest/c11logtest/c11logtest.vcxproj.filters +++ b/c11logtest/c11logtest/c11logtest.vcxproj.filters @@ -90,6 +90,12 @@ Header Files\c11log + + Header Files\c11log\sinks + + + Header Files\c11log\details + diff --git a/example/bench.cpp b/example/bench.cpp index 615968f6..ec18ee1a 100644 --- a/example/bench.cpp +++ b/example/bench.cpp @@ -2,6 +2,7 @@ // #include #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(new formatters::pattern_formatter(pattern)); - logger cout_logger("example", std::make_shared()); + logger cout_logger("bench", std::make_shared() , std::move(formatter1)); cout_logger.info() << "Hello logger"; auto nullsink = std::make_shared>(); - - - logger my_logger("my_logger", nullsink); - + auto formatter2 = std::unique_ptr(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; diff --git a/example/example.cpp b/example/example.cpp index 23b385b1..6dc6e384 100644 --- a/example/example.cpp +++ b/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(); auto sink2 = std::make_shared("rotating", "txt"); c11log::logger combined("combined", { sink1, sink2 }); - + return 0; } diff --git a/include/c11log/details/fast_oss.h b/include/c11log/details/fast_oss.h index dd204576..2b67159e 100644 --- a/include/c11log/details/fast_oss.h +++ b/include/c11log/details/fast_oss.h @@ -5,8 +5,10 @@ #include #include +#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_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; }; diff --git a/include/c11log/details/line_logger.h b/include/c11log/details/line_logger.h index 64b4035e..86f04c82 100644 --- a/include/c11log/details/line_logger.h +++ b/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); } diff --git a/include/c11log/details/log_msg.h b/include/c11log/details/log_msg.h index b8920a0f..58f2cd38 100644 --- a/include/c11log/details/log_msg.h +++ b/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; + }; } } diff --git a/include/c11log/formatter.h b/include/c11log/formatter.h index ae77201a..65e5b028 100644 --- a/include/c11log/formatter.h +++ b/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 << ']'; } + diff --git a/include/c11log/pattern_formatter.h b/include/c11log/pattern_formatter.h new file mode 100644 index 00000000..08917ab5 --- /dev/null +++ b/include/c11log/pattern_formatter.h @@ -0,0 +1,285 @@ +#pragma once + +#include +#include +#include +#include + +#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(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> _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(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(new details::name_appender())); + break; + // message log level + case 'l': + _appenders.push_back(std::unique_ptr(new details::level_appender())); + break; + // message text + case('t') : + _appenders.push_back(std::unique_ptr(new details::t_appender())); + break; + // year + case('Y') : + _appenders.push_back(std::unique_ptr(new details::Y_appender())); + break; + // year 2 digits + case('y') : + _appenders.push_back(std::unique_ptr(new details::y_appender())); + break; + // month + case('m') : + // minute + _appenders.push_back(std::unique_ptr(new details::m_appender())); + break; + // day in month + case('d') : + _appenders.push_back(std::unique_ptr(new details::d_appender())); + break; + // hour (24) + case('H') : + _appenders.push_back(std::unique_ptr(new details::H_appender())); + break; + // hour (12) + case('I') : + _appenders.push_back(std::unique_ptr(new details::I_appender())); + break; + // minutes + case('M') : + _appenders.push_back(std::unique_ptr(new details::M_appender())); + break; + // seconds + case('S') : + _appenders.push_back(std::unique_ptr(new details::S_appender())); + break; + // milliseconds part + case('e'): + _appenders.push_back(std::unique_ptr(new details::e_appender())); + break; + // % sign + case('%') : + _appenders.push_back(std::unique_ptr(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