Skip to content

Instantly share code, notes, and snippets.

@kinchungwong
Last active January 28, 2019 22:08
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save kinchungwong/56f8dadbecf43e67bd1139daa1caf32e to your computer and use it in GitHub Desktop.
Save kinchungwong/56f8dadbecf43e67bd1139daa1caf32e to your computer and use it in GitHub Desktop.
Thoughts - OpenCV Logger Revamp - 2019-01-28

Decision needed

  • Need to decide how we want to implement the "tag" feature of logging.
  • Check the "Accompanying a tag with each log message" section for some options.

Thoughts - OpenCV Logger Revamp - 2019-01-28

Front-end vs middleware vs backend

  • Front-end refers to how the library code and application code uses logging.
    • Use of the logging function or macro
    • Use of any facilities in support of logging
    • Upkeeping of any data (for example, "tag" or "category") in support of logging
    • Local customizations of logging behavior within a compilation unit, or within a part of the library or application.
  • Middleware refers to how the features of logging are enabled (implemented)
    • Filtering by log level
    • Tag-specific filtering by log level
    • Line-of-code filtering
  • Backend refers to the sending of filtered log messages and data to the final recipient.
    • It might be another logging framework.
    • The simplest recipient is just printing everything to standard stream or error stream.

Constraints on code change

  • Importance of front-end stability; namely, library code only needs to be recompiled without modification for changes in the logging facility.
    • Note: since existing library code doesn't seem to specify any meaningful tag, scattered library code changes are needed to make use of the tag-based filtering feature.
    • In general, we want to minimize the amount of additional code (within library code) needed to make use of logging facility.
  • Importance of front-end compatibility; namely, library code that uses the legacy frontend only needs to be recompiled without modification for the newly revamped logging facility.
  • Importance of C++ exported functions and types stability
    • Prefer exporting non-member functions.
    • Prefer primitives in exported function arguments and variables.
    • Avoid any changes to types already exported in an earlier library version.

Configurability

  • The ability to change behavior.
  • Configuration changes that require a small code change and recompile:
    • Integration with a different logging backend
    • Change the string output format when using the default backend
    • Changing of compile-time logging stripping threshold
  • Configuration changes at runtime
    • Change the log level threshold for log messages associated with a particular tag

Runtime overhead concerns

  • Cost of gathering various context information about a log message
  • Cost of checking a log level variable enum
  • Cost of checking a log level by name
    • By exact string match
    • By hash comparison only
    • By hash comparison, followed by exact string match
    • By string prefix, delimited
    • By string prefix, flexible
    • By wildcard
    • By regular expressions
  • Cost of formatting the content of a log message into a string
  • Cost (and worst-time latency) of calling a function protected by mutex
    • Contention between threads trying to acquire the same mutex
  • Blocking vs non-blocking operations
    • (Also known as: synchronous logging vs asynchronous logging)
    • In asynchronous logging, logging arguments need to be formatted and copied into a buffer (or a queue of buffers). In C++, the lifetime of logging arguments can be as short as the duration of the logging invocation.

Implementation techniques

  • Heavy use of C/C++ macros is unavoidable.
  • C/C++ macros need to be understandable and documented, in case it needs to be troubleshooted.
    • A design document for the main logging macro will be written.

Accompanying a tag with each log message

  • DECISION_NEEDED

Option 1. A tag is just a string; no more.

Option 1a. A tag (string) is only used for backend filtering; does not participate in frontend filtering.

  • Treat it like a string, and send it to the backend.
  • This is the approach used in Android "logcat".
  • Message formatting always take place, since filtering does not happen until the formatted message and its tag arrives at the backend.

Option 1b. A tag (string) is used for front-end filtering

  • Advantage: filtering can happen early, so that message formatting can be skipped if it is to be ignored.
  • Runtime overhead: string matching against a configured list of tag names

Option 2. A tag consists of a string (name) and some data that facilitates filtering.

Option 2a. Precompute and store the hash of the string along with the tag

  • Runtime overhead reduction.
    • Faster string matching against a configured list of tag names.
    • Hash comparison does not involve looping over null-terminated strings.
  • Limitations
    • Hashing does not help with wildcard or regex matching of tag names.
  • Requirements
    • The hash function (and the bit width) has to be chosen, instead of using compiler-vendor-specific implementation provided with the C++ standard library.

Option 2b. Associate the tag with a log level variable

  • Technically, a log level variable is the memory address to a mutable integer.
  • A log level variable can be accessed (read/written) by any code at any time.
  • (See discussion on atomicity and/or protection against compiler optimization passes)
  • Requirements - registration of the variable
    • Registration is needed if some code needs to access the variable by tag name (string), without having C++ access to the variable or being located in the same compilation unit.
    • Registration puts the name and the address of the variable in a table.
    • Registration is done with a singleton "manager".
    • There are additional implementation requirements for that registration manager.

Option 3. An existing library-wide introspection facility (class or type info) is used as the tag

  • Currently, OpenCV does not have such facility, so there is nothing we can reuse.
  • cv::Algorithm is similar, but not every class in C++ inherits from it, which would be a bad idea anyway.
  • With C++11 and RTTI, the std::type_index could be used.

Option 4. Ability to accept more than one kind of tagging options

  • (To be explored. Currently not on the plan.)

Option 5. Ability to associate zero, one, or multiple tags with each logging message

  • (To be explored. Currently not on the plan.)

Option 6. Treat the "tag" as a C/C++ macro argument; allow logging macro to derive additional names (C++ identifiers or other preprocessor definitions) by macro string concatenation operators.

  • (Can be used in combination with options listed above.)
  • (To be explored more fully.)

Previous discussions on log tag, log scope, and capturing module and/or component information

  • This is a recap on previous discussions.
  • Important reminder. Decisions made in previous discussions do not always carry over to the current design.

Discussion on "component" from original OE-11 RFC

  • https://github.com/opencv/opencv/wiki/OE-11.-Logging
  • The original OE-11 RFC calls for a "component" parameter.
  • It is used to identify certain parts or areas of the OpenCV library.
  • It is supposed to facilitate log filtering, both programmatically and visually.

Discussion on "log scope"

  • A "log scope" is a hierarchical (multiple level of nesting) organization of components.
  • Examples of "log scopes" are: "module", "class", "functions", "events", ...
  • opencv/opencv#11003 (comment)
  • It was followed up with an attempt to formalize "log scope", but those attempts were deemed too rigid, and the amount of code needed to manage such data is deemed too much.
  • opencv/opencv#11003 (comment)
  • opencv/opencv#11003 (comment)
  • It was followed up with an attempt to simplify "log scope", keeping only the requirement that a "log scope" can optionally have a parent "log scope". That was also deemed too much.
  • opencv/opencv#11003 (comment)
  • There was also concern about runtime overhead, because creating a log message for a deeply nested log scope requires checking the log level rules for all parent log scopes.
  • opencv/opencv#11003 (comment)

A nudge toward learning from existing logging designs rather than blue-skying

Discussion on "log tag", referencing the Android "logcat" design

  • https://developer.android.com/studio/command-line/logcat
  • In Android "logcat", a tag is just a name string.
  • In Android "logcat", log filtering happens in the backend. Therefore, the log message is always formatted and sent. Tag-based filtering happens at the recipient, which is typically a remote computer attached to a development device.

Discussion on "category", referencing the GStreamer design


Accompanying line-of-code information with each log message

Compiled binary file size concerns

  • When every log message invokes the special macros __FILE__ and __FUNCTION__, the compiled binary files will contain many string literals. This will increase the compiled binary file size.

Requirements for a singleton logging manager

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment