diff --git a/bench/spdlog b/bench/spdlog index 21413e5..32fedcf 160000 --- a/bench/spdlog +++ b/bench/spdlog @@ -1 +1 @@ -Subproject commit 21413e599a8bae53bb8e49360849bfae32334a72 +Subproject commit 32fedcf90c656267d1f9cd8a272bd6ef4c29fd2d diff --git a/fmt b/fmt index d141cdb..64dc8fb 160000 --- a/fmt +++ b/fmt @@ -1 +1 @@ -Subproject commit d141cdbeb0fb422a3fb7173b285fd38e0d1772dc +Subproject commit 64dc8fbada9898fccddce0dda3cb0c9695712a3d diff --git a/fmtlog-inl.h b/fmtlog-inl.h index a0ab2da..4828e87 100644 --- a/fmtlog-inl.h +++ b/fmtlog-inl.h @@ -227,7 +227,7 @@ class fmtlogDetailT : tb(buffer) {} fmtlog::ThreadBuffer* tb; - const fmtlog::SPSCVarQueueOPT<>::MsgHeader* header = nullptr; + const fmtlog::SPSCVarQueueOPT::MsgHeader* header = nullptr; }; std::vector bgThreadBuffers; std::mutex logInfoMutex; @@ -343,7 +343,7 @@ class fmtlogDetailT if (thr.joinable()) thr.join(); } - void handleLog(fmt::string_view threadName, const fmtlog::SPSCVarQueueOPT<>::MsgHeader* header) { + void handleLog(fmt::string_view threadName, const fmtlog::SPSCVarQueueOPT::MsgHeader* header) { setArgVal<6>(threadName); StaticLogInfo& info = bgLogInfos[header->logId]; const char* data = (const char*)(header + 1); @@ -375,7 +375,7 @@ class fmtlogDetailT logLevel = (const char*)"DBG INF WRN ERR OFF" + (info.logLevel << 2); size_t headerPos = membuf.size(); - fmt::detail::vformat_to(membuf, headerPattern, fmt::basic_format_args(args.data(), parttenArgSize)); + fmtlog::vformat_to(membuf, headerPattern, fmt::basic_format_args(args.data(), parttenArgSize)); size_t bodyPos = membuf.size(); if (info.formatToFn) { @@ -492,6 +492,29 @@ void fmtlogT<_>::registerLogInfo(uint32_t& logId, FormatToFn fn, const char* loc d.logInfos.emplace_back(fn, location, level, fmtString); } +template +void fmtlogT<_>::vformat_to(fmtlog::MemoryBuffer& out, fmt::string_view fmt, + fmt::format_args args) { + fmt::detail::vformat_to(out, fmt, args); +} + +template +size_t fmtlogT<_>::formatted_size(fmt::string_view fmt, fmt::format_args args) { + auto buf = fmt::detail::counting_buffer<>(); + fmt::detail::vformat_to(buf, fmt, args); + return buf.count(); +} + +template +void fmtlogT<_>::vformat_to(char* out, fmt::string_view fmt, fmt::format_args args) { + fmt::vformat_to(out, fmt, args); +} + +template +fmtlogT<_>::SPSCVarQueueOPT::MsgHeader* fmtlogT<_>::SPSCVarQueueOPT::allocMsg(uint32_t size) { + return alloc(size); +} + template void fmtlogT<_>::preallocate() { fmtlogDetailWrapper<>::impl.preallocate(); diff --git a/fmtlog.h b/fmtlog.h index a719986..96a88eb 100644 --- a/fmtlog.h +++ b/fmtlog.h @@ -75,6 +75,7 @@ struct UnrefPtr> : std::true_type template struct UnrefPtr : std::true_type { using type = Arg; }; + }; // namespace fmtlogdetail template @@ -101,8 +102,8 @@ class fmtlogT // Set the file for logging static void setLogFile(const char* filename, bool truncate = false); - // Set an existing FILE* for logging, if manageFp is false fmtlog will not buffer log internally and will not close - // the FILE* + // Set an existing FILE* for logging, if manageFp is false fmtlog will not buffer log internally + // and will not close the FILE* static void setLogFile(FILE* fp, bool manageFp = false); // Collect log msgs from all threads and write to log file @@ -130,7 +131,8 @@ class fmtlogT // bodyPos: log body index in the msg // logFilePos: log file position of this msg typedef void (*LogCBFn)(int64_t ns, LogLevel level, fmt::string_view location, size_t basePos, - fmt::string_view threadName, fmt::string_view msg, size_t bodyPos, size_t logFilePos); + fmt::string_view threadName, fmt::string_view msg, size_t bodyPos, + size_t logFilePos); // Set a callback function for all log msgs with a mininum log level static void setLogCB(LogCBFn cb, LogLevel minCBLogLevel); @@ -158,46 +160,23 @@ class fmtlogT // Stop the polling thread static void stopPollingThread(); -private: - fmtlogT() { init(); } - - void init() { - if (!inited) { - inited = true; - tscns.init(); - currentLogLevel = INF; - } - } - - template - friend class fmtlogDetailT; - template - friend struct fmtlogWrapper; - template - friend void test(const S& format, Args&&...); - - using Context = fmt::format_context; - using MemoryBuffer = fmt::basic_memory_buffer; - typedef const char* (*FormatToFn)(fmt::string_view format, const char* data, MemoryBuffer& out, int& argIdx, - std::vector>& args); - - static void registerLogInfo(uint32_t& logId, FormatToFn fn, const char* location, LogLevel level, - fmt::string_view fmtString); - // https://github.com/MengRao/SPSC_Queue - template class SPSCVarQueueOPT { public: struct MsgHeader { + inline void push(uint32_t sz) { *(volatile uint32_t*)&size = sz + sizeof(MsgHeader); } + uint32_t size; uint32_t logId; }; - static constexpr uint32_t BLK_CNT = Bytes / sizeof(MsgHeader); + static constexpr uint32_t BLK_CNT = (1 << 20) / sizeof(MsgHeader); + + MsgHeader* allocMsg(uint32_t size); - MsgHeader* alloc(uint32_t size_) { - size = size_ + sizeof(MsgHeader); + MsgHeader* alloc(uint32_t size) { + size += sizeof(MsgHeader); uint32_t blk_sz = (size + sizeof(MsgHeader) - 1) / sizeof(MsgHeader); if (blk_sz >= free_write_cnt) { uint32_t read_idx_cache = *(volatile uint32_t*)&read_idx; @@ -205,7 +184,6 @@ class fmtlogT free_write_cnt = BLK_CNT - write_idx; if (blk_sz >= free_write_cnt && read_idx_cache != 0) { // wrap around blk[0].size = 0; - std::atomic_thread_fence(std::memory_order_release); blk[write_idx].size = 1; write_idx = 0; free_write_cnt = read_idx_cache; @@ -218,28 +196,14 @@ class fmtlogT return nullptr; } } - return &blk[write_idx]; - } - - void push() { - uint32_t blk_sz = (size + sizeof(MsgHeader) - 1) / sizeof(MsgHeader); - blk[write_idx + blk_sz].size = 0; - std::atomic_thread_fence(std::memory_order_release); - blk[write_idx].size = size; + MsgHeader* ret = &blk[write_idx]; write_idx += blk_sz; free_write_cnt -= blk_sz; + blk[write_idx].size = 0; + return ret; } - template - bool tryPush(uint32_t size, Writer writer) { - MsgHeader* header = alloc(size); - if (!header) return false; - writer(header); - push(); - return true; - } - - const MsgHeader* front() { + inline const MsgHeader* front() { uint32_t size = blk[read_idx].size; if (size == 1) { // wrap around read_idx = 0; @@ -249,33 +213,22 @@ class fmtlogT return &blk[read_idx]; } - void pop() { + inline void pop() { uint32_t blk_sz = (blk[read_idx].size + sizeof(MsgHeader) - 1) / sizeof(MsgHeader); *(volatile uint32_t*)&read_idx = read_idx + blk_sz; } - template - bool tryPop(Reader reader) { - MsgHeader* header = front(); - if (!header) return false; - reader(header); - pop(); - return true; - } - private: alignas(64) MsgHeader blk[BLK_CNT] = {}; - - alignas(128) uint32_t write_idx = 0; + uint32_t write_idx = 0; uint32_t free_write_cnt = BLK_CNT; - uint32_t size; alignas(128) uint32_t read_idx = 0; }; struct ThreadBuffer { - SPSCVarQueueOPT<> varq; + SPSCVarQueueOPT varq; bool shouldDeallocate = false; char name[32]; size_t nameSize; @@ -294,7 +247,8 @@ class fmtlogT } else { #ifdef _WIN32 - return calibrate(1000000 * 100); // wait more time as Windows' system time is in 100ns precision + return calibrate(1000000 * + 100); // wait more time as Windows' system time is in 100ns precision #else return calibrate(1000000 * 10); // #endif @@ -355,18 +309,33 @@ class fmtlogT void adjustOffset() { ns_offset = base_ns - (int64_t)(base_tsc * tsc_ghz_inv); } - alignas(64) double tsc_ghz_inv; // make sure tsc_ghz_inv and ns_offset are on the same cache line + alignas(64) double tsc_ghz_inv; int64_t ns_offset; int64_t base_tsc; int64_t base_ns; }; - bool inited = false; + void init() { + tscns.init(); + currentLogLevel = INF; + } + + using Context = fmt::format_context; + using MemoryBuffer = fmt::basic_memory_buffer; + typedef const char* (*FormatToFn)(fmt::string_view format, const char* data, MemoryBuffer& out, + int& argIdx, std::vector>& args); + + static void registerLogInfo(uint32_t& logId, FormatToFn fn, const char* location, LogLevel level, + fmt::string_view fmtString); + + static void vformat_to(MemoryBuffer& out, fmt::string_view fmt, fmt::format_args args); + + static size_t formatted_size(fmt::string_view fmt, fmt::format_args args); + + static void vformat_to(char* out, fmt::string_view fmt, fmt::format_args args); -public: TSCNS tscns; -private: volatile LogLevel currentLogLevel; static FAST_THREAD_LOCAL ThreadBuffer* threadBuffer; @@ -550,8 +519,8 @@ class fmtlogT } template - static const char* formatTo(fmt::string_view format, const char* data, MemoryBuffer& out, int& argIdx, - std::vector>& args) { + static const char* formatTo(fmt::string_view format, const char* data, MemoryBuffer& out, + int& argIdx, std::vector>& args) { constexpr size_t num_args = sizeof...(Args); constexpr size_t num_dtors = fmt::detail::count()...>(); const char* dtor_args[std::max(num_dtors, (size_t)1)]; @@ -564,7 +533,7 @@ class fmtlogT else { ret = decodeArgs(data, args.data() + argIdx, dtor_args); } - fmt::detail::vformat_to(out, format, fmt::basic_format_args(args.data() + argIdx, num_args)); + vformat_to(out, format, fmt::basic_format_args(args.data() + argIdx, num_args)); destructArgs<0, Args...>(dtor_args); return ret; @@ -642,17 +611,17 @@ class fmtlogT } constexpr size_t num_cstring = fmt::detail::count()...>(); size_t cstringSizes[std::max(num_cstring, (size_t)1)]; - size_t allocSize = getArgSizes<0>(cstringSizes, args...) + 8; + size_t alloc_size = 8 + getArgSizes<0>(cstringSizes, args...); if (threadBuffer == nullptr) preallocate(); do { - if (threadBuffer->varq.tryPush(allocSize, [&](typename SPSCVarQueueOPT<>::MsgHeader* header) { - header->logId = logId; - char* writePos = (char*)(header + 1); - *(int64_t*)writePos = tsc; - writePos += 8; - encodeArgs<0>(cstringSizes, writePos, std::forward(args)...); - })) - return; + auto header = threadBuffer->varq.allocMsg(alloc_size); + if (!header) continue; + header->logId = logId; + char* out = (char*)(header + 1); + *(int64_t*)out = tsc; + out += 8; + encodeArgs<0>(cstringSizes, out, std::forward(args)...); + header->push(alloc_size); } while (FMTLOG_BLOCK); } @@ -663,20 +632,21 @@ class fmtlogT fmt::detail::check_format_string(format); } fmt::string_view sv(format); - size_t formatted_size = fmt::formatted_size(fmt::runtime(sv), args...); - size_t allocSize = formatted_size + 8 + 8; + auto&& fmt_args = fmt::make_format_args(args...); + size_t fmt_size = formatted_size(sv, fmt_args); + size_t alloc_size = 8 + 8 + fmt_size; if (threadBuffer == nullptr) preallocate(); do { - if (threadBuffer->varq.tryPush(allocSize, [&](typename SPSCVarQueueOPT<>::MsgHeader* header) { - header->logId = (uint32_t)level; - char* writePos = (char*)(header + 1); - *(int64_t*)writePos = tscns.rdtsc(); - writePos += 8; - *(const char**)writePos = location; - writePos += 8; - fmt::format_to(writePos, fmt::runtime(sv), args...); - })) - return; + auto header = threadBuffer->varq.allocMsg(alloc_size); + if (!header) continue; + header->logId = (uint32_t)level; + char* out = (char*)(header + 1); + *(int64_t*)out = tscns.rdtsc(); + out += 8; + *(const char**)out = location; + out += 8; + vformat_to(out, sv, fmt_args); + header->push(alloc_size); } while (FMTLOG_BLOCK); } };