[java] Make selenium.debug/webdriver.verbose configure the real logger - #17832
[java] Make selenium.debug/webdriver.verbose configure the real logger#17832MohabMohie wants to merge 18 commits into
Conversation
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.
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.
PR Summary by Qodo[Java] Unify debug switches with Selenium logger configuration
AI Description
Diagram
High-Level Assessment
Files changed (8)
|
Code Review by Qodo
Context used✅ Compliance rules (platform):
18 rules 1. Live toggle drops logs
|
…ver 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.
…uest 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
- 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.
|
Code review by qodo was updated up to the latest commit 31ea2ca |
|
Code review by qodo was updated up to the latest commit d44ad4e |
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 SeleniumHQ#17834 Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
…el() 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 SeleniumHQ#17835 Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
…vel() 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 SeleniumHQ#17835 Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
…ugLogLevel() 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 SeleniumHQ#17835 Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
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 SeleniumHQ#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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
|
Code review by qodo was updated up to the latest commit 9c3f4ff |
…egistration 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG
|
Code review by qodo was updated up to the latest commit 6b86a19 |
… run (#4353) Surfaced while independently re-verifying a delegate coder's claimed test results on Selenium PR SeleniumHQ/selenium#17832 round 2 -- a first re-run silently returned cached greens before catching itself and forcing --nocache_test_results. Claude-Session: https://claude.ai/code/session_01LfxetzdJtF13MCJDRNQwgG Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
…nstalled 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.
… 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.
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 31ea2ca, replaced a Mockito executor with a plain lambda since CommandExecutor is a @FunctionalInterface. Applies the identical pattern here: an AtomicReference<Command>-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.
…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.
|
Code review by qodo was updated up to the latest commit b030733 |
…root handler qodo re-reviewed the Bug A fix from commit f46f340 (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.
| public static boolean isHandledBySeleniumDebugHandler(String loggerName, Level level) { | ||
| if (!(isDebugging() || isDebugAll())) { | ||
| return false; |
There was a problem hiding this comment.
1. Live toggle drops logs 📘 Rule violation ▣ Testability
isHandledBySeleniumDebugHandler() reports records as handled based only on the live debug property, even when configureLogger() has not yet installed its handler. After Grid logging is configured, toggling debug before the next configuration call can suppress FINE records from Grid’s root handler or duplicate them when toggled off, and the new test does not cover either transition.
Agent Prompt
## Issue description
The duplicate-suppression helper uses live debug switches instead of checking whether Selenium's debug handler is currently installed. This can suppress unhandled records or allow duplicates during the interval between a property change and the next `configureLogger()` call.
## Issue Context
The helper's Javadoc promises `true` only when the installed handler already covers the record. The regression test sets the property before configuring logging, so it does not exercise runtime transitions after Grid handlers are installed.
## Fix Focus Areas
- java/src/org/openqa/selenium/internal/Debug.java[87-98]
- java/src/org/openqa/selenium/grid/log/LoggingOptions.java[206-214]
- java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java[143-185]
ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools
| Handler handler = new FlushingHandler(out); | ||
| handler.setFormatter(new TerseFormatter(getLogTimestampFormat())); | ||
| handler.setLevel(level); | ||
| handler.setFilter(NOT_ALREADY_HANDLED_BY_SELENIUM_DEBUG_HANDLER); |
There was a problem hiding this comment.
2. Debug logs bypass grid sink 🐞 Bug ◔ Observability
The new root-handler filter rejects Selenium-hierarchy FINE/CONFIG records when debugging is enabled, leaving Debug's ConsoleHandler to emit them only to stderr. Consequently, these diagnostics are absent from Grid's configured log file and bypass structured JSON formatting.
Agent Prompt
## Issue description
The duplicate-suppression filter removes Selenium FINE/CONFIG records from Grid's configured file or structured handler. Those records are instead emitted only through Debug's plain stderr ConsoleHandler, changing their configured destination and format.
## Issue Context
Duplicate output should be prevented without excluding debug diagnostics from the operator-selected Grid sink. Update the interaction between LoggingOptions and Debug so Grid-owned logging receives each record exactly once.
## Fix Focus Areas
- java/src/org/openqa/selenium/grid/log/LoggingOptions.java[189-213]
- java/src/org/openqa/selenium/internal/Debug.java[72-99]
- java/src/org/openqa/selenium/internal/Debug.java[158-163]
- java/test/org/openqa/selenium/grid/log/LoggingOptionsTest.java[143-185]
ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools
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 SeleniumHQ#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).
|
Code review by qodo was updated up to the latest commit a3e7dc3 |
|
Code review by qodo was updated up to the latest commit 2fba7ef |
|
This PR has too large of scope, and now references five separate issues, which makes it quite challenging to review Maybe limit this PR to just the debug-logger mechanism and tests and then you can follow up with the migration and other bug fixes in future PRs after it is merged? |
📋 Executive Summary
(kept up to date after every commit on this PR)
What changed:
-Dselenium.debug=true, its legacy twin-Dselenium.webdriver.verbose=true,and
SE_DEBUGnow all do the same real thing — raise the actualorg.openqa.seleniumJUL loggerto
FINEand attach a Selenium-owned handler, instead of each switch silently changing what ahandful of hand-picked call sites individually decide to report. The switch is live: flipping it
mid-run takes effect for every driver constructed afterward, not just ones created before the
JVM's first driver class loaded.
Why it's worth merging: it closes the long-standing inconsistency from #12892 ("some things
are logged this way and some things aren't") with one real mechanism instead of another one-off
patch, fixes a genuine duplicate-INFO-output bug for existing
SE_DEBUGusers, and — across tworounds of review on this PR — also fixes several independently-discovered real bugs it would
otherwise have introduced or left standing: an already-more-verbose logger level getting silently
demoted to
FINE;RetryRequest's log level going stale once the switch became toggleable atruntime; a null-
CapabilitiesNPE inRemoteWebDriver's 3-arg constructor that contradicted itsown documented "null means empty" contract; and two classes (
bidi/devtoolsConnection) plusGrid's external-JUL-config startup path that could construct without ever raising the logger at
all.
How to use it: nothing changes for existing users of either switch — same properties, same
SE_DEBUGvariable, just more consistent and more visible output. Set-Dselenium.debug=true(orSE_DEBUG) and read Selenium's ownFINE-level diagnostics through whatever logging setup youalready have; no new API surface, no migration needed.
Status: mechanism + all 9 original automated review findings addressed, plus both follow-ups
tracked at #17833 landed on this same PR as additional commits: the pre-existing second-driver
discovery-logging gap (#17834, fixed at the single
DriverFinder.getBinaryPaths()chokepoint everydriver construction path — including
InternetExplorerDriver, previously uncovered even for thefirst driver — funnels through) and the full mechanical migration of the remaining
getDebugLogLevel()call sites across 14 files (#17835) off the deprecated method onto a fixedLevel.FINE. A second review round then surfaced 10 more findings, now also landed on this PR: theRemoteWebDrivernull-capabilities NPE fix (with regression test), two retry/registration-failurelog sites bumped from
FINEtoWARNINGsince they're bounded, actionable, operationally-visibleevents rather than routine chatter,
Debug.configureLogger()added tobidi/devtoolsConnection's constructors and to Grid's external-JUL-config startup path (both previously able torun with the logger never raised), and property-fixture hygiene fixes across five test files so
selenium.webdriver.verboseis cleared/restored alongsideselenium.debugeverywhere. Oneadjacent, out-of-scope fixture-hygiene gap in
DriverFinderTestfound during that pass is trackedseparately at #17836.
An independent third-pass review then surfaced one more real bug and three test-coverage gaps, now
also landed on this PR:
LoggingOptions.configureLogging()'s pre-existing handler-cleanup loop(enumerates every registered logger and strips its handlers) was silently removing the handler
Debug.configureLogger()had just installed one line above, sinceDebugholds a strong staticreference that keeps
org.openqa.seleniumregistered too -- fixed by having that loop skip it byname, rather than reordering the call (reordering would have broken the existing
external-JUL-config early-return case). Regression tests were added proving
RedisBackedNodeRegistry's WARNING-level registration-failure log (already correct, just untested)actually fires, proving
devtools.Connection's constructor actually configures the debug loggerwhen built directly (bypassing
RemoteWebDriver/DriverFinder), and de-mockingRemoteWebDriverInitializationTest's null-capabilities regression test onto a plainCommandExecutorlambda, matching this file's other de-mocked test. One qodo finding remains openon this PR (
DriverFinderTest's discovery-regression test using a Mockito-backedDriverService):it does not actually fall under #17836 as this PR previously assumed -- #17836 tracks an unrelated
selenium.webdriver.verbosefixture-hygiene gap in the same file, not the mocking-style finding.Left unresolved pending a decision on how to track it. Otherwise nothing further planned on this
PR; ready for another review pass.
🔗 Related Issues
Closes #12892
Closes #17834
Closes #17835
Design rationale (the five-options analysis behind choosing option 4) was
worked through in ShaftHQ/SHAFT_ENGINE#4307; linked for reviewer context
only.
💥 What does this PR do?
Selenium Java currently has two separate, disconnected answers to "how do I
turn on debug logging?"
-Dselenium.debug=true(and its older twin-Dselenium.webdriver.verbose=true) changes what severity roughly 64hand-picked log statements report at — INFO instead of FINE — without
touching the real logger at all.
SE_DEBUGdoes something completelydifferent: it raises the actual
org.openqa.seleniumlogger to FINE andattaches a handler. Titus put it plainly when he opened #12892: "right now
some things are logged this way and some things aren't and I think we need
to be consistent one way or another." This PR makes them consistent by
making
-Dselenium.debug=true/-Dselenium.webdriver.verbose=truedo whatSE_DEBUGalready does.Of the five options Titus laid out in #12892 — (1) deprecate both properties
and delete
Debugentirely, (2) move all general-debug logging ontogetDebugLogLevel(), (3) drop the-agentlib:jdwpdebugger auto-detection,(4) change the real logger level instead of the reported level, (5) make the
switch work if flipped mid-run — this PR adopts option 4 as the
mechanism. Option 5 comes along for free as a consequence. Option 2 does
not: the ~64
getDebugLogLevel()call sites still report at INFO whileeverything else reports at FINE, so what they log is now consistently
visible but not consistently levelled — migrating them is the mechanical
follow-up noted below. Option 3 is already merged, separately, in #16584.
Option 1 is not adopted; see Implementation Notes.
Behavior changes — several are real and deliberate:
You're already using
SE_DEBUG:Previously it had no filter, so if you were relying on the default JVM
root
ConsoleHandler, you'd have seen every INFO+ record fromorg.openqa.seleniumprinted twice (once from the root handler, oncefrom Selenium's own unfiltered one). That duplicate is gone — no visible
change for the common case.
Logger.getLogger("org.openqa.selenium").setUseParentHandlers(false), orstripped the root logger's handlers — you were relying on Selenium's own
(previously unfiltered) handler as your only source of INFO+ output from
this logger. You will now see less output than before: Selenium's
handler only surfaces FINE-and-below. This is a real, if narrow, behavior
change, not just a bugfix.
is now reliably visible again for the first driver constructed in a JVM
when
SE_DEBUGis set at JVM start (see Implementation Notes for theprecise limit of this).
You're using
-Dselenium.debug=trueor-Dselenium.webdriver.verbose=truetoday:
FINE-level record underorg.openqa.seleniumis now visible, not just the ~64 lines previouslypromoted to INFO. Deliberate, but a real, noticeable change in output
volume.
RemoteWebDrivernow actually takes effect for drivers constructedafterward (previously impossible: frozen in a
staticblock atclass-load time).
(previously only
SE_DEBUGdid) — otherwise Grid operators using thisproperty would silently lose Grid diagnostics under the new mechanism.
Calling the deprecated
getDebugLogLevel()directly: no change. Marked@Deprecated(forRemoval = true)but returns exactly what it always did.Testing:
New
DebugTest, no mocks, realLogger/Handler/System.setPropertywithsave-and-restore: live property read, legacy
selenium.webdriver.verbose,level raising, reversibility (including the compare-and-restore fix, proven
by changing the level a second time after turning debugging on),
idempotency, user-installed handlers left alone, INFO-and-above records not
duplicated (proven by capturing actual published records through a stub
handler, not just asserting the filter's own verdict against itself), and
the deprecated method's unchanged return values.
New
RemoteWebDriverInitializationTestcase proving the constructor-levelfix specifically (constructs twice, since the static block only fires once
per JVM).
New
LoggingOptionsTest(this class had zero coverage before), proving-Dselenium.debug=truenow also forces Grid's log level to FINE.Not unit-tested (needs a real browser): manually verify
System.setProperty("selenium.debug","true"); new ChromeDriver();printsFINE records to stderr.
🔧 Implementation Notes
Why option 4, not option 1 (deleting
Debug)? Titus attached areservation to option 4 itself: "this could break things for users if they
have other implementations." Read at face value that applies to any
implementation of option 4, including this one, so it's worth stating
exactly how far this PR goes. The sketch in the issue sets the level on
every handler of the root logger, globally and irreversibly. This PR
doesn't do that: it only touches the
org.openqa.seleniumlogger by name,adds one handler Selenium owns and can remove again, and never mutates a
handler it didn't create. It's also not new: this is exactly what
Debug.configureLogger()has already been doing forSE_DEBUGsince#16816/#16900/#17009. This PR's claim is "stop
maintaining a second, Java-only mechanism next to the one already shipped
and working," not "introduce something new."
@asolntsev, who wrote the prior-art PR #16584 in this same area, has said
he'd prefer deleting
Debugoutright (option 1). This PR goes with option 4instead because the
selenium.debug/selenium.webdriver.verboseproperties are the shipped, user-facing surface(the class itself lives in
org.openqa.selenium.internal),isDebugging()gates a security-relevant branch (see Additional Considerations), and
removing the properties would take away the documented easy switch with
nothing to migrate users to. Titus himself called option 1 "too drastic" in
the issue, while staying open to it if agreed.
Known gaps:
The reversibility guarantee has one inherent edge case.
configureLogger()restores the pre-debug level on turn-off unlesssomething else changed the level in between (in which case that external
change is correctly left alone — the compare-and-restore fix in this
PR). But JUL has no level-change listener, so if that external override
happens to set the level to exactly
Level.FINE(the same value Debugitself sets),
configureLogger()can't tell the two apart. In that onecase, turn-off still restores the pre-debug level and silently overrides
that deliberate FINE. Inherent to a snapshot-based approach without a
real listener API; not fixed by this PR.
The static-initializer fix for early driver-discovery logging only
covers the first driver built in a JVM.
RemoteWebDriver's staticinitializer (JLS 12.4.2) is guaranteed to run once, before any subclass
constructor body — including argument expressions passed to a
subclass's own
super(...)call, which is whereChromeDriver/FirefoxDriver perform DriverFinder/SeleniumManager
discovery logging. That's covered for the first driver instance. For a
second driver, if the debug switch gets flipped between the first and
second construction, that second driver's own discovery logging still
runs before
configureLogger()is reached via the instance constructor— still missed. Same gap that has always existed on trunk; this PR
narrows it (first-driver case now works), doesn't close it.
Grid stdout/stderr routing is now inconsistent between the two
switches.
LoggingOptions.setLoggingLevel()now honors both-Dselenium.debug=trueandSE_DEBUGfor the FINE level.LoggingOptions.getOutputStream()(unchanged by this PR) still keysonly on
SE_DEBUGfor stdout vs. stderr. Net effect: on Grid,-Dselenium.debug=truesends FINE output to stdout whileSE_DEBUG=truesends it to stderr. Not a regression; not fixed here.🤖 AI assistance
code-review pass that found the two defects fixed in the second
commit (stale-snapshot clobbering on turn-off, and the dropped
static-initializer coverage for driver-discovery logging), the
follow-up fix pass for those defects, and this PR description.
Human-directed and human-reviewed throughout; I own the design
decisions and can explain every change in this diff.
💡 Additional Considerations
fix only covers the first driver constructed in a JVM) is a narrowing of
an existing gap, not a full close. Flagging for maintainers to decide
whether that's acceptable as-is or needs a follow-up before/after merge.
Tracked at [🐛 Bug]: Second driver's discovery logging still misses a debug switch flipped mid-run #17834 (part of the umbrella follow-up tracker, [Feature]: Follow-up tracker for the remaining gaps from #17832's Java debug-logging consistency mechanism #17833) so it
doesn't get lost regardless of that call.
isDebugging()to also honorSE_DEBUGis explicitly notdone here.
RemoteWebDriver'sUnreachableBrowserExceptionbranch uses!Debug.isDebugging()to decide between a redacted key-set and fullcommand parameters (avoiding credential leaks against authenticated
Grids). Untouched in this PR. Worth noting:
isDebugging()is now alive property read instead of one frozen at class load, so this
branch's decision is now flippable mid-JVM-run via
System.setPropertyfrom anywhere in the process — behavior at any fixed instant is
unchanged, but that liveness is new. Whether
isDebugging()should alsohonor
SE_DEBUGis a separate, deliberately unresolved maintainerquestion.
getDebugLogLevel()call sites across 14 files to plain
Level.FINEis intentionally leftout of this PR as a separate, purely mechanical follow-up. This PR is the
mechanism only. Tracked at [Feature]: Migrate remaining getDebugLogLevel() call sites (and any other ad-hoc debug-log-level logic) to fixed logger levels #17835 (part of [Feature]: Follow-up tracker for the remaining gaps from #17832's Java debug-logging consistency mechanism #17833), scoped a bit wider
than just these call sites — full logging/level standardization across
every method that logs anything in the Java bindings.
🔄 Types of changes
Bug fix: the debug properties now control the real logger, and SE_DEBUG's
duplicate INFO output is gone. New feature: flipping the switch mid-run now
works, and
-Dselenium.debug=truenow also raises Grid's log level — bothtested. Not marked breaking: no API surface changes; the shifts under the
existing switches are in output volume/visibility, with the one narrow
exception (custom logging setups relying on Selenium's previously
unfiltered handler) called out under Behavior changes above.