This looks really great, much better than building a debug line piecemeal. Shall we also mention in a comment that this can work for all Ceph types that implement:

https://fmt.dev/latest/api.html#std-ostream-support

Also note:

With some templates, let's add:

template<class T> requires HasPrint<T>
struct fmt:formatter<T> : ostream_formatter {};

? (Haven't tried this but I think it should work.)

really appreciate it @cbodley

I'm not sure we should encourage relying in existing ostream support (which is slow).
The best option is to always add a formatter to each new type. And common_fmt adds a lazy option, too.

thanks for the reviews! i think i'd prefer to limit the pr's scope just to dout, rather than the formatting of ceph types in general. we're using fmt quite a bit already, and a lot of our types already have formatters

this pr was motivated by discussion in #55076 (comment) and #56008 (review), where the combination of libfmt and std::ostream led to unnecessary overhead. we'll get the best performance if we stick to one model or the other

i tend to agree with @ronen-fr that their ostream_formatter is probably adding too much overhead to be a good default. i see from detail::format_value() that it's constructing a std::basic_ostream and std::basic_streambuf for each value. long ago in #19100 we found that those constructor calls were surprisingly expensive (i think because of a global lock to look up the locale?)

it's fine for types to opt in to the ostream_formatter on a case-by-case basis, but the lack of default ostream support will at least make us stop and think about it. if there are enough examples of good custom formatters, we'll be more likely to copy one of those instead

do you buy that @batrick?

I'm not sure we should encourage relying in existing ostream support (which is slow).

huh?

As I understand things, this PR is only optimizing the case where we'd like to use fmt::format to create an intermediate formatted string (at least one extra heap allocation) when we could just write to the ostream?

long ago in #19100

it's changed a lot, more recently than that: #23721

I put a lot of effort into eliminating all heap allocations for debug logging. (So the "slow" comment with respect to the use of the ostream is somewhat puzzling.)

do you buy that @batrick?

Maybe I misunderstood what

struct fmt:formatter<T> : ostream_formatter {};

was actually doing. My hope was that it would teach fmt::format_to to call our T::print method with the ostream we passed. If it's creating an intermediate ostream then that sucks and makes it unsuitable.

If it's creating an intermediate ostream then that sucks and makes it unsuitable.

that's my understanding. this pr passes a std::ostream_iterator to fmt::format_to(OutputIt), so fmt never actually has access to our dout stream. and the same formatters have to work with fmt::format() where there is no underlying ostream

Circling back: fmt::print is pretty sophisticated about this:

$ cat fmt-ostream.cc 
#include <iostream>
#include <fmt/core.h>
#include <fmt/ostream.h>
#include <sstream>


struct dumpme {
  int a;
  int b;
  friend inline std::ostream& operator<<(std::ostream& os, const dumpme& o) {
    return os << "long string to heap allocate: " <<  o.a << " " << o.b;
  }
};

template<> struct fmt::formatter<dumpme> : ostream_formatter {};

int main (int argc, char*argv[])
{
  auto o = dumpme{1,2};

  auto opt = std::string(argv[1]);

  for (int i = 0; i < 1000; ++i) {
    if (opt == "dump") {
      std::cout << "dumpme is " << o << std::endl;
    } else if (opt == "string") {
      std::string s = fmt::format("dumpme is {}\n", o);
      std::cout << s;
    } else if (opt == "print") {
      fmt::print(std::cout, "dumpme is {}\n", o);
    }
  }

  return 0;
}

running:

$ g++ --std=c++20 fmt-ostream.cc -lfmt ; for s in dump string print; do valgrind --leak-check=full ./a.out $s > /dev/null; done
==1402093== Memcheck, a memory error detector
==1402093== Copyright (C) 2002-2024, and GNU GPL'd, by Julian Seward et al.
==1402093== Using Valgrind-3.23.0 and LibVEX; rerun with -h for copyright info
==1402093== Command: ./a.out dump
==1402093== 
==1402093== 
==1402093== HEAP SUMMARY:
==1402093==     in use at exit: 0 bytes in 0 blocks
==1402093==   total heap usage: 2 allocs, 2 frees, 77,824 bytes allocated
==1402093== 
==1402093== All heap blocks were freed -- no leaks are possible
==1402093== 
==1402093== For lists of detected and suppressed errors, rerun with: -s
==1402093== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
==1402101== Memcheck, a memory error detector
==1402101== Copyright (C) 2002-2024, and GNU GPL'd, by Julian Seward et al.
==1402101== Using Valgrind-3.23.0 and LibVEX; rerun with -h for copyright info
==1402101== Command: ./a.out string
==1402101== 
==1402101== 
==1402101== HEAP SUMMARY:
==1402101==     in use at exit: 0 bytes in 0 blocks
==1402101==   total heap usage: 1,002 allocs, 1,002 frees, 122,824 bytes allocated
==1402101== 
==1402101== All heap blocks were freed -- no leaks are possible
==1402101== 
==1402101== For lists of detected and suppressed errors, rerun with: -s
==1402101== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
==1402108== Memcheck, a memory error detector
==1402108== Copyright (C) 2002-2024, and GNU GPL'd, by Julian Seward et al.
==1402108== Using Valgrind-3.23.0 and LibVEX; rerun with -h for copyright info
==1402108== Command: ./a.out print
==1402108== 
==1402108== 
==1402108== HEAP SUMMARY:
==1402108==     in use at exit: 0 bytes in 0 blocks
==1402108==   total heap usage: 2 allocs, 2 frees, 77,824 bytes allocated
==1402108== 
==1402108== All heap blocks were freed -- no leaks are possible
==1402108== 
==1402108== For lists of detected and suppressed errors, rerun with: -s
==1402108== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

There are no intermediate allocations (i.e. an intermediate std::ostream created by fmt::print). So I think teaching fmt::print to handle our types with operator<< or requires HasPrint would be a step in the right direction with no loss in performance.

the code i linked above https://github.com/fmtlib/fmt/blob/master/include/fmt/ostream.h#L98 doesn't heap-allocate these things, so they wouldn't show up in valgrind. i think we'd need an actual benchmark to measure the difference between a type that uses ostream_formatter and an identical type with a hand-crafted formatter

maybe include our common/fmt_common.h also, to reduce the number of required 'include' lines?

this doesn't depend on anything in fmt_common.h. <fmt/core.h> seems to be the minimal include for fmt::format_to()

@cbodley If I want to mix the use of fmt::format_to and normal << dumps, should I just be calling fmt::format_to manually? Maybe we can enable something like:

dout(20) << df("{}: {}: ", __FILE__, __FUNC__) << ... << dendl;

i like the syntax. df() would need to return a struct that captures its arguments for the ostream operator, but i'm not sure how to preserve the constexpr-ness of the format string. this is what i came up with: https://godbolt.org/z/7sdqTMddh but it only compiles if i wrap the format string in fmt::runtime(f.fmt) for the call to fmt::format_to(). that gives up compile-time checking and makes it slower at runtime. maybe something like df<"{}: {}: ">(__FILE__, __FUNC__) could work, but it doesn't look like as nice

the alternative would be to use a separate statement to call format_to:

dout(2);
fmt::format_to(std::ostream_iterator<char>(*_dout), "{}: {}: ", __FILE__, __FUNC__);
*_dout << ... << dendl;

but it doesn't seem necessary to mix the two this way. if you want to use fmt, why can't it handle the << ... << part too?

@cbodley If I want to mix the use of fmt::format_to and normal << dumps, should I just be calling fmt::format_to manually? Maybe we can enable something like:

dout(20) << df("{}: {}: ", __FILE__, __FUNC__) << ... << dendl;

i'd avoid this. as Casey puts, it's broken in two ways.

• it sacrifices the compile-time format check
• it materializes the format arguments even when they are not going to be formatted at all

probably we could go with:

dout_fmt(20, "{}: {}: {}", __FILE__, __FUNC__, fmt::streamed(foo));

i like the syntax. df() would need to return a struct that captures its arguments for the ostream operator, but i'm not sure how to preserve the constexpr-ness of the format string.

#define df(...) (fmt::print(*_dout, __VA_ARGS__), *_dout)

would work?

neat. does that still respect the order of operator<<s? ie "a" << df(...) << "b" prints after a and before b?

Yes, that's a good question. I believe that's venturing into undefined territory, nevermind.

IIRC, fmt::print() is able to print to an ostream, see https://fmt.dev/latest/api.html#_CPPv4IDpEN3fmt5printEvRNSt7ostreamE13format_stringIDp1TEDpRR1T

can we use it directly?

would it be more or less efficient?

i propose this just because it's simpler. i don't think performance-wise it is different from Casey's implementatino.

ok. if casey had written it with print, I wouldn't have noticed, just wondered

thanks @tchaikov! i wasn't aware of fmt::print()

would it be more or less efficient?

the ostream version is potentially more efficient since ostream_iterator can only write one output byte at a time while ostream::write() can write several

wow, nice improvement