Revise L3 interfaces to plug-in diff logging schemes [ usability & perf benchmarking needs ]

[gapisback]

This thread proposes a small collection of revisions to core L3 interfaces. The main motivation is to have a standard interface in user-programs, especially performance u-benchmarking toolkits like client-server-msgs-perf, so that we can run workloads against different types of logging-interfaces.

These revised interfaces may be useful even for general user-applications, beyond simply for performance benchmarking. Not all need to be done together. We can discuss and choose to implement some of these incrementally.

Proposed extensions to L3 interfaces

1. Extend l3_init() to take a logging-type argument, to choose between mmap(), fprintf(), write(), spdlog etc.
2. Rename l3_log_simple() to be simply l3_log(), with mmap()'ed logging being the default.
3. Consider adding a timestamp field in L3_ENTRY{}. Or, cache L3_LOG->idx counter as a proxy.
4. Support life-cycle of L3-logging { init, pause, resume, stop/deinit }, which manage themmap()-ed file.

NOTE: I plan to prorotype some of these suggested changes in part to address the asks in issue #43, while working on extended performance benchmarking in a dev-branch. That experience will guide us towards making an informed choice between these approaches.

Details

1. Extend l3_init() to take a logging-type argument, to choose between mmap(), fprintf(), write(), spdlog etc.

Suggested interface is something like: l3_init(enum_t l3_log_type, const char *log_file)

Possible enumerated types to support are:

• L3_LOG_DEFAULT == L3_LOG_MMAP
• L3_LOG_MMAP
• L3_LOG_STDOUT
• L3_LOG_FPRINTF
• L3_LOG_WRITE
• L3_LOG_SPDLOG
• ... whatever else we can think of in the future ...

Current usage of:

 44     const char *log = "/tmp/l3.c-small-unit-test.dat";
 45     int e = l3_init(log);

Will change to something like:

 44     const char *log = "/tmp/l3.c-small-unit-test.dat";
 45     int e = l3_init(L3_LOG_DEFAULT, log);

In case L3_LOG_FPRINTF or L3_LOG_WRITE is used, we will fopen() or open(), respectively, the specified log-file to return either a FILE * or a file-descriptor and it will be appropriately used in subsequent logging calls.

---

2. Rename l3_log_simple() to be simply l3_log(), with mmap()'ed logging being the default.

This is a naming simplification. l3_log() is the default logging scheme to mmap()-ed file.

Other interfaces would be on the lines of: l3_log_stdout(), l3_log_fprintf(), l3_log_write(), l3_log_spdlog(), ... Details to be worked out during finer designs.

---

3. Consider adding a timestamp field in L3_ENTRY{}. Or, cache L3_LOG->idx counter as a proxy.

The 1st comment I get when discussing current interfaces is whether we will save-off a time stamp for the log-entry. Currently we are not doing that.

Not having a timestamp makes it difficult for the user to map the dumped log-entry to some sequence of time.

Specifically when the log-contents roll-over in an mmap()-ed file, it becomes difficult to know what the most recent and latest log entry is.

We can do one of few things:

• Stash away the log's index; i.e. L3_LOG->idx along with the log-entry. This will at least establish some sequencing across log entries.

• The dump script should, by default, spit out log-entries in sorted order. This will make diagnostics easier to figure out the sequence of logged entries.

• Cache a hi-resolution time stamp, say RDTSC — Read Time-Stamp Counter, which is available on Intel processors. This Medium article explains how-to use this __rdtsc() interface. Quoting from this article:

"The best solution is of course to use the RDTSC function which counts ticks in clock cycles of the CPU; that means for every tick registered by the RDTSC one iteration or one cycle of the CPU has taken place. "

---

4. Support life-cycle of mmap()-ed file, by adding l3_deinit().

Currently the user's program has no way to turn OFF logging.

Consider a way to start / suspend / resume / stop logging through extensions that play with mmap(), munmap() and so on. Suspend / resume may just be L3-local state variables:

• l3_init() or, l3_log_init()
• l3_pause(). or, l3_log_pause() or, l3_log_suspend()
• l3_resume(). or, l3_log_resume()
• l3_deinit(). or, l3_log_stop()

[gregthelaw]

1. Yes, looks good.
2. Yes. I also think we should get rid of l3_log_fast, and just use the asm implementation on x86-64 and fallback to C elsewhere. One caveat, I need to work out how to fix the asm's use of TLS, right now it's super sketchy!
3. I like the idea of optionally logging rdtsc. Or even calling libc's clock_gettime(), which these days will avoid a syscall and use rdtsc but in a way that let's you map to actual time of day. However, it should be optional as it will have some performance overhead. That said, I think we can easily disambiguate the most-recent log entry because we store the index in the mmaped file, so l3_dump.py should look at the index, and print things in order.
4. Yes, would be good.

However, I'm not sure about doing 3+4 in the short term. These feel like good/useful features to have, but I think the priority should be getting traction. I don't think they'd influence whether cppcon is accepted talk. Over the years I have discovered that programming is a lot easier than marketing, but marketing is more important :) (Except for fixing l3_dump_log.py to pay attention to the index, we should just do that, as it stands it's basically a bug!)