feat(logging): Introduce spdlog and remove simple_logger and screen_logger

.clang-tidy

@@ -20,7 +20,7 @@
 CheckOptions: []
 # Disable some checks that are not useful for us now.
 # They are sorted by names, and should be consistent to build_tools/clang_tidy.py.
-Checks: 'abseil-*,boost-*,bugprone-*,cert-*,clang-analyzer-*,concurrency-*,cppcoreguidelines-*,darwin-*,fuchsia-*,google-*,hicpp-*,linuxkernel-*,llvm-*,misc-*,modernize-*,performance-*,portability-*,readability-*,-bugprone-easily-swappable-parameters,-bugprone-lambda-function-name,-bugprone-macro-parentheses,-cert-err58-cpp,-concurrency-mt-unsafe,-cppcoreguidelines-avoid-c-arrays,-cppcoreguidelines-avoid-magic-numbers,-cppcoreguidelines-avoid-non-const-global-variables,-cppcoreguidelines-macro-usage,-cppcoreguidelines-non-private-member-variables-in-classes,-cppcoreguidelines-owning-memory,-cppcoreguidelines-pro-bounds-array-to-pointer-decay,-cppcoreguidelines-pro-bounds-pointer-arithmetic,-cppcoreguidelines-pro-type-const-cast,-cppcoreguidelines-pro-type-union-access,-fuchsia-default-arguments-calls,-fuchsia-overloaded-operator,-fuchsia-statically-constructed-objects,-google-readability-avoid-underscore-in-googletest-name,-hicpp-avoid-c-arrays,-hicpp-named-parameter,-hicpp-no-array-decay,-llvm-include-order,-misc-definitions-in-headers,-misc-non-private-member-variables-in-classes,-modernize-avoid-c-arrays,-modernize-replace-disallow-copy-and-assign-macro,-modernize-use-trailing-return-type,-readability-function-cognitive-complexity,-readability-identifier-length,-readability-magic-numbers,-readability-named-parameter'
+Checks: 'abseil-*,boost-*,bugprone-*,cert-*,clang-analyzer-*,concurrency-*,cppcoreguidelines-*,darwin-*,fuchsia-*,google-*,hicpp-*,linuxkernel-*,llvm-*,misc-*,modernize-*,performance-*,portability-*,readability-*,-bugprone-easily-swappable-parameters,-bugprone-lambda-function-name,-bugprone-macro-parentheses,-cert-err58-cpp,-concurrency-mt-unsafe,-cppcoreguidelines-avoid-c-arrays,-cppcoreguidelines-avoid-magic-numbers,-cppcoreguidelines-avoid-non-const-global-variables,-cppcoreguidelines-macro-usage,-cppcoreguidelines-non-private-member-variables-in-classes,-cppcoreguidelines-owning-memory,-cppcoreguidelines-pro-bounds-array-to-pointer-decay,-cppcoreguidelines-pro-bounds-pointer-arithmetic,-cppcoreguidelines-pro-type-const-cast,-cppcoreguidelines-pro-type-union-access,-fuchsia-default-arguments-calls,-fuchsia-overloaded-operator,-fuchsia-statically-constructed-objects,-google-readability-avoid-underscore-in-googletest-name,-hicpp-avoid-c-arrays,-hicpp-named-parameter,-hicpp-no-array-decay,-llvm-header-guard,-llvm-include-order,-misc-definitions-in-headers,-misc-non-private-member-variables-in-classes,-modernize-avoid-c-arrays,-modernize-replace-disallow-copy-and-assign-macro,-modernize-use-trailing-return-type,-readability-function-cognitive-complexity,-readability-identifier-length,-readability-magic-numbers,-readability-named-parameter'
 ExtraArgs:
 ExtraArgsBefore: []
 FormatStyle: none

.licenserc.yaml

@@ -609,8 +609,6 @@ header:
     - 'src/utils/ports.h'
     - 'src/utils/priority_queue.h'
     - 'src/utils/shared_io_service.h'
-    - 'src/utils/simple_logger.cpp'
-    - 'src/utils/simple_logger.h'
     - 'src/utils/singleton_store.h'
     - 'src/utils/strings.cpp'
     - 'src/utils/strings.h'
@@ -632,7 +630,6 @@ header:
     - 'src/utils/test/join_point_test.cpp'
     - 'src/utils/test/json_helper_test.cpp'
     - 'src/utils/test/lock.std.cpp'
-    - 'src/utils/test/logger.cpp'
     - 'src/utils/test/logging.cpp'
     - 'src/utils/test/output_utils_test.cpp'
     - 'src/utils/test/priority_queue.cpp'

build_tools/clang_tidy.py

@@ -53,8 +53,6 @@ def tidy_on_path(path):
             "--",
             path]
         subprocess.check_call(cmd, stdout=patch_file, cwd=ROOT)
-        # TODO(yingchun): some checks could be disabled before we fix them.
-        #  "-checks=-llvm-include-order,-modernize-concat-nested-namespaces,-cppcoreguidelines-macro-usage,-cppcoreguidelines-special-member-functions,-hicpp-special-member-functions,-bugprone-easily-swappable-parameters,-google-readability-avoid-underscore-in-googletest-name,-cppcoreguidelines-avoid-c-arrays,-hicpp-avoid-c-arrays,-modernize-avoid-c-arrays,-llvm-header-guard,-cppcoreguidelines-pro-bounds-pointer-arithmetic",
         cmdline = ["clang-tidy-diff",
                    "-clang-tidy-binary",
                    "clang-tidy",
@@ -84,6 +82,7 @@ def tidy_on_path(path):
                            "-hicpp-avoid-c-arrays,"
                            "-hicpp-named-parameter,"
                            "-hicpp-no-array-decay,"
+                           "-llvm-header-guard,"
                            "-llvm-include-order,"
                            "-misc-definitions-in-headers,"
                            "-misc-non-private-member-variables-in-classes,"

cmake_modules/BaseFunctions.cmake

@@ -216,6 +216,12 @@ function(dsn_setup_compiler_flags)
   if(${BUILD_TEST})
     add_definitions(-DMOCK_TEST)
   endif()
+  # Use external fmt library instead of spdlog bundled.
+  add_definitions(-DSPDLOG_FMT_EXTERNAL)
+  # Define the compile time lowest log level to be active.
+  add_definitions(-DSPDLOG_ACTIVE_LEVEL=SPDLOG_LEVEL_DEBUG)
+  # Compile with -fno-exceptions. Call abort() on any spdlog exceptions.
+  add_definitions(-DSPDLOG_NO_EXCEPTIONS=ON)
 
   set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -std=c++17 -gdwarf-4" CACHE STRING "" FORCE)
 

src/aio/test/config.ini

@@ -42,7 +42,6 @@ enable_default_app_mimic = true
 tool = nativerun
 pause_on_start = false
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 [aio_test]
 op_buffer_size = 12

src/base/test/config.ini

@@ -36,8 +36,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 logging_flush_on_exit = true
 
 enable_default_app_mimic = true

src/block_service/test/config-test.ini

@@ -37,7 +37,6 @@ pools = THREAD_POOL_DEFAULT,THREAD_POOL_BLOCK_SERVICE
 tool = nativerun
 pause_on_start = false
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 [tools.simple_logger]
 fast_flush = true

src/client/test/config.ini

@@ -36,8 +36,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_INFO
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 logging_flush_on_exit = false
 
 enable_default_app_mimic = true

src/client_lib/pegasus_client_impl.cpp

@@ -17,7 +17,6 @@
  * under the License.
  */
 
-#include <fmt/core.h>
 #include <pegasus/error.h>
 #include <algorithm>
 #include <chrono>

src/common/test/config-test.ini

@@ -47,8 +47,6 @@ cli_local = false
 cli_remote = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simple_logger]
 fast_flush = true

src/failure_detector/test/config-test.ini

@@ -71,7 +71,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 
 [tools.simple_logger]

src/failure_detector/test/config-whitelist-test-failed.ini

@@ -72,7 +72,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 
 [tools.simple_logger]

src/failure_detector/test/config-whitelist-test.ini

@@ -72,7 +72,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 
 [tools.simple_logger]

src/geo/bench/config.ini

@@ -36,8 +36,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_INFO
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 logging_flush_on_exit = true
 
 enable_default_app_mimic = true

src/geo/test/config.ini

@@ -36,8 +36,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 logging_flush_on_exit = true
 
 enable_default_app_mimic = true

src/gutil/test/map_util_unittest.cpp

@@ -17,16 +17,15 @@
 #include "gutil/map_util.h"
 
 #include <absl/hash/hash.h>
-#include <string_view>
-#include <fmt/core.h>
-#include <stdint.h>
+#include <cstdint>
 #include <algorithm>
 #include <deque>
 #include <list>
 #include <map>
 #include <memory>
 #include <set>
 #include <string>
+#include <string_view>
 #include <utility>
 #include <vector>
 

src/http/pprof_http_service.cpp

@@ -19,8 +19,9 @@
 
 #include "pprof_http_service.h"
 
-#include <ctype.h>
-#include <errno.h>
+// IWYU pragma: no_include <bits/types/struct_FILE.h>
+#include <cctype>
+#include <cerrno>
 #include <fcntl.h>
 #include <gperftools/heap-profiler.h>
 #include <gperftools/malloc_extension.h>
@@ -41,7 +42,6 @@
 #include "http/http_server.h"
 #include "http/http_status_code.h"
 #include "runtime/api_layer1.h"
-#include "utils/api_utilities.h"
 #include "utils/blob.h"
 #include "utils/defer.h"
 #include "utils/fmt_logging.h"
@@ -98,7 +98,7 @@ static bool has_ext(const std::string &name, const std::string &ext)
 static int extract_symbols_from_binary(std::map<uintptr_t, std::string> &addr_map,
                                        const lib_info &lib_info)
 {
-    SCOPED_LOG_TIMING(INFO, "load {}", lib_info.path);
+    SCOPED_LOG_TIMING(info, "load {}", lib_info.path);
     std::string cmd = "nm -C -p ";
     cmd.append(lib_info.path);
     std::stringstream ss;
@@ -195,8 +195,8 @@ static int extract_symbols_from_binary(std::map<uintptr_t, std::string> &addr_ma
 
 static void load_symbols()
 {
-    SCOPED_LOG_TIMING(INFO, "load all symbols");
-    auto fp = fopen("/proc/self/maps", "r");
+    SCOPED_LOG_TIMING(info, "load all symbols");
+    auto *fp = fopen("/proc/self/maps", "r");
     if (fp == nullptr) {
         return;
     }
@@ -267,7 +267,7 @@ static void load_symbols()
     extract_symbols_from_binary(symbol_map, info);
 
     size_t num_removed = 0;
-    LOG_TIMING_IF(INFO, num_removed > 0, "removed {} entries", num_removed);
+    LOG_TIMING_IF(info, num_removed > 0, "removed {} entries", num_removed);
     bool last_is_empty = false;
     for (auto it = symbol_map.begin(); it != symbol_map.end();) {
         if (it->second.empty()) {

src/http/test/config-test.ini

@@ -38,7 +38,6 @@ toollets = tracer, profiler
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 [tools.simple_logger]
 fast_flush = true

src/meta/duplication/meta_duplication_service.cpp

@@ -46,8 +46,8 @@
 #include "rpc/rpc_message.h"
 #include "rpc/serialization.h"
 #include "runtime/api_layer1.h"
+#include "spdlog/common.h"
 #include "task/async_calls.h"
-#include "utils/api_utilities.h"
 #include "utils/blob.h"
 #include "utils/chrono_literals.h"
 #include "utils/error_code.h"
@@ -178,10 +178,10 @@ void meta_duplication_service::do_modify_duplication(std::shared_ptr<app_state>
     } while (0)
 
 #define LOG_WARNING_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, ...)                                \
-    LOG_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, LOG_LEVEL_WARNING, __VA_ARGS__)
+    LOG_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, spdlog::level::warn, __VA_ARGS__)
 
 #define LOG_ERROR_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, ...)                                  \
-    LOG_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, LOG_LEVEL_ERROR, __VA_ARGS__)
+    LOG_DUP_HINT_AND_RETURN_IF_NOT(expr, resp, ec, spdlog::level::err, __VA_ARGS__)
 
 // This call will not recreate if the duplication
 // with the same app name and remote end point already exists.

src/meta/test/config-test.ini

@@ -45,8 +45,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simple_logger]
 fast_flush = true

src/meta/test/dump_file.cpp

@@ -24,9 +24,10 @@
  * THE SOFTWARE.
  */
 
-#include <stdint.h>
-#include <stdio.h>
-#include <string.h>
+#include <fcntl.h> // IWYU pragma: keep
+#include <cstdint>
+#include <cstdio>
+#include <cstring>
 #include <memory>
 #include <string>
 #include <vector>

src/meta/test/meta_state/config-test.ini

@@ -55,8 +55,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simple_logger]
 fast_flush = true

src/nfs/test/config.ini

@@ -39,4 +39,3 @@ enable_default_app_mimic = true
 tool = nativerun
 pause_on_start = false
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger

src/nfs/test/nfs_test_file1

@@ -56,8 +56,6 @@ cli_local = true
 cli_remote = true
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simulator]
 random_seed = 0

src/nfs/test/nfs_test_file2

@@ -43,9 +43,6 @@ cli_local = true
 cli_remote = true
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
-
 
 [tools.simulator]
 random_seed = 0

src/redis_protocol/proxy/config.ini

@@ -44,8 +44,6 @@ toollets = profiler
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_INFO
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 enable_default_app_mimic = true
 
 [tools.simple_logger]

src/redis_protocol/proxy_ut/config.ini

@@ -44,8 +44,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-;logging_factory_name = dsn::tools::screen_logger
 enable_default_app_mimic = true
 
 [tools.simple_logger]

src/replica/bulk_load/test/config-test.ini

@@ -45,8 +45,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simple_logger]
 fast_flush = true

src/replica/replica_2pc.cpp

@@ -62,12 +62,12 @@
 #include "rpc/serialization.h"
 #include "runtime/api_layer1.h"
 #include "security/access_controller.h"
+#include "spdlog/common.h"
 #include "split/replica_split_manager.h"
 #include "task/async_calls.h"
 #include "task/task.h"
 #include "task/task_code.h"
 #include "task/task_spec.h"
-#include "utils/api_utilities.h"
 #include "utils/autoref_ptr.h"
 #include "utils/error_code.h"
 #include "utils/flags.h"
@@ -238,14 +238,15 @@ void replica::init_prepare(mutation_ptr &mu, bool reconciliation, bool pop_all_c
     const auto request_count = mu->client_requests.size();
     mu->data.header.last_committed_decree = last_committed_decree();
 
-    log_level_t level = LOG_LEVEL_DEBUG;
+    spdlog::level::level_enum level = spdlog::level::debug;
     if (mu->data.header.decree == invalid_decree) {
         mu->set_id(get_ballot(), _prepare_list->max_decree() + 1);
         // print a debug log if necessary
         if (FLAGS_prepare_decree_gap_for_debug_logging > 0 &&
-            mu->get_decree() % FLAGS_prepare_decree_gap_for_debug_logging == 0)
-            level = LOG_LEVEL_INFO;
-        mu->set_timestamp(_uniq_timestamp_us.next());
+            mu->get_decree() % FLAGS_prepare_decree_gap_for_debug_logging == 0) {
+            level = spdlog::level::info;
+        }
+        mu->set_timestamp(static_cast<int64_t>(_uniq_timestamp_us.next()));
     } else {
         mu->set_id(get_ballot(), mu->data.header.decree);
     }

src/replica/split/test/config-test.ini

@@ -45,8 +45,6 @@ tool = nativerun
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
-
 
 [tools.simple_logger]
 fast_flush = true

src/replica/storage/simple_kv/config.ini

@@ -64,8 +64,6 @@ toollets = tracer, profiler, fault_injector
 pause_on_start = false
 
 ;logging_start_level = LOG_LEVEL_WARNING
-;logging_factory_name = dsn::tools::screen_logger
-;logging_factory_name = dsn::tools::hpc_logger
 
 [tools.simulator]
 random_seed = 0

src/replica/storage/simple_kv/test/case-000.ini

@@ -68,7 +68,6 @@ toollets = test_injector
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 [tools.simple_logger]
 short_header = false

src/replica/storage/simple_kv/test/case-001.ini

@@ -68,7 +68,6 @@ toollets = test_injector
 pause_on_start = false
 
 logging_start_level = LOG_LEVEL_DEBUG
-logging_factory_name = dsn::tools::simple_logger
 
 [tools.simple_logger]
 short_header = false