Logging in Trieste

[mjp41]

This PR creates a logging/tracing library for Trieste to use. This can then be used by downstream projects such as rego-cpp and verona. The intent is to reduce the cost of checking whether log should be generated.

There is a pure C++ approach to using the library

   trieste::logging::Info() << "Hello " << 5;

that will output a log message if the Info level should be printed. The messages are output on destruction of the Log object, so that there is no tearing in a concurrent setting.

The log object can also be a local variable to allow more complex messages to be constructed.

trieste::logging::Info out;
out << "Hello" << trieste::logging::Indent;
for (int i = 0; i < 10 ; i++)
  out << "i = " << i << std::endl; 
out << trieste::logging::Undent;
out << "Goodbye.";

which will print the following at the end of out's scope:

Hello
 i = 0
 i = 1
 i = 2
Goodbye.

Here we use the Indent and Undent line terminators that alter the indentation level of the following lines.

The implementation tries very hard to force the compiler to move the logging off the fast path. For example:

  size_t fib(size_t i)
  {
    if (i < 2)
    {
      return i;
    }

    logging::Info() << "fib(" << i << ") = ? " << std::endl;

    auto result = fib(i - 1) + fib(i - 2);
    logging::Info() << "fib(" << i << ") = " << result << std::endl;
    return result;
  }

generates

000000000002bf30 <infix::fib(unsigned long)>:
   2bf30:       53                      push   %rbx
   2bf31:       48 81 ec b0 01 00 00    sub    $0x1b0,%rsp
   2bf38:       48 89 f8                mov    %rdi,%rax
   2bf3b:       48 89 7c 24 08          mov    %rdi,0x8(%rsp)
   2bf40:       48 83 ff 02             cmp    $0x2,%rdi
   2bf44:       72 4b                   jb     2bf91 <infix::fib(unsigned long)+0x61>
   2bf46:       c6 44 24 18 00          movb   $0x0,0x18(%rsp)
   2bf4b:       80 3d f6 cf 0e 00 01    cmpb   $0x1,0xecff6(%rip)        # 118f48 <trieste::logging::detail::report_level>
   2bf52:       74 46                   je     2bf9a <infix::fib(unsigned long)+0x6a>
   2bf54:       48 8b 7c 24 08          mov    0x8(%rsp),%rdi
   2bf59:       48 ff cf                dec    %rdi
   2bf5c:       e8 cf ff ff ff          call   2bf30 <infix::fib(unsigned long)>
   2bf61:       48 89 c3                mov    %rax,%rbx
   2bf64:       48 8b 7c 24 08          mov    0x8(%rsp),%rdi
   2bf69:       48 83 c7 fe             add    $0xfffffffffffffffe,%rdi
   2bf6d:       e8 be ff ff ff          call   2bf30 <infix::fib(unsigned long)>
   2bf72:       48 01 d8                add    %rbx,%rax
   2bf75:       48 89 44 24 10          mov    %rax,0x10(%rsp)
   2bf7a:       c6 44 24 18 00          movb   $0x0,0x18(%rsp)
   2bf7f:       80 3d c2 cf 0e 00 01    cmpb   $0x1,0xecfc2(%rip)        # 118f48 <trieste::logging::detail::report_level>
   2bf86:       0f 84 98 00 00 00       je     2c024 <infix::fib(unsigned long)+0xf4>
   2bf8c:       48 8b 44 24 10          mov    0x10(%rsp),%rax
   2bf91:       48 81 c4 b0 01 00 00    add    $0x1b0,%rsp
   2bf98:       5b                      pop    %rbx
   2bf99:       c3                      ret    
   2bf9a:       48 8d 7c 24 18          lea    0x18(%rsp),%rdi
   2bf9f:       e8 4c 1e 04 00          call   6ddf0 <trieste::logging::Log<(trieste::logging::detail::LogLevel)4>::start()>
   ...

There is additionally a macro that can be enables LOG with defining TRIESTE_EXPOSE_LOG_MACRO. This uses macro tricks such that

  LOG(Info) << "Hello " << "World" << fib(23);

will only evaluated fib(23) if the Info level should be printed. This is not the case for the pure C++ version:

  trieste::logging::Info() << "Hello " << "World" << fib(23);