Overhaul compiler tracing and logging infrastructure

[0xdaryl]

This PR begins to overhaul the diagnostic tracing and logging infrastructure in
the compiler component. Much of the motivation and proposed design was
presented at the Oct 24, 2024 OMR Architecture Meeting [1] and interested
parties are encouraged to watch that presentation for more background.

[1] https://www.youtube.com/watch?v=n9A0-2p-x8o

Further changes to improve the performance and functionality of the diagnostic
capabilities of the compiler component using this PR as a baseline will come
later.

NOTE: This is a breaking change for projects consuming the OMR compiler component
that use the existing tracing and logging infrastructure. Some work (tedious, but not
difficult) will be required to adapt to the new APIs. See below for details.

I intend to communicate with all known downstream consumers of the OMR compiler
informing them of the change and offering assistance with migration if
necessary (or, as in the case of OpenJ9, doing the work outright). My goal is
to have this PR merged with at least one month's grace before the next Eclipse
OMR release.

Goals (non-exhaustive)

• Reduce the pathlength overhead of tracing and logging diagnostic functions.
  Methods are significantly slower to compile when logging is enabled (e.g.,
  4x-20x in some measurements), and logged methods are a significant source of
  non-determinancy when investigating problems.
• Improve the memory resource consumption of diagnostic functions. Many
  diagnostic reporting operations consume far more memory than is necessary, and
  much of this memory is not reclaimed during a compilation which affects
  non-diagnostic operations and optimizations in the compiler.
• Standardize on a unified, simplified, extensible, and documented API for
  tracing and logging.
• Enable creative debugging techniques by allowing diagnostic functions to be
  used with more than just the log file on the TR::Compilation object
• Reduce technical debt by simplifying, refactoring, and documenting the
  diagnostic functions.

Contributions

• Introduces a TR::Logger abstract class declaring a lightweight logging API
  and a family of useful logger implementations. Detailed documentation for
  Loggers can be found in doc/compiler/debug/Loggers.md

• Provides several implementations of Loggers for various purposes and situations,
  some of which (for example, the CStdIOStreamLogger) with a significantly shorter
  pathlength for writing diagnostic content than the current implementation.

• Replaces TR::FILE with TR::Logger as the currency for tracing and
  logging. Ensures a TR::Logger object is passed to all diagnostic functions.

  Currently, many diagnostic functions make an assumption that their output will
  go to the log file found on the TR::Compilation object. This makes it
  difficult to support creative debugging techniques (such as dumping a data
  structure to an alternate file or simply stdio) because the destination is
  fixed. Many diagnostic functions accept TR::FILE pointers for the output
  destination, but this limits their output to a file.

  To improve versatility, this PR ensures all diagnostic functions accept a
  TR::Logger parameter when appropriate. This is in lieu of any TR::FILE
  parameters that may currently be passed. To improve consistency in the APIs,
  the parameter is nearly always passed as the first parameter. There are
  circumstances where a TR::Logger is not passed, but only in situations where
  the logging destination can be obviously derived from the context.

• Deprecates and removes where possible existing redundant diagnostic output
  mechanisms.

  There are several means in use for producing diagnostic output. These include:

  • A traceMsg() macro
  • TR_Debug::trace() function
  • A diagnostic() macro (for DEBUG builds only)
  • Raw trfprintf() / TR::IO::fprintf() family of functions
  • Raw fprintf() family of functions (CPP runtime)

  All uses of these diagnostic functions or macros have been scrutinized, and
  most have been converted to a Logger equivalent. Their usage is deprecated,
  and in some cases have been removed entirely from the code base.

• Ensures all diagnostic output is guarded with a trace option.

  Currently, there are many diagnostic artifacts written unconditionally to the
  log file. This needlessly increases the size of a log file and incurs an
  overhead cost, and there is no way for a user to suppress it. Such output is
  also often provided without needed context, which greatly diminishes its
  usefulness.

  With this PR, all diagnostic output is now guarded with a trace option.

  A common pattern for guarding a single output function is the following:

  if (trace)
    {
    log->printf("My output: %d\n", myInt);
    }
  

  To improve code readability and density, convenience macros have been introduced
  for the print family of functions that should be used in lieu of the pattern
  above. For example, the code above is equivalent to:

  trprintf(trace, log, "My output: %d\n", myInt);
  

  If multiple output functions share a single guard then the macros should not be
  used. This PR uses the convenience macros where appropriate.

  With the introduction of loggers, it is possible to catch unguarded output by
  introducing an "asserting logger" that can be installed under control of a
  debug option. This will generate a JIT assert if any of printing functions are
  called, allowing a developer to identify unguarded diagnostic output. Such a
  logger is also useful to add to a testing mode of a project that the OMR
  compiler is built into so that detecting unguarded output becomes part of its
  regular testing.

• Makes guarding diagnostic output by the mere existence of a log file an
  anti-pattern.

  There are currently many places in the JIT where diagnostic output is
  controlled by the mere presence or absence of a log file. This is an
  anti-pattern and should be replaced with a proper trace option guard. This PR
  converts many of such checks to trace options, however some still remain in the
  code due to complexities in refactoring. These should all be eliminated in
  future PRs.

• Chooses the most efficient API function for the information to output.

  This PR introduces specialized output functions that do not expect all
  diagnostic output to be C strings that may contain format specifiers. For
  instance, new variants to output a constant string or a single character are
  provided that do not expect varargs or format specifiers. The goal is to
  provide alternatives to developers to reduce the pathlength to output an
  unformatted string or character.

Testing

This PR was tested on 64-bit and 32-bit compilers in OMR and the OpenJ9 project
on all architectures. An asserting logger was installed in place of the default
logger to identify any unguarded tracing output, and any remaining issues
were fixed.

JitServer and JitDump paths were tested on x86 Linux as well.

Requirements for downstream projects

Downstream projects consuming the OMR compiler may have to adapt to the new
logging infrastructure. The main requirements are:

• Choose and define the TR::Logger you want to use. The default Logger in OMR
  simply eats its input.
• Use TR:Logger instead of TR::FILE for diagnostic functions
• Replace uses of deprecated tracing and logging functions and macros such as
  traceMsg() and trfprintf with equivalent functions on the logger (e.g.,
  printf())

I considered maintaining the existing infrastructure in parallel with the new
infrastructure, but with the amount of duplication, ugliness of the code,
performance implications of morphing one API into another, and the relatively
small number of known downstream consumers, I decided against it.

[0xdaryl]

FYI @mstoodle @vijaysun-omr @mpirvu @zl-wang @dsouzai @ymanton @jdmpapin @knn-k @kevindean12 @gita-omr @hzongaro @r30shah @JamesKingdon @klangman

While seemingly a large PR, the bulk of this PR consists of refactored changes to the existing tracing/diagnostic/logging sites to use the new logging infrastructure.

The main new contributions can be found in compiler/ras/Logger.hpp and compiler/ras/Logger.cpp. Documentation for Loggers can be found in doc/compiler/debug/Loggers.md.

[kevindean12]

@0xdaryl This looks good to me overall. One point of clarification, just to make sure I'm following and can make the right choices about what I do and don't want to override downstream: it looks like (absent any downstream overrides of Options::getDefaultLogger() or Options::createLoggerForLogFile()) if I provide a log file name via a log= option, it will by default use the TR::CStdIOStreamLogger to write to the specified log file (from whatever places other options might cause there to be logging output at that point, say tracing of trees after optimization passes for example). Is that right?

[0xdaryl]

Yes, that's right. I had forgotten (because it has been a while since I looked at that part of the code :-) ) that it will wrap the TR::CStdIOStreamLogger with a TR::CircularLogger if the traceFileLength JIT option is used. This is exactly the same behaviour as it was before this PR. So you do not have to do anything downstream to get this functionality.

[kevindean12]

Yes, that's right. I had forgotten (because it has been a while since I looked at that part of the code :-) ) that it will wrap the TR::CStdIOStreamLogger with a TR::CircularLogger if the traceFileLength JIT option is used. This is exactly the same behaviour as it was before this PR. So you do not have to do anything downstream to get this functionality.

Great! Thanks for the confirmation.

[0xdaryl]

Jenkins build all

[0xdaryl]

Jenkins build all

Fixed the missing include on the AIX build.

[dsouzai]

Overall LGTM; I have one minor question.

[dsouzai]

Wouldn't it be useful to actually print out the data passed to this logger in the assert?