Tmpe: Document logging stuff

Created on 28 Jul 2019  ยท  4Comments  ยท  Source: CitiesSkylinesMods/TMPE

I'll create a markdown doc with notes about best practice for logging seeing as it turned out to be more nuanced than we originally expected.

Some details in this comment: https://github.com/krzychu124/Cities-Skylines-Traffic-Manager-President-Edition/issues/349#issuecomment-512650775

@kvakvs Can you comment with some notes on the Format method(s) you added to the Log class? Which situations is it best to use those?

I'll do a draft of the doc and send a PR for review.

docs in-progress meta

Most helpful comment

  • Log.Trace, Log.Debug, Log.Info, Log.Warning, Log.Error -- these format the message in place,

    • โœ” Cheap if there is a const string or a very simple format call with a few args.

    • โœ” Cheap if wrapped in an if (booleanValue) { ... }

    • Log.Debug and Log.Trace are optimized away if not in Debug mode

    • โš  Expensive if multiple $"string {interpolations}" are used (like breaking into multiple lines)

  • Log.DebugFormat, Log.InfoFormat, ... - these format message later, when logging. Good for very-very long format strings with multiple complex arguments.

    • โœ” As they use format string literal, it can be split multiple lines without perf penalty

    • ๐Ÿ’ฒ The cost incurred: bulding args array (with pointers)

    • Prevents multiple calls to string.Format as opposed to multiline $"string {interpolations}"

    • Log.DebugFormat is optimized away, others are not, so is a good idea to wrap in if (boolValue)

    • โš  Expensive if not wrapped in a if () condition

  • Log.DebugIf, Log.WarningIf, ... - these first check a condition, and then call a lambda, which provides a formatted string.

    • โœ” Lambda building is just as cheap as format args building

    • ๐Ÿ’ฒ The cost incurred: each captured variable (pointer) is copied into lambda

    • โœ” Actual string is formatted ONLY if the condition holds true

    • Log.DebugIf is optimized away if not in Debug mode

    • โš  Cannot capture out and ref values

  • Log.NotImpl logs an error if something is not implemented and only in debug mode

All 4 comments

  • Log.Trace, Log.Debug, Log.Info, Log.Warning, Log.Error -- these format the message in place,

    • โœ” Cheap if there is a const string or a very simple format call with a few args.

    • โœ” Cheap if wrapped in an if (booleanValue) { ... }

    • Log.Debug and Log.Trace are optimized away if not in Debug mode

    • โš  Expensive if multiple $"string {interpolations}" are used (like breaking into multiple lines)

  • Log.DebugFormat, Log.InfoFormat, ... - these format message later, when logging. Good for very-very long format strings with multiple complex arguments.

    • โœ” As they use format string literal, it can be split multiple lines without perf penalty

    • ๐Ÿ’ฒ The cost incurred: bulding args array (with pointers)

    • Prevents multiple calls to string.Format as opposed to multiline $"string {interpolations}"

    • Log.DebugFormat is optimized away, others are not, so is a good idea to wrap in if (boolValue)

    • โš  Expensive if not wrapped in a if () condition

  • Log.DebugIf, Log.WarningIf, ... - these first check a condition, and then call a lambda, which provides a formatted string.

    • โœ” Lambda building is just as cheap as format args building

    • ๐Ÿ’ฒ The cost incurred: each captured variable (pointer) is copied into lambda

    • โœ” Actual string is formatted ONLY if the condition holds true

    • Log.DebugIf is optimized away if not in Debug mode

    • โš  Cannot capture out and ref values

  • Log.NotImpl logs an error if something is not implemented and only in debug mode

each captured value is copied into lambda

This is not true. A lambda captures a variable, not a value.

A pointer.
Does not matter when the log is executed right away and everything is still equal to their expected values, but this might be important when the log is deferred to logging thread and the string value is produced later.

A pointer.

Well... Not a pointer. Semantically - a variable. It's better to think this way. For a reference type, this will be a reference. For a value type, this will be a struct copy indeed. (Which might cause unexpected behavior, but it's off-topic for this issue.)

Was this page helpful?
0 / 5 - 0 ratings

Related issues

scottmcm picture scottmcm  ยท  29Comments

aubergine10 picture aubergine10  ยท  32Comments

FireController1847 picture FireController1847  ยท  28Comments

VictorPhilipp picture VictorPhilipp  ยท  34Comments

aubergine10 picture aubergine10  ยท  30Comments