remove unnecessary allocation from backend worker

odygrd · Nov 14, 2023 · 517db05 · 517db05
1 parent 856bcab
commit 517db05
Show file tree

Hide file tree

Showing 3 changed files with 86 additions and 7 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -55,6 +55,8 @@
 ## v3.4.1
 
 - Reduce backend worker unnecessary allocation. ([#368](https://github.com/odygrd/quill/issues/368))
+- Adjusted handling for empty `std::string_view` instances, addressing an issue where logging empty strings triggered an
+  unintended `memcpy` with zero size and a nullptr, leading to address sanitizer warnings.
 
 ## v3.4.0
 

diff --git a/quill/include/quill/detail/Serialize.h b/quill/include/quill/detail/Serialize.h
@@ -115,6 +115,8 @@ QUILL_NODISCARD QUILL_ATTRIBUTE_HOT inline std::byte* decode_args(
     char const* str = reinterpret_cast<char const*>(in);
     std::string_view const v{str, strlen(str)};
     args.emplace_back(fmtquill::detail::make_arg<TFormatContext>(v));
+
+    // for c_strings we add +1 to the length as we also want to copy the null terminated char
     return decode_args<TFormatContext, DestructIdx, Args...>(in + v.length() + 1, args, destruct_args);
   }
   else if constexpr (is_type_of_string<Arg>())
@@ -271,6 +273,8 @@ QUILL_NODISCARD QUILL_ATTRIBUTE_HOT constexpr std::byte* encode_args(size_t* c_s
   }
   else if constexpr (is_type_of_c_string<Arg>())
   {
+    assert((c_string_sizes[CstringIdx] > 0) &&
+           "we include the null terminated char to the size of the string for C strings");
     std::memcpy(out, arg, c_string_sizes[CstringIdx]);
     return encode_args<CstringIdx + 1>(c_string_sizes, out + c_string_sizes[CstringIdx],
                                        std::forward<Args>(args)...);
@@ -283,8 +287,12 @@ QUILL_NODISCARD QUILL_ATTRIBUTE_HOT constexpr std::byte* encode_args(size_t* c_s
     std::memcpy(out, &len, sizeof(size_t));
     out += sizeof(size_t);
 
-    // copy the string, no need to zero terminate it as we got the length
-    std::memcpy(out, arg.data(), arg.length());
+    if (len != 0)
+    {
+      // copy the string, no need to zero terminate it as we got the length
+      std::memcpy(out, arg.data(), arg.length());
+    }
+
     return encode_args<CstringIdx>(c_string_sizes, out + arg.length(), std::forward<Args>(args)...);
   }
 #if defined(_WIN32)
@@ -293,9 +301,13 @@ QUILL_NODISCARD QUILL_ATTRIBUTE_HOT constexpr std::byte* encode_args(size_t* c_s
     out = detail::align_pointer<alignof(size_t), std::byte>(out);
     size_t const len = c_string_sizes[CstringIdx];
     std::memcpy(out, &len, sizeof(size_t));
-
     out += sizeof(size_t);
-    wide_string_to_narrow(out, c_string_sizes[CstringIdx], std::wstring_view{arg, wcslen(arg)});
+
+    if (c_string_sizes[CstringIdx] != 0)
+    {
+      wide_string_to_narrow(out, c_string_sizes[CstringIdx], std::wstring_view{arg, wcslen(arg)});
+    }
+
     return encode_args<CstringIdx + 1>(c_string_sizes, out + c_string_sizes[CstringIdx],
                                        std::forward<Args>(args)...);
   }
@@ -307,7 +319,11 @@ QUILL_NODISCARD QUILL_ATTRIBUTE_HOT constexpr std::byte* encode_args(size_t* c_s
     std::memcpy(out, &len, sizeof(size_t));
     out += sizeof(size_t);
 
-    wide_string_to_narrow(out, c_string_sizes[CstringIdx], arg);
+    if (c_string_sizes[CstringIdx] != 0)
+    {
+      wide_string_to_narrow(out, c_string_sizes[CstringIdx], arg);
+    }
+
     return encode_args<CstringIdx + 1>(c_string_sizes, out + c_string_sizes[CstringIdx],
                                        std::forward<Args>(args)...);
   }

diff --git a/quill/test/LogTest.cpp b/quill/test/LogTest.cpp
@@ -59,7 +59,6 @@ TEST_CASE("default_logger_with_filehandler_1")
       {
         Logger* default_logger = lm.logger_collection().get_logger();
 
-        // log using the raw selialization queue
         std::string s = "adipiscing";
         LOG_INFO(default_logger, "Lorem ipsum dolor sit amet, consectetur {} {} {} {}", s, "elit", 1, 3.14);
         LOG_ERROR(default_logger,
@@ -84,6 +83,69 @@ TEST_CASE("default_logger_with_filehandler_1")
   quill::detail::remove_file(filename);
 }
 
+/***/
+TEST_CASE("default_logger_with_filehandler_1_empty_strings")
+{
+  fs::path const filename{"test_default_logger_with_filehandler_1_empty_strings"};
+  {
+    LogManager lm;
+
+    // Set a file handler as the custom logger handler and log to it
+    quill::Config cfg;
+    cfg.default_handlers.emplace_back(lm.handler_collection().create_handler<FileHandler>(
+      filename.string(),
+      []()
+      {
+        quill::FileHandlerConfig cfg;
+        cfg.set_open_mode('w');
+        return cfg;
+      }(),
+      FileEventNotifier{}));
+
+    lm.configure(cfg);
+
+    lm.start_backend_worker(false, std::initializer_list<int32_t>{});
+
+    std::thread frontend(
+      [&lm]()
+      {
+        Logger* default_logger = lm.logger_collection().get_logger();
+
+        std::string s = "adipiscing";
+        std::string_view const begin_s{"begin_s"};
+        std::string_view const end_s{"end_s"};
+        std::string_view const empty_sv{};
+        std::string const empty_s{};
+        char const* empty_cs = "";
+        char empty_ca[] = "";
+
+        LOG_INFO(default_logger,
+                 "Lorem ipsum dolor sit amet, consectetur {} {} {} {} {} [{}] [{}] [{}] [{}] {}", s,
+                 "elit", 1, 3.14, begin_s, empty_sv, empty_s, empty_cs, empty_ca, end_s);
+        LOG_ERROR(default_logger,
+                  "Nulla tempus, libero at dignissim viverra, lectus libero finibus ante {} {} {} "
+                  "[{}] [{}] [{}] [{}] {}",
+                  2, true, begin_s, empty_sv, empty_s, empty_cs, empty_ca, end_s);
+      });
+
+    frontend.join();
+
+    // Let all log get flushed to the file
+    lm.flush();
+
+    std::vector<std::string> const file_contents = quill::testing::file_contents(filename);
+
+    REQUIRE_EQ(file_contents.size(), 2);
+    REQUIRE(quill::testing::file_contains(
+      file_contents, std::string{"LOG_INFO      root         Lorem ipsum dolor sit amet, consectetur adipiscing elit 1 3.14 begin_s [] [] [] [] end_s"}));
+    REQUIRE(quill::testing::file_contains(
+      file_contents, std::string{"LOG_ERROR     root         Nulla tempus, libero at dignissim viverra, lectus libero finibus ante 2 true begin_s [] [] [] []"}));
+
+    lm.stop_backend_worker();
+  }
+  quill::detail::remove_file(filename);
+}
+
 /***/
 TEST_CASE("default_logger_with_filehandler_2")
 {
@@ -164,7 +226,6 @@ TEST_CASE("default_logger_with_filehandler_cformat")
       {
         Logger* default_logger = lm.logger_collection().get_logger();
 
-        // log using the raw selialization queue
         std::string s = "adipiscing";
         LOG_INFO_CFORMAT(default_logger, "Lorem ipsum dolor sit amet, consectetur %s %s %d %f",
                          s.data(), "elit", 1, 3.14);