Log message assembled by concatenation or interpolation instead of a template

ID

vbnet.maintainability.logger_constant_template

Severity

info

Remediation Complexity

trivial

Remediation Risk

low

Remediation Effort

low

Resource

Api Design

Language

VB.NET

Description

Reports a log message that is assembled before the logging call receives it - a concatenation with & or + that joins a string literal to a value, or an interpolated $"…​" string - rather than passed as a constant template with the values as separate arguments. The call is recognised by a receiver named like a logger (log, _logger, Me.Logger) together with a level method (Debug, Info, Information, Warn, Warning, Error, Fatal, Trace, Verbose, Critical, or the LogXxx forms), and covers both the message-first and the exception-first overloads. A concatenation passed as a later argument - a value being formatted into an already-constant template - is not reported, and neither is a concatenation whose operator sits inside the literal itself, as in "Q & A reloaded". Test sources are excluded.

The level method may be written escaped with brackets, as in log.[Error](…​), which VB requires when the name collides with a keyword; that form is recognised. One coverage gap is worth stating: a message pre-built with String.Format inside the call, as in log.Debug(String.Format("Bytes for {0}", msg)), has the same problem - the text is assembled before the logger decides whether the level is enabled - but it is not reported.

Rationale

Once the values are pasted into the string, they stop being data. A logging backend that receives a constant template plus its arguments can emit each value as a named field, so the resulting event can be queried - every log line for one order id, a latency percentile across a million requests - and the template itself becomes a stable identity that groups every occurrence of the same event. A message assembled beforehand arrives as one opaque sentence: the fields are gone, each line is textually unique, and retrieving anything from it means regular expressions over log text that break the next time the wording changes. The cost is paid whether or not the message is ever emitted, which is the part that surprises people. A logging call takes its arguments by value, so the concatenation runs, allocates its intermediate strings and formats every value at the call site - and only then does the logger check whether the level is enabled and, in the usual production configuration, discard the result. A Debug call in a hot loop therefore costs its full formatting even in a deployment where debug logging is switched off, which is exactly the code that gets left in because it looks free. Interpolation hides the same behaviour behind friendlier syntax.

The following code illustrates the pattern detected by this rule:

Public Sub Accept(orderId As Integer, total As Decimal)
    ' FLAGGED: Log message assembled by concatenation or interpolation instead of a template
    _logger.LogInformation("Order " & orderId & " accepted")

    ' FLAGGED: Log message assembled by concatenation or interpolation instead of a template
    _logger.LogInformation($"Order {orderId} totalling {total} accepted")

    ' FLAGGED: Log message assembled by concatenation or interpolation instead of a template
    log.Warn("Retrying order " + CStr(orderId))

    ' FLAGGED: Log message assembled by concatenation or interpolation instead of a template
    Me.Logger.Debug("Running total is " & total & " for order " & orderId)

Remediation

Pass a constant template as the message and let the logger supply the values: with Microsoft.Extensions.Logging, named placeholders as in _logger.LogInformation("Order {OrderId} accepted", orderId); with a logger that takes positional arguments, the {0}-style overload. Keep the exception in the exception parameter rather than concatenating ex.Message into the text, so the stack trace survives. Where a genuinely expensive value has to be computed for the message, guard it with the logger’s level check (If _logger.IsEnabled(LogLevel.Debug) Then) instead of paying for it unconditionally.

' Before: one opaque sentence, formatted even when the level is off
_logger.LogInformation("Order " & orderId & " accepted for " & total)

' After: queryable fields, formatted only if the level is enabled
_logger.LogInformation("Order \{OrderId} accepted for \{Total}", orderId, total)

Configuration

This detector does not need any configuration.