Setting BackendOptions log_timestamp_ordering_grace_period to 0 milliseconds causes assertion error in Debug build

[jellehierck]

Describe the bug
Setting BackendOptions log_timestamp_ordering_grace_period to 0 milliseconds causes an assertion error when built with Debug.

To Reproduce

• Clone Quill with tag v7.3.0 from github

• Add the following program to the example executables (based on the minimal example in the README):

  // examples/bug_log_timestamp_ordering_grace_period.cpp
  
  #include "quill/Backend.h"
  #include "quill/Frontend.h"
  #include "quill/LogMacros.h"
  #include "quill/Logger.h"
  #include "quill/backend/BackendOptions.h"
  #include "quill/sinks/ConsoleSink.h"
  #include <chrono>
  #include <string_view>
  
  int main()
  {
    quill::BackendOptions backendOptions;
    backendOptions.log_timestamp_ordering_grace_period = std::chrono::milliseconds(0);
    quill::Backend::start(backendOptions);
  
    quill::Logger* logger = quill::Frontend::create_or_get_logger(
      "root", quill::Frontend::create_or_get_sink<quill::ConsoleSink>("sink_id_1"));
  
    LOG_INFO(logger, "Hello from {}!", std::string_view{"Quill"});
  }

• Add the new example to examples/CMakeLists.txt

• Build the project with build type Debug

  cmake -S . -B build -DQUILL_BUILD_EXAMPLES=ON -DCMAKE_BUILD_TYPE=Debug
  cmake --build build

• Run the new program

  ./build/examples/quill_example_bug_log_timestamp_ordering_grace_period

• The following result is obtained:

  quill_example_bug_log_timestamp_ordering_grace_period: /home/jelle/thesis/zmq/quill-temp/include/quill/backend/BackendWorker.h:538: bool quill::v7::detail::BackendWorker::_populate_transit_event_from_frontend_queue(std::byte*&, quill::v7::detail::ThreadContext*, uint64_t): Assertion `count_digits(transit_event->timestamp) == count_digits(ts_now)' failed.
  Aborted (core dumped)
  

Expected Behaviour
When the exact same program is built in Release mode, it executes happily. I would have expected this behaviour to be the same for both build modes.

cmake -S . -B build -DQUILL_BUILD_EXAMPLES=ON -DCMAKE_BUILD_TYPE=Release
cmake --build build
./build/examples/quill_example_bug_log_timestamp_ordering_grace_period

Result:

10:14:04.639673421 [20078] bug_log_timestamp_ordering_grace_period.cpp:19 LOG_INFO      root         Hello from Quill!

Environment

• Operating System: Ubuntu 20.04
• Compiler: g++ (Ubuntu 9.4.0-1ubuntu1~20.04.2) 9.4.0

Additional context
I dug around with the VS Code debugger for a bit, and I believe the issue lies in include/quill/backend/BackendWorker.h.

When I build the example program with Debug build type and use VS Code debugger, the violated assertion is at BackendWorker.h:538, which seems to be a section only executed in debug builds.

The argument ts_now is set to 18446744073709551615, which causes the assertion to be violated. ts_now is set in BackendWorker.h:391. ts_now is set to the maximum value when the BackendOptions log_timestamp_ordering_grace_period is set to 0. Was this the intention, or is the assert statement maybe wrong somehow?

[odygrd]

thanks for reporting! yes that is indeed a bug, we should avoid this check when the timestamp is set to max. I will push a fix to master soon