Add Conditional attribute to LogDebug and LogTrace

[cilerler]

LogDebug and LogTrace should be decorated with Conditional attribute and tied with defined DEBUG & TRACE in order to not evaluate expensive objects on production.

Reproduce steps

project.json

{
  "buildOptions": {
    "emitEntryPoint": true,
    "debugType": "portable",
    "define": [ ]
  }
}

appsettings.json

  "Logging": {
    "IncludeScopes": true,
    "LogLevel": {
      "Default": "Information",
      "System": "Error",
      "Microsoft": "Error"
    }
  }

AddressRepository.cs

_logger.LogDebug(JsonConvert.SerializeObject(address));
_logger.LogTrace(JsonConvert.SerializeObject(address));

Actual result

Evaluates JsonConvert.SerializeObject(address)

Expected result

It should not evaluate JsonConvert.SerializeObject(address) unless DEBUG and/or TRACE is set on appsettings.json.

[BrennanConroy]

Calling _logger.LogDebug(JsonConvert.SerializeObject(address)) will always evaluate JsonConvert.SerializeObject(address) if you don't want it to evaluate if DEBUG or TRACE isn't set then you need to wrap it in a call to if (_logger.IsEnabled(LogLevel.Debug))

[cilerler]

if you don't want it to evaluate if DEBUG or TRACE isn't set then you need to wrap it in a call to if (_logger.IsEnabled(LogLevel.Debug))

I'm not sure if I understood correctly, what other options I have?

All I need is not decorating my code with #if or if (_logger.IsEnabled(LogLevel.Debug)) stuff for each logging request and I would like MLF to evaluate those ONLY if proper word (DEBUG, TRACE) defined in project.json

I believe if you decorate code here with [Conditional("DEBUG")] attribute, it should no longer evaluate it since no one can call the method. Is that a wrong assumption?

proof of concept

if you will remove the #define MLF part it will not evaluate.

#define MLF

void Main()
{
    Log(new Address { State = "FL", City = "Boca Raton" });
}

[Conditional("MLF")]
private void Log(Address address)
{
    Console.WriteLine(JsonConvert.SerializeObject(address));
}


public class Address
{
    public Address()
    {
        Console.WriteLine("Initializing address");
    }

    public string City { get; set; }
    public string State { get; set; }
}

[BrennanConroy]

#define DEBUG and LogLevel.Debug represent 2 entirely different concepts.

You can add your custom behavior to your programs by adding extension methods that use the Conditional attribute.

[cilerler]

Sure thing both of those concepts have different parts but this doesn't mean that they don't have common area. Therefore please re-consider to tie LOGGING with DEFINITIONS (not even need to be DEBUG and/or TRACE if you don't want to, simply LOGDEBUG, LOGTRACE, LOGINFORMATION etc. can serve the purpose)

This would give us great benefit of eliminating debug code run on production settings as a native way.

By the way, thank you for mentioning to implement it as extension method. It solves my need but still I believe native way would have more benefits. 👍

If anyone interesting with that feature here is the code

[roji]

+1 on this, at the very least for LogTrace. For performance-sensitive applications, the overhead of repeatedly checking whether the loglevel is enabled can be unacceptable, adding [Conditional("DEBUG")] would mitigate this in release. This seems to be a pretty standard feature with logging packages (e.g. NLog).

[roji]

Another option is to add separate methods, i.e. ConditionalLogTrace, ConditionalLogDebug which would be identical to LogTrace, LogDebug apart from having [Conditional("DEBUG") on them.

[cilerler]

@roji having separate methods wouldn't be nice. It must be tied with Conditional attribute in order to be ignorable by compiler.

[roji]

@cilerler, what I'm proposing is indeed tied with the Conditional attribute, but rather than adding it to the existing LogTrace, LogDebug it would be added to new methods. This would provide programmers with the choice of saying "log this trace message in release" or not, based on whether that call would be too expensive or not.

The problem is that in many cases it makes sense to log some debug- (and even trace-) level messages even in release builds, just not necessarily all debug/trace messages.

[cilerler]

My bad, didn't get your point at first time, makes sense. 👍 Thank you for the explanation.

[davidfowl]

I have to say I agree with @BrennanConroy. Conflating compile time constructs with the logging system isn't correct. You can already do what you want today just not using extension methods, I don't see why we should bake those in.

[roji]

@davidfowl (and @BrennanConroy) I don't think anyone's conflating things - I think we fully understand the difference between #define DEBUG and LogLevel.Debug (it's true that it's unfortunate they have the same name).

This is simply about permitting developers to avoid the performance penalty of checking if an event should be logged, for performance-sensitive applications. It makes sense for trace and debug log events to always get logged in debug builds (since performance doesn't matter and we're debugging), but in release the cost may be too high.

Can this be implemented via external wrappers rather than baked into the library? Sure. But then the same question can be asked of extensions methods such as LogDebug(), which could be left out (this is just an absurd example).

[davidfowl]

This is simply about permitting developers to avoid the performance penalty of checking if an event should be logged, for performance-sensitive applications. It makes sense for trace and debug log events to always get logged in debug builds (since performance doesn't matter and we're debugging), but in release the cost may be too high.

I absolutely disagree. One of the features of the logging system is being able to change the level as the application is running. Compiling away log statements is anti this. I think what you want it's a different function altogether and should not be in the core, at least not yet.

Can this be implemented via external wrappers rather than baked into the library? Sure. But then the same question can be asked of extensions methods such as LogDebug(), which could be left out (this is just an absurd example).

I think it should be, at least to begin with. The bar is higher for things going into the main library. If it turns out people want to compile away their statements as a mainline scenario we can look at it. For now I'd suggest making another library with ConditonalBlah log methods.

[roji]

I absolutely disagree. One of the features of the logging system is being able to change the level as the application is running. Compiling away log statements is anti this. I think what you want it's a different function altogether and should not be in the core, at least not yet.

Sure, until one starts to remove LogTrace() invocations because these are slowing the application down, even if disabled. You guys have done some pretty amazing performance-oriented work recently, so this shouldn't be a coming out of the blue. I've worked in many scenarios where putting a LogTrace() in some hot-path is simply unacceptable, and at the same time it's important to be able to understand what's going on in there, when running a debug build. So you compromise by compiling those specific problematic LogTrace() invocations out of your release build.

However, since conditional wrappers for logging can be implemented externally, at least it's possible to leave these out to some external library.

[davidfowl]

Sure, until one starts to remove LogTrace() invocations because these are slowing the application down, even if disabled.

That's why you use the IsEnabled check. We do this ourselves in hot paths. That's why it should always be there, just switched off until necessary. Having it compiled away takes away some usefulness. There might be scenarios where that's warranted but it's not the mainline use case.

[roji]

Sure, until one starts to remove LogTrace() invocations because these are slowing the application down, even if disabled.

That's why you use the IsEnabled check. We do this ourselves in hot paths. That's why it should always be there, just switched off until necessary. Having it compiled away takes away some usefulness. There might be scenarios where that's warranted but it's not the mainline use case.

As I wrote above, the whole point here is that calling IsEnabled is too much of a performance hit in certain scenarios. Is this something that happens in mainstream code? No. But if you're trying to make .NET a high-performance platform, then these things matter.

Again, I find it really fine to say that this kind of performance-sensitive app is very rare, and therefore this feature doesn't belong in the main library (especially since it can be implemented outside). But it's important to acknowledge that scenarios that warrant this do exist.

[davidfowl]

As I wrote above, the whole point here is that calling IsEnabled is too much of a performance hit in certain scenarios. Is this something that happens in mainstream code? No. But if you're trying to make .NET a high-performance platform, then these things matter.

Show me the numbers.

[roji]

In, say, a low-latency algo-trading application, whatever the cost of branching on whether logging is enabled or not, that's one branch that can and should be eliminated. And that's regardless of much that check actually costs.

[damageboy]

I personally use the same construct as provided by NLog, i.e. ConditionalDebug() and ConditionalTrace() for exactly the same reasons.

We have some very high perf code, including code-generated code that we lace with these variants of NLog code, and we teach developers to always carefully think when calling a logging function about "where" they are in the code:

• if this is a tight loop / high sensitivity code, they should always use ConditionalXXX()
• if not, use the regular variant.

The effects of these logging functions/constructs are multi-fold:

• JIT'd code size
• Inlining
• Readability (ConditionalXXX() being more readable than if (Log.IsDebugEnabled) Log.Debug() in NLOG-ish)

Another niche side-effect is that VS/R# know how to mark the ConditionalXXX() statements as inactive when the selected configuration is Release/Debug, which makes reviewing code a more pleasant procedure.

In theory there's no-one/nothing limiting me from making these as extension methods and putting the [Conditional()] attribute on my own extensions, but I fail to see the big deal with providing this for ALL users to be able to benefit from if they wish to do so.

[muratg]

We are closing this issue because no further action is planned for this issue. If you still have any issues or questions, please log a new issue with any additional details that you have.