From ea410d1e184bb6b538a2de6f954bf940a441e6b9 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 17:07:21 +0300 Subject: [PATCH 01/20] [java] Make selenium.debug/webdriver.verbose configure the real logger Debug.isDebugging() was cached in a static block at class-load time, so changing selenium.debug or selenium.webdriver.verbose mid-run had no effect, and getDebugLogLevel() shifted individual log statements between INFO and FINE instead of touching the logger itself. This was a second, Java-only mechanism alongside SE_DEBUG's Debug.configureLogger(), which already does the right thing: raise the real org.openqa.selenium logger to FINE and attach a handler. Make isDebugging() a live property read instead of a cached static field. Widen configureLogger() to fire for isDebugging() as well as isDebugAll(), and make it idempotent (tracks the handler it installed) and reversible (removes exactly that handler and restores the previous logger level when every switch turns back off). Attach the handler at FINE with a filter that excludes INFO-and-above so it never duplicates records the caller's own handlers already print. Move the configureLogger() call out of RemoteWebDriver's static initializer and into its canonical constructor so a property change made after the class has already loaded still takes effect for drivers constructed afterwards. Extend LoggingOptions.setLoggingLevel() to also honor isDebugging(), so Grid operators using -Dselenium.debug=true don't lose Grid diagnostic output now that SE_DEBUG is no longer the only switch configureLogger() reacts to. getDebugLogLevel() is deprecated for removal; its behavior is unchanged (still INFO while debugging, FINE otherwise) and existing call sites keep working, pointing callers at the logger-based mechanism instead. Adds DebugTest with no mocks, exercising the live property read, the legacy verbose property, idempotency, reversibility, and that the installed handler leaves the caller's own handlers untouched. --- .../selenium/grid/log/LoggingOptions.java | 5 +- .../org/openqa/selenium/internal/Debug.java | 63 +++++-- .../selenium/remote/RemoteWebDriver.java | 7 +- .../openqa/selenium/internal/DebugTest.java | 163 ++++++++++++++++++ 4 files changed, 216 insertions(+), 22 deletions(-) create mode 100644 java/test/org/openqa/selenium/internal/DebugTest.java diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index b812bac69f186..602aa82ab4a60 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -87,9 +87,10 @@ public String getLogEncoding() { public LoggingOptions setLoggingLevel() { String configLevel = config.get(LOGGING_SECTION, "log-level").orElse(DEFAULT_LOG_LEVEL); - if (Debug.isDebugAll()) { + if (Debug.isDebugAll() || Debug.isDebugging()) { System.err.println( - "WARNING: Environment Variable `SE_DEBUG` is set; forcing Grid log level to FINE and" + "WARNING: Selenium debug logging is enabled (`SE_DEBUG`, `-Dselenium.debug=true`, or" + + " `-Dselenium.webdriver.verbose=true`); forcing Grid log level to FINE and" + " overriding configured log level."); configLevel = Level.FINE.getName(); } diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index 0b012f180f59e..40c607fea7ee8 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -18,32 +18,40 @@ package org.openqa.selenium.internal; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.logging.ConsoleHandler; +import java.util.logging.Filter; +import java.util.logging.Handler; import java.util.logging.Level; import java.util.logging.Logger; -import java.util.logging.SimpleFormatter; -import java.util.logging.StreamHandler; /** Used to provide information about whether Selenium is running under debug mode. */ public class Debug { - private static final boolean IS_DEBUG; private static final AtomicBoolean DEBUG_WARNING_LOGGED = new AtomicBoolean(false); private static final Logger SELENIUM_LOGGER = Logger.getLogger("org.openqa.selenium"); - private static boolean loggerConfigured = false; - static { - IS_DEBUG = - Boolean.getBoolean("selenium.debug") || Boolean.getBoolean("selenium.webdriver.verbose"); - } + private static boolean loggerConfigured = false; + private static Handler installedHandler = null; + private static Level previousLevel = null; private Debug() { // Utility class } public static boolean isDebugging() { - return IS_DEBUG; + return Boolean.getBoolean("selenium.debug") || Boolean.getBoolean("selenium.webdriver.verbose"); } + /** + * @deprecated Individual log statements no longer change what severity they report at based on + * this switch; {@link #configureLogger()} raises the real {@code org.openqa.selenium} + * logger to {@link Level#FINE} instead, which is the ordinary way to see Selenium's debug + * output. Enable it with {@code -Dselenium.debug=true}, the {@code SE_DEBUG} environment + * variable, or directly via {@code Logger.getLogger("org.openqa.selenium").setLevel(Level + * .FINE)}. This method's own behavior is unchanged and kept only for existing call sites + * still comparing against it. + */ + @Deprecated(forRemoval = true) public static Level getDebugLogLevel() { return isDebugging() ? Level.INFO : Level.FINE; } @@ -59,16 +67,39 @@ public static boolean isDebugAll() { return everything; } - public static void configureLogger() { - if (!isDebugAll() || loggerConfigured) { + /** + * Reflects the current debug switches ({@code -Dselenium.debug=true}, {@code + * -Dselenium.webdriver.verbose=true}, {@code SE_DEBUG}) onto the real {@code + * org.openqa.selenium} logger: raises it to {@link Level#FINE} and attaches a handler Selenium + * owns, filtered to leave {@link Level#INFO} and above to the caller's own handlers so output + * they already print is never duplicated. Idempotent: repeated calls while the switches are + * unchanged do nothing. Reversible: once every switch is off, the next call removes exactly the + * handler this method installed and restores the logger's previous level. Safe to call from + * concurrent driver construction. + */ + public static synchronized void configureLogger() { + boolean shouldDebug = isDebugging() || isDebugAll(); + if (shouldDebug == loggerConfigured) { return; } - SELENIUM_LOGGER.setLevel(Level.FINE); + if (shouldDebug) { + previousLevel = SELENIUM_LOGGER.getLevel(); + SELENIUM_LOGGER.setLevel(Level.FINE); + + Handler handler = new ConsoleHandler(); + handler.setLevel(Level.FINE); + Filter belowInfo = record -> record.getLevel().intValue() < Level.INFO.intValue(); + handler.setFilter(belowInfo); + SELENIUM_LOGGER.addHandler(handler); + installedHandler = handler; + } else { + SELENIUM_LOGGER.removeHandler(installedHandler); + installedHandler.close(); + installedHandler = null; + SELENIUM_LOGGER.setLevel(previousLevel); + } - StreamHandler handler = new StreamHandler(System.err, new SimpleFormatter()); - handler.setLevel(Level.FINE); - SELENIUM_LOGGER.addHandler(handler); - loggerConfigured = true; + loggerConfigured = shouldDebug; } } diff --git a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java index 4573903e94daf..e200fdc619f42 100644 --- a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java +++ b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java @@ -122,10 +122,6 @@ public class RemoteWebDriver PrintsPage, TakesScreenshot { - static { - org.openqa.selenium.internal.Debug.configureLogger(); - } - private static final Logger LOG = Logger.getLogger(RemoteWebDriver.class.getName()); /** Boolean system property that defines whether the tracing is enabled or not. */ @@ -205,6 +201,9 @@ public RemoteWebDriver(CommandExecutor executor, Capabilities capabilities) { public RemoteWebDriver( CommandExecutor executor, Capabilities capabilities, ClientConfig clientConfig) { + // Instance-time (not class-load-time) so a property change made after this class has already + // loaded still takes effect for drivers constructed afterwards. + Debug.configureLogger(); this.clientConfig = Require.nonNull("Client config", clientConfig); this.executor = Require.nonNull("Command executor", executor); this.capabilities = requireNonNullElseGet(capabilities, () -> new ImmutableCapabilities()); diff --git a/java/test/org/openqa/selenium/internal/DebugTest.java b/java/test/org/openqa/selenium/internal/DebugTest.java new file mode 100644 index 0000000000000..c9564cdc7a13d --- /dev/null +++ b/java/test/org/openqa/selenium/internal/DebugTest.java @@ -0,0 +1,163 @@ +// Licensed to the Software Freedom Conservancy (SFC) under one +// or more contributor license agreements. See the NOTICE file +// distributed with this work for additional information +// regarding copyright ownership. The SFC 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.openqa.selenium.internal; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.util.logging.ConsoleHandler; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.Logger; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; + +@Tag("UnitTests") +class DebugTest { + + private static final Logger SELENIUM_LOGGER = Logger.getLogger("org.openqa.selenium"); + + private String oldDebugProperty; + private String oldVerboseProperty; + + @BeforeEach + void storeSystemProperties() { + oldDebugProperty = System.getProperty("selenium.debug"); + oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); + System.clearProperty("selenium.debug"); + System.clearProperty("selenium.webdriver.verbose"); + } + + @AfterEach + void restoreSystemProperties() { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + if (oldVerboseProperty != null) { + System.setProperty("selenium.webdriver.verbose", oldVerboseProperty); + } else { + System.clearProperty("selenium.webdriver.verbose"); + } + // Re-sync configureLogger's internal state/handler with the now-restored properties so a + // handler installed by one test never leaks into the next. + Debug.configureLogger(); + } + + @Test + void isDebuggingReflectsPropertySetAfterClassLoad() { + assertThat(Debug.isDebugging()).isFalse(); + + System.setProperty("selenium.debug", "true"); + + assertThat(Debug.isDebugging()).isTrue(); + } + + @Test + void isDebuggingHonoursTheLegacyVerboseProperty() { + assertThat(Debug.isDebugging()).isFalse(); + + System.setProperty("selenium.webdriver.verbose", "true"); + + assertThat(Debug.isDebugging()).isTrue(); + } + + @Test + void configureLoggerRaisesSeleniumLoggerToFine() { + System.setProperty("selenium.debug", "true"); + + Debug.configureLogger(); + + assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + } + + @Test + void configureLoggerRestoresPreviousLevelWhenDebuggingIsTurnedOff() { + SELENIUM_LOGGER.setLevel(Level.WARNING); + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + + System.clearProperty("selenium.debug"); + Debug.configureLogger(); + + assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.WARNING); + } + + @Test + void configureLoggerIsIdempotent() { + int before = SELENIUM_LOGGER.getHandlers().length; + System.setProperty("selenium.debug", "true"); + + for (int i = 0; i < 5; i++) { + Debug.configureLogger(); + } + + assertThat(SELENIUM_LOGGER.getHandlers().length - before).isEqualTo(1); + } + + @Test + void configureLoggerLeavesUserHandlersAlone() { + Handler userHandler = new ConsoleHandler(); + SELENIUM_LOGGER.addHandler(userHandler); + try { + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + assertThat(SELENIUM_LOGGER.getHandlers()).contains(userHandler); + + System.clearProperty("selenium.debug"); + Debug.configureLogger(); + assertThat(SELENIUM_LOGGER.getHandlers()).contains(userHandler); + } finally { + SELENIUM_LOGGER.removeHandler(userHandler); + } + } + + @Test + void infoRecordsAreNotDuplicatedWhenDebuggingIsEnabled() { + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + + Handler[] handlers = SELENIUM_LOGGER.getHandlers(); + assertThat(handlers).hasSize(1); + Handler seleniumOwnedHandler = handlers[0]; + + // Selenium's own handler must stay silent for INFO-and-above records so it never prints the + // same line the caller's own (e.g. root/console) handler already prints for them; it exists + // only to surface the FINE-and-below records those handlers don't. + assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.INFO, "info-record"))) + .isFalse(); + assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.WARNING, "warning-record"))) + .isFalse(); + assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.FINE, "fine-record"))) + .isTrue(); + } + + @Test + @SuppressWarnings({"deprecation", "removal"}) + void getDebugLogLevelStillReportsInfoWhileDeprecated() { + System.setProperty("selenium.debug", "true"); + assertThat(Debug.getDebugLogLevel()).isEqualTo(Level.INFO); + + System.clearProperty("selenium.debug"); + assertThat(Debug.getDebugLogLevel()).isEqualTo(Level.FINE); + } +} From 7fcf6b6d5fc018b89074897012c219c416d06c1d Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 17:48:52 +0300 Subject: [PATCH 02/20] [java] Fix review findings in the debug logging mechanism change Two defects found by review of the previous commit, both reproduced with a failing test first: Debug.configureLogger() clobbered a logger level set by something else after debugging was turned on. Turning debugging back off restored a stale snapshot taken when debugging was turned on, even if the level had since changed again in between. Now it only restores the snapshot if the logger's current level still matches the FINE it set; otherwise something else already overrode it and that override is left alone. RemoteWebDriver's static initializer was dropped in the earlier commit in favor of calling configureLogger() from the canonical constructor. That regresses coverage: driver subclasses like ChromeDriver and FirefoxDriver perform driver-discovery logging (DriverFinder, SeleniumManager) as part of computing arguments to their own super(...) call, which runs before RemoteWebDriver's constructor body ever executes. Only the class's static initializer, guaranteed by JLS 12.4.2 to run before any subclass constructor body, catches that. Restored the static initializer alongside the constructor call; configureLogger() is idempotent so both are safe to keep, each covering a different gap. Also strengthens the test suite: the reversibility test now changes the level a second time after turning debugging on and asserts the newer value survives, instead of setting it before turning on, which made the bug impossible to observe. The INFO-duplication test now captures and counts actual published records through a stub handler plus captured stderr output, instead of only asserting the handler's own isLoggable() result against its own filter. Adds a constructor wiring test for RemoteWebDriver and a small new test package for LoggingOptions, which had no coverage before this change. --- .../org/openqa/selenium/grid/log/BUILD.bazel | 1 + .../org/openqa/selenium/internal/Debug.java | 36 +++--- .../selenium/remote/RemoteWebDriver.java | 11 ++ .../org/openqa/selenium/grid/log/BUILD.bazel | 14 +++ .../selenium/grid/log/LoggingOptionsTest.java | 86 ++++++++++++++ .../openqa/selenium/internal/DebugTest.java | 106 +++++++++++++++--- .../RemoteWebDriverInitializationTest.java | 47 ++++++++ 7 files changed, 270 insertions(+), 31 deletions(-) create mode 100644 java/test/org/openqa/selenium/grid/log/BUILD.bazel create mode 100644 java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java diff --git a/java/src/org/openqa/selenium/grid/log/BUILD.bazel b/java/src/org/openqa/selenium/grid/log/BUILD.bazel index 68c796f96396b..78b93d5c555ae 100644 --- a/java/src/org/openqa/selenium/grid/log/BUILD.bazel +++ b/java/src/org/openqa/selenium/grid/log/BUILD.bazel @@ -7,6 +7,7 @@ java_library( visibility = [ "//java/src/org/openqa/selenium/grid:__subpackages__", "//java/src/org/openqa/selenium/remote/server:__subpackages__", + "//java/test/org/openqa/selenium/grid/log:__pkg__", ], deps = [ "//java:auto-service", diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index 40c607fea7ee8..5ff693f3fc631 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -44,12 +44,12 @@ public static boolean isDebugging() { /** * @deprecated Individual log statements no longer change what severity they report at based on - * this switch; {@link #configureLogger()} raises the real {@code org.openqa.selenium} - * logger to {@link Level#FINE} instead, which is the ordinary way to see Selenium's debug - * output. Enable it with {@code -Dselenium.debug=true}, the {@code SE_DEBUG} environment - * variable, or directly via {@code Logger.getLogger("org.openqa.selenium").setLevel(Level - * .FINE)}. This method's own behavior is unchanged and kept only for existing call sites - * still comparing against it. + * this switch; {@link #configureLogger()} raises the real {@code org.openqa.selenium} logger + * to {@link Level#FINE} instead, which is the ordinary way to see Selenium's debug output. + * Enable it with {@code -Dselenium.debug=true}, the {@code SE_DEBUG} environment variable, or + * directly via {@code Logger.getLogger("org.openqa.selenium").setLevel(Level.FINE)}. This + * method's own behavior is unchanged and kept only for existing call sites still comparing + * against it. */ @Deprecated(forRemoval = true) public static Level getDebugLogLevel() { @@ -69,13 +69,16 @@ public static boolean isDebugAll() { /** * Reflects the current debug switches ({@code -Dselenium.debug=true}, {@code - * -Dselenium.webdriver.verbose=true}, {@code SE_DEBUG}) onto the real {@code - * org.openqa.selenium} logger: raises it to {@link Level#FINE} and attaches a handler Selenium - * owns, filtered to leave {@link Level#INFO} and above to the caller's own handlers so output - * they already print is never duplicated. Idempotent: repeated calls while the switches are - * unchanged do nothing. Reversible: once every switch is off, the next call removes exactly the - * handler this method installed and restores the logger's previous level. Safe to call from - * concurrent driver construction. + * -Dselenium.webdriver.verbose=true}, {@code SE_DEBUG}) onto the real {@code org.openqa.selenium} + * logger: raises it to {@link Level#FINE} and attaches a handler Selenium owns, filtered to leave + * {@link Level#INFO} and above to the caller's own handlers so output they already print is never + * duplicated. Idempotent: repeated calls while the switches are unchanged do nothing. Reversible: + * once every switch is off, the next call removes exactly the handler this method installed and + * restores the logger's level to what it was before debugging turned on, unless something else + * changed the level in the meantime -- that change is left alone rather than clobbered. This + * can't distinguish an external override that happens to also set exactly {@link Level#FINE}: + * since JUL has no level-change listener to tell the two apart, that specific case still restores + * the pre-debug level. Safe to call from concurrent driver construction. */ public static synchronized void configureLogger() { boolean shouldDebug = isDebugging() || isDebugAll(); @@ -97,7 +100,12 @@ public static synchronized void configureLogger() { SELENIUM_LOGGER.removeHandler(installedHandler); installedHandler.close(); installedHandler = null; - SELENIUM_LOGGER.setLevel(previousLevel); + // Only restore the snapshotted level if nothing else changed it in the meantime. If the + // logger's current level no longer matches the FINE we set, someone else already overrode + // it after we turned debugging on, and restoring our stale snapshot would clobber theirs. + if (Level.FINE.equals(SELENIUM_LOGGER.getLevel())) { + SELENIUM_LOGGER.setLevel(previousLevel); + } } loggerConfigured = shouldDebug; diff --git a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java index e200fdc619f42..b91565a925c55 100644 --- a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java +++ b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java @@ -122,6 +122,17 @@ public class RemoteWebDriver PrintsPage, TakesScreenshot { + // Guarantees (JLS 12.4.2) that debug logging is configured before ANY subclass constructor + // body runs -- including argument expressions passed to a subclass's own super(...) call, e.g. + // ChromeDriver/FirefoxDriver's DriverFinder/SeleniumManager discovery, which logs at FINE + // before super(...) is ever reached. configureLogger() is idempotent, so this and the call in + // the canonical instance constructor below are both safe to keep: this one covers logging that + // happens before an instance exists, the other picks up a property changed after this class + // already loaded. + static { + Debug.configureLogger(); + } + private static final Logger LOG = Logger.getLogger(RemoteWebDriver.class.getName()); /** Boolean system property that defines whether the tracing is enabled or not. */ diff --git a/java/test/org/openqa/selenium/grid/log/BUILD.bazel b/java/test/org/openqa/selenium/grid/log/BUILD.bazel new file mode 100644 index 0000000000000..ddc9c1a23b016 --- /dev/null +++ b/java/test/org/openqa/selenium/grid/log/BUILD.bazel @@ -0,0 +1,14 @@ +load("@rules_jvm_external//:defs.bzl", "artifact") +load("//java:defs.bzl", "JUNIT5_DEPS", "java_test_suite") + +java_test_suite( + name = "SmallTests", + size = "small", + srcs = glob(["*Test.java"]), + deps = [ + "//java/src/org/openqa/selenium/grid/config", + "//java/src/org/openqa/selenium/grid/log", + artifact("org.assertj:assertj-core"), + artifact("org.junit.jupiter:junit-jupiter-api"), + ] + JUNIT5_DEPS, +) diff --git a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java new file mode 100644 index 0000000000000..ea5758fb2f752 --- /dev/null +++ b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java @@ -0,0 +1,86 @@ +// Licensed to the Software Freedom Conservancy (SFC) under one +// or more contributor license agreements. See the NOTICE file +// distributed with this work for additional information +// regarding copyright ownership. The SFC 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.openqa.selenium.grid.log; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.util.Map; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.openqa.selenium.grid.config.MapConfig; + +@Tag("UnitTests") +class LoggingOptionsTest { + + private String oldDebugProperty; + + @BeforeEach + void storeSystemProperty() { + oldDebugProperty = System.getProperty("selenium.debug"); + System.clearProperty("selenium.debug"); + } + + @AfterEach + void restoreSystemProperty() { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + } + + @Test + void setLoggingLevelForcesFineWhenSeleniumDebugPropertyIsSet() { + System.setProperty("selenium.debug", "true"); + + String output = captureStderrDuring(() -> new LoggingOptions(emptyConfig()).setLoggingLevel()); + + // Before this change, only the SE_DEBUG environment variable (isDebugAll()) forced Grid's log + // level to FINE; -Dselenium.debug=true had no effect on Grid at all. Grid operators using that + // property must not silently lose Grid diagnostic output now that RemoteWebDriver's + // configureLogger() reacts to it too. + assertThat(output).contains("forcing Grid log level to FINE"); + } + + @Test + void setLoggingLevelDoesNotForceFineWhenNoDebugSwitchIsSet() { + String output = captureStderrDuring(() -> new LoggingOptions(emptyConfig()).setLoggingLevel()); + + assertThat(output).doesNotContain("forcing Grid log level to FINE"); + } + + private static MapConfig emptyConfig() { + return new MapConfig(Map.of()); + } + + private static String captureStderrDuring(Runnable action) { + PrintStream originalErr = System.err; + ByteArrayOutputStream captured = new ByteArrayOutputStream(); + try { + System.setErr(new PrintStream(captured)); + action.run(); + } finally { + System.setErr(originalErr); + } + return captured.toString(); + } +} diff --git a/java/test/org/openqa/selenium/internal/DebugTest.java b/java/test/org/openqa/selenium/internal/DebugTest.java index c9564cdc7a13d..b754211bc5e9b 100644 --- a/java/test/org/openqa/selenium/internal/DebugTest.java +++ b/java/test/org/openqa/selenium/internal/DebugTest.java @@ -19,6 +19,11 @@ import static org.assertj.core.api.Assertions.assertThat; +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.util.ArrayList; +import java.util.List; +import java.util.UUID; import java.util.logging.ConsoleHandler; import java.util.logging.Handler; import java.util.logging.Level; @@ -36,11 +41,13 @@ class DebugTest { private String oldDebugProperty; private String oldVerboseProperty; + private Level oldLoggerLevel; @BeforeEach void storeSystemProperties() { oldDebugProperty = System.getProperty("selenium.debug"); oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); + oldLoggerLevel = SELENIUM_LOGGER.getLevel(); System.clearProperty("selenium.debug"); System.clearProperty("selenium.webdriver.verbose"); } @@ -60,6 +67,10 @@ void restoreSystemProperties() { // Re-sync configureLogger's internal state/handler with the now-restored properties so a // handler installed by one test never leaks into the next. Debug.configureLogger(); + // A test may have changed the logger's level directly (simulating code other than Debug + // touching it); put it back exactly as found so tests stay isolated regardless of what + // configureLogger()'s own restore logic decided to do. + SELENIUM_LOGGER.setLevel(oldLoggerLevel); } @Test @@ -90,18 +101,45 @@ void configureLoggerRaisesSeleniumLoggerToFine() { } @Test - void configureLoggerRestoresPreviousLevelWhenDebuggingIsTurnedOff() { - SELENIUM_LOGGER.setLevel(Level.WARNING); + void configureLoggerDoesNotClobberALevelChangedWhileDebuggingWasOn() { System.setProperty("selenium.debug", "true"); Debug.configureLogger(); assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + // Something other than Debug changes the level while debugging is still on -- e.g. the user's + // own logging config. + SELENIUM_LOGGER.setLevel(Level.WARNING); + System.clearProperty("selenium.debug"); Debug.configureLogger(); + // The externally-set WARNING must survive. Debug must not clobber it with the level that was + // ambient before IT turned debugging on -- that snapshot is stale the moment anything else + // changes the level in between. assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.WARNING); } + @Test + void configureLoggerRestoresPreDebugLevelAndRemovesHandlerWhenTurnedOff() { + Level preDebugLevel = SELENIUM_LOGGER.getLevel(); + List handlersBeforeDebug = new ArrayList<>(List.of(SELENIUM_LOGGER.getHandlers())); + + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + + List handlersWhileDebugging = new ArrayList<>(List.of(SELENIUM_LOGGER.getHandlers())); + handlersWhileDebugging.removeAll(handlersBeforeDebug); + assertThat(handlersWhileDebugging).hasSize(1); + Handler installedHandler = handlersWhileDebugging.get(0); + + // No external override happens in between -- this is the plain turn-on/turn-off round trip. + System.clearProperty("selenium.debug"); + Debug.configureLogger(); + + assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(preDebugLevel); + assertThat(SELENIUM_LOGGER.getHandlers()).doesNotContain(installedHandler); + } + @Test void configureLoggerIsIdempotent() { int before = SELENIUM_LOGGER.getHandlers().length; @@ -133,22 +171,56 @@ void configureLoggerLeavesUserHandlersAlone() { @Test void infoRecordsAreNotDuplicatedWhenDebuggingIsEnabled() { - System.setProperty("selenium.debug", "true"); - Debug.configureLogger(); + List userHandlerRecords = new ArrayList<>(); + Handler userHandler = + new Handler() { + @Override + public void publish(LogRecord record) { + userHandlerRecords.add(record); + } + + @Override + public void flush() {} + + @Override + public void close() {} + }; + // Simulates a handler the caller already has attached directly to this logger (e.g. their + // own handler at INFO) that already prints INFO-and-above records on its own. + userHandler.setLevel(Level.INFO); + SELENIUM_LOGGER.addHandler(userHandler); + + boolean oldUseParentHandlers = SELENIUM_LOGGER.getUseParentHandlers(); + // Isolate this check to handlers attached directly to org.openqa.selenium. Propagation to the + // JVM's own root logger handler is a separate, legitimate print channel this test isn't + // about, and it would otherwise be indistinguishable from a real duplicate here. + SELENIUM_LOGGER.setUseParentHandlers(false); + + PrintStream originalErr = System.err; + ByteArrayOutputStream capturedErr = new ByteArrayOutputStream(); + String marker = "duplicate-check-" + UUID.randomUUID(); + try { + System.setErr(new PrintStream(capturedErr)); + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + + SELENIUM_LOGGER.log(Level.INFO, marker); + for (Handler handler : SELENIUM_LOGGER.getHandlers()) { + handler.flush(); + } + } finally { + System.setErr(originalErr); + SELENIUM_LOGGER.setUseParentHandlers(oldUseParentHandlers); + SELENIUM_LOGGER.removeHandler(userHandler); + } - Handler[] handlers = SELENIUM_LOGGER.getHandlers(); - assertThat(handlers).hasSize(1); - Handler seleniumOwnedHandler = handlers[0]; - - // Selenium's own handler must stay silent for INFO-and-above records so it never prints the - // same line the caller's own (e.g. root/console) handler already prints for them; it exists - // only to surface the FINE-and-below records those handlers don't. - assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.INFO, "info-record"))) - .isFalse(); - assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.WARNING, "warning-record"))) - .isFalse(); - assertThat(seleniumOwnedHandler.isLoggable(new LogRecord(Level.FINE, "fine-record"))) - .isTrue(); + // The caller's own handler must still see the record: Selenium never suppresses records for + // handlers it doesn't own. + assertThat(userHandlerRecords).extracting(LogRecord::getMessage).containsExactly(marker); + // Selenium's own handler must not ALSO print it to stderr -- otherwise the exact same line + // the caller's handler just printed would appear a second time, straight from Selenium's own + // console handler. + assertThat(capturedErr.toString()).doesNotContain(marker); } @Test diff --git a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java index 5759b4f253ea8..1d32cfb6fd845 100644 --- a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java +++ b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java @@ -41,7 +41,11 @@ import java.time.Duration; import java.util.Map; import java.util.UUID; +import java.util.logging.Level; +import java.util.logging.Logger; import org.jspecify.annotations.NullMarked; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; import org.mockito.ArgumentCaptor; @@ -49,6 +53,7 @@ import org.openqa.selenium.ImmutableCapabilities; import org.openqa.selenium.Platform; import org.openqa.selenium.SessionNotCreatedException; +import org.openqa.selenium.internal.Debug; import org.openqa.selenium.remote.http.ClientConfig; import org.openqa.selenium.remote.http.Contents; import org.openqa.selenium.remote.http.HttpClient; @@ -58,7 +63,49 @@ @Tag("UnitTests") class RemoteWebDriverInitializationTest { + private static final Logger SELENIUM_LOGGER = Logger.getLogger("org.openqa.selenium"); + private boolean quitCalled = false; + private String oldDebugProperty; + private Level oldLoggerLevel; + + @BeforeEach + void storeDebugState() { + oldDebugProperty = System.getProperty("selenium.debug"); + oldLoggerLevel = SELENIUM_LOGGER.getLevel(); + System.clearProperty("selenium.debug"); + } + + @AfterEach + void restoreDebugState() { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + Debug.configureLogger(); + SELENIUM_LOGGER.setLevel(oldLoggerLevel); + } + + @Test + void constructingASecondDriverPicksUpADebugPropertyChangedAfterTheFirst() throws IOException { + // First construction: touches (and, the first time in this JVM, initializes) the class while + // debugging is off -- exercises the static initializer with nothing to react to yet. + new RemoteWebDriver( + WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder), + new ImmutableCapabilities()); + + System.setProperty("selenium.debug", "true"); + + // Second construction, after the property changed. The class's static initializer already + // ran once and won't run again, so picking this up can only be the canonical constructor's + // own call to Debug.configureLogger(). + new RemoteWebDriver( + WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder), + new ImmutableCapabilities()); + + assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + } @Test void testQuitsIfStartSessionFails() { From a30865bcf0a86252d60af260bb504144fe1b0571 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 19:51:08 +0300 Subject: [PATCH 03/20] [java] Add javadoc to LoggingOptions#setLoggingLevel and RemoteWebDriver 3-arg ctor Documents the debug-switch override behavior (SE_DEBUG / -Dselenium.debug=true / -Dselenium.webdriver.verbose=true) on the two methods added by the debug logging consistency mechanism, so API consumers see the effect from Javadoc without reading the implementation. --- .../openqa/selenium/grid/log/LoggingOptions.java | 9 +++++++++ .../org/openqa/selenium/remote/RemoteWebDriver.java | 13 +++++++++++++ 2 files changed, 22 insertions(+) diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index 602aa82ab4a60..4795f84f658aa 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -85,6 +85,15 @@ public String getLogEncoding() { return config.get(LOGGING_SECTION, "log-encoding").orElse(null); } + /** + * Resolves the Grid log level from the {@code log-level} entry of the logging config section + * and stores it for {@link #configureLogging()}. Any active Selenium debug switch ({@code + * SE_DEBUG}, {@code -Dselenium.debug=true}, {@code -Dselenium.webdriver.verbose=true}) + * overrides the configured value and forces {@link Level#FINE}. An unparseable configured + * value falls back to the default ({@code INFO}). + * + * @return this instance, for method chaining + */ public LoggingOptions setLoggingLevel() { String configLevel = config.get(LOGGING_SECTION, "log-level").orElse(DEFAULT_LOG_LEVEL); if (Debug.isDebugAll() || Debug.isDebugging()) { diff --git a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java index b91565a925c55..01785ec74881d 100644 --- a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java +++ b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java @@ -210,6 +210,19 @@ public RemoteWebDriver(CommandExecutor executor, Capabilities capabilities) { this(executor, capabilities, ClientConfig.defaultConfig()); } + /** + * Creates a new driver that runs its commands through the given executor, requesting a new + * session with the given capabilities. Before the session starts, the current Selenium debug + * switches are reflected onto the {@code org.openqa.selenium} logger via {@link + * Debug#configureLogger()}, so a debug property changed at runtime takes effect for every + * driver constructed afterwards. + * + * @param executor the command executor used to communicate with the remote end; must not be + * null + * @param capabilities the capabilities requested for the new session; null is treated as an + * empty set of capabilities + * @param clientConfig the HTTP client configuration for the connection; must not be null + */ public RemoteWebDriver( CommandExecutor executor, Capabilities capabilities, ClientConfig clientConfig) { // Instance-time (not class-load-time) so a property change made after this class has already From e732035fed4c9b2273dd7dd12bc2aa79a73e3b13 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 19:55:43 +0300 Subject: [PATCH 04/20] [java] Address qodo review findings: Debug logger verbosity, RetryRequest stale log level - DebugTest: replace SELENIUM_LOGGER field with seleniumLogger() helper so the linter's per-class logger-naming check stops flagging a deliberate shared-category logger. - Debug#isDebugging(): add missing Javadoc. - Debug#configureLogger(): only raise the selenium logger to FINE when it is currently less verbose than FINE, so an already more-verbose level (e.g. FINER from W3CHttpResponseCodec) is never clobbered; only restore the pre-debug level when this method was the one that raised it. Adds a cross-binding Javadoc comparison against Python's SE_DEBUG import-time behavior (py/selenium/webdriver/__init__.py). - RetryRequest: stop caching Debug.getDebugLogLevel() in a static field at class-init -- now that the debug switch is live/toggleable at runtime, the snapshot went stale forever after the first read. Call it live at each log site instead, matching every other of the 64 call sites in java/src except this one. New/updated tests: - DebugTest: configureLoggerDoesNotLowerAnAlreadyMoreVerboseLevel, configureLoggerDoesNotRestoreALevelItNeverChanged. - RetryRequestTest: retryLogLevelTracksDebugToggleAtEachLogSite. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../org/openqa/selenium/internal/Debug.java | 66 ++++++++++---- .../selenium/remote/http/RetryRequest.java | 8 +- .../openqa/selenium/internal/DebugTest.java | 90 +++++++++++++------ .../remote/http/RetryRequestTest.java | 53 +++++++++++ 4 files changed, 173 insertions(+), 44 deletions(-) diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index 5ff693f3fc631..af9c88cf24a30 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -33,11 +33,20 @@ public class Debug { private static boolean loggerConfigured = false; private static Handler installedHandler = null; private static Level previousLevel = null; + private static boolean levelRaisedByDebug = false; private Debug() { // Utility class } + /** + * Reports whether Selenium debug logging has been requested via the {@code selenium.debug} or + * the legacy {@code selenium.webdriver.verbose} system property. Read live on every call, so a + * property change made at runtime is reflected immediately. + * + * @return true when either the {@code selenium.debug} or the {@code selenium.webdriver.verbose} + * system property is set to {@code true}; false otherwise + */ public static boolean isDebugging() { return Boolean.getBoolean("selenium.debug") || Boolean.getBoolean("selenium.webdriver.verbose"); } @@ -70,15 +79,26 @@ public static boolean isDebugAll() { /** * Reflects the current debug switches ({@code -Dselenium.debug=true}, {@code * -Dselenium.webdriver.verbose=true}, {@code SE_DEBUG}) onto the real {@code org.openqa.selenium} - * logger: raises it to {@link Level#FINE} and attaches a handler Selenium owns, filtered to leave - * {@link Level#INFO} and above to the caller's own handlers so output they already print is never - * duplicated. Idempotent: repeated calls while the switches are unchanged do nothing. Reversible: - * once every switch is off, the next call removes exactly the handler this method installed and - * restores the logger's level to what it was before debugging turned on, unless something else - * changed the level in the meantime -- that change is left alone rather than clobbered. This - * can't distinguish an external override that happens to also set exactly {@link Level#FINE}: - * since JUL has no level-change listener to tell the two apart, that specific case still restores - * the pre-debug level. Safe to call from concurrent driver construction. + * logger: raises it to {@link Level#FINE} when it is currently less verbose than {@link + * Level#FINE}; a level already at {@link Level#FINE} or more verbose is left untouched. It also + * attaches a handler Selenium owns, filtered to leave {@link Level#INFO} and above to the + * caller's own handlers so output they already print is never duplicated. Idempotent: repeated + * calls while the switches are unchanged do nothing. Reversible: once every switch is off, the + * next call removes exactly the handler this method installed and restores the logger's level to + * what it was before debugging turned on, only when this method was the one that raised it and + * unless something else changed the level in the meantime -- that change is left alone rather + * than clobbered. This can't distinguish an external override that happens to also set exactly + * {@link Level#FINE}: since JUL has no level-change listener to tell the two apart, that specific + * case still restores the pre-debug level. Safe to call from concurrent driver construction. + * + *

Cross-binding note: the Python binding does the analogous thing at import time (the + * {@code SE_DEBUG} block at the top of {@code py/selenium/webdriver/__init__.py}): when the + * {@code SE_DEBUG} environment variable is set it puts the {@code selenium} logger at + * {@code DEBUG} and attaches an unfiltered {@code StreamHandler} if the logger has none of + * its own. Two deliberate differences here: Java only raises the level when the logger is + * currently less verbose than {@link Level#FINE} (Python sets {@code DEBUG} unconditionally), + * and Java's handler is filtered to records below {@link Level#INFO} so output the caller's + * own handlers already print is never duplicated. */ public static synchronized void configureLogger() { boolean shouldDebug = isDebugging() || isDebugAll(); @@ -87,8 +107,21 @@ public static synchronized void configureLogger() { } if (shouldDebug) { - previousLevel = SELENIUM_LOGGER.getLevel(); - SELENIUM_LOGGER.setLevel(Level.FINE); + Level currentLevel = SELENIUM_LOGGER.getLevel(); + // Only raise the level when the logger is currently LESS verbose than FINE (higher + // intValue). A null level inherits the parent's (default INFO), so raising applies then + // too. An already more-verbose level (FINER, FINEST, ALL) is left alone: lowering it + // would make records like W3CHttpResponseCodec's FINER diagnostics unloggable while + // "debugging". This reads the logger's own level, not its effective level -- a + // more-verbose level inherited from a parent while this logger's own level is unset is + // still pinned to FINE, since JUL offers no way to read the effective level. + levelRaisedByDebug = currentLevel == null || currentLevel.intValue() > Level.FINE.intValue(); + if (levelRaisedByDebug) { + previousLevel = currentLevel; + SELENIUM_LOGGER.setLevel(Level.FINE); + } else { + previousLevel = null; + } Handler handler = new ConsoleHandler(); handler.setLevel(Level.FINE); @@ -100,12 +133,15 @@ public static synchronized void configureLogger() { SELENIUM_LOGGER.removeHandler(installedHandler); installedHandler.close(); installedHandler = null; - // Only restore the snapshotted level if nothing else changed it in the meantime. If the - // logger's current level no longer matches the FINE we set, someone else already overrode - // it after we turned debugging on, and restoring our stale snapshot would clobber theirs. - if (Level.FINE.equals(SELENIUM_LOGGER.getLevel())) { + // Restore only when Debug itself raised the level AND nothing else changed it since. The + // FINE-equality guard keeps the existing "external override while debugging" protection; + // levelRaisedByDebug additionally covers the case where Debug never touched the level at + // all and so has nothing to restore. + if (levelRaisedByDebug && Level.FINE.equals(SELENIUM_LOGGER.getLevel())) { SELENIUM_LOGGER.setLevel(previousLevel); } + levelRaisedByDebug = false; + previousLevel = null; } loggerConfigured = shouldDebug; diff --git a/java/src/org/openqa/selenium/remote/http/RetryRequest.java b/java/src/org/openqa/selenium/remote/http/RetryRequest.java index 17a3f7e0ed25c..de1343512da24 100644 --- a/java/src/org/openqa/selenium/remote/http/RetryRequest.java +++ b/java/src/org/openqa/selenium/remote/http/RetryRequest.java @@ -21,14 +21,12 @@ import static java.net.HttpURLConnection.HTTP_UNAVAILABLE; import java.net.ConnectException; -import java.util.logging.Level; import java.util.logging.Logger; import org.openqa.selenium.internal.Debug; public class RetryRequest implements Filter { private static final Logger LOG = Logger.getLogger(RetryRequest.class.getName()); - private static final Level LOG_LEVEL = Debug.getDebugLogLevel(); private static final int RETRIES_ON_CONNECTION_FAILURE = 3; private static final int RETRIES_ON_SERVER_ERROR = 2; @@ -50,7 +48,7 @@ public HttpHandler apply(HttpHandler next) { // must be a connection failure and check whether we have retries left for this if (isConnectionFailure && i < RETRIES_ON_CONNECTION_FAILURE) { - LOG.log(LOG_LEVEL, "Retry #" + (i + 1) + " on ConnectException", ex); + LOG.log(Debug.getDebugLogLevel(), "Retry #" + (i + 1) + " on ConnectException", ex); continue; } @@ -65,7 +63,9 @@ public HttpHandler apply(HttpHandler next) { // must be a server error and check whether we have retries left for this if (isServerError && i < RETRIES_ON_SERVER_ERROR) { - LOG.log(LOG_LEVEL, "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); + LOG.log( + Debug.getDebugLogLevel(), + "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); continue; } diff --git a/java/test/org/openqa/selenium/internal/DebugTest.java b/java/test/org/openqa/selenium/internal/DebugTest.java index b754211bc5e9b..747e5bccf9004 100644 --- a/java/test/org/openqa/selenium/internal/DebugTest.java +++ b/java/test/org/openqa/selenium/internal/DebugTest.java @@ -37,7 +37,14 @@ @Tag("UnitTests") class DebugTest { - private static final Logger SELENIUM_LOGGER = Logger.getLogger("org.openqa.selenium"); + /** + * The shared {@code org.openqa.selenium} logger whose state {@link Debug#configureLogger()} + * manages -- deliberately not this test class's own logger, because the behavior under test + * lives on the shared category. + */ + private static Logger seleniumLogger() { + return Logger.getLogger("org.openqa.selenium"); + } private String oldDebugProperty; private String oldVerboseProperty; @@ -47,7 +54,7 @@ class DebugTest { void storeSystemProperties() { oldDebugProperty = System.getProperty("selenium.debug"); oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); - oldLoggerLevel = SELENIUM_LOGGER.getLevel(); + oldLoggerLevel = seleniumLogger().getLevel(); System.clearProperty("selenium.debug"); System.clearProperty("selenium.webdriver.verbose"); } @@ -70,7 +77,7 @@ void restoreSystemProperties() { // A test may have changed the logger's level directly (simulating code other than Debug // touching it); put it back exactly as found so tests stay isolated regardless of what // configureLogger()'s own restore logic decided to do. - SELENIUM_LOGGER.setLevel(oldLoggerLevel); + seleniumLogger().setLevel(oldLoggerLevel); } @Test @@ -97,18 +104,18 @@ void configureLoggerRaisesSeleniumLoggerToFine() { Debug.configureLogger(); - assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); } @Test void configureLoggerDoesNotClobberALevelChangedWhileDebuggingWasOn() { System.setProperty("selenium.debug", "true"); Debug.configureLogger(); - assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); // Something other than Debug changes the level while debugging is still on -- e.g. the user's // own logging config. - SELENIUM_LOGGER.setLevel(Level.WARNING); + seleniumLogger().setLevel(Level.WARNING); System.clearProperty("selenium.debug"); Debug.configureLogger(); @@ -116,18 +123,18 @@ void configureLoggerDoesNotClobberALevelChangedWhileDebuggingWasOn() { // The externally-set WARNING must survive. Debug must not clobber it with the level that was // ambient before IT turned debugging on -- that snapshot is stale the moment anything else // changes the level in between. - assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.WARNING); + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.WARNING); } @Test void configureLoggerRestoresPreDebugLevelAndRemovesHandlerWhenTurnedOff() { - Level preDebugLevel = SELENIUM_LOGGER.getLevel(); - List handlersBeforeDebug = new ArrayList<>(List.of(SELENIUM_LOGGER.getHandlers())); + Level preDebugLevel = seleniumLogger().getLevel(); + List handlersBeforeDebug = new ArrayList<>(List.of(seleniumLogger().getHandlers())); System.setProperty("selenium.debug", "true"); Debug.configureLogger(); - List handlersWhileDebugging = new ArrayList<>(List.of(SELENIUM_LOGGER.getHandlers())); + List handlersWhileDebugging = new ArrayList<>(List.of(seleniumLogger().getHandlers())); handlersWhileDebugging.removeAll(handlersBeforeDebug); assertThat(handlersWhileDebugging).hasSize(1); Handler installedHandler = handlersWhileDebugging.get(0); @@ -136,36 +143,36 @@ void configureLoggerRestoresPreDebugLevelAndRemovesHandlerWhenTurnedOff() { System.clearProperty("selenium.debug"); Debug.configureLogger(); - assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(preDebugLevel); - assertThat(SELENIUM_LOGGER.getHandlers()).doesNotContain(installedHandler); + assertThat(seleniumLogger().getLevel()).isEqualTo(preDebugLevel); + assertThat(seleniumLogger().getHandlers()).doesNotContain(installedHandler); } @Test void configureLoggerIsIdempotent() { - int before = SELENIUM_LOGGER.getHandlers().length; + int before = seleniumLogger().getHandlers().length; System.setProperty("selenium.debug", "true"); for (int i = 0; i < 5; i++) { Debug.configureLogger(); } - assertThat(SELENIUM_LOGGER.getHandlers().length - before).isEqualTo(1); + assertThat(seleniumLogger().getHandlers().length - before).isEqualTo(1); } @Test void configureLoggerLeavesUserHandlersAlone() { Handler userHandler = new ConsoleHandler(); - SELENIUM_LOGGER.addHandler(userHandler); + seleniumLogger().addHandler(userHandler); try { System.setProperty("selenium.debug", "true"); Debug.configureLogger(); - assertThat(SELENIUM_LOGGER.getHandlers()).contains(userHandler); + assertThat(seleniumLogger().getHandlers()).contains(userHandler); System.clearProperty("selenium.debug"); Debug.configureLogger(); - assertThat(SELENIUM_LOGGER.getHandlers()).contains(userHandler); + assertThat(seleniumLogger().getHandlers()).contains(userHandler); } finally { - SELENIUM_LOGGER.removeHandler(userHandler); + seleniumLogger().removeHandler(userHandler); } } @@ -188,13 +195,13 @@ public void close() {} // Simulates a handler the caller already has attached directly to this logger (e.g. their // own handler at INFO) that already prints INFO-and-above records on its own. userHandler.setLevel(Level.INFO); - SELENIUM_LOGGER.addHandler(userHandler); + seleniumLogger().addHandler(userHandler); - boolean oldUseParentHandlers = SELENIUM_LOGGER.getUseParentHandlers(); + boolean oldUseParentHandlers = seleniumLogger().getUseParentHandlers(); // Isolate this check to handlers attached directly to org.openqa.selenium. Propagation to the // JVM's own root logger handler is a separate, legitimate print channel this test isn't // about, and it would otherwise be indistinguishable from a real duplicate here. - SELENIUM_LOGGER.setUseParentHandlers(false); + seleniumLogger().setUseParentHandlers(false); PrintStream originalErr = System.err; ByteArrayOutputStream capturedErr = new ByteArrayOutputStream(); @@ -204,14 +211,14 @@ public void close() {} System.setProperty("selenium.debug", "true"); Debug.configureLogger(); - SELENIUM_LOGGER.log(Level.INFO, marker); - for (Handler handler : SELENIUM_LOGGER.getHandlers()) { + seleniumLogger().log(Level.INFO, marker); + for (Handler handler : seleniumLogger().getHandlers()) { handler.flush(); } } finally { System.setErr(originalErr); - SELENIUM_LOGGER.setUseParentHandlers(oldUseParentHandlers); - SELENIUM_LOGGER.removeHandler(userHandler); + seleniumLogger().setUseParentHandlers(oldUseParentHandlers); + seleniumLogger().removeHandler(userHandler); } // The caller's own handler must still see the record: Selenium never suppresses records for @@ -223,6 +230,39 @@ public void close() {} assertThat(capturedErr.toString()).doesNotContain(marker); } + @Test + void configureLoggerDoesNotLowerAnAlreadyMoreVerboseLevel() { + // The application already asked for MORE verbosity than the debug switch provides, e.g. to + // see W3CHttpResponseCodec's FINER response-decoding diagnostics. + seleniumLogger().setLevel(Level.FINER); + + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + // Turning debug on must never make the logger LESS verbose than it already was. + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINER); + + System.clearProperty("selenium.debug"); + Debug.configureLogger(); + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINER); + } + + @Test + void configureLoggerDoesNotRestoreALevelItNeverChanged() { + seleniumLogger().setLevel(Level.FINER); + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); // debug on, level untouched (already more verbose than FINE) + + // Something else deliberately drops verbosity to FINE while debugging is on. + seleniumLogger().setLevel(Level.FINE); + + System.clearProperty("selenium.debug"); + Debug.configureLogger(); + + // Debug never changed the level (it was already more verbose when debug turned on), so + // turning debug off must not "restore" a pre-debug snapshot it never took either. + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); + } + @Test @SuppressWarnings({"deprecation", "removal"}) void getDebugLogLevelStillReportsInfoWhileDeprecated() { diff --git a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java index aec6358cdf088..2bd1fe87deb43 100644 --- a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java +++ b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java @@ -41,6 +41,10 @@ import java.util.concurrent.Future; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicReference; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.Logger; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.openqa.selenium.TimeoutException; @@ -339,6 +343,55 @@ void shouldRethrowOnConnectFailure() { assertThat(count).hasValue(4); } + @Test + void retryLogLevelTracksDebugToggleAtEachLogSite() { + // Force RetryRequest's class initialization BEFORE the debug property changes, pinning the + // stale-static-snapshot repro regardless of test execution order. + HttpHandler handler = + new RetryRequest().andFinally(request -> new HttpResponse().setStatus(HTTP_UNAVAILABLE)); + + Logger log = Logger.getLogger(RetryRequest.class.getName()); + List records = new ArrayList<>(); + Handler capture = + new Handler() { + @Override + public void publish(LogRecord record) { + records.add(record); + } + + @Override + public void flush() {} + + @Override + public void close() {} + }; + capture.setLevel(Level.ALL); + Level oldLevel = log.getLevel(); + String oldDebugProperty = System.getProperty("selenium.debug"); + log.setLevel(Level.ALL); + log.addHandler(capture); + try { + System.setProperty("selenium.debug", "true"); + handler.execute(new HttpRequest(GET, "/")); + assertThat(records).isNotEmpty(); + assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.INFO)); + + records.clear(); + System.clearProperty("selenium.debug"); + handler.execute(new HttpRequest(GET, "/")); + assertThat(records).isNotEmpty(); + assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.FINE)); + } finally { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + log.removeHandler(capture); + log.setLevel(oldLevel); + } + } + @Test void shouldDeliverUnmodifiedServerErrors() { AtomicInteger count = new AtomicInteger(0); From 31ea2ca10274f286a924c2ba9b9cad1d6c3ff59c Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 19:57:08 +0300 Subject: [PATCH 05/20] [java] Fix logger-field lint finding and de-mock a RemoteWebDriver test - Replace the SELENIUM_LOGGER static field with a seleniumLogger() helper in RemoteWebDriverInitializationTest, documenting why the test deliberately reads the shared org.openqa.selenium logger category rather than its own class logger. - Rewrite constructingASecondDriverPicksUpADebugPropertyChangedAfterTheFirst to use a plain lambda CommandExecutor instead of a Mockito mock, since the test makes no verify()/interaction assertions. --- .../RemoteWebDriverInitializationTest.java | 29 ++++++++++++------- 1 file changed, 18 insertions(+), 11 deletions(-) diff --git a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java index 1d32cfb6fd845..4a0d034207d9b 100644 --- a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java +++ b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java @@ -63,7 +63,14 @@ @Tag("UnitTests") class RemoteWebDriverInitializationTest { - private static final Logger SELENIUM_LOGGER = Logger.getLogger("org.openqa.selenium"); + /** + * The shared {@code org.openqa.selenium} logger that {@code Debug.configureLogger()} manages -- + * deliberately not this test class's own logger, because the assertion is about the shared + * category's state. + */ + private static Logger seleniumLogger() { + return Logger.getLogger("org.openqa.selenium"); + } private boolean quitCalled = false; private String oldDebugProperty; @@ -72,7 +79,7 @@ class RemoteWebDriverInitializationTest { @BeforeEach void storeDebugState() { oldDebugProperty = System.getProperty("selenium.debug"); - oldLoggerLevel = SELENIUM_LOGGER.getLevel(); + oldLoggerLevel = seleniumLogger().getLevel(); System.clearProperty("selenium.debug"); } @@ -84,27 +91,27 @@ void restoreDebugState() { System.clearProperty("selenium.debug"); } Debug.configureLogger(); - SELENIUM_LOGGER.setLevel(oldLoggerLevel); + seleniumLogger().setLevel(oldLoggerLevel); } @Test - void constructingASecondDriverPicksUpADebugPropertyChangedAfterTheFirst() throws IOException { + void constructingASecondDriverPicksUpADebugPropertyChangedAfterTheFirst() { + // A plain in-memory executor (no mocking framework): answers the single NEW_SESSION command + // each construction issues by echoing the requested capabilities back. + CommandExecutor inMemoryExecutor = command -> echoCapabilities.apply(command); + // First construction: touches (and, the first time in this JVM, initializes) the class while // debugging is off -- exercises the static initializer with nothing to react to yet. - new RemoteWebDriver( - WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder), - new ImmutableCapabilities()); + new RemoteWebDriver(inMemoryExecutor, new ImmutableCapabilities()); System.setProperty("selenium.debug", "true"); // Second construction, after the property changed. The class's static initializer already // ran once and won't run again, so picking this up can only be the canonical constructor's // own call to Debug.configureLogger(). - new RemoteWebDriver( - WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder), - new ImmutableCapabilities()); + new RemoteWebDriver(inMemoryExecutor, new ImmutableCapabilities()); - assertThat(SELENIUM_LOGGER.getLevel()).isEqualTo(Level.FINE); + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); } @Test From cdf85f7f70d89faff0b8cf4e840a984c088ff986 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 20:34:29 +0300 Subject: [PATCH 06/20] [java] Configure debug logger before driver discovery in DriverFinder DriverFinder.getBinaryPaths() is the single funnel all browser driver classes (including InternetExplorerDriver, which never reaches RemoteWebDriver's instance constructor at all) go through for discovery logging, before RemoteWebDriver's own constructor-level Debug.configureLogger() call is reached. Call it there instead, fixing the second-driver-onward gap for every construction path in one place. Closes #17834 Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../selenium/remote/service/DriverFinder.java | 7 +++ .../remote/service/DriverFinderTest.java | 52 +++++++++++++++++++ 2 files changed, 59 insertions(+) diff --git a/java/src/org/openqa/selenium/remote/service/DriverFinder.java b/java/src/org/openqa/selenium/remote/service/DriverFinder.java index 60ba25060b98a..6a8131c032e6c 100644 --- a/java/src/org/openqa/selenium/remote/service/DriverFinder.java +++ b/java/src/org/openqa/selenium/remote/service/DriverFinder.java @@ -27,6 +27,7 @@ import org.openqa.selenium.Capabilities; import org.openqa.selenium.Proxy; import org.openqa.selenium.WebDriverException; +import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Require; import org.openqa.selenium.manager.SeleniumManager; import org.openqa.selenium.manager.SeleniumManagerOutput.Result; @@ -91,6 +92,12 @@ public boolean hasBrowserPath() { } private Result getBinaryPaths() { + // Discovery logging (this class and SeleniumManager) can run before any RemoteWebDriver + // constructor -- e.g. as an argument to a browser driver's super(...) call, or with no + // RemoteWebDriver involved at all (InternetExplorerDriver, DriverService's lazy lookup, the + // DriverInfo classes). Reflect the current debug switches before that logging happens; + // configureLogger() is idempotent, so repeated calls are cheap. + Debug.configureLogger(); if (result == null) { try { String driverName = service.getDriverName(); diff --git a/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java b/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java index 6a89fbb5176c9..4d20e50f7e17f 100644 --- a/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java +++ b/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java @@ -33,6 +33,9 @@ import java.util.ArrayList; import java.util.List; import java.util.Map; +import java.util.logging.Level; +import java.util.logging.Logger; +import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; @@ -42,6 +45,7 @@ import org.openqa.selenium.Proxy; import org.openqa.selenium.Proxy.ProxyType; import org.openqa.selenium.chrome.ElectronOptions; +import org.openqa.selenium.internal.Debug; import org.openqa.selenium.manager.SeleniumManager; import org.openqa.selenium.manager.SeleniumManagerOutput.Result; import uk.org.webcompere.systemstubs.environment.EnvironmentVariables; @@ -65,6 +69,54 @@ void createMocks() { when(service.getDriverName()).thenReturn("driverName"); } + /** + * The shared {@code org.openqa.selenium} logger that {@code Debug.configureLogger()} manages -- + * deliberately not this test class's own logger, because the assertion is about the shared + * category's state. + */ + private static Logger seleniumLogger() { + return Logger.getLogger("org.openqa.selenium"); + } + + private String oldDebugProperty; + private Level oldLoggerLevel; + + @BeforeEach + void storeDebugState() { + oldDebugProperty = System.getProperty("selenium.debug"); + oldLoggerLevel = seleniumLogger().getLevel(); + System.clearProperty("selenium.debug"); + } + + @AfterEach + void restoreDebugState() { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + Debug.configureLogger(); + seleniumLogger().setLevel(oldLoggerLevel); + } + + @Test + void secondDiscoveryPicksUpADebugPropertyChangedAfterTheFirst() { + when(service.getExecutable()).thenReturn(driverFile.toString()); + Capabilities capabilities = new ImmutableCapabilities("browserName", "chrome"); + + // First discovery while debugging is off -- nothing for configureLogger to react to. + new DriverFinder(service, capabilities).getDriverPath(); + + System.setProperty("selenium.debug", "true"); + + // Second discovery after the property changed. No RemoteWebDriver constructor is involved + // (this is also the only coverage InternetExplorerDriver's discovery path gets), so only + // getBinaryPaths' own Debug.configureLogger() call can pick this up. + new DriverFinder(service, capabilities).getDriverPath(); + + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); + } + @Test void serviceValueIgnoresSeleniumManager() { when(service.getExecutable()).thenReturn(driverFile.toString()); From 63b0e87e04db4e1b6a393357b278ea31c81c8175 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 21:33:21 +0300 Subject: [PATCH 07/20] [java] Migrate grid distributor logging off deprecated getDebugLogLevel() LocalGridModel, LocalNodeRegistry, LocalDistributor, RedisBackedGridModel, RedisBackedNodeRegistry, and RedisBackedDistributor now log at a fixed Level.FINE instead of Debug.getDebugLogLevel()'s deprecated INFO/FINE dance -- Debug.configureLogger() already makes FINE visible when debugging, so nothing is lost. Also collapses two now-pointless isLoggable(FINE) guards in the two Distributor classes. Part of #17835 Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../distributor/local/LocalDistributor.java | 9 +++------ .../distributor/local/LocalGridModel.java | 6 +++--- .../distributor/local/LocalNodeRegistry.java | 17 ++++++++--------- .../redis/RedisBackedDistributor.java | 9 +++------ .../redis/RedisBackedGridModel.java | 6 +++--- .../redis/RedisBackedNodeRegistry.java | 19 +++++++++---------- 6 files changed, 29 insertions(+), 37 deletions(-) diff --git a/java/src/org/openqa/selenium/grid/distributor/local/LocalDistributor.java b/java/src/org/openqa/selenium/grid/distributor/local/LocalDistributor.java index 65715330c0a65..d522d80e6240e 100644 --- a/java/src/org/openqa/selenium/grid/distributor/local/LocalDistributor.java +++ b/java/src/org/openqa/selenium/grid/distributor/local/LocalDistributor.java @@ -18,7 +18,6 @@ package org.openqa.selenium.grid.distributor.local; import static org.openqa.selenium.concurrent.ExecutorServices.shutdownGracefully; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.remote.RemoteTags.CAPABILITIES; import static org.openqa.selenium.remote.RemoteTags.CAPABILITIES_EVENT; import static org.openqa.selenium.remote.RemoteTags.SESSION_ID; @@ -464,7 +463,7 @@ private SlotId reserveSlot(RequestId requestId, Capabilities caps) { if (slotIds.isEmpty()) { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format("No slots found for request %s and capabilities %s", requestId, caps)); return null; } @@ -574,7 +573,7 @@ public void run() { sessionCreatorExecutor.execute(() -> handleNewSessionRequest(req)); } catch (RejectedExecutionException e) { LOG.log( - getDebugLogLevel(), + Level.FINE, "Dropping session creation task while shutting down distributor", e); } @@ -632,9 +631,7 @@ private void handleNewSessionRequest(SessionRequest sessionRequest) { if (response.isLeft() && response.left() instanceof RetrySessionRequestException) { try (Span childSpan = span.createSpan("distributor.retry")) { - if (LOG.isLoggable(getDebugLogLevel())) { - LOG.log(getDebugLogLevel(), "Retrying {0}", sessionRequest.getDesiredCapabilities()); - } + LOG.log(Level.FINE, "Retrying {0}", sessionRequest.getDesiredCapabilities()); boolean retried = sessionQueue.retryAddToQueue(sessionRequest); attributeMap.put("request.retry_add", retried); diff --git a/java/src/org/openqa/selenium/grid/distributor/local/LocalGridModel.java b/java/src/org/openqa/selenium/grid/distributor/local/LocalGridModel.java index da497a794c5f5..3608e9547ea34 100644 --- a/java/src/org/openqa/selenium/grid/distributor/local/LocalGridModel.java +++ b/java/src/org/openqa/selenium/grid/distributor/local/LocalGridModel.java @@ -33,6 +33,7 @@ import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReadWriteLock; import java.util.concurrent.locks.ReentrantReadWriteLock; +import java.util.logging.Level; import java.util.logging.Logger; import org.jspecify.annotations.Nullable; import org.openqa.selenium.events.EventBus; @@ -49,7 +50,6 @@ import org.openqa.selenium.grid.data.SlotId; import org.openqa.selenium.grid.distributor.GridModel; import org.openqa.selenium.grid.server.EventBusOptions; -import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Require; import org.openqa.selenium.remote.SessionId; @@ -101,7 +101,7 @@ public void add(NodeStatus node) { && next.getExternalUri().equals(node.getExternalUri())) { iterator.remove(); - LOG.log(Debug.getDebugLogLevel(), "Refreshing node with id {0}", node.getNodeId()); + LOG.log(Level.FINE, "Refreshing node with id {0}", node.getNodeId()); NodeStatus refreshed = rewrite(node, next.getAvailability()); nodes.add(refreshed); nodePurgeTimes.put(refreshed.getNodeId(), Instant.now()); @@ -140,7 +140,7 @@ public void add(NodeStatus node) { // Nodes are initially added in the "down" state until something changes their availability LOG.log( - Debug.getDebugLogLevel(), + Level.FINE, "Adding node with id {0} and URI {1}", new Object[] {node.getNodeId(), node.getExternalUri()}); NodeStatus refreshed = rewrite(node, DOWN); diff --git a/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java b/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java index bcd21fc1675d0..4bc786552e37d 100644 --- a/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java +++ b/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java @@ -22,7 +22,6 @@ import static org.openqa.selenium.grid.data.Availability.DOWN; import static org.openqa.selenium.grid.data.Availability.DRAINING; import static org.openqa.selenium.grid.data.Availability.UP; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import java.net.URI; import java.time.Duration; @@ -228,7 +227,7 @@ public void add(Node node) { } } catch (Exception e) { LOG.log( - getDebugLogLevel(), String.format("Exception while adding Node %s", node.getUri()), e); + Level.FINE, String.format("Exception while adding Node %s", node.getUri()), e); return; } @@ -298,7 +297,7 @@ public void updateNodeAvailability(URI nodeUri, NodeId id, Availability availabi writeLock.lock(); try { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format("Health check result for %s was %s", nodeUri, availability)); model.setAvailability(id, availability); model.updateHealthCheckCount(id, availability); @@ -310,7 +309,7 @@ public void updateNodeAvailability(URI nodeUri, NodeId id, Availability availabi @Override public void runHealthChecks() { if (!healthChecksInProgress.compareAndSet(false, true)) { - LOG.log(getDebugLogLevel(), "Skipping health checks because previous cycle is still running"); + LOG.log(Level.FINE, "Skipping health checks because previous cycle is still running"); return; } @@ -335,7 +334,7 @@ public void runHealthChecks() { futures.add(nodeHealthCheckExecutor.submit(() -> runHealthCheck(nodeId, check))); } catch (RejectedExecutionException e) { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format( "Unable to schedule health check for node %s, running in caller thread", nodeId), @@ -351,7 +350,7 @@ public void runHealthChecks() { Thread.currentThread().interrupt(); break; } catch (Exception e) { - LOG.log(getDebugLogLevel(), "Error waiting for health check execution", e); + LOG.log(Level.FINE, "Error waiting for health check execution", e); } } } finally { @@ -452,7 +451,7 @@ private void runHealthCheck(NodeId nodeId, Runnable check) { try { check.run(); } catch (Throwable t) { - LOG.log(getDebugLogLevel(), "Health check execution failed for node " + nodeId, t); + LOG.log(Level.FINE, "Health check execution failed for node " + nodeId, t); } } @@ -462,7 +461,7 @@ private Runnable asRunnableHealthCheck(Node node) { return () -> { boolean checkFailed = false; Exception failedCheckException = null; - LOG.log(getDebugLogLevel(), "Running healthcheck for Node " + node.getUri()); + LOG.log(Level.FINE, "Running healthcheck for Node " + node.getUri()); HealthCheck.Result result; try { @@ -500,7 +499,7 @@ public boolean reserve(SlotId slotId) { NodeId nodeId = slotId.getOwningNodeId(); Node node = nodes.get(nodeId); if (node == null) { - LOG.log(getDebugLogLevel(), String.format("Unable to find node with id %s", slotId)); + LOG.log(Level.FINE, String.format("Unable to find node with id %s", slotId)); return false; } diff --git a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedDistributor.java b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedDistributor.java index 72bc8c2e02139..69ea7622622ab 100644 --- a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedDistributor.java +++ b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedDistributor.java @@ -18,7 +18,6 @@ package org.openqa.selenium.grid.distributor.redis; import static org.openqa.selenium.concurrent.ExecutorServices.shutdownGracefully; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.remote.RemoteTags.CAPABILITIES; import static org.openqa.selenium.remote.RemoteTags.CAPABILITIES_EVENT; import static org.openqa.selenium.remote.RemoteTags.SESSION_ID; @@ -506,7 +505,7 @@ private SlotId reserveSlot(RequestId requestId, Capabilities caps) { if (slotIds.isEmpty()) { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format("No slots found for request %s and capabilities %s", requestId, caps)); return null; } @@ -629,7 +628,7 @@ public void run() { sessionCreatorExecutor.execute(() -> handleNewSessionRequest(req)); } catch (RejectedExecutionException e) { LOG.log( - getDebugLogLevel(), + Level.FINE, "Dropping session creation task while shutting down distributor", e); } @@ -684,9 +683,7 @@ private void handleNewSessionRequest(SessionRequest sessionRequest) { if (response.isLeft() && response.left() instanceof RetrySessionRequestException) { try (Span childSpan = span.createSpan("distributor.retry")) { - if (LOG.isLoggable(getDebugLogLevel())) { - LOG.log(getDebugLogLevel(), "Retrying {0}", sessionRequest.getDesiredCapabilities()); - } + LOG.log(Level.FINE, "Retrying {0}", sessionRequest.getDesiredCapabilities()); boolean retried = sessionQueue.retryAddToQueue(sessionRequest); attributeMap.put("request.retry_add", retried); childSpan.addEvent("Retry adding to front of queue. No slot available.", attributeMap); diff --git a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedGridModel.java b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedGridModel.java index 8977d95a29c42..fc0b5eafc02cb 100644 --- a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedGridModel.java +++ b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedGridModel.java @@ -26,6 +26,7 @@ import java.util.Optional; import java.util.Set; import java.util.UUID; +import java.util.logging.Level; import java.util.logging.Logger; import org.jspecify.annotations.Nullable; import org.openqa.selenium.events.EventBus; @@ -40,7 +41,6 @@ import org.openqa.selenium.grid.data.Slot; import org.openqa.selenium.grid.data.SlotId; import org.openqa.selenium.grid.distributor.GridModel; -import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Require; import org.openqa.selenium.json.Json; import org.openqa.selenium.redis.GridRedisClient; @@ -197,7 +197,7 @@ public void add(NodeStatus node) { if (existing.getNodeId().equals(node.getNodeId()) && existing.getExternalUri().equals(node.getExternalUri())) { // Same node refreshing — keep existing availability. - LOG.log(Debug.getDebugLogLevel(), "Refreshing node with id {0}", node.getNodeId()); + LOG.log(Level.FINE, "Refreshing node with id {0}", node.getNodeId()); NodeStatus refreshed = rewrite(node, existing.getAvailability()); writeNodeBlob(refreshed); redis.set(lastTouchKey(node.getNodeId()), String.valueOf(Instant.now().toEpochMilli())); @@ -229,7 +229,7 @@ public void add(NodeStatus node) { // Add as DOWN until health check promotes it. LOG.log( - Debug.getDebugLogLevel(), + Level.FINE, "Adding node with id {0} and URI {1}", new Object[] {node.getNodeId(), node.getExternalUri()}); NodeStatus asDown = rewrite(node, DOWN); diff --git a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java index d4d8119f510b7..7b8ad352bae78 100644 --- a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java +++ b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java @@ -22,7 +22,6 @@ import static org.openqa.selenium.grid.data.Availability.DOWN; import static org.openqa.selenium.grid.data.Availability.DRAINING; import static org.openqa.selenium.grid.data.Availability.UP; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import java.net.URI; import java.time.Duration; @@ -292,7 +291,7 @@ public void add(Node node) { } } catch (Exception e) { LOG.log( - getDebugLogLevel(), String.format("Exception while adding Node %s", node.getUri()), e); + Level.FINE, String.format("Exception while adding Node %s", node.getUri()), e); return; } @@ -361,7 +360,7 @@ public void updateNodeAvailability(URI nodeUri, NodeId id, Availability availabi writeLock.lock(); try { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format("Health check result for %s was %s", nodeUri, availability)); model.setAvailability(id, availability); model.updateHealthCheckCount(id, availability); @@ -373,7 +372,7 @@ public void updateNodeAvailability(URI nodeUri, NodeId id, Availability availabi @Override public void runHealthChecks() { if (!healthChecksInProgress.compareAndSet(false, true)) { - LOG.log(getDebugLogLevel(), "Skipping health checks because previous cycle is still running"); + LOG.log(Level.FINE, "Skipping health checks because previous cycle is still running"); return; } @@ -400,7 +399,7 @@ public void runHealthChecks() { redis.setIfAbsent("grid:healthcheck:lock:" + nodeId, instanceId, lockTtlMillis); if (!won) { LOG.log( - getDebugLogLevel(), + Level.FINE, "Another replica is handling health check for node {0}, skipping", nodeId); return; @@ -409,7 +408,7 @@ public void runHealthChecks() { futures.add(nodeHealthCheckExecutor.submit(() -> runHealthCheck(nodeId, check))); } catch (RejectedExecutionException e) { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format( "Unable to schedule health check for node %s, running in caller thread", nodeId), @@ -425,7 +424,7 @@ public void runHealthChecks() { Thread.currentThread().interrupt(); break; } catch (Exception e) { - LOG.log(getDebugLogLevel(), "Error waiting for health check execution", e); + LOG.log(Level.FINE, "Error waiting for health check execution", e); } } } finally { @@ -521,7 +520,7 @@ private void runHealthCheck(NodeId nodeId, Runnable check) { try { check.run(); } catch (Throwable t) { - LOG.log(getDebugLogLevel(), "Health check execution failed for node " + nodeId, t); + LOG.log(Level.FINE, "Health check execution failed for node " + nodeId, t); } } @@ -531,7 +530,7 @@ private Runnable asRunnableHealthCheck(Node node) { return () -> { boolean checkFailed = false; Exception failedCheckException = null; - LOG.log(getDebugLogLevel(), "Running healthcheck for Node " + node.getUri()); + LOG.log(Level.FINE, "Running healthcheck for Node " + node.getUri()); HealthCheck.Result result; try { @@ -560,7 +559,7 @@ public boolean reserve(SlotId slotId) { NodeId nodeId = slotId.getOwningNodeId(); Node node = nodes.get(nodeId); if (node == null) { - LOG.log(getDebugLogLevel(), String.format("Unable to find node with id %s", slotId)); + LOG.log(Level.FINE, String.format("Unable to find node with id %s", slotId)); return false; } try { From fb70a79f7dd6d905678277dae0bc4817f1ac01a1 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 21:33:30 +0300 Subject: [PATCH 08/20] [java] Migrate node/netty/remote logging off deprecated getDebugLogLevel() LocalNode, ProxyNodeWebsockets, RelaySessionFactory, RequestConverter, RemoteWebDriverBuilder, and RetryRequest now log at a fixed Level.FINE instead of Debug.getDebugLogLevel()'s deprecated INFO/FINE dance -- Debug.configureLogger() already makes FINE visible when debugging, so nothing is lost. Part of #17835 Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../selenium/grid/node/ProxyNodeWebsockets.java | 5 ++--- .../openqa/selenium/grid/node/local/LocalNode.java | 7 +++---- .../grid/node/relay/RelaySessionFactory.java | 5 ++--- .../selenium/netty/server/RequestConverter.java | 13 ++++++------- .../selenium/remote/RemoteWebDriverBuilder.java | 9 ++++----- .../openqa/selenium/remote/http/RetryRequest.java | 8 +++----- 6 files changed, 20 insertions(+), 27 deletions(-) diff --git a/java/src/org/openqa/selenium/grid/node/ProxyNodeWebsockets.java b/java/src/org/openqa/selenium/grid/node/ProxyNodeWebsockets.java index d6b9b34696fcc..6a4222b294bd8 100644 --- a/java/src/org/openqa/selenium/grid/node/ProxyNodeWebsockets.java +++ b/java/src/org/openqa/selenium/grid/node/ProxyNodeWebsockets.java @@ -17,7 +17,6 @@ package org.openqa.selenium.grid.node; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.remote.http.HttpMethod.GET; import io.netty.buffer.Unpooled; @@ -181,7 +180,7 @@ private Optional> findCdpEndpoint( } if (cdpUri.isPresent()) { - LOG.log(getDebugLogLevel(), String.format("Endpoint found in %s", cdpEndpointCap)); + LOG.log(Level.FINE, String.format("Endpoint found in %s", cdpEndpointCap)); return cdpUri.map(cdp -> createWsEndPoint(cdp, downstream, sessionConsumer, sessionId)); } else { try { @@ -246,7 +245,7 @@ private Optional> findVncEndpoint( LOG.warning("Invalid URI for endpoint " + vncLocalAddress); return Optional.empty(); } - LOG.log(getDebugLogLevel(), String.format("Endpoint found in %s", "se:vncLocalAddress")); + LOG.log(Level.FINE, String.format("Endpoint found in %s", "se:vncLocalAddress")); return vncUri.map(vnc -> createWsEndPoint(vnc, downstream, sessionConsumer, sessionId)); } diff --git a/java/src/org/openqa/selenium/grid/node/local/LocalNode.java b/java/src/org/openqa/selenium/grid/node/local/LocalNode.java index 06b78eaa89405..d2198e9668987 100644 --- a/java/src/org/openqa/selenium/grid/node/local/LocalNode.java +++ b/java/src/org/openqa/selenium/grid/node/local/LocalNode.java @@ -114,7 +114,6 @@ import org.openqa.selenium.grid.node.config.NodeOptions; import org.openqa.selenium.grid.node.docker.DockerSession; import org.openqa.selenium.grid.security.Secret; -import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Either; import org.openqa.selenium.internal.Require; import org.openqa.selenium.io.FileHandler; @@ -407,7 +406,7 @@ private void stopTimedOutSession( } } } else { - LOG.log(Debug.getDebugLogLevel(), "Received stop session notification with null values"); + LOG.log(Level.FINE, "Received stop session notification with null values"); span.setStatus(Status.INVALID_ARGUMENT); span.addEvent("Received stop session notification with null values", attributeMap); } @@ -1412,7 +1411,7 @@ private boolean decrementSessionCount() { if (this.drainAfterSessions) { int remainingSessions = this.sessionCount.decrementAndGet(); LOG.log( - Debug.getDebugLogLevel(), + Level.FINE, "{0} remaining sessions before draining Node", remainingSessions); return remainingSessions >= 0; @@ -1428,7 +1427,7 @@ private void restoreSessionCount() { if (this.drainAfterSessions) { int remainingSessions = this.sessionCount.incrementAndGet(); LOG.log( - Debug.getDebugLogLevel(), + Level.FINE, "Session creation failed, restored count. {0} remaining sessions before draining Node", remainingSessions); } diff --git a/java/src/org/openqa/selenium/grid/node/relay/RelaySessionFactory.java b/java/src/org/openqa/selenium/grid/node/relay/RelaySessionFactory.java index 949d96f9ca311..f715c9302bb43 100644 --- a/java/src/org/openqa/selenium/grid/node/relay/RelaySessionFactory.java +++ b/java/src/org/openqa/selenium/grid/node/relay/RelaySessionFactory.java @@ -49,7 +49,6 @@ import org.openqa.selenium.grid.node.ActiveSession; import org.openqa.selenium.grid.node.DefaultActiveSession; import org.openqa.selenium.grid.node.SessionFactory; -import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Either; import org.openqa.selenium.internal.Require; import org.openqa.selenium.remote.CapabilityType; @@ -244,7 +243,7 @@ public boolean isServiceUp() { try (HttpClient client = clientFactory.createClient(clientConfig)) { HttpResponse response = client.execute(new HttpRequest(HttpMethod.GET, serviceStatusUrl.toString())); - LOG.log(Debug.getDebugLogLevel(), response::contentAsString); + LOG.log(Level.FINE, response::contentAsString); return response.getStatus() == 200; } catch (Exception e) { LOG.log( @@ -252,7 +251,7 @@ public boolean isServiceUp() { () -> String.format( "Error checking service status %s. %s", serviceStatusUrl, e.getMessage())); - LOG.log(Debug.getDebugLogLevel(), "Error checking service status " + serviceStatusUrl, e); + LOG.log(Level.FINE, "Error checking service status " + serviceStatusUrl, e); } return false; } diff --git a/java/src/org/openqa/selenium/netty/server/RequestConverter.java b/java/src/org/openqa/selenium/netty/server/RequestConverter.java index 4b98fe4ffa1f6..6084536a91c7a 100644 --- a/java/src/org/openqa/selenium/netty/server/RequestConverter.java +++ b/java/src/org/openqa/selenium/netty/server/RequestConverter.java @@ -38,9 +38,9 @@ import io.netty.util.ReferenceCountUtil; import java.util.Set; import java.util.concurrent.atomic.AtomicLong; +import java.util.logging.Level; import java.util.logging.Logger; import org.jspecify.annotations.Nullable; -import org.openqa.selenium.internal.Debug; import org.openqa.selenium.remote.http.Contents; import org.openqa.selenium.remote.http.HttpMethod; import org.openqa.selenium.remote.http.HttpRequest; @@ -58,10 +58,10 @@ class RequestConverter extends SimpleChannelInboundHandler { @Override protected void channelRead0(ChannelHandlerContext ctx, HttpObject msg) throws Exception { - LOG.log(Debug.getDebugLogLevel(), "Incoming message: {0}", msg); + LOG.log(Level.FINE, "Incoming message: {0}", msg); if (msg instanceof io.netty.handler.codec.http.HttpRequest) { - LOG.log(Debug.getDebugLogLevel(), "Start of http request: {0}", msg); + LOG.log(Level.FINE, "Start of http request: {0}", msg); io.netty.handler.codec.http.HttpRequest nettyRequest = (io.netty.handler.codec.http.HttpRequest) msg; @@ -112,7 +112,7 @@ protected void channelRead0(ChannelHandlerContext ctx, HttpObject msg) throws Ex } if (msg instanceof LastHttpContent) { - LOG.log(Debug.getDebugLogLevel(), "End of http request: {0}", msg); + LOG.log(Level.FINE, "End of http request: {0}", msg); if (buffer != null) { request.setContent( @@ -128,7 +128,7 @@ protected void channelRead0(ChannelHandlerContext ctx, HttpObject msg) throws Ex @Override public void channelInactive(ChannelHandlerContext ctx) throws Exception { - LOG.log(Debug.getDebugLogLevel(), "Channel became inactive."); + LOG.log(Level.FINE, "Channel became inactive."); super.channelInactive(ctx); } @@ -172,8 +172,7 @@ private HttpRequest createRequest( } catch (Exception ignore) { ctx.writeAndFlush( new DefaultFullHttpResponse(HttpVersion.HTTP_1_1, HttpResponseStatus.BAD_REQUEST)); - LOG.log( - Debug.getDebugLogLevel(), "Not possible to decode parameters. {0}", nettyRequest.uri()); + LOG.log(Level.FINE, "Not possible to decode parameters. {0}", nettyRequest.uri()); return null; } } diff --git a/java/src/org/openqa/selenium/remote/RemoteWebDriverBuilder.java b/java/src/org/openqa/selenium/remote/RemoteWebDriverBuilder.java index 036d441f1d733..ebf1e14ebe2d7 100644 --- a/java/src/org/openqa/selenium/remote/RemoteWebDriverBuilder.java +++ b/java/src/org/openqa/selenium/remote/RemoteWebDriverBuilder.java @@ -18,7 +18,6 @@ package org.openqa.selenium.remote; import static java.util.logging.Level.WARNING; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.remote.DriverCommand.QUIT; import static org.openqa.selenium.remote.http.HttpMethod.DELETE; @@ -37,6 +36,7 @@ import java.util.TreeMap; import java.util.function.Function; import java.util.function.Supplier; +import java.util.logging.Level; import java.util.logging.Logger; import java.util.stream.Collectors; import java.util.stream.StreamSupport; @@ -114,8 +114,7 @@ public RemoteWebDriverBuilder oneOf(Capabilities maybeThis, Capabilities... orOn Require.nonNull("Capabilities to use", maybeThis); if (!requestedCapabilities.isEmpty()) { - LOG.log( - getDebugLogLevel(), "Removing existing requested capabilities: " + requestedCapabilities); + LOG.log(Level.FINE, "Removing existing requested capabilities: " + requestedCapabilities); requestedCapabilities.clear(); } @@ -155,7 +154,7 @@ public RemoteWebDriverBuilder addMetadata(String key, Object value) { Object previous = metadata.put(key, value); if (previous != null) { LOG.log( - getDebugLogLevel(), + Level.FINE, String.format( "Overwriting metadata %s. Previous value %s, new value %s", key, previous, value)); } @@ -176,7 +175,7 @@ public RemoteWebDriverBuilder setCapability(String capabilityName, Object value) Object previous = additionalCapabilities.put(capabilityName, value); if (previous != null) { LOG.log( - getDebugLogLevel(), + Level.FINE, () -> String.format( "Overwriting capability %s. Previous value %s, new value %s", diff --git a/java/src/org/openqa/selenium/remote/http/RetryRequest.java b/java/src/org/openqa/selenium/remote/http/RetryRequest.java index de1343512da24..00efadec5e7f8 100644 --- a/java/src/org/openqa/selenium/remote/http/RetryRequest.java +++ b/java/src/org/openqa/selenium/remote/http/RetryRequest.java @@ -21,8 +21,8 @@ import static java.net.HttpURLConnection.HTTP_UNAVAILABLE; import java.net.ConnectException; +import java.util.logging.Level; import java.util.logging.Logger; -import org.openqa.selenium.internal.Debug; public class RetryRequest implements Filter { @@ -48,7 +48,7 @@ public HttpHandler apply(HttpHandler next) { // must be a connection failure and check whether we have retries left for this if (isConnectionFailure && i < RETRIES_ON_CONNECTION_FAILURE) { - LOG.log(Debug.getDebugLogLevel(), "Retry #" + (i + 1) + " on ConnectException", ex); + LOG.log(Level.FINE, "Retry #" + (i + 1) + " on ConnectException", ex); continue; } @@ -63,9 +63,7 @@ public HttpHandler apply(HttpHandler next) { // must be a server error and check whether we have retries left for this if (isServerError && i < RETRIES_ON_SERVER_ERROR) { - LOG.log( - Debug.getDebugLogLevel(), - "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); + LOG.log(Level.FINE, "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); continue; } From 1f03c239833f3ab7c840abc751d4374561326de3 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 21:33:41 +0300 Subject: [PATCH 09/20] [java] Migrate devtools/bidi Connection logging off deprecated getDebugLogLevel() devtools.Connection and bidi.Connection now log at a fixed Level.FINE instead of Debug.getDebugLogLevel()'s deprecated INFO/FINE dance -- Debug.configureLogger() already makes FINE visible when debugging, so nothing is lost. This is the last of the three parallel migration groups (grid distributor, node/netty/remote, protocols) that together complete the full getDebugLogLevel() call-site migration. Closes #17835 Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- java/src/org/openqa/selenium/bidi/Connection.java | 11 +++++------ java/src/org/openqa/selenium/devtools/Connection.java | 11 +++++------ 2 files changed, 10 insertions(+), 12 deletions(-) diff --git a/java/src/org/openqa/selenium/bidi/Connection.java b/java/src/org/openqa/selenium/bidi/Connection.java index 45376716bec5c..4bdfa73cb8374 100644 --- a/java/src/org/openqa/selenium/bidi/Connection.java +++ b/java/src/org/openqa/selenium/bidi/Connection.java @@ -18,7 +18,6 @@ package org.openqa.selenium.bidi; import static java.util.concurrent.TimeUnit.MILLISECONDS; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.json.Json.MAP_TYPE; import static org.openqa.selenium.remote.http.HttpMethod.GET; @@ -147,7 +146,7 @@ public String toString() { try (JsonOutput out = JSON.newOutput(json).writeClassName(false)) { out.write(serialized); } - LOG.log(getDebugLogLevel(), "-> {0}", json); + LOG.log(Level.FINE, "-> {0}", json); socket.sendText(json); if (!command.getSendsResponse()) { @@ -302,7 +301,7 @@ private void handle(CharSequence data) { // TODO: decode once, and once only String asString = String.valueOf(data); - LOG.log(getDebugLogLevel(), "<- {0}", asString); + LOG.log(Level.FINE, "<- {0}", asString); Map raw = JSON.toType(asString, MAP_TYPE); if (raw.get("id") instanceof Number @@ -346,7 +345,7 @@ private void handleResponse(String rawDataString, Map rawDataMap private void handleEventResponse(Map rawDataMap) { LOG.log( - getDebugLogLevel(), + Level.FINE, () -> String.format( "Method %s called with %s callbacks available", @@ -365,7 +364,7 @@ private void handleEventResponse(Map rawDataMap) { .filter( event -> { LOG.log( - getDebugLogLevel(), + Level.FINE, "Matching {0} with {1}", new Object[] {rawDataMap.get("method"), event.getKey().getMethod()}); return rawDataMap.get("method").equals(event.getKey().getMethod()); @@ -387,7 +386,7 @@ private void handleEventResponse(Map rawDataMap) { @SuppressWarnings("unchecked") Consumer obj = (Consumer) action; LOG.log( - getDebugLogLevel(), + Level.FINE, "Calling callback for {0} using {1} being passed {2}", new Object[] {event.getKey(), obj, finalValue}); obj.accept(finalValue); diff --git a/java/src/org/openqa/selenium/devtools/Connection.java b/java/src/org/openqa/selenium/devtools/Connection.java index 9a91094d85b8f..7c54b48570391 100644 --- a/java/src/org/openqa/selenium/devtools/Connection.java +++ b/java/src/org/openqa/selenium/devtools/Connection.java @@ -18,7 +18,6 @@ package org.openqa.selenium.devtools; import static java.util.concurrent.TimeUnit.MILLISECONDS; -import static org.openqa.selenium.internal.Debug.getDebugLogLevel; import static org.openqa.selenium.json.Json.MAP_TYPE; import static org.openqa.selenium.remote.http.HttpMethod.GET; @@ -182,7 +181,7 @@ public CompletableFuture send(@Nullable SessionID sessionId, Command c try (JsonOutput out = JSON.newOutput(json).writeClassName(false)) { out.write(Map.copyOf(serialized)); } - LOG.log(getDebugLogLevel(), "-> {0}", json); + LOG.log(Level.FINE, "-> {0}", json); socket.sendText(json); if (!command.getSendsResponse()) { @@ -267,7 +266,7 @@ private void handle(long sequence, CharSequence data) { // TODO: decode once, and once only String asString = String.valueOf(data); - LOG.log(getDebugLogLevel(), "<- {0}", asString); + LOG.log(Level.FINE, "<- {0}", asString); Map raw = JSON.toType(asString, MAP_TYPE); if (raw.get("id") instanceof Number @@ -300,7 +299,7 @@ private void handle(long sequence, CharSequence data) { } } else if (raw.get("method") instanceof String && raw.get("params") instanceof Map) { LOG.log( - getDebugLogLevel(), + Level.FINE, "Method {0} called with {1} callbacks available", new Object[] {raw.get("method"), eventCallbacks.size()}); Lock lock = callbacksLock.readLock(); @@ -320,7 +319,7 @@ private void handle(long sequence, CharSequence data) { .peek( event -> LOG.log( - getDebugLogLevel(), + Level.FINE, "Matching {0} with {1}", new Object[] {raw.get("method"), event.getKey().getMethod()})) .filter(event -> raw.get("method").equals(event.getKey().getMethod())) @@ -358,7 +357,7 @@ private void handle(long sequence, CharSequence data) { @SuppressWarnings("unchecked") BiConsumer obj = (BiConsumer) action; LOG.log( - getDebugLogLevel(), + Level.FINE, "Calling callback for {0} using {1} being passed {2}", new Object[] {event.getKey(), obj, params}); obj.accept(sequence, params); From 9c3f4ff63b668958bc20499cc4f0ea6194732d40 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 21:40:36 +0300 Subject: [PATCH 10/20] [java] Fix RetryRequestTest for the getDebugLogLevel() migration retryLogLevelTracksDebugToggleAtEachLogSite locked in the pre-migration behavior (report level toggles INFO/FINE with the debug switch). Now that RetryRequest always logs at a fixed Level.FINE (part of #17835's migration, previous commit), that assertion is obsolete, not a regression -- rewritten as retryLogsAtFineRegardlessOfDebugToggle to lock in the new invariant on both sides of the switch instead. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../openqa/selenium/remote/http/RetryRequestTest.java | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java index 2bd1fe87deb43..1541a257e8038 100644 --- a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java +++ b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java @@ -344,9 +344,11 @@ void shouldRethrowOnConnectFailure() { } @Test - void retryLogLevelTracksDebugToggleAtEachLogSite() { - // Force RetryRequest's class initialization BEFORE the debug property changes, pinning the - // stale-static-snapshot repro regardless of test execution order. + void retryLogsAtFineRegardlessOfDebugToggle() { + // RetryRequest no longer varies its own report level with the debug switch (that was the + // deprecated getDebugLogLevel() dance, migrated away as part of #17835) -- it always logs at + // FINE, and Debug.configureLogger() is what makes FINE visible when debugging is on. Lock in + // that invariant on both sides of the switch instead of the pre-migration toggle behavior. HttpHandler handler = new RetryRequest().andFinally(request -> new HttpResponse().setStatus(HTTP_UNAVAILABLE)); @@ -374,7 +376,7 @@ public void close() {} System.setProperty("selenium.debug", "true"); handler.execute(new HttpRequest(GET, "/")); assertThat(records).isNotEmpty(); - assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.INFO)); + assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.FINE)); records.clear(); System.clearProperty("selenium.debug"); From 6b86a1938a2846757eea2ea32a4fb9111fdc3cd9 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Tue, 28 Jul 2026 22:16:13 +0300 Subject: [PATCH 11/20] Fix qodo-code-review round-2 findings: null-capabilities NPE, retry/registration log visibility, and BiDi/CDP/Grid debug-logging gaps - RemoteWebDriver: startSession() now receives the coalesced this.capabilities instead of the raw (possibly null) constructor parameter, fixing an NPE when constructing with null capabilities and honoring the constructor's own "null is treated as empty" contract. - Debug.getDebugLogLevel(): complete the Javadoc with a purpose sentence and @return. - RetryRequest: bump both retry log statements from FINE to WARNING -- a connection-failure or server-error retry is operationally significant and bounded to a handful of attempts, not routine diagnostics that should require debug mode to see. - LocalNodeRegistry / RedisBackedNodeRegistry: bump the add() exception log (which aborts node registration) from FINE to WARNING. - bidi.Connection / devtools.Connection: call Debug.configureLogger() as the first constructor statement so wire diagnostics are visible under -Dselenium.debug=true even when a Connection is constructed directly, without going through RemoteWebDriver or DriverFinder. - LoggingOptions.configureLogging(): call Debug.configureLogger() before the external-JUL-config early return, so Grid's own FINE-level wire diagnostics (RequestConverter, bidi/devtools Connection) stay visible under -Dselenium.debug=true even when an external java.util.logging.config.* property is set. - Test fixtures (LoggingOptionsTest, RemoteWebDriverInitializationTest, RetryRequestTest): symmetrically save/clear/restore the legacy selenium.webdriver.verbose property alongside selenium.debug, so an externally-set legacy property can't leak into "no switch" baseline assertions. Adds regression tests for the null-capabilities fix, the node-registry log level, and the Grid external-JUL-config log visibility gap; dismisses the DriverFinderTest mock-vs-real DriverService suggestion as inconsistent with the file's established convention (verifies the already-fixed DriverFinder.getBinaryPaths() Debug.configureLogger() call needs no further change). Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG --- .../org/openqa/selenium/bidi/Connection.java | 6 ++ .../openqa/selenium/devtools/Connection.java | 7 +++ .../distributor/local/LocalNodeRegistry.java | 2 +- .../redis/RedisBackedNodeRegistry.java | 2 +- .../selenium/grid/log/LoggingOptions.java | 9 +++ .../org/openqa/selenium/internal/Debug.java | 4 ++ .../selenium/remote/RemoteWebDriver.java | 2 +- .../selenium/remote/http/RetryRequest.java | 4 +- .../local/LocalNodeRegistryTest.java | 58 +++++++++++++++++++ .../org/openqa/selenium/grid/log/BUILD.bazel | 1 + .../selenium/grid/log/LoggingOptionsTest.java | 42 ++++++++++++++ .../RemoteWebDriverInitializationTest.java | 31 ++++++++++ .../remote/http/RetryRequestTest.java | 19 ++++-- 13 files changed, 177 insertions(+), 10 deletions(-) diff --git a/java/src/org/openqa/selenium/bidi/Connection.java b/java/src/org/openqa/selenium/bidi/Connection.java index 4bdfa73cb8374..48d244f800676 100644 --- a/java/src/org/openqa/selenium/bidi/Connection.java +++ b/java/src/org/openqa/selenium/bidi/Connection.java @@ -46,6 +46,7 @@ import org.jspecify.annotations.Nullable; import org.openqa.selenium.Beta; import org.openqa.selenium.WebDriverException; +import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Either; import org.openqa.selenium.internal.Require; import org.openqa.selenium.json.Json; @@ -77,6 +78,11 @@ public class Connection implements Closeable { private final AtomicBoolean underlyingSocketClosed = new AtomicBoolean(false); public Connection(HttpClient client, String url) { + // Reflect the current debug switches before this connection starts logging its wire + // diagnostics at FINE -- callers that construct a Connection directly (never going through + // RemoteWebDriver or DriverFinder) would otherwise never trigger the raise. Idempotent and + // cheap, same pattern as DriverFinder.getBinaryPaths(). + Debug.configureLogger(); Require.nonNull("HTTP client", client); Require.nonNull("URL to connect to", url); diff --git a/java/src/org/openqa/selenium/devtools/Connection.java b/java/src/org/openqa/selenium/devtools/Connection.java index 7c54b48570391..98b9621d55a0c 100644 --- a/java/src/org/openqa/selenium/devtools/Connection.java +++ b/java/src/org/openqa/selenium/devtools/Connection.java @@ -50,6 +50,7 @@ import org.jspecify.annotations.Nullable; import org.openqa.selenium.WebDriverException; import org.openqa.selenium.devtools.idealized.target.model.SessionID; +import org.openqa.selenium.internal.Debug; import org.openqa.selenium.internal.Either; import org.openqa.selenium.internal.Require; import org.openqa.selenium.json.Json; @@ -91,6 +92,12 @@ public Connection(HttpClient client, String url) { } public Connection(HttpClient client, String url, ClientConfig clientConfig) { + // Reflect the current debug switches before this connection starts logging its wire + // diagnostics at FINE -- callers that construct a Connection directly (never going through + // RemoteWebDriver or DriverFinder) would otherwise never trigger the raise. Idempotent and + // cheap, same pattern as DriverFinder.getBinaryPaths(). The deprecated 2-arg constructor + // delegates here, so this single call point covers both. + Debug.configureLogger(); this.client = Require.nonNull("HTTP client", client); this.wsConfig = wsClientConfig(clientConfig, url); this.socket = this.client.openSocket(new HttpRequest(GET, wsConfig.baseUri()), new Listener()); diff --git a/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java b/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java index 4bc786552e37d..42a38c54c4826 100644 --- a/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java +++ b/java/src/org/openqa/selenium/grid/distributor/local/LocalNodeRegistry.java @@ -227,7 +227,7 @@ public void add(Node node) { } } catch (Exception e) { LOG.log( - Level.FINE, String.format("Exception while adding Node %s", node.getUri()), e); + Level.WARNING, String.format("Exception while adding Node %s", node.getUri()), e); return; } diff --git a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java index 7b8ad352bae78..2177e06a05c15 100644 --- a/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java +++ b/java/src/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistry.java @@ -291,7 +291,7 @@ public void add(Node node) { } } catch (Exception e) { LOG.log( - Level.FINE, String.format("Exception while adding Node %s", node.getUri()), e); + Level.WARNING, String.format("Exception while adding Node %s", node.getUri()), e); return; } diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index 4795f84f658aa..3ed19edfe8aca 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -138,6 +138,15 @@ public void configureLogging() { return; } + // Reflect the current debug switches onto the shared org.openqa.selenium logger before + // anything else below -- in particular, before the external-JUL-config early return just + // below hands the rest of logging setup off entirely. Without this, Selenium's own FINE-level + // wire diagnostics (RequestConverter, the BiDi/CDP Connection classes) stay invisible under + // -Dselenium.debug=true whenever an external `java.util.logging.config.*` property is set, + // since nothing else on Grid's startup path would ever call this. Idempotent and cheap, same + // chokepoint pattern as DriverFinder.getBinaryPaths(). + Debug.configureLogger(); + String configClass = System.getProperty("java.util.logging.config.class"); String configFile = System.getProperty("java.util.logging.config.file"); diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index af9c88cf24a30..60644513c7b5e 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -52,6 +52,9 @@ public static boolean isDebugging() { } /** + * Returns the log level that debug output should be reported at: {@link Level#INFO} when {@link + * #isDebugging()} is true, {@link Level#FINE} otherwise. + * * @deprecated Individual log statements no longer change what severity they report at based on * this switch; {@link #configureLogger()} raises the real {@code org.openqa.selenium} logger * to {@link Level#FINE} instead, which is the ordinary way to see Selenium's debug output. @@ -59,6 +62,7 @@ public static boolean isDebugging() { * directly via {@code Logger.getLogger("org.openqa.selenium").setLevel(Level.FINE)}. This * method's own behavior is unchanged and kept only for existing call sites still comparing * against it. + * @return {@link Level#INFO} when debugging is enabled; {@link Level#FINE} otherwise */ @Deprecated(forRemoval = true) public static Level getDebugLogLevel() { diff --git a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java index 01785ec74881d..8d3442a5acb90 100644 --- a/java/src/org/openqa/selenium/remote/RemoteWebDriver.java +++ b/java/src/org/openqa/selenium/remote/RemoteWebDriver.java @@ -233,7 +233,7 @@ public RemoteWebDriver( this.capabilities = requireNonNullElseGet(capabilities, () -> new ImmutableCapabilities()); try { - startSession(capabilities); + startSession(this.capabilities); } catch (RuntimeException e) { try { quit(); diff --git a/java/src/org/openqa/selenium/remote/http/RetryRequest.java b/java/src/org/openqa/selenium/remote/http/RetryRequest.java index 00efadec5e7f8..f9957eb1facf4 100644 --- a/java/src/org/openqa/selenium/remote/http/RetryRequest.java +++ b/java/src/org/openqa/selenium/remote/http/RetryRequest.java @@ -48,7 +48,7 @@ public HttpHandler apply(HttpHandler next) { // must be a connection failure and check whether we have retries left for this if (isConnectionFailure && i < RETRIES_ON_CONNECTION_FAILURE) { - LOG.log(Level.FINE, "Retry #" + (i + 1) + " on ConnectException", ex); + LOG.log(Level.WARNING, "Retry #" + (i + 1) + " on ConnectException", ex); continue; } @@ -63,7 +63,7 @@ public HttpHandler apply(HttpHandler next) { // must be a server error and check whether we have retries left for this if (isServerError && i < RETRIES_ON_SERVER_ERROR) { - LOG.log(Level.FINE, "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); + LOG.log(Level.WARNING, "Retry #" + (i + 1) + " on ServerError: " + response.getStatus()); continue; } diff --git a/java/test/org/openqa/selenium/grid/distributor/local/LocalNodeRegistryTest.java b/java/test/org/openqa/selenium/grid/distributor/local/LocalNodeRegistryTest.java index 35e479d9160a1..d59ed0bd809b8 100644 --- a/java/test/org/openqa/selenium/grid/distributor/local/LocalNodeRegistryTest.java +++ b/java/test/org/openqa/selenium/grid/distributor/local/LocalNodeRegistryTest.java @@ -23,6 +23,8 @@ import java.lang.reflect.Field; import java.net.URI; import java.time.Duration; +import java.util.ArrayList; +import java.util.List; import java.util.Map; import java.util.Set; import java.util.UUID; @@ -33,6 +35,10 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.Logger; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -185,6 +191,58 @@ void shouldRunHealthChecksForMultipleNodesConcurrently() throws Exception { } } + @Test + void addLogsAtWarningWhenNodeStatusThrows() { + // An exception here aborts registration entirely (see the catch block in add()) -- that's an + // actionable failure, not routine diagnostics, so it must be visible at WARNING by default. + NodeId nodeId = new NodeId(UUID.randomUUID()); + RuntimeException statusFailure = new RuntimeException("node heartbeat started before ready"); + Node node = + new TestNode( + tracer, + nodeId, + URI.create("http://example:4444"), + registrationSecret, + () -> { + throw new AssertionError("health check must not run for a node that failed add()"); + }) { + @Override + public NodeStatus getStatus() { + throw statusFailure; + } + }; + + Logger log = Logger.getLogger(LocalNodeRegistry.class.getName()); + List records = new ArrayList<>(); + Handler capture = + new Handler() { + @Override + public void publish(LogRecord record) { + records.add(record); + } + + @Override + public void flush() {} + + @Override + public void close() {} + }; + capture.setLevel(Level.ALL); + Level oldLevel = log.getLevel(); + log.setLevel(Level.ALL); + log.addHandler(capture); + try { + registry.add(node); + + assertThat(records).hasSize(1); + assertThat(records.get(0).getLevel()).isEqualTo(Level.WARNING); + assertThat(records.get(0).getThrown()).isSameAs(statusFailure); + } finally { + log.removeHandler(capture); + log.setLevel(oldLevel); + } + } + @Test void closeShouldShutdownNodeHealthCheckWorkerPool() throws Exception { ExecutorService nodeHealthCheckExecutor = getNodeHealthCheckExecutor(registry); diff --git a/java/test/org/openqa/selenium/grid/log/BUILD.bazel b/java/test/org/openqa/selenium/grid/log/BUILD.bazel index ddc9c1a23b016..9b80074266ceb 100644 --- a/java/test/org/openqa/selenium/grid/log/BUILD.bazel +++ b/java/test/org/openqa/selenium/grid/log/BUILD.bazel @@ -6,6 +6,7 @@ java_test_suite( size = "small", srcs = glob(["*Test.java"]), deps = [ + "//java/src/org/openqa/selenium:core", "//java/src/org/openqa/selenium/grid/config", "//java/src/org/openqa/selenium/grid/log", artifact("org.assertj:assertj-core"), diff --git a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java index ea5758fb2f752..b362846612c8f 100644 --- a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java +++ b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java @@ -22,21 +22,31 @@ import java.io.ByteArrayOutputStream; import java.io.PrintStream; import java.util.Map; +import java.util.logging.Level; +import java.util.logging.Logger; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; import org.openqa.selenium.grid.config.MapConfig; +import org.openqa.selenium.internal.Debug; @Tag("UnitTests") class LoggingOptionsTest { private String oldDebugProperty; + // Legacy alias for selenium.debug -- Debug.isDebugging() honors either, so a test JVM that + // happens to have this set externally must not leak into the "no switch" baseline assertions. + private String oldVerboseProperty; + private Level oldSeleniumLoggerLevel; @BeforeEach void storeSystemProperty() { oldDebugProperty = System.getProperty("selenium.debug"); + oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); + oldSeleniumLoggerLevel = Logger.getLogger("org.openqa.selenium").getLevel(); System.clearProperty("selenium.debug"); + System.clearProperty("selenium.webdriver.verbose"); } @AfterEach @@ -46,6 +56,16 @@ void restoreSystemProperty() { } else { System.clearProperty("selenium.debug"); } + if (oldVerboseProperty != null) { + System.setProperty("selenium.webdriver.verbose", oldVerboseProperty); + } else { + System.clearProperty("selenium.webdriver.verbose"); + } + // Reverts whatever configureLogging() may have done to the shared org.openqa.selenium logger + // via Debug.configureLogger() during the test, now that the properties are back to their + // original values. + Debug.configureLogger(); + Logger.getLogger("org.openqa.selenium").setLevel(oldSeleniumLoggerLevel); } @Test @@ -68,6 +88,28 @@ void setLoggingLevelDoesNotForceFineWhenNoDebugSwitchIsSet() { assertThat(output).doesNotContain("forcing Grid log level to FINE"); } + @Test + void configureLoggingRaisesSeleniumLoggerEvenWithExternalJulConfigSet() { + // configureLogging() early-returns once an external java.util.logging.config.* property is + // detected, handing the rest of logging setup off entirely. Debug.configureLogger() must still + // run before that early return, or Selenium's own FINE-level wire diagnostics stay invisible + // under -Dselenium.debug=true whenever an operator has such a property set. + System.setProperty("selenium.debug", "true"); + String oldConfigFile = System.getProperty("java.util.logging.config.file"); + System.setProperty("java.util.logging.config.file", "does-not-need-to-exist.properties"); + try { + new LoggingOptions(emptyConfig()).configureLogging(); + + assertThat(Logger.getLogger("org.openqa.selenium").getLevel()).isEqualTo(Level.FINE); + } finally { + if (oldConfigFile != null) { + System.setProperty("java.util.logging.config.file", oldConfigFile); + } else { + System.clearProperty("java.util.logging.config.file"); + } + } + } + private static MapConfig emptyConfig() { return new MapConfig(Map.of()); } diff --git a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java index 4a0d034207d9b..9ca1c6defd884 100644 --- a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java +++ b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java @@ -74,13 +74,18 @@ private static Logger seleniumLogger() { private boolean quitCalled = false; private String oldDebugProperty; + // Legacy alias for selenium.debug -- Debug.isDebugging() honors either, so a test JVM that + // happens to have this set externally must not leak into the "no switch" baseline assertions. + private String oldVerboseProperty; private Level oldLoggerLevel; @BeforeEach void storeDebugState() { oldDebugProperty = System.getProperty("selenium.debug"); + oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); oldLoggerLevel = seleniumLogger().getLevel(); System.clearProperty("selenium.debug"); + System.clearProperty("selenium.webdriver.verbose"); } @AfterEach @@ -90,6 +95,11 @@ void restoreDebugState() { } else { System.clearProperty("selenium.debug"); } + if (oldVerboseProperty != null) { + System.setProperty("selenium.webdriver.verbose", oldVerboseProperty); + } else { + System.clearProperty("selenium.webdriver.verbose"); + } Debug.configureLogger(); seleniumLogger().setLevel(oldLoggerLevel); } @@ -209,6 +219,27 @@ && singleton(capabilities) assertThat(driver.getSessionId()).isNotNull(); } + @Test + void constructorTreatsNullCapabilitiesAsEmptyCapabilities() throws IOException { + // Javadoc on the canonical constructor promises "null is treated as an empty set of + // capabilities" -- verify startSession() actually receives the coalesced empty + // ImmutableCapabilities, not the raw null parameter, and that this does not NPE. + CommandExecutor executor = + WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder); + + RemoteWebDriver driver = new RemoteWebDriver(executor, null); + + verify(executor) + .execute( + argThat( + command -> + command.getName().equals(DriverCommand.NEW_SESSION) + && command.getSessionId() == null + && singleton(new ImmutableCapabilities()) + .equals(command.getParameters().get("capabilities")))); + assertThat(driver.getSessionId()).isNotNull(); + } + @Test void canHandlePlatformNameCapability() { WebDriverFixture fixture = diff --git a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java index 1541a257e8038..a998446be01f9 100644 --- a/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java +++ b/java/test/org/openqa/selenium/remote/http/RetryRequestTest.java @@ -344,11 +344,13 @@ void shouldRethrowOnConnectFailure() { } @Test - void retryLogsAtFineRegardlessOfDebugToggle() { + void retryLogsAtWarningRegardlessOfDebugToggle() { // RetryRequest no longer varies its own report level with the debug switch (that was the // deprecated getDebugLogLevel() dance, migrated away as part of #17835) -- it always logs at - // FINE, and Debug.configureLogger() is what makes FINE visible when debugging is on. Lock in - // that invariant on both sides of the switch instead of the pre-migration toggle behavior. + // WARNING, since a connection-failure/server-error retry is an operationally significant, + // actionable event (bounded to a handful of attempts by RETRIES_ON_CONNECTION_FAILURE / + // RETRIES_ON_SERVER_ERROR), not routine diagnostics that should require debug mode to see. Lock + // in that invariant on both sides of the switch instead of the pre-migration toggle behavior. HttpHandler handler = new RetryRequest().andFinally(request -> new HttpResponse().setStatus(HTTP_UNAVAILABLE)); @@ -370,25 +372,32 @@ public void close() {} capture.setLevel(Level.ALL); Level oldLevel = log.getLevel(); String oldDebugProperty = System.getProperty("selenium.debug"); + String oldVerboseProperty = System.getProperty("selenium.webdriver.verbose"); log.setLevel(Level.ALL); log.addHandler(capture); try { System.setProperty("selenium.debug", "true"); handler.execute(new HttpRequest(GET, "/")); assertThat(records).isNotEmpty(); - assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.FINE)); + assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.WARNING)); records.clear(); System.clearProperty("selenium.debug"); + System.clearProperty("selenium.webdriver.verbose"); handler.execute(new HttpRequest(GET, "/")); assertThat(records).isNotEmpty(); - assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.FINE)); + assertThat(records).allSatisfy(r -> assertThat(r.getLevel()).isEqualTo(Level.WARNING)); } finally { if (oldDebugProperty != null) { System.setProperty("selenium.debug", oldDebugProperty); } else { System.clearProperty("selenium.debug"); } + if (oldVerboseProperty != null) { + System.setProperty("selenium.webdriver.verbose", oldVerboseProperty); + } else { + System.clearProperty("selenium.webdriver.verbose"); + } log.removeHandler(capture); log.setLevel(oldLevel); } From f46f340a3b0f0136a43d0c539d63017017741322 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 00:57:54 +0300 Subject: [PATCH 12/20] [java] Fix LoggingOptions.configureLogging() stripping Debug's just-installed handler The handler-stripping loop in configureLogging() enumerates every registered logger and removes its handlers so Grid's own console setup starts from a clean slate. org.openqa.selenium stays registered throughout (Debug holds a strong static reference to it), so the handler Debug.configureLogger() had just installed one line above was getting swept up in that too -- removed before configureLogging() returned. Debug's installed-handler bookkeeping has no way to learn a handler was removed out from under it, so once stripped its idempotency guard prevented ever reinstalling one until the debug switch was toggled off and back on. The loop now skips the org.openqa.selenium logger by name. Reordering Debug.configureLogger() to run after the loop instead was considered and rejected: it must still run before the external-JUL-config early return a few lines below, or the existing configureLoggingRaisesSeleniumLoggerEvenWithExternalJulConfigSet regression test breaks. Found in an independent third-pass review, not previously reported on the PR. --- .../selenium/grid/log/LoggingOptions.java | 14 +++++++++-- .../selenium/grid/log/LoggingOptionsTest.java | 25 +++++++++++++++++++ 2 files changed, 37 insertions(+), 2 deletions(-) diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index 3ed19edfe8aca..2b5a3f10b6e9a 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -156,11 +156,21 @@ public void configureLogging() { return; } - // Remove all handlers from existing loggers + // Remove all handlers from existing loggers, except org.openqa.selenium: Debug.configureLogger() + // above may have just installed a handler there for debug-mode output, and this loop would + // otherwise strip it moments later (Debug holds a strong static reference so that logger stays + // registered here too). Debug's own installed-handler bookkeeping has no way to learn a handler + // was removed out from under it, so once stripped its idempotency guard would prevent ever + // reinstalling one until the debug switch is toggled off and back on. LogManager logManager = LogManager.getLogManager(); Enumeration names = logManager.getLoggerNames(); while (names.hasMoreElements()) { - Logger logger = logManager.getLogger(names.nextElement()); + String name = names.nextElement(); + if ("org.openqa.selenium".equals(name)) { + continue; + } + + Logger logger = logManager.getLogger(name); if (logger == null) { continue; } diff --git a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java index b362846612c8f..fd3415e3b86ae 100644 --- a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java +++ b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java @@ -22,7 +22,9 @@ import java.io.ByteArrayOutputStream; import java.io.PrintStream; import java.util.Map; +import java.util.logging.Handler; import java.util.logging.Level; +import java.util.logging.LogRecord; import java.util.logging.Logger; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; @@ -110,6 +112,29 @@ void configureLoggingRaisesSeleniumLoggerEvenWithExternalJulConfigSet() { } } + @Test + void configureLoggingPreservesDebugHandlerWhenNoExternalJulConfigIsSet() { + // configureLogging() enumerates every registered logger and strips its handlers so Grid's own + // console setup starts from a clean slate. org.openqa.selenium stays registered throughout + // (Debug holds a strong static reference to it), so the handler Debug.configureLogger() just + // installed one line above used to get swept up in that too: removed before configureLogging() + // returned, leaving debug mode silently broken since Debug's bookkeeping has no way to learn + // its handler was removed out from under it. + System.setProperty("selenium.debug", "true"); + + new LoggingOptions(emptyConfig()).configureLogging(); + + Logger seleniumLogger = Logger.getLogger("org.openqa.selenium"); + Handler[] handlers = seleniumLogger.getHandlers(); + assertThat(handlers).hasSize(1); + assertThat(handlers[0].getLevel()).isEqualTo(Level.FINE); + + LogRecord infoRecord = new LogRecord(Level.INFO, "info message"); + LogRecord fineRecord = new LogRecord(Level.FINE, "fine message"); + assertThat(handlers[0].isLoggable(infoRecord)).isFalse(); + assertThat(handlers[0].isLoggable(fineRecord)).isTrue(); + } + private static MapConfig emptyConfig() { return new MapConfig(Map.of()); } From ad47d32ef5dd9976b6c9d5a4d569e87d7e782f1a Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 01:03:11 +0300 Subject: [PATCH 13/20] [java] Add regression test proving devtools.Connection configures the debug logger qodo-code-review thread databaseId 3668700786 flagged that no test constructs bidi.Connection or devtools.Connection directly and verifies the constructor actually calls Debug.configureLogger() -- both were fixed to call it (so direct construction, bypassing RemoteWebDriver/DriverFinder, still gets FINE diagnostics under -Dselenium.debug=true), but neither had a test proving it. Adds ConnectionTest to devtools' existing small-tests unit suite (extending it rather than bidi's, which only has heavyweight real-browser large-tests already set up) using a minimal hand-written HttpClient fake -- no Mockito, consistent with this PR's real-Logger/real-Handler test style throughout. Temporarily commented out the constructor's Debug.configureLogger() call to watch the test fail for the right reason (logger level null instead of FINE), then restored it and watched the test pass. --- .../org/openqa/selenium/devtools/BUILD.bazel | 1 + .../selenium/devtools/ConnectionTest.java | 116 ++++++++++++++++++ 2 files changed, 117 insertions(+) create mode 100644 java/test/org/openqa/selenium/devtools/ConnectionTest.java diff --git a/java/test/org/openqa/selenium/devtools/BUILD.bazel b/java/test/org/openqa/selenium/devtools/BUILD.bazel index 7c0b8f68509b9..e1a402a87424e 100644 --- a/java/test/org/openqa/selenium/devtools/BUILD.bazel +++ b/java/test/org/openqa/selenium/devtools/BUILD.bazel @@ -4,6 +4,7 @@ load("//java:defs.bzl", "JUNIT5_DEPS", "java_library", "java_selenium_test_suite SMALL_TESTS = [ "CdpEndpointFinderTest.java", "CdpVersionFinderTest.java", + "ConnectionTest.java", ] java_test_suite( diff --git a/java/test/org/openqa/selenium/devtools/ConnectionTest.java b/java/test/org/openqa/selenium/devtools/ConnectionTest.java new file mode 100644 index 0000000000000..1dd317dfd588c --- /dev/null +++ b/java/test/org/openqa/selenium/devtools/ConnectionTest.java @@ -0,0 +1,116 @@ +// Licensed to the Software Freedom Conservancy (SFC) under one +// or more contributor license agreements. See the NOTICE file +// distributed with this work for additional information +// regarding copyright ownership. The SFC 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.openqa.selenium.devtools; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.util.logging.Level; +import java.util.logging.Logger; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.openqa.selenium.internal.Debug; +import org.openqa.selenium.remote.http.ClientConfig; +import org.openqa.selenium.remote.http.HttpClient; +import org.openqa.selenium.remote.http.HttpRequest; +import org.openqa.selenium.remote.http.HttpResponse; +import org.openqa.selenium.remote.http.Message; +import org.openqa.selenium.remote.http.WebSocket; + +@Tag("UnitTests") +class ConnectionTest { + + private String oldDebugProperty; + private Level oldLoggerLevel; + + @BeforeEach + void storeSystemProperty() { + oldDebugProperty = System.getProperty("selenium.debug"); + oldLoggerLevel = seleniumLogger().getLevel(); + System.clearProperty("selenium.debug"); + } + + @AfterEach + void restoreSystemProperty() { + if (oldDebugProperty != null) { + System.setProperty("selenium.debug", oldDebugProperty); + } else { + System.clearProperty("selenium.debug"); + } + // Re-sync configureLogger's internal state/handler with the now-restored property so a + // handler installed by this test never leaks into the next. + Debug.configureLogger(); + seleniumLogger().setLevel(oldLoggerLevel); + } + + private static Logger seleniumLogger() { + return Logger.getLogger("org.openqa.selenium"); + } + + @Test + void constructingConnectionDirectlyConfiguresTheSeleniumLoggerWhenDebugging() { + // devtools.Connection is sometimes constructed directly rather than through RemoteWebDriver or + // DriverFinder -- neither of which would run in that path to trigger Debug.configureLogger() + // otherwise. No test previously constructed a Connection directly and checked that its own + // constructor actually configures the shared org.openqa.selenium logger. + System.setProperty("selenium.debug", "true"); + + try (Connection connection = + new Connection( + new NoOpHttpClient(), + "ws://localhost:9222/devtools/page/1", + ClientConfig.defaultConfig())) { + assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); + } + } + + /** Minimal real (not mocked) {@link HttpClient} whose socket never talks to the network. */ + private static class NoOpHttpClient implements HttpClient { + @Override + public HttpResponse execute(HttpRequest request) { + throw new UnsupportedOperationException("execute"); + } + + @Override + public WebSocket openSocket(HttpRequest request, WebSocket.Listener listener) { + return new WebSocket() { + @Override + public WebSocket send(Message message) { + return this; + } + + @Override + public void close() {} + }; + } + + @Override + public java.util.concurrent.CompletableFuture> + sendAsyncNative( + java.net.http.HttpRequest request, java.net.http.HttpResponse.BodyHandler handler) { + throw new UnsupportedOperationException("sendAsyncNative"); + } + + @Override + public java.net.http.HttpResponse sendNative( + java.net.http.HttpRequest request, java.net.http.HttpResponse.BodyHandler handler) { + throw new UnsupportedOperationException("sendNative"); + } + } +} From a4abcb7bc2274e167815dd077e52fbc2b99fdb27 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 01:05:20 +0300 Subject: [PATCH 14/20] [java] De-mock constructorTreatsNullCapabilitiesAsEmptyCapabilities qodo-code-review thread databaseId 3668700801 flagged that this regression test still pulled its CommandExecutor from WebDriverFixture.prepareExecutorMock() (Mockito-backed) where every other test-quality finding on this PR was fixed the same way -- e.g. constructingASecondDriverPicksUpADebugPropertyChangedAfterTheFirst in this same file, already fixed in commit 31ea2ca102, replaced a Mockito executor with a plain lambda since CommandExecutor is a @FunctionalInterface. Applies the identical pattern here: an AtomicReference-capturing lambda records the single NEW_SESSION command and answers it by echoing the requested capabilities back (echoCapabilities), replacing the verify()/argThat() Mockito assertion with plain field assertions on the captured command. Behavior asserted is unchanged; full class re-run green. --- .../RemoteWebDriverInitializationTest.java | 23 +++++++++++-------- 1 file changed, 13 insertions(+), 10 deletions(-) diff --git a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java index 9ca1c6defd884..25e4291499e5e 100644 --- a/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java +++ b/java/test/org/openqa/selenium/remote/RemoteWebDriverInitializationTest.java @@ -41,6 +41,7 @@ import java.time.Duration; import java.util.Map; import java.util.UUID; +import java.util.concurrent.atomic.AtomicReference; import java.util.logging.Level; import java.util.logging.Logger; import org.jspecify.annotations.NullMarked; @@ -220,23 +221,25 @@ && singleton(capabilities) } @Test - void constructorTreatsNullCapabilitiesAsEmptyCapabilities() throws IOException { + void constructorTreatsNullCapabilitiesAsEmptyCapabilities() { // Javadoc on the canonical constructor promises "null is treated as an empty set of // capabilities" -- verify startSession() actually receives the coalesced empty // ImmutableCapabilities, not the raw null parameter, and that this does not NPE. + // A plain in-memory executor (no mocking framework): records the single NEW_SESSION command + // this construction issues, then answers it by echoing the requested capabilities back. + AtomicReference sentCommand = new AtomicReference<>(); CommandExecutor executor = - WebDriverFixture.prepareExecutorMock(echoCapabilities, nullValueResponder); + command -> { + sentCommand.set(command); + return echoCapabilities.apply(command); + }; RemoteWebDriver driver = new RemoteWebDriver(executor, null); - verify(executor) - .execute( - argThat( - command -> - command.getName().equals(DriverCommand.NEW_SESSION) - && command.getSessionId() == null - && singleton(new ImmutableCapabilities()) - .equals(command.getParameters().get("capabilities")))); + assertThat(sentCommand.get().getName()).isEqualTo(DriverCommand.NEW_SESSION); + assertThat(sentCommand.get().getSessionId()).isNull(); + assertThat(sentCommand.get().getParameters().get("capabilities")) + .isEqualTo(singleton(new ImmutableCapabilities())); assertThat(driver.getSessionId()).isNotNull(); } From b030733c827aa398edec205d2f416e85ac875792 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 01:07:33 +0300 Subject: [PATCH 15/20] [java] Add regression test for RedisBackedNodeRegistry's WARNING log on add() failure qodo-code-review thread databaseId 3668700792 ("Redis warning fix untested") flagged that RedisBackedNodeRegistry.add() already logs at Level.WARNING when node.getStatus() throws during registration (RedisBackedNodeRegistry.java:293-294, already shipped/correct), but unlike its sibling LocalNodeRegistry -- which has LocalNodeRegistryTest.addLogsAtWarningWhenNodeStatusThrows -- this path had zero test coverage. Mirrors the Local test's real-Logger/real-Handler style, adapted to this file's existing testcontainers-backed Redis fixture. Watched RED first (temporarily downgraded the log call to Level.FINE, confirmed the test fails with "expected WARNING but was FINE"), then restored and watched GREEN. --- .../redis/RedisBackedNodeRegistryTest.java | 60 +++++++++++++++++++ 1 file changed, 60 insertions(+) diff --git a/java/test/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistryTest.java b/java/test/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistryTest.java index 22e80836bd54c..f579e30661f34 100644 --- a/java/test/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistryTest.java +++ b/java/test/org/openqa/selenium/grid/distributor/redis/RedisBackedNodeRegistryTest.java @@ -26,6 +26,8 @@ import java.net.URISyntaxException; import java.time.Duration; import java.time.Instant; +import java.util.ArrayList; +import java.util.List; import java.util.Map; import java.util.Set; import java.util.UUID; @@ -33,6 +35,10 @@ import java.util.concurrent.Executors; import java.util.concurrent.Future; import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.Logger; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -238,6 +244,60 @@ void isReadyReturnsTrueWhenBusIsReady() { assertThat(registry.isReady()).isTrue(); } + @Test + void addLogsAtWarningWhenNodeStatusThrows() { + // An exception here aborts registration entirely (see the catch block in add()) -- that's an + // actionable failure, not routine diagnostics, so it must be visible at WARNING by default. + // Mirrors LocalNodeRegistryTest.addLogsAtWarningWhenNodeStatusThrows: RedisBackedNodeRegistry's + // add() has the identical catch-and-warn path but had no test of its own. + NodeId nodeId = new NodeId(UUID.randomUUID()); + RuntimeException statusFailure = new RuntimeException("node heartbeat started before ready"); + TestNode node = + new TestNode( + tracer, + nodeId, + uri(PortProber.findFreePort()), + secret, + () -> { + throw new AssertionError("health check must not run for a node that failed add()"); + }) { + @Override + public NodeStatus getStatus() { + throw statusFailure; + } + }; + + Logger log = Logger.getLogger(RedisBackedNodeRegistry.class.getName()); + List records = new ArrayList<>(); + Handler capture = + new Handler() { + @Override + public void publish(LogRecord record) { + records.add(record); + } + + @Override + public void flush() {} + + @Override + public void close() {} + }; + capture.setLevel(Level.ALL); + Level oldLevel = log.getLevel(); + log.setLevel(Level.ALL); + log.addHandler(capture); + try { + registry.add(node); + + assertThat(records).hasSize(1); + assertThat(records.get(0).getLevel()).isEqualTo(Level.WARNING); + assertThat(records.get(0).getThrown()).isSameAs(statusFailure); + } finally { + log.removeHandler(capture); + log.setLevel(oldLevel); + } + } + private static class TestNode extends Node { private final NodeStatus status; From a3e7dc3354175b69e87d227229efa54d1302ee36 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 01:26:08 +0300 Subject: [PATCH 16/20] [java] Fix duplicate FINE-range org.openqa.selenium output on Grid's root handler qodo re-reviewed the Bug A fix from commit f46f340a3b (skip org.openqa.selenium in configureLogging()'s handler-stripping loop) and found it exposes a genuine duplicate-output bug once combined with Grid's own logging setup: it's correct in isolation, but Debug.configureLogger()'s handler on org.openqa.selenium never disables useParentHandlers, so a FINE/CONFIG-range org.openqa.selenium record now reaches BOTH that handler (prints it, unchanged) AND, via normal JUL propagation, whatever handler configureLogging() then attaches to the ROOT logger a few lines later -- which forces the root logger to FINE too and was previously unfiltered by logger name. Same record, printed twice. This is new: pre-PR, Grid never called Debug.configureLogger() at all; mid-PR before the Bug A fix, Debug's handler got stripped immediately so the duplication never had a chance to manifest. Disabling propagation on org.openqa.selenium was considered and rejected: Debug's handler explicitly filters OUT everything INFO-and-above, so cutting propagation too would silently drop every INFO/WARNING/SEVERE org.openqa.selenium record from Grid's own formatted output -- a worse regression than the one being fixed. Fix: Debug.isHandledBySeleniumDebugHandler(loggerName, level) (Debug.java) is a new shared predicate exposing exactly the range Debug's own handler covers (FINE/CONFIG, org.openqa.selenium or a descendant, while a debug switch is on) -- kept next to the handler it describes rather than duplicated. Grid's own root handlers (plain-log and structured-log, LoggingOptions.java) now carry a filter built on that predicate, so they skip exactly the records Debug's handler already prints and pass everything else through unchanged, including INFO+ org.openqa.selenium output and all non-Selenium logging. TDD: new configureLoggingDoesNotDuplicateSeleniumDebugRecordsThroughGridsRootHandler in LoggingOptionsTest publishes a real FINE record through both real handlers (Debug's, captured via redirected stderr; Grid's, routed to a temp file via log-file config) and asserts it's captured by Debug's handler but not duplicated into Grid's, while an existing INFO line still reaches the file. Watched RED first (marker present in the Grid log file), then GREEN after the fix. Full existing scoped suite re-run clean: DebugTest, LoggingOptionsTest, RemoteWebDriverInitializationTest, RetryRequestTest, LocalNodeRegistryTest, RedisBackedNodeRegistryTest, ConnectionTest, DriverFinderTest. --- .../selenium/grid/log/LoggingOptions.java | 12 +++++ .../org/openqa/selenium/internal/Debug.java | 28 +++++++++++ .../selenium/grid/log/LoggingOptionsTest.java | 48 +++++++++++++++++++ 3 files changed, 88 insertions(+) diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index 2b5a3f10b6e9a..000f9ccb5fac7 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -26,6 +26,7 @@ import java.util.Enumeration; import java.util.List; import java.util.Locale; +import java.util.logging.Filter; import java.util.logging.Handler; import java.util.logging.Level; import java.util.logging.LogManager; @@ -189,6 +190,7 @@ public void configureLogging() { Handler handler = new FlushingHandler(out); handler.setFormatter(new TerseFormatter(getLogTimestampFormat())); handler.setLevel(level); + handler.setFilter(NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER); configureLogEncoding(logger, encoding, handler); } @@ -196,10 +198,20 @@ public void configureLogging() { Handler handler = new FlushingHandler(out); handler.setFormatter(new JsonFormatter()); handler.setLevel(level); + handler.setFilter(NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER); configureLogEncoding(logger, encoding, handler); } } + // Records that Debug.configureLogger()'s own handler on org.openqa.selenium already prints + // (FINE/CONFIG-range records from that logger or a descendant, while a debug switch is on) must + // not also print through this root handler -- that handler's own useParentHandlers is never + // disabled, so the same record reaches both. INFO-and-above org.openqa.selenium records, and + // everything from every other logger, are untouched: Debug's handler never covered those in the + // first place. + private static final Filter NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER = + record -> !Debug.isHandledBySeleniumDebugHandler(record.getLoggerName(), record.getLevel()); + private void configureLogEncoding(Logger logger, @Nullable String encoding, Handler handler) { String message; try { diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index 60644513c7b5e..2672f32c510a8 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -69,6 +69,34 @@ public static Level getDebugLogLevel() { return isDebugging() ? Level.INFO : Level.FINE; } + /** + * Reports whether a log record from {@code loggerName} at {@code level} would already be + * emitted by the handler {@link #configureLogger()} installs directly on {@code + * org.openqa.selenium} -- that handler and its filter together cover exactly {@link + * Level#FINE}- and {@link Level#CONFIG}-range records from that logger and its descendants, + * while {@link #isDebugging()} or {@link #isDebugAll()} is true. A caller + * further up the logger hierarchy (e.g. a handler on the root logger, which receives the same + * record too via normal handler propagation) can use this to avoid printing it a second time, + * without disabling propagation itself -- which would instead silently drop every {@link + * Level#INFO}-and-above {@code org.openqa.selenium} record that caller would otherwise print. + * + * @param loggerName the originating logger's name; {@code null} is never covered + * @param level the record's level + * @return true when {@link #configureLogger()}'s own handler already covers this record + */ + public static boolean isHandledBySeleniumDebugHandler(String loggerName, Level level) { + if (!(isDebugging() || isDebugAll())) { + return false; + } + boolean withinSeleniumHierarchy = + loggerName != null + && (loggerName.equals("org.openqa.selenium") + || loggerName.startsWith("org.openqa.selenium.")); + return withinSeleniumHierarchy + && level.intValue() >= Level.FINE.intValue() + && level.intValue() < Level.INFO.intValue(); + } + public static boolean isDebugAll() { boolean everything = Boolean.parseBoolean(System.getenv("SE_DEBUG")); if (everything && DEBUG_WARNING_LOGGED.compareAndSet(false, true)) { diff --git a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java index fd3415e3b86ae..14ef5672273eb 100644 --- a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java +++ b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java @@ -20,10 +20,15 @@ import static org.assertj.core.api.Assertions.assertThat; import java.io.ByteArrayOutputStream; +import java.io.IOException; import java.io.PrintStream; +import java.nio.file.Files; +import java.nio.file.Path; import java.util.Map; +import java.util.UUID; import java.util.logging.Handler; import java.util.logging.Level; +import java.util.logging.LogManager; import java.util.logging.LogRecord; import java.util.logging.Logger; import org.junit.jupiter.api.AfterEach; @@ -135,6 +140,49 @@ void configureLoggingPreservesDebugHandlerWhenNoExternalJulConfigIsSet() { assertThat(handlers[0].isLoggable(fineRecord)).isTrue(); } + @Test + void configureLoggingDoesNotDuplicateSeleniumDebugRecordsThroughGridsRootHandler() + throws IOException { + // Debug.configureLogger() (called one line into configureLogging()) installs a handler + // directly on org.openqa.selenium that already prints FINE/CONFIG-range records to stderr -- + // it never disables useParentHandlers, so those same records also propagate up to whatever + // handler(s) configureLogging() itself then attaches to the ROOT logger a few lines later. + // Nothing stopped Grid's own root handler from ALSO accepting them: a FINE record from any + // org.openqa.selenium(.*) logger got printed twice, once by each handler. INFO-and-above + // records must be unaffected -- Debug's own handler already excludes those, so they only ever + // reached Grid's root handler in the first place. + System.setProperty("selenium.debug", "true"); + Path logFile = Files.createTempFile("logging-options-test", ".log"); + String marker = "duplicate-check-" + UUID.randomUUID(); + try { + String seleniumErr = + captureStderrDuring( + () -> { + new LoggingOptions( + new MapConfig( + Map.of( + "logging", + Map.of("log-file", logFile.toAbsolutePath().toString())))) + .configureLogging(); + Logger.getLogger("org.openqa.selenium.grid.log.LoggingOptionsTest").fine(marker); + }); + + // Debug's own handler on org.openqa.selenium must still print it -- unchanged behavior. + assertThat(seleniumErr).contains(marker); + // Grid's root handler must not ALSO print it now that the two ranges overlap. + String gridLog = Files.readString(logFile); + assertThat(gridLog).doesNotContain(marker); + // INFO+ output Grid already prints (e.g. its own "Using encoding" startup line) must still + // reach the file -- only the FINE/CONFIG range Debug's handler already owns is suppressed. + assertThat(gridLog).contains("Using"); + } finally { + for (Handler handler : LogManager.getLogManager().getLogger("").getHandlers()) { + handler.close(); + } + Files.deleteIfExists(logFile); + } + } + private static MapConfig emptyConfig() { return new MapConfig(Map.of()); } From 2fba7efc5e98a334bf10535265f68989807d70d1 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 01:28:43 +0300 Subject: [PATCH 17/20] [java] De-mock secondDiscoveryPicksUpADebugPropertyChangedAfterTheFirst qodo-code-review thread databaseId 3668308297 ("Discovery regression uses mockito") flagged that this test exercises DriverFinder through a Mockito-backed DriverService instead of a real/in-memory implementation. It was initially scoped to defer to #17836, but that issue turns out to track an unrelated selenium.webdriver.verbose fixture-hygiene gap in this same file, not this finding -- so fixing it directly instead, matching the same category of fix already applied three times elsewhere on this PR (Mockito executor -> plain fake, matching this codebase's own established convention). Adds a small in-memory InMemoryDriverService (extends the real, abstract DriverService, port 0, no real I/O) local to this one test only -- the other tests in this file make real verify()/interaction assertions on the shared Mockito service field and are unaffected. This test makes no such assertions, only checking the shared org.openqa.selenium logger's level, so it needs no mocking framework: getExecutable() answers straight from the constructor-set path (inherited, not overridden), getDriverName() returns a fixed name, and the two abstract accessors throw since getBinaryPaths() never reaches them once getExecutable() already resolves a path. Full class re-run green (10/10). --- .../remote/service/DriverFinderTest.java | 39 +++++++++++++++++-- 1 file changed, 35 insertions(+), 4 deletions(-) diff --git a/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java b/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java index 4d20e50f7e17f..6dcfebc3449ea 100644 --- a/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java +++ b/java/test/org/openqa/selenium/remote/service/DriverFinderTest.java @@ -100,23 +100,54 @@ void restoreDebugState() { } @Test - void secondDiscoveryPicksUpADebugPropertyChangedAfterTheFirst() { - when(service.getExecutable()).thenReturn(driverFile.toString()); + void secondDiscoveryPicksUpADebugPropertyChangedAfterTheFirst() throws IOException { + // A small in-memory DriverService (no mocking framework): this test makes no verify()/ + // interaction assertions on the service, only on the shared org.openqa.selenium logger's + // level, so it doesn't need Mockito's machinery -- matching the pattern already applied + // elsewhere on this PR (e.g. RemoteWebDriverInitializationTest, commit 31ea2ca102). + DriverService inMemoryService = new InMemoryDriverService(driverFile); Capabilities capabilities = new ImmutableCapabilities("browserName", "chrome"); // First discovery while debugging is off -- nothing for configureLogger to react to. - new DriverFinder(service, capabilities).getDriverPath(); + new DriverFinder(inMemoryService, capabilities).getDriverPath(); System.setProperty("selenium.debug", "true"); // Second discovery after the property changed. No RemoteWebDriver constructor is involved // (this is also the only coverage InternetExplorerDriver's discovery path gets), so only // getBinaryPaths' own Debug.configureLogger() call can pick this up. - new DriverFinder(service, capabilities).getDriverPath(); + new DriverFinder(inMemoryService, capabilities).getDriverPath(); assertThat(seleniumLogger().getLevel()).isEqualTo(Level.FINE); } + /** + * Minimal real {@link DriverService}: {@link #getExecutable()} answers straight from the + * constructor-set path (inherited, not overridden), {@link #getDriverName()} returns a fixed + * name, and the two abstract accessors throw since {@code getBinaryPaths()} never reaches them + * once {@link #getExecutable()} already resolves a path. + */ + private static class InMemoryDriverService extends DriverService { + InMemoryDriverService(Path driverFile) throws IOException { + super(driverFile.toFile(), 0, DEFAULT_TIMEOUT, null, null); + } + + @Override + protected String getDriverName() { + return "driverName"; + } + + @Override + public String getDriverProperty() { + throw new UnsupportedOperationException("getDriverProperty"); + } + + @Override + protected String getDriverEnvironmentVariable() { + throw new UnsupportedOperationException("getDriverEnvironmentVariable"); + } + } + @Test void serviceValueIgnoresSeleniumManager() { when(service.getExecutable()).thenReturn(driverFile.toString()); From d864d0c82ae3571fa4ea9750bc6d979f26438e5b Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 08:39:16 +0300 Subject: [PATCH 18/20] [java] Close the live-property race in isHandledBySeleniumDebugHandler() qodo-code-review found that isHandledBySeleniumDebugHandler() checked the live isDebugging()/isDebugAll() system property instead of whether configureLogger()'s handler is actually installed right now. The two can diverge: nothing installs or removes the handler except a call to configureLogger() itself, so a property flip and the next call that reacts to it are not atomic. In that narrow window, a caller (Grid's root handler filter) could either suppress a record Debug's handler isn't actually there to print (silent loss) or fail to suppress one it still is (duplicate again). Adds Debug.isHandlerCurrentlyInstalled(), a synchronized accessor over the existing private loggerConfigured state, and switches isHandledBySeleniumDebugHandler() to key off that instead of re-deriving the live property. This was the smaller, cleaner of the two options discussed (the alternative was documenting the race as an accepted limitation, same tier as the existing FINE-equality note) and closes the race properly rather than just describing it. TDD: new DebugTest.isHandledBySeleniumDebugHandlerReflectsActualHandlerInstallationNotLiveProperty flips the property off without calling configureLogger() again and asserts the predicate still reports "handled" (the handler is still attached). Watched RED against the old live-property check (returned false the instant the property flipped), then GREEN after the fix. Full DebugTest and LoggingOptionsTest classes re-run clean. --- .../org/openqa/selenium/internal/Debug.java | 24 +++++++++++++---- .../openqa/selenium/internal/DebugTest.java | 27 +++++++++++++++++++ 2 files changed, 46 insertions(+), 5 deletions(-) diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index 2672f32c510a8..f13c1c1394d63 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -69,15 +69,29 @@ public static Level getDebugLogLevel() { return isDebugging() ? Level.INFO : Level.FINE; } + /** + * Reports whether {@link #configureLogger()}'s handler is attached to {@code + * org.openqa.selenium} right now. Unlike {@link #isDebugging()} or {@link #isDebugAll()}, which + * read the live system property/environment variable, this reflects the handler's actual, + * current installation state -- the two can genuinely diverge for however long it takes some + * caller to next invoke {@link #configureLogger()} after a switch changes, since nothing installs + * or removes the handler except that call. + * + * @return true when a handler installed by {@link #configureLogger()} is currently attached + */ + public static synchronized boolean isHandlerCurrentlyInstalled() { + return loggerConfigured; + } + /** * Reports whether a log record from {@code loggerName} at {@code level} would already be * emitted by the handler {@link #configureLogger()} installs directly on {@code * org.openqa.selenium} -- that handler and its filter together cover exactly {@link * Level#FINE}- and {@link Level#CONFIG}-range records from that logger and its descendants, - * while {@link #isDebugging()} or {@link #isDebugAll()} is true. A caller - * further up the logger hierarchy (e.g. a handler on the root logger, which receives the same - * record too via normal handler propagation) can use this to avoid printing it a second time, - * without disabling propagation itself -- which would instead silently drop every {@link + * whenever that handler is {@linkplain #isHandlerCurrentlyInstalled() currently installed}. A + * caller further up the logger hierarchy (e.g. a handler on the root logger, which receives the + * same record too via normal handler propagation) can use this to avoid printing it a second + * time, without disabling propagation itself -- which would instead silently drop every {@link * Level#INFO}-and-above {@code org.openqa.selenium} record that caller would otherwise print. * * @param loggerName the originating logger's name; {@code null} is never covered @@ -85,7 +99,7 @@ public static Level getDebugLogLevel() { * @return true when {@link #configureLogger()}'s own handler already covers this record */ public static boolean isHandledBySeleniumDebugHandler(String loggerName, Level level) { - if (!(isDebugging() || isDebugAll())) { + if (!isHandlerCurrentlyInstalled()) { return false; } boolean withinSeleniumHierarchy = diff --git a/java/test/org/openqa/selenium/internal/DebugTest.java b/java/test/org/openqa/selenium/internal/DebugTest.java index 747e5bccf9004..2634a937dac1a 100644 --- a/java/test/org/openqa/selenium/internal/DebugTest.java +++ b/java/test/org/openqa/selenium/internal/DebugTest.java @@ -272,4 +272,31 @@ void getDebugLogLevelStillReportsInfoWhileDeprecated() { System.clearProperty("selenium.debug"); assertThat(Debug.getDebugLogLevel()).isEqualTo(Level.FINE); } + + @Test + void isHandledBySeleniumDebugHandlerReflectsActualHandlerInstallationNotLiveProperty() { + // isHandledBySeleniumDebugHandler() exists so a caller further up the logger hierarchy (e.g. + // Grid's root handler) can tell whether THIS handler will actually also print a given record, + // to avoid a duplicate. That question is about the handler's real, current installation + // state, not the live system property: a property change takes effect only once something + // calls configureLogger() again to react to it, and the two can genuinely diverge for however + // long that takes -- checking the live property instead would answer "yes, handled" the + // instant the property flips, even though the handler that must actually be there to back + // that answer hasn't been installed (or removed) yet. + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + assertThat(Debug.isHandledBySeleniumDebugHandler("org.openqa.selenium", Level.FINE)).isTrue(); + + // The property flips off, but nothing has called configureLogger() again yet -- the handler + // installed above is still attached and will still print a FINE record published right now. + System.clearProperty("selenium.debug"); + assertThat(Debug.isHandledBySeleniumDebugHandler("org.openqa.selenium", Level.FINE)) + .as("the handler installed while debugging was on is still attached and still handling") + .isTrue(); + + // Only once configureLogger() actually reacts does the handler come off, and only then must + // callers stop treating this range as already handled. + Debug.configureLogger(); + assertThat(Debug.isHandledBySeleniumDebugHandler("org.openqa.selenium", Level.FINE)).isFalse(); + } } From 71be9244c6aaef244be26611390022e8b4541533 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 08:43:31 +0300 Subject: [PATCH 19/20] [java] Do not suppress Selenium debug records from a configured Grid log-file qodo-code-review found that the previous duplicate-suppression fix (commit a3e7dc3354) was too broad: it suppressed FINE/CONFIG-range org.openqa.selenium records from Grid's root handler unconditionally whenever Debug's own handler also covered them, but that's only a real duplicate when both handlers write to the same visible destination. Debug's handler always targets stderr (java.util.logging.ConsoleHandler's fixed target). Grid's root handler only shares that destination when getOutputStream() defaults it to System.out/System.err (no log-file configured) -- when an operator configures a log-file, that's a genuinely separate destination Debug never writes to, so suppressing there silently dropped the record from the operator's chosen sink and its plain/structured formatting instead of de-duplicating anything. That's the exact regression the qodo thread flagged. LoggingOptions.rootHandlerFilter() now checks the same log-file condition getOutputStream() itself already uses (config.get(LOGGING_SECTION, "log-file").isPresent()): suppression only applies when no log-file is configured. When one is, both Debug's stderr trace and the file legitimately receive the record. TDD: split the previous single test into two. The old test was rewritten (configureLoggingDoesNotDuplicateSeleniumDebugRecordsWhenNoLogFileIsConfigured) to actually exercise the no-log-file default (captures real stdout+stderr instead of routing through a file, which was actually testing the case this fix now treats differently). A new sibling (configureLoggingLetsSeleniumDebugRecordsReachAConfiguredLogFileAlongsideDebugsHandler) covers the log-file case and was watched RED first (marker missing from the file under the old unconditional-suppression code), then GREEN after this fix. Full scoped suite (DebugTest, LoggingOptionsTest, RemoteWebDriverInitializationTest, RetryRequestTest, LocalNodeRegistryTest, RedisBackedNodeRegistryTest, ConnectionTest, DriverFinderTest) re-run clean. --- .../selenium/grid/log/LoggingOptions.java | 33 ++++--- .../selenium/grid/log/LoggingOptionsTest.java | 86 ++++++++++++++++--- 2 files changed, 95 insertions(+), 24 deletions(-) diff --git a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java index 000f9ccb5fac7..b9158dc7fc664 100644 --- a/java/src/org/openqa/selenium/grid/log/LoggingOptions.java +++ b/java/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -190,7 +190,7 @@ public void configureLogging() { Handler handler = new FlushingHandler(out); handler.setFormatter(new TerseFormatter(getLogTimestampFormat())); handler.setLevel(level); - handler.setFilter(NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER); + handler.setFilter(rootHandlerFilter()); configureLogEncoding(logger, encoding, handler); } @@ -198,19 +198,32 @@ public void configureLogging() { Handler handler = new FlushingHandler(out); handler.setFormatter(new JsonFormatter()); handler.setLevel(level); - handler.setFilter(NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER); + handler.setFilter(rootHandlerFilter()); configureLogEncoding(logger, encoding, handler); } } - // Records that Debug.configureLogger()'s own handler on org.openqa.selenium already prints - // (FINE/CONFIG-range records from that logger or a descendant, while a debug switch is on) must - // not also print through this root handler -- that handler's own useParentHandlers is never - // disabled, so the same record reaches both. INFO-and-above org.openqa.selenium records, and - // everything from every other logger, are untouched: Debug's handler never covered those in the - // first place. - private static final Filter NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER = - record -> !Debug.isHandledBySeleniumDebugHandler(record.getLoggerName(), record.getLevel()); + /** + * Records that Debug.configureLogger()'s own handler on {@code org.openqa.selenium} already + * prints (FINE/CONFIG-range records from that logger or a descendant, while its handler is + * installed) must not also print through this root handler, PROVIDED this root handler's + * destination is the one Debug's handler also writes to -- that handler's own + * useParentHandlers is never disabled, so the same record reaches both. That's only true when + * no {@code log-file} is configured: {@link #getOutputStream()} then defaults this handler to + * {@code System.out}/{@code System.err}, the same visible destination as Debug's own {@code + * ConsoleHandler} (fixed to {@code System.err}) in every realistic deployment. A configured + * log-file is a genuinely separate destination Debug never writes to, so suppressing there + * would silently drop the record from the operator's chosen sink instead of de-duplicating it + * -- worse than the problem this filter exists to solve. INFO-and-above {@code + * org.openqa.selenium} records, and everything from every other logger, are untouched either + * way: Debug's handler never covered those in the first place. + */ + private Filter rootHandlerFilter() { + boolean logFileConfigured = config.get(LOGGING_SECTION, "log-file").isPresent(); + return record -> + logFileConfigured + || !Debug.isHandledBySeleniumDebugHandler(record.getLoggerName(), record.getLevel()); + } private void configureLogEncoding(Logger logger, @Nullable String encoding, Handler handler) { String message; diff --git a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java index 14ef5672273eb..0382dafe0f65b 100644 --- a/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java +++ b/java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java @@ -141,19 +141,48 @@ void configureLoggingPreservesDebugHandlerWhenNoExternalJulConfigIsSet() { } @Test - void configureLoggingDoesNotDuplicateSeleniumDebugRecordsThroughGridsRootHandler() - throws IOException { + void configureLoggingDoesNotDuplicateSeleniumDebugRecordsWhenNoLogFileIsConfigured() { // Debug.configureLogger() (called one line into configureLogging()) installs a handler // directly on org.openqa.selenium that already prints FINE/CONFIG-range records to stderr -- // it never disables useParentHandlers, so those same records also propagate up to whatever // handler(s) configureLogging() itself then attaches to the ROOT logger a few lines later. - // Nothing stopped Grid's own root handler from ALSO accepting them: a FINE record from any - // org.openqa.selenium(.*) logger got printed twice, once by each handler. INFO-and-above - // records must be unaffected -- Debug's own handler already excludes those, so they only ever - // reached Grid's root handler in the first place. + // With no log-file configured, getOutputStream() defaults that root handler to System.out (no + // SE_DEBUG here) -- a different JUL handler/stream than Debug's stderr one, but the same + // visible destination in every realistic deployment (Grid's primary real-world usage is + // containerized, where the container log driver merges stdout+stderr into one stream a human + // actually reads), so nothing stopped a FINE record from org.openqa.selenium(.*) printing + // twice, once from each handler. INFO-and-above records must be unaffected -- Debug's own + // handler already excludes those, so they only ever reached Grid's root handler in the first + // place. System.setProperty("selenium.debug", "true"); - Path logFile = Files.createTempFile("logging-options-test", ".log"); String marker = "duplicate-check-" + UUID.randomUUID(); + + Captured captured = + captureStdOutAndErrDuring( + () -> { + new LoggingOptions(emptyConfig()).configureLogging(); + Logger.getLogger("org.openqa.selenium.grid.log.LoggingOptionsTest").fine(marker); + }); + + // Debug's own handler on org.openqa.selenium must still print it -- unchanged behavior. + assertThat(captured.err()).contains(marker); + // Grid's root handler (defaulting to stdout here) must not ALSO print it. + assertThat(captured.out()).doesNotContain(marker); + } + + @Test + void configureLoggingLetsSeleniumDebugRecordsReachAConfiguredLogFileAlongsideDebugsHandler() + throws IOException { + // A configured log-file is a destination genuinely separate from anything Debug touches -- + // Debug's own handler always targets stderr (java.util.logging.ConsoleHandler's fixed + // target), regardless of Grid's own logging config. Suppressing FINE/CONFIG-range + // org.openqa.selenium records from that file the same way they're suppressed from the + // stdout/stderr default (above) would silently drop them from the operator's chosen sink and + // its plain/structured formatting -- worse than the duplicate this suppression exists to fix. + // Debug's stderr trace legitimately coexists with the file here; both must fire. + System.setProperty("selenium.debug", "true"); + Path logFile = Files.createTempFile("logging-options-test", ".log"); + String marker = "log-file-check-" + UUID.randomUUID(); try { String seleniumErr = captureStderrDuring( @@ -167,14 +196,8 @@ void configureLoggingDoesNotDuplicateSeleniumDebugRecordsThroughGridsRootHandler Logger.getLogger("org.openqa.selenium.grid.log.LoggingOptionsTest").fine(marker); }); - // Debug's own handler on org.openqa.selenium must still print it -- unchanged behavior. assertThat(seleniumErr).contains(marker); - // Grid's root handler must not ALSO print it now that the two ranges overlap. - String gridLog = Files.readString(logFile); - assertThat(gridLog).doesNotContain(marker); - // INFO+ output Grid already prints (e.g. its own "Using encoding" startup line) must still - // reach the file -- only the FINE/CONFIG range Debug's handler already owns is suppressed. - assertThat(gridLog).contains("Using"); + assertThat(Files.readString(logFile)).contains(marker); } finally { for (Handler handler : LogManager.getLogManager().getLogger("").getHandlers()) { handler.close(); @@ -198,4 +221,39 @@ private static String captureStderrDuring(Runnable action) { } return captured.toString(); } + + private static Captured captureStdOutAndErrDuring(Runnable action) { + PrintStream originalOut = System.out; + PrintStream originalErr = System.err; + ByteArrayOutputStream capturedOut = new ByteArrayOutputStream(); + ByteArrayOutputStream capturedErr = new ByteArrayOutputStream(); + try { + System.setOut(new PrintStream(capturedOut)); + System.setErr(new PrintStream(capturedErr)); + action.run(); + } finally { + System.setOut(originalOut); + System.setErr(originalErr); + } + return new Captured(capturedOut.toString(), capturedErr.toString()); + } + + /** Plain holder, not a record: this test target still compiles at source level 11. */ + private static class Captured { + private final String out; + private final String err; + + Captured(String out, String err) { + this.out = out; + this.err = err; + } + + String out() { + return out; + } + + String err() { + return err; + } + } } From f8129c5b4fb57bb34e194320c422f9a843d54467 Mon Sep 17 00:00:00 2001 From: Mohab Mohie Date: Wed, 29 Jul 2026 08:57:57 +0300 Subject: [PATCH 20/20] [java] Check the real handler list in isHandlerCurrentlyInstalled(), not cached bookkeeping qodo-code-review found that isHandlerCurrentlyInstalled() returned the loggerConfigured bookkeeping flag rather than actually checking whether installedHandler is still attached to org.openqa.selenium. If anything outside Debug removes the handler without going through configureLogger() -- LogManager.getLogManager().reset() (routine in embedding scenarios: Spring Boot's JavaLoggingSystem, a Log4j-JUL bridge, a container shutdown hook) or a direct SELENIUM_LOGGER.removeHandler() call by unrelated code -- the flag stays stale-true. LoggingOptions.rootHandlerFilter() then trusts that stale "yes, Debug already handles this" answer and suppresses the record from Grid's own root handler too, even though nothing will actually print it anymore: silent data loss, the same failure class the last two rounds fixed, via a different trigger. isHandlerCurrentlyInstalled() now checks the logger's live handler list (installedHandler != null && SELENIUM_LOGGER.getHandlers() still contains it) instead of trusting loggerConfigured alone. loggerConfigured itself is untouched -- configureLogger()'s own idempotency guard still needs it and is a separate concern from this external-removal detection. TDD: new DebugTest.isHandlerCurrentlyInstalledReflectsExternalHandlerRemoval installs the handler via configureLogger(), then removes it directly via SELENIUM_LOGGER.removeHandler() without going through Debug at all (simulating the external-actor scenario), and asserts isHandlerCurrentlyInstalled() now correctly reports false. Watched RED against the cached-flag implementation ("expecting false but was true"), then GREEN after the fix. Full scoped suite (DebugTest, LoggingOptionsTest, RemoteWebDriverInitializationTest, RetryRequestTest, LocalNodeRegistryTest, RedisBackedNodeRegistryTest, ConnectionTest, DriverFinderTest) re-run clean. --- .../org/openqa/selenium/internal/Debug.java | 11 +++++-- .../openqa/selenium/internal/DebugTest.java | 29 +++++++++++++++++++ 2 files changed, 38 insertions(+), 2 deletions(-) diff --git a/java/src/org/openqa/selenium/internal/Debug.java b/java/src/org/openqa/selenium/internal/Debug.java index f13c1c1394d63..ee5846d1a4877 100644 --- a/java/src/org/openqa/selenium/internal/Debug.java +++ b/java/src/org/openqa/selenium/internal/Debug.java @@ -17,6 +17,7 @@ package org.openqa.selenium.internal; +import java.util.Arrays; import java.util.concurrent.atomic.AtomicBoolean; import java.util.logging.ConsoleHandler; import java.util.logging.Filter; @@ -75,12 +76,18 @@ public static Level getDebugLogLevel() { * read the live system property/environment variable, this reflects the handler's actual, * current installation state -- the two can genuinely diverge for however long it takes some * caller to next invoke {@link #configureLogger()} after a switch changes, since nothing installs - * or removes the handler except that call. + * or removes the handler except that call. This checks the logger's real handler list rather + * than trusting the {@code loggerConfigured} bookkeeping flag alone, since something outside + * this class can remove the handler without ever going through {@link #configureLogger()} -- + * e.g. {@code LogManager.getLogManager().reset()} (routine in embedding scenarios: Spring Boot's + * {@code JavaLoggingSystem}, a Log4j-JUL bridge, a container shutdown hook) or a direct {@code + * removeHandler()} call by unrelated code -- which would otherwise leave the flag stale-true. * * @return true when a handler installed by {@link #configureLogger()} is currently attached */ public static synchronized boolean isHandlerCurrentlyInstalled() { - return loggerConfigured; + return installedHandler != null + && Arrays.asList(SELENIUM_LOGGER.getHandlers()).contains(installedHandler); } /** diff --git a/java/test/org/openqa/selenium/internal/DebugTest.java b/java/test/org/openqa/selenium/internal/DebugTest.java index 2634a937dac1a..5f29e7bb6006f 100644 --- a/java/test/org/openqa/selenium/internal/DebugTest.java +++ b/java/test/org/openqa/selenium/internal/DebugTest.java @@ -299,4 +299,33 @@ void isHandledBySeleniumDebugHandlerReflectsActualHandlerInstallationNotLiveProp Debug.configureLogger(); assertThat(Debug.isHandledBySeleniumDebugHandler("org.openqa.selenium", Level.FINE)).isFalse(); } + + @Test + void isHandlerCurrentlyInstalledReflectsExternalHandlerRemoval() { + // isHandlerCurrentlyInstalled() must answer whether Debug's handler is REALLY still attached + // to org.openqa.selenium, not just whether Debug's own bookkeeping thinks it installed one and + // was never told otherwise. Something outside Debug entirely can remove that handler without + // going through configureLogger() -- e.g. LogManager.getLogManager().reset() (routine in + // embedding scenarios: Spring Boot's JavaLoggingSystem, a Log4j-JUL bridge, a container + // shutdown hook) or a direct removeHandler() call by unrelated code -- and Debug has no way to + // be told when that happens. + List handlersBeforeDebug = new ArrayList<>(List.of(seleniumLogger().getHandlers())); + + System.setProperty("selenium.debug", "true"); + Debug.configureLogger(); + assertThat(Debug.isHandlerCurrentlyInstalled()).isTrue(); + + List handlersWhileDebugging = new ArrayList<>(List.of(seleniumLogger().getHandlers())); + handlersWhileDebugging.removeAll(handlersBeforeDebug); + assertThat(handlersWhileDebugging).hasSize(1); + Handler installedHandler = handlersWhileDebugging.get(0); + + // Simulates the external-actor scenario: something other than Debug removes the handler + // directly, without ever calling configureLogger(). + seleniumLogger().removeHandler(installedHandler); + + assertThat(Debug.isHandlerCurrentlyInstalled()) + .as("the handler was removed out from under Debug's bookkeeping by something else") + .isFalse(); + } }