diff --git a/src/main/java/com/databricks/jdbc/log/JulLogger.java b/src/main/java/com/databricks/jdbc/log/JulLogger.java index 92b40256a..aa4209755 100644 --- a/src/main/java/com/databricks/jdbc/log/JulLogger.java +++ b/src/main/java/com/databricks/jdbc/log/JulLogger.java @@ -156,6 +156,13 @@ public void publish(LogRecord record) { } private void log(Level level, String message, Throwable throwable) { + // Skip the work (notably the expensive getCaller() stack-trace walk) when the + // configured level would discard this record anyway. See GitHub issue #1511: + // reading array/complex-type columns logs once per element, and an unconditional + // stack walk per element dominates CPU even when logging is effectively disabled. + if (!logger.isLoggable(level)) { + return; + } String[] callerClassMethod = getCaller(); if (throwable == null) { logger.logp(level, callerClassMethod[0], callerClassMethod[1], message); diff --git a/src/test/java/com/databricks/jdbc/log/JulLoggerTest.java b/src/test/java/com/databricks/jdbc/log/JulLoggerTest.java index 0a2ad7f48..515427f87 100644 --- a/src/test/java/com/databricks/jdbc/log/JulLoggerTest.java +++ b/src/test/java/com/databricks/jdbc/log/JulLoggerTest.java @@ -24,6 +24,10 @@ public class JulLoggerTest { @BeforeEach void setUp() { mockLogger = Mockito.mock(Logger.class); + // By default treat every level as enabled so the existing verify-based tests + // exercise the real logging path. Individual tests override this to assert the + // level-guard added for GitHub issue #1511. + Mockito.when(mockLogger.isLoggable(Mockito.any())).thenReturn(true); julLogger = new JulLogger("test"); julLogger.logger = mockLogger; } @@ -117,6 +121,35 @@ void testErrorWithThrowableAndFormatArgContainingPercent() { "error(Throwable, String, Object...) should not throw when formatted message contains % characters"); } + @Test + void testNoLoggingWhenLevelDisabled() { + // Regression test for GitHub issue #1511: when the configured level would discard + // the record, log() must short-circuit before doing any work (notably the expensive + // getCaller() stack-trace walk), so logp() is never invoked. + Mockito.when(mockLogger.isLoggable(Mockito.any())).thenReturn(false); + + julLogger.trace("trace message"); + julLogger.debug("debug message"); + julLogger.info("info message"); + julLogger.warn("warn message"); + julLogger.error("error message"); + julLogger.error(new Exception("boom"), "error with throwable"); + + Mockito.verify(mockLogger, Mockito.never()) + .logp( + Mockito.any(Level.class), + Mockito.anyString(), + Mockito.anyString(), + Mockito.anyString()); + Mockito.verify(mockLogger, Mockito.never()) + .logp( + Mockito.any(Level.class), + Mockito.anyString(), + Mockito.anyString(), + Mockito.anyString(), + Mockito.any(Throwable.class)); + } + @Test void testInitLoggerWithStdout() throws IOException { JulLogger.initLogger(Level.INFO, JulLogger.STDOUT, 1024, 1);