[
https://issues.apache.org/jira/browse/GROOVY-12378?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Paul King updated GROOVY-12378:
-------------------------------
Description:
Follow-up to GROOVY-12354. Logging frameworks locate the caller of a logging
statement by walking the stack, and every frame Groovy's runtime inserts
between the statement and the logger makes that answer wrong:
* on a JVM, whenever a call is dispatched through the metaclass rather than
linked at the call site: the reflective cold tier when enabled, a dynamic
method name ({{log."$level"(msg)}}), an explicit {{invokeMethod}};
* in a GraalVM native image, always: GraalVM's method-handle interpreter frames
are visible to {{StackWalker}} and stack traces in both dispatch modes.
{{java.util.logging}} and Logback have package skip lists that cover this
(documented in the invokedynamic guide). Log4j2 has no equivalent hook, and its
tracker shows it never will: every wrapper-related report (LOG4J2-555,
LOG4J2-1028, LOG4J2-2975, discussions #2133 and #2243) is answered with "pass
the boundary FQCN" or "use {{LogBuilder.withLocation}}", and wrappers are
discouraged outright. The FQCN boundary cannot express Groovy's case, because
the runtime frames sit *after* the last logger frame. The other answer fits
exactly: {{LogBuilder.withLocation(StackTraceElement)}} lets the caller supply
the location, and Log4j2's own LOG4J2-1449 endorsed compile-time locations when
Scala asked for them (it stalled only on a garbage-free API shape, which Groovy
does not need).
The {{@Log4j2}} AST transform knows the class, method, source file and line of
every logging statement it rewrites, so it can supply the location at compile
time.
h3. Proposal
Add {{boolean staticLocation() default false}} to
{{groovy.util.logging.Log4j2}}. When set,
{{Log4j2LoggingStrategy.wrapLoggingMethodCall}} emits the builder form instead
of the guarded direct call:
{code:java}
// today
if (log.isInfoEnabled()) log.info(msg)
// with staticLocation = true
log.atInfo().withLocation($LOC$3).log(msg)
{code}
where {{$LOC$n}} is a {{private static final StackTraceElement}} per call site,
initialised from the annotated class name, enclosing method name, source file
name and line of the statement. No allocation or stack walk happens at run
time; the builder's own level check replaces the {{isXxxEnabled}} guard.
Overload mapping onto {{LogBuilder}}: message and parameterised {{log(String,
Object...)}} as-is; {{Marker}} first argument via {{withMarker}}; trailing
{{Throwable}} via {{withThrowable}}; {{Supplier}}, {{Message}},
{{CharSequence}} and {{Object}} arguments onto the corresponding {{log(...)}}
overloads. Statements the strategy does not rewrite today (see
{{LogASTTransformation.usesSimpleMethodArgumentsOnly}}) keep their current
handling.
Compatibility: {{LogBuilder}} exists since Log4j2 2.13 (2019);
{{withLocation(StackTraceElement)}} is an interface default that is a no-op for
foreign implementations, so it degrades to today's behaviour rather than
failing. If {{staticLocation = true}} and
{{org.apache.logging.log4j.LogBuilder}} cannot be resolved on the compile
classpath, the transform must report a compilation error, not silently emit the
old shape: an opt-in that does nothing would be worse than none.
h3. Why opt-in
The generated code is arguably better for every user: supplying the location
removes Log4j2's runtime stack walk, the expensive part of any
{{%C}}/{{%M}}/{{%F}}/{{%L}} layout, and fixes the metaclass-routed shapes on
the JVM that the GROOVY-12354 default flip does not reach. It is nevertheless
gated because the call shape changes (tests that mock the logger or inspect
generated bytecode will notice), because of the 2.13 floor, and because a
behaviour change to a widely used transform belongs in a point release as an
option first. Flipping the default, and a {{CompilerConfiguration}} switch so a
native build can enable it project-wide, are follow-ups once it has seen use.
h3. Scope
Only statements generated by the transform. A hand-declared logger field keeps
today's behaviour, for which the documented settings remain the answer.
{{@Log}}, {{@Slf4j}} and {{@Commons}} have no equivalent API (SLF4J's
{{CallerBoundaryAware}} is a boundary, not a location) and are out of scope.
h3. Tests and docs
* Transform tests: generated shape with and without the attribute; each
overload mapping; one {{StackTraceElement}} per call site with the statement's
line, not the class or method line; the compile error when {{LogBuilder}} is
absent.
* Behavioural test with {{log4j-core}}: a {{%C.%M(%F:%L)}} layout reports the
annotated class and statement line when the call is made through
{{log."$level"(msg)}}, which is wrong without the option on every Groovy
version.
* Document the attribute on {{@Log4j2}} and add it to the "Caller location"
section of the invokedynamic guide, including the native-image subsection, as
the recommended setting for Log4j2 users there.
> @Log4j2: staticLocation option to emit compile-time caller locations via
> LogBuilder.withLocation
> ------------------------------------------------------------------------------------------------
>
> Key: GROOVY-12378
> URL: https://issues.apache.org/jira/browse/GROOVY-12378
> Project: Groovy
> Issue Type: Improvement
> Reporter: Paul King
> Assignee: Paul King
> Priority: Major
>
> Follow-up to GROOVY-12354. Logging frameworks locate the caller of a logging
> statement by walking the stack, and every frame Groovy's runtime inserts
> between the statement and the logger makes that answer wrong:
> * on a JVM, whenever a call is dispatched through the metaclass rather than
> linked at the call site: the reflective cold tier when enabled, a dynamic
> method name ({{log."$level"(msg)}}), an explicit {{invokeMethod}};
> * in a GraalVM native image, always: GraalVM's method-handle interpreter
> frames are visible to {{StackWalker}} and stack traces in both dispatch modes.
> {{java.util.logging}} and Logback have package skip lists that cover this
> (documented in the invokedynamic guide). Log4j2 has no equivalent hook, and
> its tracker shows it never will: every wrapper-related report (LOG4J2-555,
> LOG4J2-1028, LOG4J2-2975, discussions #2133 and #2243) is answered with "pass
> the boundary FQCN" or "use {{LogBuilder.withLocation}}", and wrappers are
> discouraged outright. The FQCN boundary cannot express Groovy's case, because
> the runtime frames sit *after* the last logger frame. The other answer fits
> exactly: {{LogBuilder.withLocation(StackTraceElement)}} lets the caller
> supply the location, and Log4j2's own LOG4J2-1449 endorsed compile-time
> locations when Scala asked for them (it stalled only on a garbage-free API
> shape, which Groovy does not need).
> The {{@Log4j2}} AST transform knows the class, method, source file and line
> of every logging statement it rewrites, so it can supply the location at
> compile time.
> h3. Proposal
> Add {{boolean staticLocation() default false}} to
> {{groovy.util.logging.Log4j2}}. When set,
> {{Log4j2LoggingStrategy.wrapLoggingMethodCall}} emits the builder form
> instead of the guarded direct call:
> {code:java}
> // today
> if (log.isInfoEnabled()) log.info(msg)
> // with staticLocation = true
> log.atInfo().withLocation($LOC$3).log(msg)
> {code}
> where {{$LOC$n}} is a {{private static final StackTraceElement}} per call
> site, initialised from the annotated class name, enclosing method name,
> source file name and line of the statement. No allocation or stack walk
> happens at run time; the builder's own level check replaces the
> {{isXxxEnabled}} guard.
> Overload mapping onto {{LogBuilder}}: message and parameterised {{log(String,
> Object...)}} as-is; {{Marker}} first argument via {{withMarker}}; trailing
> {{Throwable}} via {{withThrowable}}; {{Supplier}}, {{Message}},
> {{CharSequence}} and {{Object}} arguments onto the corresponding {{log(...)}}
> overloads. Statements the strategy does not rewrite today (see
> {{LogASTTransformation.usesSimpleMethodArgumentsOnly}}) keep their current
> handling.
> Compatibility: {{LogBuilder}} exists since Log4j2 2.13 (2019);
> {{withLocation(StackTraceElement)}} is an interface default that is a no-op
> for foreign implementations, so it degrades to today's behaviour rather than
> failing. If {{staticLocation = true}} and
> {{org.apache.logging.log4j.LogBuilder}} cannot be resolved on the compile
> classpath, the transform must report a compilation error, not silently emit
> the old shape: an opt-in that does nothing would be worse than none.
> h3. Why opt-in
> The generated code is arguably better for every user: supplying the location
> removes Log4j2's runtime stack walk, the expensive part of any
> {{%C}}/{{%M}}/{{%F}}/{{%L}} layout, and fixes the metaclass-routed shapes on
> the JVM that the GROOVY-12354 default flip does not reach. It is nevertheless
> gated because the call shape changes (tests that mock the logger or inspect
> generated bytecode will notice), because of the 2.13 floor, and because a
> behaviour change to a widely used transform belongs in a point release as an
> option first. Flipping the default, and a {{CompilerConfiguration}} switch so
> a native build can enable it project-wide, are follow-ups once it has seen
> use.
> h3. Scope
> Only statements generated by the transform. A hand-declared logger field
> keeps today's behaviour, for which the documented settings remain the answer.
> {{@Log}}, {{@Slf4j}} and {{@Commons}} have no equivalent API (SLF4J's
> {{CallerBoundaryAware}} is a boundary, not a location) and are out of scope.
> h3. Tests and docs
> * Transform tests: generated shape with and without the attribute; each
> overload mapping; one {{StackTraceElement}} per call site with the
> statement's line, not the class or method line; the compile error when
> {{LogBuilder}} is absent.
> * Behavioural test with {{log4j-core}}: a {{%C.%M(%F:%L)}} layout reports the
> annotated class and statement line when the call is made through
> {{log."$level"(msg)}}, which is wrong without the option on every Groovy
> version.
> * Document the attribute on {{@Log4j2}} and add it to the "Caller location"
> section of the invokedynamic guide, including the native-image subsection, as
> the recommended setting for Log4j2 users there.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
