From bef09e39e8b96d0f2366dcd66c2ed7c887aa7614 Mon Sep 17 00:00:00 2001 From: "shalk(xiao kun)" Date: Thu, 22 Oct 2026 11:57:18 +0800 Subject: [PATCH] feat(mockserver): bridge MockWebServer JUL logs to SLF4J okhttp's MockWebServer logs through java.util.logging directly, so its output bypassed slf4j/logback in test runs even when jul-to-slf4j was already on the classpath. Add an opt-in JUL to SLF4J bridge for MockWebServer logs: - Only the okhttp3.mockwebserver.MockWebServer logger is reconfigured, never the JUL root logger, so unrelated JUL handlers keep receiving records. - Skipped when jul-to-slf4j is absent or when the binding is slf4j-jdk14, which would turn the bridge into a JUL<->SLF4J logging loop. - Reference-counted per ApolloTestingServer instance, so concurrently running servers do not remove the bridge from under each other. - The ownership count only moves once the logger transition succeeded, so a failed acquire leaves the bridge reusable for later servers and a failed release stays retryable instead of poisoning the count. - The MockWebServer logger is retained strongly for the bridge's lifetime so GC cannot silently detach its handler during startup. start()/close() keep their behaviour; callers opt in with acquireJulBridge() and releaseJulBridge(). --- CHANGES.md | 1 + apollo-mockserver/pom.xml | 6 + .../mockserver/ApolloTestingServer.java | 30 ++ .../apollo/mockserver/JulSlf4jBridge.java | 189 +++++++++++ .../apollo/mockserver/JulSlf4jBridgeTest.java | 314 ++++++++++++++++++ 5 files changed, 540 insertions(+) create mode 100644 apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridge.java create mode 100644 apollo-mockserver/src/test/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridgeTest.java diff --git a/CHANGES.md b/CHANGES.md index c18c8d75..80f4654d 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -8,6 +8,7 @@ Apollo Java 2.6.0 * [Fix Apollo client local cache fallback for Spring Boot 3 executable JARs](https://github.com/apolloconfig/apollo-java/pull/136) * [Support `extendInfo`/`parentAppId` in OpenAPI `getNamespace(s)` client calls](https://github.com/apolloconfig/apollo-java/pull/144) +* [Add an opt-in JUL to SLF4J bridge for MockWebServer logs](https://github.com/apolloconfig/apollo-java/pull/147) ------------------ All issues and pull requests are [here](https://github.com/apolloconfig/apollo-java/milestone/6?closed=1) diff --git a/apollo-mockserver/pom.xml b/apollo-mockserver/pom.xml index 9dec2d50..30bb0067 100644 --- a/apollo-mockserver/pom.xml +++ b/apollo-mockserver/pom.xml @@ -53,6 +53,12 @@ com.ctrip.framework.apollo apollo-client + + org.slf4j + jul-to-slf4j + 1.7.21 + true + com.squareup.okhttp3 mockwebserver diff --git a/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/ApolloTestingServer.java b/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/ApolloTestingServer.java index e69acc45..4aae4d07 100644 --- a/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/ApolloTestingServer.java +++ b/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/ApolloTestingServer.java @@ -79,6 +79,8 @@ public class ApolloTestingServer implements AutoCloseable { private boolean closed; + private boolean bridgeAcquired; + static { try { System.setProperty("apollo.longPollingInitialDelayInMills", "0"); @@ -143,6 +145,34 @@ public void close() { } } + /** + * Installs the JUL-to-SLF4J bridge for MockWebServer logs on the currently active server. + * Callers must pair every call with {@link #releaseJulBridge()}. + * + *

A failed installation propagates and leaves neither the JUL logger nor the bridge's + * ownership count changed, so it can be retried and a later {@link #releaseJulBridge()} is a + * no-op. + */ + public void acquireJulBridge() { + if (!bridgeAcquired) { + JulSlf4jBridge.install(); + bridgeAcquired = true; + } + } + + /** + * Releases the JUL-to-SLF4J bridge acquired by {@link #acquireJulBridge()}. + * + *

A failed release keeps this instance owning the bridge, so calling this method again + * retries the teardown. + */ + public void releaseJulBridge() { + if (bridgeAcquired) { + JulSlf4jBridge.uninstall(); + bridgeAcquired = false; + } + } + public boolean isClosed() { return closed; } diff --git a/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridge.java b/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridge.java new file mode 100644 index 00000000..548f4b8d --- /dev/null +++ b/apollo-mockserver/src/main/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridge.java @@ -0,0 +1,189 @@ +/* + * Copyright 2026 Apollo Authors + * + * Licensed 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 com.ctrip.framework.apollo.mockserver; + +import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Handler; +import java.util.logging.Logger; +import org.slf4j.LoggerFactory; + +/** + * Routes okhttp's MockWebServer logs (which go through java.util.logging directly) to + * slf4j/logback for the lifetime of active {@link ApolloTestingServer} instances. + * + *

Unlike {@code SLF4JBridgeHandler#install()}, this only touches the JUL logger used by + * MockWebServer, not the JUL root logger, so unrelated JUL handlers elsewhere in the JVM are + * never removed. It also skips installing when the SLF4J binding is slf4j-jdk14, since bridging + * JUL to an SLF4J binding that itself delegates back to JUL creates an infinite loop. Calls are + * reference-counted so concurrently running mock servers don't uninstall the bridge out from + * under each other. + * + *

The ownership count is only moved once the corresponding logger transition succeeded, so a + * failed {@link #install()} leaves the bridge reusable and a failed {@link #uninstall()} can be + * retried instead of driving the count out of sync with the JUL logger state. + * + *

Uses reflection to instantiate {@code SLF4JBridgeHandler} so the class can load even when + * {@code jul-to-slf4j} is not on the classpath. + */ +final class JulSlf4jBridge { + + private static final org.slf4j.Logger LOG = LoggerFactory.getLogger(JulSlf4jBridge.class); + private static final String MOCK_WEB_SERVER_LOGGER_NAME = "okhttp3.mockwebserver.MockWebServer"; + private static final String SLF4J_BRIDGE_HANDLER_CLASS = "org.slf4j.bridge.SLF4JBridgeHandler"; + private static final AtomicInteger ACTIVE = new AtomicInteger(0); + + private static Handler[] originalHandlers; + private static boolean originalUseParentHandlers; + private static boolean bridged; + private static Logger mockWebServerLogger; + private static Handler bridgeHandler; + + private JulSlf4jBridge() {} + + static synchronized void install() { + if (ACTIVE.get() <= 0) { + installForFirstOwner(); + } + // Only an owner whose install succeeded consumes a slot, so a failed install cannot make + // later servers skip their own installation. + ACTIVE.incrementAndGet(); + } + + private static void installForFirstOwner() { + if (!isBridgeHandlerAvailable()) { + LOG.warn("Skipping JUL-to-SLF4J bridge for MockWebServer logs because " + + "jul-to-slf4j is not on the classpath"); + return; + } + if (isJdk14Binding(LoggerFactory.getILoggerFactory().getClass().getName())) { + LOG.warn("Skipping JUL-to-SLF4J bridge for MockWebServer logs because the SLF4J binding " + + "is slf4j-jdk14; bridging it would create an infinite JUL<->SLF4J logging loop."); + return; + } + + Logger logger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + Handler[] handlers = logger.getHandlers(); + boolean useParentHandlers = logger.getUseParentHandlers(); + + Handler handler = null; + try { + handler = newBridgeHandler(); + for (Handler original : handlers) { + logger.removeHandler(original); + } + logger.addHandler(handler); + logger.setUseParentHandlers(false); + } catch (RuntimeException | Error e) { + // Leave no half-installed bridge behind, otherwise later servers would see a bridge + // count that no installed bridge corresponds to. + removeHandlerQuietly(logger, handler); + restoreHandlers(logger, handlers, useParentHandlers); + throw e; + } + + mockWebServerLogger = logger; + originalHandlers = handlers; + originalUseParentHandlers = useParentHandlers; + bridgeHandler = handler; + bridged = true; + } + + private static boolean isBridgeHandlerAvailable() { + try { + Class.forName(SLF4J_BRIDGE_HANDLER_CLASS); + return true; + } catch (ClassNotFoundException e) { + return false; + } + } + + private static Handler newBridgeHandler() { + try { + return (Handler) Class.forName(SLF4J_BRIDGE_HANDLER_CLASS).newInstance(); + } catch (ClassNotFoundException | InstantiationException | IllegalAccessException e) { + throw new IllegalStateException( + "SLF4JBridgeHandler was available during check but not during instantiation", e); + } + } + + static synchronized void uninstall() { + int active = ACTIVE.get(); + if (active <= 0) { + // Nothing is acquired, so releasing must not drive the count below zero. + return; + } + if (active > 1 || !bridged) { + ACTIVE.decrementAndGet(); + return; + } + // The last owner gives up its slot only once the JUL logger is restored, so a failed + // teardown stays retryable instead of leaving the count out of sync. + teardown(); + ACTIVE.decrementAndGet(); + } + + private static void teardown() { + mockWebServerLogger.removeHandler(bridgeHandler); + restoreHandlers(mockWebServerLogger, originalHandlers, originalUseParentHandlers); + originalHandlers = null; + originalUseParentHandlers = false; + mockWebServerLogger = null; + bridgeHandler = null; + bridged = false; + } + + /** Restores the previously removed handlers, without ever failing the caller. */ + private static void restoreHandlers(Logger logger, Handler[] handlers, + boolean useParentHandlers) { + try { + for (Handler handler : handlers) { + if (!containsHandler(logger.getHandlers(), handler)) { + logger.addHandler(handler); + } + } + logger.setUseParentHandlers(useParentHandlers); + } catch (RuntimeException | Error e) { + LOG.warn("Failed to restore the JUL handlers of {}", logger.getName(), e); + } + } + + private static void removeHandlerQuietly(Logger logger, Handler handler) { + if (handler == null) { + return; + } + try { + logger.removeHandler(handler); + } catch (RuntimeException | Error e) { + LOG.warn("Failed to remove the JUL bridge handler from {}", logger.getName(), e); + } + } + + private static boolean containsHandler(Handler[] handlers, Handler target) { + for (Handler handler : handlers) { + if (handler == target) { + return true; + } + } + return false; + } + + /** Package-visible for testing without depending on the actual runtime SLF4J binding. */ + static boolean isJdk14Binding(String iLoggerFactoryClassName) { + return "org.slf4j.impl.JDK14LoggerFactory".equals(iLoggerFactoryClassName) + || "org.slf4j.jul.JDK14LoggerFactory".equals(iLoggerFactoryClassName); + } +} diff --git a/apollo-mockserver/src/test/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridgeTest.java b/apollo-mockserver/src/test/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridgeTest.java new file mode 100644 index 00000000..614a476d --- /dev/null +++ b/apollo-mockserver/src/test/java/com/ctrip/framework/apollo/mockserver/JulSlf4jBridgeTest.java @@ -0,0 +1,314 @@ +/* + * Copyright 2026 Apollo Authors + * + * Licensed 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 com.ctrip.framework.apollo.mockserver; + +import static org.junit.jupiter.api.Assertions.assertArrayEquals; +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assumptions.assumeTrue; + +import java.lang.reflect.Field; +import java.security.Permission; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Handler; +import java.util.logging.Logger; +import java.util.logging.LoggingPermission; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; +import org.slf4j.bridge.SLF4JBridgeHandler; + +class JulSlf4jBridgeTest { + + private static final String MOCK_WEB_SERVER_LOGGER_NAME = "okhttp3.mockwebserver.MockWebServer"; + private static final boolean SECURITY_MANAGER_SUPPORTED = isSecurityManagerSupported(); + + @AfterEach + void releaseAnyBridgeOwnership() { + // The bridge is JVM global state; make every test start from an unowned bridge even when + // another test failed half way through. + for (int owned = activeCount(); owned > 0; owned--) { + JulSlf4jBridge.uninstall(); + } + } + + @Test + void isJdk14BindingDetectsKnownFactoryClassNames() { + assertTrue(JulSlf4jBridge.isJdk14Binding("org.slf4j.impl.JDK14LoggerFactory")); + assertTrue(JulSlf4jBridge.isJdk14Binding("org.slf4j.jul.JDK14LoggerFactory")); + assertFalse(JulSlf4jBridge.isJdk14Binding("ch.qos.logback.classic.LoggerContext")); + } + + @Test + void installOnlyTouchesMockWebServerLoggerNotRoot() { + Logger root = Logger.getLogger(""); + Handler[] rootHandlersBefore = root.getHandlers(); + + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + Handler[] mwsHandlersBefore = mockWebServerLogger.getHandlers(); + boolean useParentBefore = mockWebServerLogger.getUseParentHandlers(); + + JulSlf4jBridge.install(); + try { + assertArrayEquals(rootHandlersBefore, root.getHandlers(), + "installing the bridge must not touch the JUL root logger's handlers"); + assertTrue(hasBridgeHandler(mockWebServerLogger), + "MockWebServer's own logger should get the bridge handler"); + assertFalse(mockWebServerLogger.getUseParentHandlers()); + } finally { + JulSlf4jBridge.uninstall(); + } + + assertArrayEquals(rootHandlersBefore, root.getHandlers()); + assertArrayEquals(mwsHandlersBefore, mockWebServerLogger.getHandlers()); + assertEquals(useParentBefore, mockWebServerLogger.getUseParentHandlers()); + } + + @Test + void closingSameServerTwiceDoesNotDisruptAnotherActiveServer() throws Exception { + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + ApolloTestingServer serverA = new ApolloTestingServer(); + ApolloTestingServer serverB = new ApolloTestingServer(); + try { + serverA.start(); + serverA.acquireJulBridge(); + serverB.start(); + serverB.acquireJulBridge(); + assertTrue(hasBridgeHandler(mockWebServerLogger)); + + serverA.releaseJulBridge(); + serverA.releaseJulBridge(); + + assertTrue(hasBridgeHandler(mockWebServerLogger), + "bridge must remain installed while server B is still running"); + } finally { + serverA.releaseJulBridge(); + serverA.close(); + serverB.releaseJulBridge(); + serverB.close(); + } + + assertFalse(hasBridgeHandler(mockWebServerLogger)); + } + + @Test + void closingNeverStartedServerDoesNotDisruptActiveServer() throws Exception { + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + ApolloTestingServer active = new ApolloTestingServer(); + ApolloTestingServer neverStarted = new ApolloTestingServer(); + try { + active.start(); + active.acquireJulBridge(); + assertTrue(hasBridgeHandler(mockWebServerLogger)); + + neverStarted.releaseJulBridge(); + + assertTrue(hasBridgeHandler(mockWebServerLogger), + "releasing a bridge that was never acquired must not affect the active bridge"); + } finally { + active.releaseJulBridge(); + active.close(); + neverStarted.close(); + } + + assertFalse(hasBridgeHandler(mockWebServerLogger)); + } + + @Test + void failedAcquisitionKeepsTheBridgeAvailableForLaterServers() { + assumeTrue(SECURITY_MANAGER_SUPPORTED, + "denying java.util.logging control requires the security manager API"); + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + assertEquals(0, activeCount(), "the bridge must start out unowned"); + + ApolloTestingServer failing = new ApolloTestingServer(); + whileLoggingControlDenied( + () -> assertThrows(SecurityException.class, failing::acquireJulBridge)); + + assertEquals(0, activeCount(), "a failed acquisition must not consume the ownership"); + assertFalse(hasBridgeHandler(mockWebServerLogger), + "a failed acquisition must not leave a half-installed bridge behind"); + + ApolloTestingServer later = new ApolloTestingServer(); + later.acquireJulBridge(); + try { + assertEquals(1, activeCount()); + assertTrue(hasBridgeHandler(mockWebServerLogger), + "a later server must still be able to install the bridge"); + } finally { + later.releaseJulBridge(); + later.close(); + failing.close(); + } + + assertFalse(hasBridgeHandler(mockWebServerLogger)); + } + + @Test + void failedReleaseKeepsTheOwnershipSoThatItCanBeRetried() { + assumeTrue(SECURITY_MANAGER_SUPPORTED, + "denying java.util.logging control requires the security manager API"); + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + assertEquals(0, activeCount(), "the bridge must start out unowned"); + + ApolloTestingServer server = new ApolloTestingServer(); + server.acquireJulBridge(); + try { + assertTrue(hasBridgeHandler(mockWebServerLogger)); + + whileLoggingControlDenied( + () -> assertThrows(SecurityException.class, server::releaseJulBridge)); + + assertEquals(1, activeCount(), "a failed release must keep the ownership for a retry"); + assertTrue(hasBridgeHandler(mockWebServerLogger), + "a failed release must leave the bridge installed"); + + server.releaseJulBridge(); + assertEquals(0, activeCount()); + assertFalse(hasBridgeHandler(mockWebServerLogger)); + + server.releaseJulBridge(); + assertEquals(0, activeCount(), "releasing more often than acquiring must not go negative"); + } finally { + server.releaseJulBridge(); + server.close(); + } + } + + @Test + void bridgeRetainsLoggerUntilMockWebServerInitializes() throws Exception { + ApolloTestingServer server = new ApolloTestingServer(); + try { + server.start(); + server.acquireJulBridge(); + + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + assertSame(mockWebServerLogger, retainedMockWebServerLogger(), + "the bridge must retain the logger MockWebServer logs to, so that GC cannot " + + "silently detach its bridge handler"); + assertTrue(hasBridgeHandler(mockWebServerLogger), + "the MockWebServer logger must keep its bridge handler for the bridge's lifetime"); + } finally { + server.releaseJulBridge(); + server.close(); + } + + assertNullRetainedLogger(); + } + + @Test + void startupFailureDoesNotInstallBridge() throws Exception { + Logger mockWebServerLogger = Logger.getLogger(MOCK_WEB_SERVER_LOGGER_NAME); + ApolloTestingServer server = new ApolloTestingServer(); + + Field locatorField = ApolloTestingServer.class.getDeclaredField("CONFIG_SERVICE_LOCATOR"); + locatorField.setAccessible(true); + Object originalLocator = locatorField.get(null); + locatorField.set(null, null); + try { + assertThrows(IllegalStateException.class, server::start, "start() must surface failures"); + assertFalse(hasBridgeHandler(mockWebServerLogger), + "a failed start() must not install the JUL bridge"); + } finally { + locatorField.set(null, originalLocator); + server.close(); + } + } + + private static boolean hasBridgeHandler(Logger logger) { + for (Handler handler : logger.getHandlers()) { + if (handler instanceof SLF4JBridgeHandler) { + return true; + } + } + return false; + } + + private static void assertNullRetainedLogger() { + assertNull(retainedMockWebServerLogger(), + "the bridge must release the retained logger on teardown"); + } + + private static int activeCount() { + try { + Field active = JulSlf4jBridge.class.getDeclaredField("ACTIVE"); + active.setAccessible(true); + return ((AtomicInteger) active.get(null)).get(); + } catch (ReflectiveOperationException e) { + throw new IllegalStateException(e); + } + } + + private static Logger retainedMockWebServerLogger() { + try { + Field field = JulSlf4jBridge.class.getDeclaredField("mockWebServerLogger"); + field.setAccessible(true); + return (Logger) field.get(null); + } catch (ReflectiveOperationException e) { + throw new IllegalStateException(e); + } + } + + /** + * Runs {@code action} while {@code java.util.logging} control checks are denied, which is how a + * JVM without permission to reconfigure JUL behaves. + */ + private static void whileLoggingControlDenied(Runnable action) { + DenyLoggingControlSecurityManager securityManager = new DenyLoggingControlSecurityManager(); + System.setSecurityManager(securityManager); + try { + securityManager.denyLoggingControl = true; + action.run(); + } finally { + securityManager.denyLoggingControl = false; + System.setSecurityManager(null); + } + } + + private static boolean isSecurityManagerSupported() { + try { + System.setSecurityManager(new DenyLoggingControlSecurityManager()); + System.setSecurityManager(null); + return true; + } catch (Throwable t) { + return false; + } + } + + /** Allows everything but {@code LoggingPermission("control")}, so JUL reconfiguration fails. */ + private static final class DenyLoggingControlSecurityManager extends SecurityManager { + + private boolean denyLoggingControl; + + @Override + public void checkPermission(Permission permission) { + // java.util.logging checks LoggingPermission("control") before every reconfiguration. + if (denyLoggingControl && permission instanceof LoggingPermission + && "control".equals(permission.getName())) { + throw new SecurityException("denied " + permission); + } + } + + @Override + public void checkPermission(Permission permission, Object context) { + checkPermission(permission); + } + } +}