upd: [imp] optimize log performance

This commit is contained in:
mutouyun 2023-01-01 16:26:55 +08:00
parent 013b2011a8
commit 983673266e
4 changed files with 96 additions and 103 deletions

View File

@ -39,9 +39,7 @@ public:
bool append(std::string const &str) noexcept;
};
/**
* \brief Supports custom fmt_to methods for imp::fmt.
*/
/// \brief Supports custom fmt_to methods for imp::fmt.
namespace detail {
class fmt_to_t {

View File

@ -9,13 +9,15 @@
#include <string>
#include <type_traits>
#include <chrono>
#include <exception>
#include <tuple>
#include <utility>
#include "libimp/def.h"
#include "libimp/detect_plat.h"
#include "libimp/export.h"
#include "libimp/enum_cast.h"
#include "libimp/fmt.h"
#include "libimp/generic.h"
LIBIMP_NAMESPACE_BEG_
namespace log {
@ -29,30 +31,69 @@ enum class level : std::int32_t {
failed,
};
/// \struct template <typename... T> struct context
/// \brief Logging context.
/// \tparam ...T - a log records all parameter types passed
template <typename... T>
struct context {
log::level level;
std::chrono::system_clock::time_point tp;
char const *func;
std::string text;
std::tuple<T...> params;
};
LIBIMP_EXPORT std::string to_string(context &&) noexcept;
LIBIMP_EXPORT bool to_string(fmt_context &ctx, context &&) noexcept;
/// \brief Custom defined fmt_to method for imp::fmt
template <typename T>
bool tag_invoke(decltype(::LIBIMP::fmt_to), fmt_context &ctx, context &&arg) noexcept {
return ::LIBIMP::log::to_string(ctx, std::move(arg));
namespace detail {
template <typename Tp, std::size_t... I, typename... A>
bool unfold_tuple_fmt_to(fmt_context &ctx, Tp const &tp, std::index_sequence<I...>, A &&...args) {
return fmt_to(ctx, std::forward<A>(args)..., std::get<I>(tp)...);
}
} // namespace log
} // namespace detail
namespace detail_log {
template <typename... T>
bool context_to_string(fmt_context &f_ctx, context<T...> const &l_ctx) noexcept {
constexpr static char types[] = {
'T', 'D', 'I', 'W', 'E', 'F',
};
LIBIMP_TRY {
auto ms = std::chrono::time_point_cast<std::chrono::milliseconds>(l_ctx.tp).time_since_epoch().count() % 1000;
return detail::unfold_tuple_fmt_to(f_ctx, l_ctx.params, std::index_sequence_for<T...>{},
"[", types[enum_cast(l_ctx.level)], "]"
"[", l_ctx.tp, ".", spec("03")(ms), "]"
"[", l_ctx.func, "] ");
} LIBIMP_CATCH(...) {
return false;
}
}
template <typename... T>
std::string context_to_string(context<T...> const &l_ctx) noexcept {
LIBIMP_TRY {
std::string log_txt;
fmt_context f_ctx(log_txt);
if (!context_to_string(f_ctx, l_ctx)) {
return {};
}
f_ctx.finish();
return log_txt;
} LIBIMP_CATCH(...) {
return {};
}
}
namespace detail {
/// \brief Custom defined fmt_to method for imp::fmt
template <typename... T>
bool tag_invoke(decltype(::LIBIMP::fmt_to), fmt_context &f_ctx, context<T...> const &l_ctx) noexcept {
return ::LIBIMP::log::to_string(f_ctx, l_ctx);
}
enum out_type : unsigned {
out_none = 0x0,
out_string = 0x1,
out_context = 0x2,
};
template <typename T>
@ -62,9 +103,6 @@ class has_fn_output {
template <typename U, typename = decltype(std::declval<U &>().output(log::level::trace, std::declval<std::string>()))>
static std::integral_constant<out_type, out_string> check(U *u);
template <typename U, typename = decltype(std::declval<U &>().output(std::declval<log::context>()))>
static std::integral_constant<out_type, out_context> check(U *u);
public:
using type = decltype(check(static_cast<T *>(nullptr)));
};
@ -73,7 +111,7 @@ template <typename T>
constexpr out_type has_fn_output_v = has_fn_output<T>::type::value;
struct vtable_t {
void (*output)(void *, log::context &&);
void (*output)(void *, log::level, std::string &&);
};
template <typename T>
@ -81,27 +119,17 @@ class traits {
template <typename U>
static auto make_fn_output() noexcept
-> std::enable_if_t<(has_fn_output_v<U> == out_none), decltype(vtable_t{}.output)> {
return [](void *, log::context &&) {};
return [](void *, log::level, std::string &&) {};
}
template <typename U>
static auto make_fn_output() noexcept
-> std::enable_if_t<(has_fn_output_v<U> == out_string), decltype(vtable_t{}.output)> {
return [](void *p, log::context &&ctx) {
auto lev = ctx.level;
auto str = to_string(std::move(ctx));
return [](void *p, log::level lev, std::string &&str) {
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 { make_fn_output<T>() };
@ -109,28 +137,35 @@ public:
}
};
} // namespace detail_log
} // namespace detail
namespace log {
class LIBIMP_EXPORT printer {
class printer {
void *objp_ {nullptr};
detail_log::vtable_t *vtable_ {nullptr};
detail::vtable_t *vtable_ {nullptr};
public:
printer() noexcept = default;
template <typename T,
/// \remark generic constructor may shadow the default copy constructor
typename = std::enable_if_t<!std::is_same<printer, T>::value>>
typename = is_not_match<printer, T>>
printer(T &p) noexcept
: objp_ (static_cast<void *>(&p))
, vtable_(detail_log::traits<T>::make_vtable()) {}
, vtable_(detail::traits<T>::make_vtable()) {}
explicit operator bool() const noexcept;
void output(context) noexcept;
explicit operator bool() const noexcept {
return (objp_ != nullptr) && (vtable_ != nullptr);
}
template <typename... T>
void output(context<T...> const &ctx) noexcept {
if (!*this) return;
LIBIMP_TRY {
vtable_->output(objp_, ctx.level, context_to_string(ctx));
} LIBIMP_CATCH(...) {}
}
};
/// \class class LIBIMP_EXPORT std_t
/// \brief Standard console output.
class LIBIMP_EXPORT std_t {
public:
@ -153,19 +188,10 @@ class grip {
if (!printer_ || (enum_cast(l) < enum_cast(level_limit_))) {
return *this;
}
context ctx;
LIBIMP_TRY {
ctx = {
printer_.output(context<A &&...> {
l, std::chrono::system_clock::now(), func_,
fmt(std::forward<A>(args)...),
};
} LIBIMP_CATCH(std::exception const &e) {
/// \remark [TBD] std::string constructor may throw an exception
ctx = {
level::failed, std::chrono::system_clock::now(), func_, e.what(),
};
}
printer_.output(std::move(ctx));
std::forward_as_tuple(std::forward<A>(args)...),
});
return *this;
}
@ -186,4 +212,4 @@ public:
} // namespace log
LIBIMP_NAMESPACE_END_
#define LIBIMP_LOG_(...) ::LIBIMP::log::grip log {__func__, __VA_ARGS__}
#define LIBIMP_LOG_(...) ::LIBIMP::log::grip log(__func__,##__VA_ARGS__)

View File

@ -1,42 +1,10 @@
#include "libimp/log.h"
#include <utility>
#include <cstdio>
LIBIMP_NAMESPACE_BEG_
namespace log {
bool to_string(fmt_context &f_ctx, context &&l_ctx) noexcept {
constexpr static char types[] = {
'T', 'D', 'I', 'W', 'E', 'F',
};
LIBIMP_TRY {
auto ms = std::chrono::time_point_cast<std::chrono::milliseconds>(l_ctx.tp).time_since_epoch().count() % 1000;
return fmt_to(f_ctx, "[", types[enum_cast(l_ctx.level)], "][", l_ctx.tp, ".", spec("03")(ms), "][", l_ctx.func, "] ", l_ctx.text);
} LIBIMP_CATCH(std::exception const &) {
return false;
}
}
std::string to_string(context &&ctx) noexcept {
std::string log_txt;
fmt_context f_ctx(log_txt);
if (!to_string(f_ctx, std::move(ctx))) {
return {};
}
f_ctx.finish();
return log_txt;
}
printer::operator bool() const noexcept {
return (objp_ != nullptr) && (vtable_ != nullptr);
}
void printer::output(context ctx) noexcept {
if (!*this) return;
vtable_->output(objp_, std::move(ctx));
}
std_t std_out;
void std_t::output(log::level l, std::string &&s) noexcept {

View File

@ -1,23 +1,24 @@
#include <iostream>
#include <string>
#include "gtest/gtest.h"
#include "libimp/log.h"
TEST(log, detail) {
EXPECT_EQ(imp::detail_log::has_fn_output_v<int>, imp::detail_log::out_none);
EXPECT_EQ(imp::log::detail::has_fn_output_v<int>, imp::log::detail::out_none);
struct foo {
int info(std::string);
};
EXPECT_EQ(imp::detail_log::has_fn_output_v<foo>, imp::detail_log::out_none);
EXPECT_EQ(imp::log::detail::has_fn_output_v<foo>, imp::log::detail::out_none);
struct bar {
int info(char const *);
void output(imp::log::level, std::string &&);
};
EXPECT_EQ(imp::detail_log::has_fn_output_v<bar>, imp::detail_log::out_string);
EXPECT_EQ(imp::log::detail::has_fn_output_v<bar>, imp::log::detail::out_string);
struct str {
str(std::string const &);
@ -25,11 +26,11 @@ TEST(log, detail) {
struct foo_bar {
void output(imp::log::level, str);
};
EXPECT_EQ(imp::detail_log::has_fn_output_v<foo_bar>, imp::detail_log::out_string);
EXPECT_EQ(imp::log::detail::has_fn_output_v<foo_bar>, imp::log::detail::out_string);
auto vt_int = imp::detail_log::traits<int>::make_vtable();
auto vt_int = imp::log::detail::traits<int>::make_vtable();
EXPECT_NE(vt_int, nullptr);
EXPECT_NO_THROW(vt_int->output(nullptr, imp::log::context{}));
EXPECT_NO_THROW(vt_int->output(nullptr, imp::log::level::error, ""));
struct log {
std::string what;
@ -37,13 +38,13 @@ TEST(log, detail) {
if (l == imp::log::level::error) what += s + '\n';
}
} ll;
auto vt_log = imp::detail_log::traits<log>::make_vtable();
auto vt_log = imp::log::detail::traits<log>::make_vtable();
EXPECT_NE(vt_log, nullptr);
vt_log->output(&ll, imp::log::context{imp::log::level::info , std::chrono::system_clock::now(), __func__, "123"});
vt_log->output(&ll, imp::log::context{imp::log::level::error, std::chrono::system_clock::now(), __func__, "321"});
vt_log->output(&ll, imp::log::context{imp::log::level::info , std::chrono::system_clock::now(), __func__, "654"});
vt_log->output(&ll, imp::log::context{imp::log::level::error, std::chrono::system_clock::now(), __func__, "456"});
vt_log->output(&ll, imp::log::level::info, "123");
vt_log->output(&ll, imp::log::level::info, "321");
vt_log->output(&ll, imp::log::level::info, "654");
vt_log->output(&ll, imp::log::level::info, "456");
std::cout << ll.what << "\n";
SUCCEED();
}
@ -60,15 +61,15 @@ TEST(log, log_printer) {
} ll;
imp::log::printer pt = ll;
pt.output({imp::log::level::info , std::chrono::system_clock::now(), __func__, "hello "});
pt.output({imp::log::level::error, std::chrono::system_clock::now(), __func__, "failed: "});
pt.output({imp::log::level::info , std::chrono::system_clock::now(), __func__, "log-pt"});
pt.output({imp::log::level::error, std::chrono::system_clock::now(), __func__, "whatever"});
pt.output(imp::log::context<char const *>{imp::log::level::info , std::chrono::system_clock::now(), __func__, "hello "});
pt.output(imp::log::context<char const *>{imp::log::level::error, std::chrono::system_clock::now(), __func__, "failed: "});
pt.output(imp::log::context<char const *>{imp::log::level::info , std::chrono::system_clock::now(), __func__, "log-pt"});
pt.output(imp::log::context<char const *>{imp::log::level::error, std::chrono::system_clock::now(), __func__, "whatever"});
std::cout << ll.i << "\n";
std::cout << ll.e << "\n";
imp::log::printer ps = imp::log::std_out;
ps.output({imp::log::level::info, std::chrono::system_clock::now(), __func__, "hello world"});
ps.output(imp::log::context<char const *>{imp::log::level::info, std::chrono::system_clock::now(), __func__, "hello world"});
SUCCEED();
}