upd: [imp] optimized log implementation

include/libimp/log.h

@@ -12,7 +12,6 @@
 #include <exception>
 
 #include "fmt/format.h"
-#include "fmt/chrono.h"
 
 #include "libimp/def.h"
 #include "libimp/detect_plat.h"
@@ -22,11 +21,6 @@
 LIBIMP_NAMESPACE_BEG_
 namespace log {
 
-template <typename Fmt, typename... A>
-std::string fmt(Fmt &&ft, A &&... args) {
-  return ::fmt::format(std::forward<Fmt>(ft), std::forward<A>(args)...);
-}
-
 enum class level : std::int32_t {
   trace,
   debug,
@@ -36,47 +30,79 @@ enum class level : std::int32_t {
   failed,
 };
 
+struct context {
+  log::level level;
+  std::chrono::system_clock::time_point tp;
+  char const *func;
+  std::string text;
+};
+
+LIBIMP_EXPORT std::string to_string(context &&) noexcept;
+
 } // namespace log
 
 namespace detail_log {
 
+enum out_type : unsigned {
+  out_none    = 0x0,
+  out_string  = 0x1,
+  out_context = 0x2,
+};
+
 template <typename T>
 class has_fn_output {
-  static std::false_type check(...);
+  static std::integral_constant<out_type, out_none> check(...);
+
   template <typename U>
-  static auto check(U *u) -> decltype(u->output(log::level::trace, std::declval<std::string>()), std::true_type{});
+  static auto check(U *u)
+    -> decltype(u->output(log::level::trace, std::declval<std::string>()), 
+                std::integral_constant<out_type, out_string>{});
+
+  template <typename U>
+  static auto check(U *u)
+    -> decltype(u->output(log::level::trace, std::declval<log::context>()), 
+                std::integral_constant<out_type, out_context>{});
 
 public:
   using type = decltype(check(static_cast<T *>(nullptr)));
 };
 
 template <typename T>
-constexpr bool has_fn_output_v = has_fn_output<T>::type::value;
+constexpr out_type has_fn_output_v = has_fn_output<T>::type::value;
 
 struct vtable_t {
-  void (*output)(void *, log::level, std::string &&);
+  void (*output)(void *, log::context &&);
 };
 
 template <typename T>
 class traits {
   template <typename U>
   static auto make_fn_output() noexcept
-    -> std::enable_if_t<has_fn_output_v<U>, void (*)(void *, log::level, std::string &&)> {
+    -> std::enable_if_t<(has_fn_output_v<U> == out_none), decltype(vtable_t{}.output)> {
-    return [](void *p, log::level l, std::string &&s) {
+    return [](void *, log::context &&) {};
-      static_cast<U *>(p)->output(l, std::move(s));
-    };
   }
+
   template <typename U>
   static auto make_fn_output() noexcept
-    -> std::enable_if_t<!has_fn_output_v<U>, void (*)(void *, log::level, std::string &&)> {
+    -> std::enable_if_t<(has_fn_output_v<U> == out_string), decltype(vtable_t{}.output)> {
-    return [](void *, log::level, std::string &&) {};
+    return [](void *p, log::context &&ctx) {
+      auto lev = ctx.level;
+      auto str = to_string(std::move(ctx));
+      static_cast<U *>(p)->output(lev, std::move(str));
+    };
+  }
+
+  template <typename U>
+  static auto make_fn_output() noexcept
+    -> std::enable_if_t<(has_fn_output_v<U> == out_context), decltype(vtable_t{}.output)> {
+    return [](void *p, log::context &&ctx) {
+      static_cast<U *>(p)->output(std::move(ctx));
+    };
   }
 
 public:
   static auto make_vtable() noexcept {
-    static vtable_t vt {
+    static vtable_t vt { make_fn_output<T>() };
-      make_fn_output<T>(),
-    };
     return &vt;
   }
 };
@@ -93,15 +119,14 @@ public:
   printer() noexcept = default;
 
   template <typename T, 
-            /// @brief generic constructor may shadow the default copy constructor
+            /// @remark generic constructor may shadow the default copy constructor
             typename = std::enable_if_t<!std::is_same<printer, T>::value>>
   printer(T &p) noexcept
     : objp_  (static_cast<void *>(&p))
     , vtable_(detail_log::traits<T>::make_vtable()) {}
 
   explicit operator bool() const noexcept;
-
+  void output(context) noexcept;
-  void output(log::level, std::string &&) noexcept;
 };
 
 class LIBIMP_EXPORT std_t {
@@ -121,18 +146,19 @@ class gripper {
     if (!printer_ || (enum_cast(l) < enum_cast(level_limit_))) {
       return *this;
     }
-    constexpr static char types[] = {
+    context ctx;
-      'T', 'D', 'I', 'W', 'E', 'F'
+    LIBIMP_TRY {
+      ctx = {
+        l, std::chrono::system_clock::now(), func_,
+        ::fmt::format(std::forward<Fmt>(ft), std::forward<A>(args)...),
       };
-    try {
+    } LIBIMP_CATCH(std::exception const &e) {
-      auto tp = std::chrono::system_clock::now();
-      auto ms = std::chrono::time_point_cast<std::chrono::milliseconds>(tp).time_since_epoch().count() % 1000;
-      auto px = fmt("[{}][{:%Y-%m-%d %H:%M:%S}.{:03}][{}] ", types[enum_cast(l)], tp, ms, func_);
-      printer_.output(l, std::move(px += fmt(std::forward<Fmt>(ft), std::forward<A>(args)...)));
-    } catch (std::exception const &e) {
       /// @remark [TBD] std::string constructor may throw an exception
-      printer_.output(level::failed, e.what());
+      ctx = {
+        level::failed, std::chrono::system_clock::now(), func_, e.what(),
+      };
     }
+    printer_.output(std::move(ctx));
     return *this;
   }
 

src/libimp/log.cpp

@@ -2,18 +2,33 @@
 #include <utility>
 #include <cstdio>
 
+#include "fmt/chrono.h"
+
 #include "libimp/log.h"
 
 LIBIMP_NAMESPACE_BEG_
 namespace log {
 
+std::string to_string(context &&ctx) noexcept {
+  constexpr static char types[] = {
+    'T', 'D', 'I', 'W', 'E', 'F',
+  };
+  LIBIMP_TRY {
+    auto ms = std::chrono::time_point_cast<std::chrono::milliseconds>(ctx.tp).time_since_epoch().count() % 1000;
+    return ::fmt::format("[{}][{:%Y-%m-%d %H:%M:%S}.{:03}][{}] {}", types[enum_cast(ctx.level)], ctx.tp, ms, ctx.func, ctx.text);
+  } LIBIMP_CATCH(std::exception const &e) {
+    /// @remark [TBD] std::string constructor may throw an exception
+    return e.what();
+  }
+}
+
 printer::operator bool() const noexcept {
   return (objp_ != nullptr) && (vtable_ != nullptr);
 }
 
-void printer::output(log::level l, std::string &&s) noexcept {
+void printer::output(context ctx) noexcept {
   if (!*this) return;
-  vtable_->output(objp_, l, std::move(s));
+  vtable_->output(objp_, std::move(ctx));
 }
 
 std_t std_out;

test/imp/test_imp_log.cpp

@@ -1,21 +1,23 @@
 
+#include <iostream>
+
 #include "gtest/gtest.h"
 
 #include "libimp/log.h"
 
 TEST(log, detail) {
-  EXPECT_FALSE(imp::detail_log::has_fn_output_v<int>);
+  EXPECT_EQ(imp::detail_log::has_fn_output_v<int>, imp::detail_log::out_none);
 
   struct foo {
     int info(std::string);
   };
-  EXPECT_FALSE(imp::detail_log::has_fn_output_v<foo>);
+  EXPECT_EQ(imp::detail_log::has_fn_output_v<foo>, imp::detail_log::out_none);
 
   struct bar {
     int info(char const *);
     void output(imp::log::level, std::string &&);
   };
-  EXPECT_TRUE(imp::detail_log::has_fn_output_v<bar>);
+  EXPECT_EQ(imp::detail_log::has_fn_output_v<bar>, imp::detail_log::out_string);
 
   struct str {
     str(std::string const &);
@@ -23,25 +25,27 @@ TEST(log, detail) {
   struct foo_bar {
     void output(imp::log::level, str);
   };
-  EXPECT_TRUE(imp::detail_log::has_fn_output_v<foo_bar>);
+  EXPECT_EQ(imp::detail_log::has_fn_output_v<foo_bar>, imp::detail_log::out_string);
 
   auto vt_int = imp::detail_log::traits<int>::make_vtable();
   EXPECT_NE(vt_int, nullptr);
-  vt_int->output(nullptr, imp::log::level::debug, "123");
+  EXPECT_NO_THROW(vt_int->output(nullptr, imp::log::context{}));
 
   struct log {
     std::string what;
     void output(imp::log::level l, std::string &&s) {
-      if (l == imp::log::level::error) what += s;
+      if (l == imp::log::level::error) what += s + '\n';
     }
   } ll;
   auto vt_log = imp::detail_log::traits<log>::make_vtable();
   EXPECT_NE(vt_log, nullptr);
-  vt_log->output(&ll, imp::log::level::info , "123");
+
-  vt_log->output(&ll, imp::log::level::error, "321");
+  vt_log->output(&ll, imp::log::context{imp::log::level::info , std::chrono::system_clock::now(), __func__, "123"});
-  vt_log->output(&ll, imp::log::level::info , "654");
+  vt_log->output(&ll, imp::log::context{imp::log::level::error, std::chrono::system_clock::now(), __func__, "321"});
-  vt_log->output(&ll, imp::log::level::error, "456");
+  vt_log->output(&ll, imp::log::context{imp::log::level::info , std::chrono::system_clock::now(), __func__, "654"});
-  EXPECT_EQ(ll.what, "321456");
+  vt_log->output(&ll, imp::log::context{imp::log::level::error, std::chrono::system_clock::now(), __func__, "456"});
+  std::cout << ll.what << "\n";
+  SUCCEED();
 }
 
 TEST(log, log_printer) {
@@ -50,21 +54,22 @@ TEST(log, log_printer) {
     std::string e;
 
     void output(imp::log::level l, std::string &&s) {
-      if (l == imp::log::level::error) e += s;
+      if (l == imp::log::level::error) e += s + "\n";
-      else if (l == imp::log::level::info) i += s;
+      else if (l == imp::log::level::info) i += s + "\n";
     }
   } ll;
 
   imp::log::printer pt = ll;
-  pt.output(imp::log::level::info , "hello ");
+  pt.output({imp::log::level::info , std::chrono::system_clock::now(), __func__, "hello "});
-  pt.output(imp::log::level::error, "failed: ");
+  pt.output({imp::log::level::error, std::chrono::system_clock::now(), __func__, "failed: "});
-  pt.output(imp::log::level::info , "log-pt");
+  pt.output({imp::log::level::info , std::chrono::system_clock::now(), __func__, "log-pt"});
-  pt.output(imp::log::level::error, "whatever");
+  pt.output({imp::log::level::error, std::chrono::system_clock::now(), __func__, "whatever"});
-  EXPECT_EQ(ll.i, "hello log-pt");
+  std::cout << ll.i << "\n";
-  EXPECT_EQ(ll.e, "failed: whatever");
+  std::cout << ll.e << "\n";
 
   imp::log::printer ps = imp::log::std_out;
-  ps.output(imp::log::level::info, "hello world\n");
+  ps.output({imp::log::level::info, std::chrono::system_clock::now(), __func__, "hello world"});
+  SUCCEED();
 }
 
 TEST(log, gripper) {
@@ -76,4 +81,5 @@ TEST(log, gripper) {
     LIBIMP_LOG_();
     log.info("hello 2");
   }
+  SUCCEED();
 }