From ff4eb562096fffbf2871f2553219295e26e94bb7 Mon Sep 17 00:00:00 2001 From: gabime Date: Sat, 30 Nov 2024 17:11:18 +0200 Subject: [PATCH] Use locking fwrite_unlocked if possible --- CMakeLists.txt | 23 +- example/example.cpp | 393 +--------------------- include/spdlog/details/file_helper-inl.h | 3 +- include/spdlog/details/os-inl.h | 12 + include/spdlog/details/os.h | 4 + include/spdlog/sinks/ansicolor_sink-inl.h | 4 +- include/spdlog/sinks/stdout_sinks-inl.h | 3 +- tests/test_misc.cpp | 31 ++ 8 files changed, 77 insertions(+), 396 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 611c9426..2ce05ec2 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -108,15 +108,15 @@ endif() if(WIN32) option(SPDLOG_WCHAR_SUPPORT "Support wchar api" OFF) option(SPDLOG_WCHAR_FILENAMES "Support wchar filenames" OFF) - option(SPDLOG_WCHAR_CONSOLE "Support wchar output to console" OFF) + option(SPDLOG_WCHAR_CONSOLE "Support wchar output to console" OFF) else() set(SPDLOG_WCHAR_SUPPORT OFF CACHE BOOL "non supported option" FORCE) set(SPDLOG_WCHAR_FILENAMES OFF CACHE BOOL "non supported option" FORCE) set(SPDLOG_WCHAR_CONSOLE OFF CACHE BOOL "non supported option" FORCE) endif() -if(MSVC) - option(SPDLOG_MSVC_UTF8 "Enable/disable msvc /utf-8 flag required by fmt lib" ON) +if(MSVC) + option(SPDLOG_MSVC_UTF8 "Enable/disable msvc /utf-8 flag required by fmt lib" ON) endif() if(${CMAKE_SYSTEM_NAME} STREQUAL "Linux") @@ -238,6 +238,19 @@ if(SPDLOG_FMT_EXTERNAL OR SPDLOG_FMT_EXTERNAL_HO) set(PKG_CONFIG_REQUIRES fmt) # add dependency to pkg-config endif() +# --------------------------------------------------------------------------------------- +# Check if fwrite_unlocked/_fwrite_nolock is available +# --------------------------------------------------------------------------------------- +include(CheckSymbolExists) +if(WIN32) + check_symbol_exists(_fwrite_nolock "stdio.h" HAVE_FWRITE_UNLOCKED) +else () + check_symbol_exists(fwrite_unlocked "stdio.h" HAVE_FWRITE_UNLOCKED) +endif() +if(HAVE_FWRITE_UNLOCKED) + target_compile_definitions(spdlog PRIVATE SPDLOG_FWRITE_UNLOCKED) +endif() + # --------------------------------------------------------------------------------------- # Add required libraries for Android CMake build # --------------------------------------------------------------------------------------- @@ -276,9 +289,9 @@ if(MSVC) if(SPDLOG_MSVC_UTF8) # fmtlib requires the /utf-8 flag when building with msvc. # see https://github.com/fmtlib/fmt/pull/4159 on the purpose of the additional - # "$<$,$>" + # "$<$,$>" target_compile_options(spdlog PUBLIC $<$,$>:/utf-8>) - target_compile_options(spdlog_header_only INTERFACE $<$,$>:/utf-8>) + target_compile_options(spdlog_header_only INTERFACE $<$,$>:/utf-8>) endif() endif() diff --git a/example/example.cpp b/example/example.cpp index 26b92a15..d344373b 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -7,394 +7,13 @@ #include #include -void load_levels_example(); -void stdout_logger_example(); -void basic_example(); -void rotating_example(); -void daily_example(); -void callback_example(); -void async_example(); -void binary_example(); -void vector_example(); -void stopwatch_example(); -void trace_example(); -void multi_sink_example(); -void user_defined_example(); -void err_handler_example(); -void syslog_example(); -void udp_example(); -void custom_flags_example(); -void file_events_example(); -void replace_default_logger_example(); -void mdc_example(); - -#include "spdlog/spdlog.h" -#include "spdlog/cfg/env.h" // support for loading levels from the environment variable -#include "spdlog/fmt/ostr.h" // support for user defined types - -int main(int, char *[]) { - // Log levels can be loaded from argv/env using "SPDLOG_LEVEL" - load_levels_example(); - - spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, - SPDLOG_VER_PATCH); - - spdlog::warn("Easy padding in numbers like {:08d}", 12); - spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42); - spdlog::info("Support for floats {:03.2f}", 1.23456); - spdlog::info("Positional args are {1} {0}..", "too", "supported"); - spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left"); - - // Runtime log levels - spdlog::set_level(spdlog::level::info); // Set global log level to info - spdlog::debug("This message should not be displayed!"); - spdlog::set_level(spdlog::level::trace); // Set specific logger's log level - spdlog::debug("This message should be displayed.."); - - // Customize msg format for all loggers - spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); - spdlog::info("This an info message with custom format"); - spdlog::set_pattern("%+"); // back to default format - spdlog::set_level(spdlog::level::info); - - // Backtrace support - // Loggers can store in a ring buffer all messages (including debug/trace) for later inspection. - // When needed, call dump_backtrace() to see what happened: - spdlog::enable_backtrace(10); // create ring buffer with capacity of 10 messages - for (int i = 0; i < 100; i++) { - spdlog::debug("Backtrace message {}", i); // not logged.. - } - // e.g. if some error happened: - spdlog::dump_backtrace(); // log them now! - - try { - stdout_logger_example(); - basic_example(); - rotating_example(); - daily_example(); - callback_example(); - async_example(); - binary_example(); - vector_example(); - multi_sink_example(); - user_defined_example(); - err_handler_example(); - trace_example(); - stopwatch_example(); - udp_example(); - custom_flags_example(); - file_events_example(); - replace_default_logger_example(); - mdc_example(); - - // Flush all *registered* loggers using a worker thread every 3 seconds. - // note: registered loggers *must* be thread safe for this to work correctly! - spdlog::flush_every(std::chrono::seconds(3)); - - // Apply some function on all registered loggers - spdlog::apply_all([&](std::shared_ptr l) { l->info("End of example."); }); - - // Release all spdlog resources, and drop all loggers in the registry. - // This is optional (only mandatory if using windows + async log). - spdlog::shutdown(); - } - - // Exceptions will only be thrown upon failed logger or sink construction (not during logging). - catch (const spdlog::spdlog_ex &ex) { - std::printf("Log initialization failed: %s\n", ex.what()); - return 1; - } -} - +#include "spdlog/spdlite.h" #include "spdlog/sinks/stdout_color_sinks.h" -// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed. -void stdout_logger_example() { - // Create color multi threaded logger. - auto console = spdlog::stdout_color_mt("console"); - // or for stderr: - // auto console = spdlog::stderr_color_mt("error-logger"); -} - -#include "spdlog/sinks/basic_file_sink.h" -void basic_example() { - // Create basic file logger (not rotated). - auto my_logger = spdlog::basic_logger_mt("file_logger", "logs/basic-log.txt", true); -} - -#include "spdlog/sinks/rotating_file_sink.h" -void rotating_example() { - // Create a file rotating logger with 5mb size max and 3 rotated files. - auto rotating_logger = - spdlog::rotating_logger_mt("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3); -} - -#include "spdlog/sinks/daily_file_sink.h" -void daily_example() { - // Create a daily logger - a new file is created every day on 2:30am. - auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); -} - -#include "spdlog/sinks/callback_sink.h" -void callback_example() { - // Create the logger - auto logger = spdlog::callback_logger_mt("custom_callback_logger", - [](const spdlog::details::log_msg & /*msg*/) { - // do what you need to do with msg - }); -} - -#include "spdlog/cfg/env.h" -void load_levels_example() { - // Set the log level to "info" and mylogger to "trace": - // SPDLOG_LEVEL=info,mylogger=trace && ./example - spdlog::cfg::load_env_levels(); - // or from command line: - // ./example SPDLOG_LEVEL=info,mylogger=trace - // #include "spdlog/cfg/argv.h" // for loading levels from argv - // spdlog::cfg::load_argv_levels(args, argv); -} - -#include "spdlog/async.h" -void async_example() { - // Default thread pool settings can be modified *before* creating the async logger: - // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread. - auto async_file = - spdlog::basic_logger_mt("async_file_logger", "logs/async_log.txt"); - // alternatively: - // auto async_file = - // spdlog::create_async("async_file_logger", - // "logs/async_log.txt"); - - for (int i = 1; i < 101; ++i) { - async_file->info("Async message #{}", i); - } -} - -// Log binary data as hex. -// Many types of std::container types can be used. -// Iterator ranges are supported too. -// Format flags: -// {:X} - print in uppercase. -// {:s} - don't separate each byte with space. -// {:p} - don't print the position on each line start. -// {:n} - don't split the output to lines. - -#if !defined SPDLOG_USE_STD_FORMAT || defined(_MSC_VER) - #include "spdlog/fmt/bin_to_hex.h" -void binary_example() { - std::vector buf; - for (int i = 0; i < 80; i++) { - buf.push_back(static_cast(i & 0xff)); - } - spdlog::info("Binary example: {}", spdlog::to_hex(buf)); - spdlog::info("Another binary example:{:n}", - spdlog::to_hex(std::begin(buf), std::begin(buf) + 10)); - // more examples: - // logger->info("uppercase: {:X}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf)); - // logger->info("hexdump style: {:a}", spdlog::to_hex(buf)); - // logger->info("hexdump style, 20 chars per line {:a}", spdlog::to_hex(buf, 20)); -} -#else -void binary_example() { - // not supported with std::format yet -} -#endif - -// Log a vector of numbers -#ifndef SPDLOG_USE_STD_FORMAT - #include "spdlog/fmt/ranges.h" -void vector_example() { - std::vector vec = {1, 2, 3}; - spdlog::info("Vector example: {}", vec); -} -#else -void vector_example() {} -#endif - -// ! DSPDLOG_USE_STD_FORMAT - -// Compile time log levels. -// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE) -void trace_example() { - // trace from default logger - SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23); - // debug from default logger - SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23); - - // trace from logger object - auto logger = spdlog::get("file_logger"); - SPDLOG_LOGGER_TRACE(logger, "another trace message"); -} - -// stopwatch example -#include "spdlog/stopwatch.h" -#include -void stopwatch_example() { - spdlog::stopwatch sw; - std::this_thread::sleep_for(std::chrono::milliseconds(123)); - spdlog::info("Stopwatch: {} seconds", sw); -} - -#include "spdlog/sinks/udp_sink.h" -void udp_example() { - spdlog::sinks::udp_sink_config cfg("127.0.0.1", 11091); - auto my_logger = spdlog::udp_logger_mt("udplog", cfg); - my_logger->set_level(spdlog::level::debug); - my_logger->info("hello world"); -} - -// A logger with multiple sinks (stdout and file) - each with a different format and log level. -void multi_sink_example() { - auto console_sink = std::make_shared(); - console_sink->set_level(spdlog::level::warn); - console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v"); - - auto file_sink = - std::make_shared("logs/multisink.txt", true); - file_sink->set_level(spdlog::level::trace); - - spdlog::logger logger("multi_sink", {console_sink, file_sink}); - logger.set_level(spdlog::level::debug); - logger.warn("this should appear in both console and file"); - logger.info("this message should not appear in the console, only in the file"); -} - -// User defined types logging -struct my_type { - int i = 0; - explicit my_type(int i) - : i(i){} -}; - -#ifndef SPDLOG_USE_STD_FORMAT // when using fmtlib -template <> -struct fmt::formatter : fmt::formatter { - auto format(my_type my, format_context &ctx) const -> decltype(ctx.out()) { - return fmt::format_to(ctx.out(), "[my_type i={}]", my.i); - } -}; - -#else // when using std::format -template <> -struct std::formatter : std::formatter { - auto format(my_type my, format_context &ctx) const -> decltype(ctx.out()) { - return std::format_to(ctx.out(), "[my_type i={}]", my.i); - } -}; -#endif - -void user_defined_example() { spdlog::info("user defined type: {}", my_type(14)); } - -// Custom error handler. Will be triggered on log failure. -void err_handler_example() { - // can be set globally or per logger(logger->set_error_handler(..)) - spdlog::set_error_handler([](const std::string &msg) { - printf("*** Custom log error handler: %s ***\n", msg.c_str()); - }); -} - -// syslog example (linux/osx/freebsd) -#ifndef _WIN32 - #include "spdlog/sinks/syslog_sink.h" -void syslog_example() { - std::string ident = "spdlog-example"; - auto syslog_logger = spdlog::syslog_logger_mt("syslog", ident, LOG_PID); - syslog_logger->warn("This is warning that will end up in syslog."); -} -#endif - -// Android example. -#if defined(__ANDROID__) - #include "spdlog/sinks/android_sink.h" -void android_example() { - std::string tag = "spdlog-android"; - auto android_logger = spdlog::android_logger_mt("android", tag); - android_logger->critical("Use \"adb shell logcat\" to view this message."); -} -#endif - -// Log patterns can contain custom flags. -// this will add custom flag '%*' which will be bound to a instance -#include "spdlog/pattern_formatter.h" -class my_formatter_flag : public spdlog::custom_flag_formatter { -public: - void format(const spdlog::details::log_msg &, - const std::tm &, - spdlog::memory_buf_t &dest) override { - std::string some_txt = "custom-flag"; - dest.append(some_txt.data(), some_txt.data() + some_txt.size()); - } - - std::unique_ptr clone() const override { - return spdlog::details::make_unique(); - } -}; - -void custom_flags_example() { - using spdlog::details::make_unique; // for pre c++14 - auto formatter = make_unique(); - formatter->add_flag('*').set_pattern("[%n] [%*] [%^%l%$] %v"); - // set the new formatter using spdlog::set_formatter(formatter) or - // logger->set_formatter(formatter) spdlog::set_formatter(std::move(formatter)); -} - -void file_events_example() { - // pass the spdlog::file_event_handlers to file sinks for open/close log file notifications - spdlog::file_event_handlers handlers; - handlers.before_open = [](spdlog::filename_t filename) { - spdlog::info("Before opening {}", filename); - }; - handlers.after_open = [](spdlog::filename_t filename, std::FILE *fstream) { - spdlog::info("After opening {}", filename); - fputs("After opening\n", fstream); - }; - handlers.before_close = [](spdlog::filename_t filename, std::FILE *fstream) { - spdlog::info("Before closing {}", filename); - fputs("Before closing\n", fstream); - }; - handlers.after_close = [](spdlog::filename_t filename) { - spdlog::info("After closing {}", filename); - }; - auto file_sink = std::make_shared("logs/events-sample.txt", - true, handlers); - spdlog::logger my_logger("some_logger", file_sink); - my_logger.info("Some log line"); -} - -void replace_default_logger_example() { - // store the old logger so we don't break other examples. - auto old_logger = spdlog::default_logger(); - - auto new_logger = - spdlog::basic_logger_mt("new_default_logger", "logs/new-default-log.txt", true); - spdlog::set_default_logger(new_logger); - spdlog::set_level(spdlog::level::info); - spdlog::debug("This message should not be displayed!"); - spdlog::set_level(spdlog::level::trace); - spdlog::debug("This message should be displayed.."); - - spdlog::set_default_logger(old_logger); -} +int main(int, char *[]) { + spdlog::lite_logger logger("console", {std::make_shared()}); + logger.info("Hello {} {} !!", "param1", 123.4); + logger.warn("Some warning message"); -// Mapped Diagnostic Context (MDC) is a map that stores key-value pairs (string values) in thread local storage. -// Each thread maintains its own MDC, which loggers use to append diagnostic information to log outputs. -// Note: it is not supported in asynchronous mode due to its reliance on thread-local storage. -#ifndef SPDLOG_NO_TLS - #include "spdlog/mdc.h" -void mdc_example() -{ - spdlog::mdc::put("key1", "value1"); - spdlog::mdc::put("key2", "value2"); - // if not using the default format, you can use the %& formatter to print mdc data as well - spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [%&] %v"); - spdlog::info("Some log message with context"); -} -#else -void mdc_example() { - // if TLS feature is disabled -} -#endif +} \ No newline at end of file diff --git a/include/spdlog/details/file_helper-inl.h b/include/spdlog/details/file_helper-inl.h index 37d1d46f..8742b96c 100644 --- a/include/spdlog/details/file_helper-inl.h +++ b/include/spdlog/details/file_helper-inl.h @@ -101,7 +101,8 @@ SPDLOG_INLINE void file_helper::write(const memory_buf_t &buf) { if (fd_ == nullptr) return; size_t msg_size = buf.size(); auto data = buf.data(); - if (std::fwrite(data, 1, msg_size, fd_) != msg_size) { + + if (!details::os::fwrite_bytes(data, msg_size, fd_)) { throw_spdlog_ex("Failed writing to file " + os::filename_to_str(filename_), errno); } } diff --git a/include/spdlog/details/os-inl.h b/include/spdlog/details/os-inl.h index e4d4771b..8ee42304 100644 --- a/include/spdlog/details/os-inl.h +++ b/include/spdlog/details/os-inl.h @@ -589,6 +589,18 @@ SPDLOG_INLINE bool fsync(FILE *fp) { #endif } +// Do non-locking fwrite if possible by the os or use the regular locking fwrite +// Return true on success. +SPDLOG_INLINE bool fwrite_bytes(const void *ptr, const size_t n_bytes, FILE *fp) { + #if defined(_WIN32) && defined(SPDLOG_FWRITE_UNLOCKED) + return _fwrite_nolock(ptr, 1, n_bytes, fp) == n_bytes; + #elif defined(SPDLOG_FWRITE_UNLOCKED) + return ::fwrite_unlocked(ptr, 1, n_bytes, fp) == n_bytes; + #else + return std::fwrite(ptr, 1, n_bytes, fp) == n_bytes; + #endif +} + } // namespace os } // namespace details } // namespace spdlog diff --git a/include/spdlog/details/os.h b/include/spdlog/details/os.h index b1069edc..5fd12bac 100644 --- a/include/spdlog/details/os.h +++ b/include/spdlog/details/os.h @@ -114,6 +114,10 @@ SPDLOG_API std::string getenv(const char *field); // Return true on success. SPDLOG_API bool fsync(FILE *fp); +// Do non-locking fwrite if possible by the os or use the regular locking fwrite +// Return true on success. +SPDLOG_API bool fwrite_bytes(const void *ptr, const size_t n_bytes, FILE *fp); + } // namespace os } // namespace details } // namespace spdlog diff --git a/include/spdlog/sinks/ansicolor_sink-inl.h b/include/spdlog/sinks/ansicolor_sink-inl.h index 2194f67b..8fd3078a 100644 --- a/include/spdlog/sinks/ansicolor_sink-inl.h +++ b/include/spdlog/sinks/ansicolor_sink-inl.h @@ -106,14 +106,14 @@ SPDLOG_INLINE void ansicolor_sink::set_color_mode(color_mode mode) template SPDLOG_INLINE void ansicolor_sink::print_ccode_(const string_view_t &color_code) { - fwrite(color_code.data(), sizeof(char), color_code.size(), target_file_); + details::os::fwrite_bytes(color_code.data(), color_code.size(), target_file_); } template SPDLOG_INLINE void ansicolor_sink::print_range_(const memory_buf_t &formatted, size_t start, size_t end) { - fwrite(formatted.data() + start, sizeof(char), end - start, target_file_); + details::os::fwrite_bytes(formatted.data() + start, end - start, target_file_); } template diff --git a/include/spdlog/sinks/stdout_sinks-inl.h b/include/spdlog/sinks/stdout_sinks-inl.h index f98244db..fff292c2 100644 --- a/include/spdlog/sinks/stdout_sinks-inl.h +++ b/include/spdlog/sinks/stdout_sinks-inl.h @@ -10,6 +10,7 @@ #include #include #include +#include #ifdef _WIN32 // under windows using fwrite to non-binary stream results in \r\r\n (see issue #1675) @@ -67,7 +68,7 @@ SPDLOG_INLINE void stdout_sink_base::log(const details::log_msg &m std::lock_guard lock(mutex_); memory_buf_t formatted; formatter_->format(msg, formatted); - ::fwrite(formatted.data(), sizeof(char), formatted.size(), file_); + details::os::fwrite_bytes(formatted.data(), formatted.size(), file_); #endif // WIN32 ::fflush(file_); // flush every line to terminal } diff --git a/tests/test_misc.cpp b/tests/test_misc.cpp index 5ae3c045..cf8e3615 100644 --- a/tests/test_misc.cpp +++ b/tests/test_misc.cpp @@ -185,3 +185,34 @@ TEST_CASE("utf8 to utf16 conversion using windows api", "[windows utf]") { REQUIRE(std::wstring(buffer.data(), buffer.size()) == std::wstring(L"\x306d\x3053")); } #endif + +struct auto_closer { + FILE* fp = nullptr; + explicit auto_closer(FILE* f) : fp(f) {} + auto_closer(const auto_closer&) = delete; + auto_closer& operator=(const auto_closer&) = delete; + ~auto_closer() { + if (fp != nullptr) (void)std::fclose(fp); + } +}; + +TEST_CASE("os::fwrite_bytes", "[os]") { + using spdlog::details::os::fwrite_bytes; + using spdlog::details::os::create_dir; + const char* filename = "log_tests/test_fwrite_bytes.txt"; + const char *msg = "hello"; + prepare_logdir(); + REQUIRE(create_dir("log_tests")); + { + auto_closer closer(std::fopen(filename, "wb")); + REQUIRE(closer.fp != nullptr); + REQUIRE(fwrite_bytes(msg, std::strlen(msg), closer.fp) == true); + REQUIRE(fwrite_bytes(msg, 0, closer.fp) == true); + std::fflush(closer.fp); + REQUIRE(spdlog::details::os::filesize(closer.fp) == 5); + } + // fwrite_bytes should return false on write failure + auto_closer closer(std::fopen(filename, "r")); + REQUIRE(closer.fp != nullptr); + REQUIRE_FALSE(fwrite_bytes("Hello", 5, closer.fp)); +}