Skip to content

Conversation

vy
Copy link
Member

@vy vy commented Jan 25, 2024

Motivated by #2204 and making log4j-api-2.x adaptable by Log4j 3, this work revamps the StatusLogger to make it self-contained and testable. Noteworthy changes are as follows:

Simplifications and improvements for self-contained implementation

  • Dependencies on PropertiesUtil and LoaderUtil are eliminated. To do so, simple system property and resource from classpath readers are implemented. See the new StatusLogger.Config class.
  • Dependency on SimpleLogger is eliminated. The default listener is fixed to a StatusConsoleListener which dumps StatusData#getFormattedStatus() output to a PrintStream.
  • [behavioural change] StatusConfiguration does not create a new StatusListener each time anymore. That is, there will not be a dedicated StatusConsoleListener for every each LoggerContext. Existing behaviour was already problematic:
    • Each StatusConfiguration created was resetting the StatusLogger listener level (hence, last one always wins)
    • Created StatusConsoleListeners weren't cleaned up
    • Even though there was a dedicated listener for each LoggerContext, there is always a single StatusLogger, defeating the purpose of per-LoggerContext listeners
  • Hence, we embraced a simpler model: There is one default StatusConsoleListener for the StatusLogger singleton. If user overrides the StatusLogger configuration in a log4j2.xml, last read configuration will be the effective one.
  • Several StatusLogger javadocs are rewritten.
  • LowLevelLogUtil is removed.
  • AbstractLogger doesn't act on log4j2.messageFactory and log4j2.flowMessageFactory properties anymore; its message and flow message factories are fixed to ParameterizedMessageFactory and DefaultFlowMessageFactory, respectively. This was necessary to avoid cyclic instantiation: PropertiesUtil is using StatusLogger, which extends AbstractLogger, which indirectly reaches back to PropertiesUtil for these two functionalities removed.

Testing-related changes

  • StatusLogger is made extendable (to enable mocking/spying)
  • StatusLogger static instance is made replaceable (to enable substituting the implementation for tests)
  • Leveraging these, @UsingStatusLoggerMock introduced

TODO

  • Introduce log4j2.messageFactory and log4j2.flowMessageFactory properties back
  • Update docs
  • Fix last remaining failing tests (already fixed some)
  • Check if there are any refactoring opportunities for @UsingStatusListener

Review kit

  1. Start with reviewing changes in o.a.l.l.status package: StatusLogger, StatusData, StatusConsoleListener, etc.
  2. Review StatusConfiguration
  3. Review o.a.l.l.test.junit.StatusLoggerMockExtension to see testing conveniences
  4. Review the rest

@vy vy added api Affects the public API tests Pull requests or issues related to tests labels Jan 25, 2024
@vy vy added this to the 2.23.0 milestone Jan 25, 2024
@vy vy requested review from jvz, ppkarwasz and rgoers January 25, 2024 21:33
@vy vy self-assigned this Jan 25, 2024
@rgoers
Copy link
Member

rgoers commented Jan 25, 2024

I will go through this as I can. It might take a couple of days depending on my available time. However, the description of the solution above seems to aim right on target.

Copy link
Contributor

@ppkarwasz ppkarwasz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks almost ready.

Remark the PropertiesUtil.Environment does not log anything about broken property sources to prevent a recursive initialization. Now we can start logging again.

Copy link
Member

@jvz jvz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like this approach so far!

@vy
Copy link
Member Author

vy commented Jan 29, 2024

@ppkarwasz, I have introduced the fallback listener concept back in cd3fadb. Would you mind reviewing it, please?

Copy link
Contributor

@ppkarwasz ppkarwasz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

ppkarwasz and others added 15 commits January 30, 2024 20:15
`[email protected]` requires the sender to have an `@apache.org`
address. Not all PMC members have this configured, this adds yet
another step to the release process and yet another condition to
hold in the RM machine, and people are not willing to drop this
requirement[1].

[1] https://lists.apache.org/thread/jc7o25gxx9w3y3xq51kwbmcbz62cwkb2
As per discussion[1], nested logging is not an official feature.
Hence, when it is broken, the build should not fail.

[1] https://lists.apache.org/thread/gnwjw7sfhxogb7c70rqr4t0v6yh4px02
Nested logging is not an officially supported feature[1].
Tests should not rely on them.

[1] https://lists.apache.org/thread/gnwjw7sfhxogb7c70rqr4t0v6yh4px02
@vy vy changed the title Draft: Make StatusLogger self-contained and testable Make StatusLogger self-contained and testable Feb 8, 2024
@vy vy merged commit ce1a3a4 into 2.x Feb 8, 2024
@vy vy deleted the 2.x-StatusLogger-revamp branch February 8, 2024 12:29
@lauredogit
Copy link

lauredogit commented Feb 23, 2024

Hi,
This change caused an issue when running on Java 8 and having configured a DateFormat for the StatusLogger (e.g. via log4j2.StatusLogger.DateFormat).

It will cause a StackOverflowError such as:

Caused by: java.lang.StackOverflowError
	at org.apache.logging.log4j.message.ParameterFormatter.analyzePattern(ParameterFormatter.java:93)
	at org.apache.logging.log4j.message.ParameterizedMessage.<init>(ParameterizedMessage.java:142)
	at org.apache.logging.log4j.message.ParameterizedMessage.<init>(ParameterizedMessage.java:176)
	at org.apache.logging.log4j.message.ParameterizedNoReferenceMessageFactory.newMessage(ParameterizedNoReferenceMessageFactory.java:105)
	at org.apache.logging.log4j.message.AbstractMessageFactory.newMessage(AbstractMessageFactory.java:103)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2686)
	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2460)
	at org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:3674)
	at org.apache.logging.log4j.spi.AbstractLogger.handleLogMessageException(AbstractLogger.java:2927)
	at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2909)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2859)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2841)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2687)
	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2460)
	at org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:3674)
	at org.apache.logging.log4j.spi.AbstractLogger.handleLogMessageException(AbstractLogger.java:2927)

which is caused by

java.time.temporal.UnsupportedTemporalTypeException: Unsupported field: YearOfEra
        at java.time.Instant.getLong(Instant.java:603)
        at java.time.format.DateTimePrintContext.getValue(DateTimePrintContext.java:298)
        at java.time.format.DateTimeFormatterBuilder$NumberPrinterParser.format(DateTimeFormatterBuilder.java:2551)
        at java.time.format.DateTimeFormatterBuilder$CompositePrinterParser.format(DateTimeFormatterBuilder.java:2190)
        at java.time.format.DateTimeFormatter.formatTo(DateTimeFormatter.java:1746)
        at java.time.format.DateTimeFormatter.format(DateTimeFormatter.java:1720)
        at org.apache.logging.log4j.status.StatusData.getFormattedStatus(StatusData.java:170)
        at org.apache.logging.log4j.status.StatusConsoleListener.log(StatusConsoleListener.java:138)
        at org.apache.logging.log4j.status.StatusLogger.notifyListener(StatusLogger.java:555)
        at org.apache.logging.log4j.status.StatusLogger.notifyListeners(StatusLogger.java:549)
        at org.apache.logging.log4j.status.StatusLogger.logMessage(StatusLogger.java:526)
        at org.apache.logging.log4j.spi.AbstractLogger.log(AbstractLogger.java:2812)
        at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2906)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2859)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2841)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2620)
        at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2567)
        at org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:3469)

because in org.apache.logging.log4j.status.StatusLogger.Config#readInstantFormatter, the code is merely

private static DateTimeFormatter readInstantFormatter(final Properties fileProvidedProperties) {
final String format = readProperty(fileProvidedProperties, STATUS_DATE_FORMAT);
return format != null ? DateTimeFormatter.ofPattern(format) : null;
}

with only DateTimeFormatter.ofPattern(format)

This works on Java 11, but on Java 8, it breaks as in https://stackoverflow.com/questions/25229124/unsupportedtemporaltypeexception-when-formatting-instant-to-string

A very simple fix is to use instead

        private static DateTimeFormatter readInstantFormatter(final Properties fileProvidedProperties) {
            final String format = readProperty(fileProvidedProperties, STATUS_DATE_FORMAT);
            return format != null ? DateTimeFormatter.ofPattern(format).withZone(ZoneId.systemDefault()) : null;
        }

Hence using
DateTimeFormatter.ofPattern(format).withZone(ZoneId.systemDefault())

@vy
Copy link
Member Author

vy commented Feb 23, 2024

@lauredogit, thanks so much for the report. I will submit a fix. We are considering a 2.23.1 release sometime soon, maybe next week?

@lauredogit
Copy link

Perfect, thanks!

I think there are 2 distinct issues at play.

The easy one to fix is the actual UnsupportedTemporalTypeException on Java 8, which will be fixed easily by adding the ".withZone(ZoneId.systemDefault())".

However, the other issue is that having such an exception thrown by the StatusLogger was causing a StackOverflowError...
and this was not mitigated by AbstractLogger.logMessageTrackRecursion().

This can be investigated later on, though.

@ppkarwasz
Copy link
Contributor

Well, logMessageTrackRecursion only tracks recursion, it doesn't do anything about it. Other parts of the system like async logger read the recursion level (and log synchronously for example).

@ppkarwasz
Copy link
Contributor

Hi @vy,

It looks like this change isn't mentioned in the 2.23.0 release notes, even though—if I recall correctly—it was one of the most significant enhancements in that version.

Notably, this change has an important (and, as I remember it, intentional) side effect for users of log4j-to-slf4j and log4j-to-jul: it disables message pooling via ReusableMessageFactory. This behavior aligns with the design of the target logging systems:

  • The default JUL implementation lacks GC-free features, and JBoss LogManager provides its own optimized log4j-to-jul integration.
  • Logback, the only native SLF4J implementation, also creates a new LoggingEvent object per log call.

So, disabling GC-free logging in these bridges was a deliberate decision—but one that should be clearly documented. Could you please update the release notes to reflect this?

Thanks!

@vy
Copy link
Member Author

vy commented Jul 20, 2025

@ppkarwasz, you're right. I've submitted #3838 to address this. Would you mind reviewing, please?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

api Affects the public API tests Pull requests or issues related to tests

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants