Fix StatusLogger time-zone issues and stack overflow

log4j-api-test/src/test/java/org/apache/logging/log4j/status/StatusLoggerDateTest.java

@@ -0,0 +1,118 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to you under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License.  You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.logging.log4j.status;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.mockito.Mockito.doAnswer;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+
+import java.time.Instant;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.Properties;
+import java.util.function.Supplier;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.message.ParameterizedNoReferenceMessageFactory;
+import org.junit.jupiter.params.ParameterizedTest;
+import org.junit.jupiter.params.provider.CsvSource;
+import org.mockito.Mockito;
+import org.mockito.stubbing.Answer;
+
+class StatusLoggerDateTest {
+
+    private static final String INSTANT_YEAR = "1970";
+
+    private static final String INSTANT_MONTH = "12";
+
+    private static final String INSTANT_DAY = "27";
+
+    private static final String INSTANT_HOUR = "12";
+
+    private static final String INSTANT_MINUTE = "34";
+
+    private static final String INSTANT_SECOND = "56";
+
+    private static final String INSTANT_FRACTION = "789";
+
+    private static final Instant INSTANT = Instant.parse(INSTANT_YEAR
+            + '-'
+            + INSTANT_MONTH
+            + '-'
+            + INSTANT_DAY
+            + 'T'
+            + INSTANT_HOUR
+            + ':'
+            + INSTANT_MINUTE
+            + ':'
+            + INSTANT_SECOND
+            + '.'
+            + INSTANT_FRACTION
+            + 'Z');
+
+    private static final Supplier<Instant> CLOCK = () -> INSTANT;
+
+    @ParameterizedTest
+    @CsvSource({
+        "yyyy-MM-dd," + (INSTANT_YEAR + '-' + INSTANT_MONTH + '-' + INSTANT_DAY),
+        "HH:mm:ss," + (INSTANT_HOUR + ':' + INSTANT_MINUTE + ':' + INSTANT_SECOND),
+        "HH:mm:ss.SSS," + (INSTANT_HOUR + ':' + INSTANT_MINUTE + ':' + INSTANT_SECOND + '.' + INSTANT_FRACTION)
+    })
+    void common_date_patterns_should_work(final String instantPattern, final String formattedInstant) {
+
+        // Create a `StatusLogger` configuration
+        final Properties statusLoggerConfigProperties = new Properties();
+        statusLoggerConfigProperties.put(StatusLogger.STATUS_DATE_FORMAT, instantPattern);
+        statusLoggerConfigProperties.put(StatusLogger.STATUS_DATE_FORMAT_ZONE, "UTC");
+        final StatusLogger.Config statusLoggerConfig = new StatusLogger.Config(statusLoggerConfigProperties);
+
+        // Create a `StatusConsoleListener` recording `StatusData`
+        final StatusConsoleListener statusConsoleListener = mock(StatusConsoleListener.class);
+        when(statusConsoleListener.getStatusLevel()).thenReturn(Level.ALL);
+        final List<StatusData> loggedStatusData = new ArrayList<>();
+        doAnswer((Answer<Void>) invocation -> {
+                    final StatusData statusData = invocation.getArgument(0, StatusData.class);
+                    loggedStatusData.add(statusData);
+                    return null;
+                })
+                .when(statusConsoleListener)
+                .log(Mockito.any());
+
+        // Create the `StatusLogger`
+        final StatusLogger logger = new StatusLogger(
+                StatusLoggerDateTest.class.getSimpleName(),
+                ParameterizedNoReferenceMessageFactory.INSTANCE,
+                statusLoggerConfig,
+                CLOCK,
+                statusConsoleListener);
+
+        // Log a message
+        final String message = "test message";
+        final Level level = Level.ERROR;
+        final Throwable throwable = new RuntimeException("test failure");
+        logger.log(level, message, throwable);
+
+        // Verify the logging
+        assertThat(loggedStatusData).hasSize(1);
+        final StatusData statusData = loggedStatusData.get(0);
+        assertThat(statusData.getLevel()).isEqualTo(level);
+        assertThat(statusData.getThrowable()).isSameAs(throwable);
+        assertThat(statusData.getFormattedStatus())
+                .matches("(?s)^" + formattedInstant + " .+ " + level + ' ' + message + ".*" + throwable.getMessage()
+                        + ".*");
+    }
+}

log4j-api-test/src/test/java/org/apache/logging/log4j/status/StatusLoggerFailingListenerTest.java

@@ -0,0 +1,66 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to you under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License.  You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.logging.log4j.status;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.Mockito.doThrow;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+
+import org.apache.logging.log4j.Level;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.junit.jupiter.api.parallel.ResourceLock;
+import uk.org.webcompere.systemstubs.SystemStubs;
+import uk.org.webcompere.systemstubs.jupiter.SystemStubsExtension;
+
+@ExtendWith(SystemStubsExtension.class)
+@ResourceLock("log4j2.StatusLogger")
+class StatusLoggerFailingListenerTest {
+
+    public static final StatusLogger STATUS_LOGGER = StatusLogger.getLogger();
+
+    private StatusListener listener;
+
+    @BeforeEach
+    void createAndRegisterListener() {
+        listener = mock(StatusListener.class);
+        STATUS_LOGGER.registerListener(listener);
+    }
+
+    @AfterEach
+    void unregisterListener() {
+        STATUS_LOGGER.removeListener(listener);
+    }
+
+    @Test
+    void logging_with_failing_listener_should_not_cause_stack_overflow() throws Exception {
+
+        // Set up a failing listener on `log(StatusData)`
+        when(listener.getStatusLevel()).thenReturn(Level.ALL);
+        final Exception listenerFailure = new RuntimeException("test failure " + Math.random());
+        doThrow(listenerFailure).when(listener).log(any());
+
+        // Log something and verify exception dump
+        final String stderr = SystemStubs.tapSystemErr(() -> STATUS_LOGGER.error("foo"));
+        final String listenerFailureClassName = listenerFailure.getClass().getCanonicalName();
+        assertThat(stderr).contains(listenerFailureClassName + ": " + listenerFailure.getMessage());
+    }
+}

log4j-api-test/src/test/java/org/apache/logging/log4j/status/StatusLoggerLevelTest.java

@@ -29,7 +29,7 @@ class StatusLoggerLevelTest {
     void effective_level_should_be_the_least_specific_one() {
 
         // Verify the initial level
-        final StatusLogger logger = StatusLogger.getLogger();
+        final StatusLogger logger = new StatusLogger();
         final Level fallbackListenerLevel = Level.ERROR;
         assertThat(logger.getLevel()).isEqualTo(fallbackListenerLevel);
 

log4j-api/src/main/java/org/apache/logging/log4j/status/StatusData.java

@@ -68,7 +68,7 @@ public StatusData(
             final Message message,
             @Nullable final Throwable throwable,
             @Nullable final String threadName) {
-        this(caller, level, message, throwable, threadName, null);
+        this(caller, level, message, throwable, threadName, null, Instant.now());
     }
 
     StatusData(
@@ -77,9 +77,10 @@ public StatusData(
             final Message message,
             @Nullable final Throwable throwable,
             @Nullable final String threadName,
-            @Nullable final DateTimeFormatter instantFormatter) {
+            @Nullable final DateTimeFormatter instantFormatter,
+            final Instant instant) {
         this.instantFormatter = instantFormatter;
-        this.instant = Instant.now();
+        this.instant = instant;
         this.caller = caller;
         this.level = requireNonNull(level, "level");
         this.message = requireNonNull(message, "message");

log4j-api/src/main/java/org/apache/logging/log4j/status/StatusLogger.java

@@ -19,9 +19,12 @@
 import static java.util.Objects.requireNonNull;
 
 import edu.umd.cs.findbugs.annotations.Nullable;
+import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
 import java.io.IOException;
 import java.io.InputStream;
 import java.net.URL;
+import java.time.Instant;
+import java.time.ZoneId;
 import java.time.format.DateTimeFormatter;
 import java.util.ArrayList;
 import java.util.Collections;
@@ -33,6 +36,7 @@
 import java.util.concurrent.locks.Lock;
 import java.util.concurrent.locks.ReadWriteLock;
 import java.util.concurrent.locks.ReentrantReadWriteLock;
+import java.util.function.Supplier;
 import org.apache.logging.log4j.Level;
 import org.apache.logging.log4j.Marker;
 import org.apache.logging.log4j.message.Message;
@@ -158,11 +162,26 @@ public class StatusLogger extends AbstractLogger {
 
     /**
      * The name of the system property that can be configured with a {@link java.time.format.DateTimeFormatter} pattern that will be used while formatting the created {@link StatusData}.
+     * <p>
+     * When not provided, {@link Instant#toString()} will be used.
+     * </p>
      *
+     * @see #STATUS_DATE_FORMAT_ZONE
      * @since 2.11.0
      */
     public static final String STATUS_DATE_FORMAT = "log4j2.StatusLogger.DateFormat";
 
+    /**
+     * The name of the system property that can be configured with a time-zone ID (e.g., {@code Europe/Amsterdam}, {@code UTC+01:00}) that will be used while formatting the created {@link StatusData}.
+     * <p>
+     * When not provided, {@link ZoneId#systemDefault()} will be used.
+     * </p>
+     *
+     * @see #STATUS_DATE_FORMAT
+     * @since 2.23.1
+     */
+    static final String STATUS_DATE_FORMAT_ZONE = "log4j2.StatusLogger.DateFormatZone";
+
     /**
      * The name of the file to be searched in the classpath to read properties from.
      *
@@ -215,10 +234,16 @@ public Config(boolean debugEnabled, int bufferCapacity, @Nullable DateTimeFormat
         }
 
         /**
-         * Constructs an instance using either system properties or a property file (i.e., {@value Config#PROPERTIES_FILE_NAME}) in the classpath, if available.
+         * Constructs the default instance using either system properties or a property file (i.e., {@value Config#PROPERTIES_FILE_NAME}) in the classpath, if available.
          */
         private Config() {
-            final Properties fileProvidedProperties = readPropertiesFile();
+            this(readPropertiesFile());
+        }
+
+        /**
+         * The lowest-level constructor intended for tests.
+         */
+        Config(final Properties fileProvidedProperties) {
             this.debugEnabled = readDebugEnabled(fileProvidedProperties);
             this.bufferCapacity = readBufferCapacity(fileProvidedProperties);
             this.fallbackListenerLevel = readFallbackListenerLevel(fileProvidedProperties);
@@ -251,7 +276,13 @@ private static Level readFallbackListenerLevel(final Properties fileProvidedProp
 
         private static DateTimeFormatter readInstantFormatter(final Properties fileProvidedProperties) {
             final String format = readProperty(fileProvidedProperties, STATUS_DATE_FORMAT);
-            return format != null ? DateTimeFormatter.ofPattern(format) : null;
+            if (format == null) {
+                return null;
+            }
+            final DateTimeFormatter formatter = DateTimeFormatter.ofPattern(format);
+            final String zoneId = readProperty(fileProvidedProperties, STATUS_DATE_FORMAT_ZONE);
+            final ZoneId effectiveZoneId = zoneId != null ? ZoneId.of(zoneId) : ZoneId.systemDefault();
+            return formatter.withZone(effectiveZoneId);
         }
 
         private static String readProperty(final Properties fileProvidedProperties, final String propertyName) {
@@ -299,6 +330,8 @@ private static final class InstanceHolder {
 
     private final Config config;
 
+    private final Supplier<Instant> clock;
+
     private final StatusConsoleListener fallbackListener;
 
     private final List<StatusListener> listeners;
@@ -313,12 +346,16 @@ private static final class InstanceHolder {
 
     /**
      * Constructs the default instance.
+     * <p>
+     * This method is visible for tests.
+     * </p>
      */
-    private StatusLogger() {
+    StatusLogger() {
         this(
                 StatusLogger.class.getSimpleName(),
                 ParameterizedNoReferenceMessageFactory.INSTANCE,
                 Config.getInstance(),
+                Instant::now,
                 new StatusConsoleListener(Config.getInstance().fallbackListenerLevel));
     }
 
@@ -338,8 +375,21 @@ public StatusLogger(
             final MessageFactory messageFactory,
             final Config config,
             final StatusConsoleListener fallbackListener) {
+        this(name, messageFactory, config, Instant::now, fallbackListener);
+    }
+
+    /**
+     * The lowest-level constructor intended for tests.
+     */
+    StatusLogger(
+            final String name,
+            final MessageFactory messageFactory,
+            final Config config,
+            final Supplier<Instant> clock,
+            final StatusConsoleListener fallbackListener) {
         super(requireNonNull(name, "name"), requireNonNull(messageFactory, "messageFactory"));
         this.config = requireNonNull(config, "config");
+        this.clock = requireNonNull(clock, "clock");
         this.fallbackListener = requireNonNull(fallbackListener, "fallbackListener");
         this.listeners = new ArrayList<>();
     }
@@ -515,15 +565,22 @@ public Level getLevel() {
     }
 
     @Override
+    @SuppressFBWarnings("INFORMATION_EXPOSURE_THROUGH_AN_ERROR_MESSAGE")
     public void logMessage(
             final String fqcn,
             final Level level,
             final Marker marker,
             final Message message,
             final Throwable throwable) {
-        final StatusData statusData = createStatusData(fqcn, level, message, throwable);
-        buffer(statusData);
-        notifyListeners(statusData);
+        try {
+            final StatusData statusData = createStatusData(fqcn, level, message, throwable);
+            buffer(statusData);
+            notifyListeners(statusData);
+        } catch (final Exception error) {
+            // We are at the lowest level of the system.
+            // Hence, there is nothing better we can do but dumping the failure.
+            error.printStackTrace(System.err);
+        }
     }
 
     private void buffer(final StatusData statusData) {
@@ -562,7 +619,8 @@ private StatusData createStatusData(
             final Message message,
             @Nullable final Throwable throwable) {
         final StackTraceElement caller = getStackTraceElement(fqcn);
-        return new StatusData(caller, level, message, throwable, null, config.instantFormatter);
+        final Instant instant = clock.get();
+        return new StatusData(caller, level, message, throwable, null, config.instantFormatter, instant);
     }
 
     @Nullable

log4j-api/src/main/java/org/apache/logging/log4j/status/package-info.java

@@ -19,7 +19,7 @@
  * used by applications reporting on the status of the logging system
  */
 @Export
-@Version("2.23.0")
+@Version("2.23.1")
 package org.apache.logging.log4j.status;
 
 import org.osgi.annotation.bundle.Export;