Skip to content

Commit b27385e

Browse files
authored
fix(bigquery-jdbc): use one logger per class to stop child-logger registration leak (#14716)
b/576218509 - Replace the per-instance `LOG = new BigQueryJdbcCustomLogger(this.toString())` field with one `static final` logger per class in `BigQueryStatement`, `BigQueryConnection`, `BigQueryDatabaseMetaData`, `BigQueryCallableStatement`, `BigQueryPooledConnection` (+ `BigQueryPooledConnectionWrapper`), `PooledConnectionListener`, and `DataSource`. Each logger is named after its own class so the `CLASS` column fallback in the formatter stays correct. - Remove the duplicate `setParent(...)` call in the 1-arg `BigQueryJdbcCustomLogger` constructor; the 2-arg constructor it delegates to already sets the parent. The second call forced a full scan of the parent's child list under the global `treeLock` on every construction. - Add regression tests to `BigQueryJdbcCustomLoggerTest`: - `testLoggerIsParentedToDriverRootLogger` locks in that every logger is still parented to the driver root logger (handlers/levels keep flowing). - `testCreatingStatementsDoesNotRegisterChildLoggers` and `testCreatingDatabaseMetaDataDoesNotRegisterChildLoggers` construct 1,000 objects and assert the root logger's child count does not grow. Both fail on `main` and pass with this change. - Add `--add-opens=java.logging/java.util.logging=ALL-UNNAMED` to the surefire `argLine` (test-only) so the regression tests can read the JDK-internal child-logger list on JDK 17+. No behavior change to per-connection log files or formatting: routing and the `[CONNECTION_ID]` column come from the MDC / record parameters, not from the logger name.
1 parent 6b99452 commit b27385e

10 files changed

Lines changed: 92 additions & 10 deletions

File tree

‎java-bigquery-jdbc/pom.xml‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -506,7 +506,12 @@
506506
<groupId>org.apache.maven.plugins</groupId>
507507
<artifactId>maven-surefire-plugin</artifactId>
508508
<configuration>
509-
<argLine>--add-opens=java.base/java.nio=org.apache.arrow.memory.core,ALL-UNNAMED</argLine>
509+
<!--
510+
java.nio is opened for Arrow's off-heap memory access. java.util.logging is opened
511+
so BigQueryJdbcCustomLoggerTest can read the JDK-internal child-logger list and
512+
assert that driver objects do not leak logger registrations.
513+
-->
514+
<argLine>--add-opens=java.base/java.nio=org.apache.arrow.memory.core,ALL-UNNAMED --add-opens=java.logging/java.util.logging=ALL-UNNAMED</argLine>
510515
</configuration>
511516
</plugin>
512517
<plugin>

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryCallableStatement.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,8 @@
4343
import java.util.Map;
4444

4545
class BigQueryCallableStatement extends BigQueryPreparedStatement implements CallableStatement {
46-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
46+
private static final BigQueryJdbcCustomLogger LOG =
47+
new BigQueryJdbcCustomLogger(BigQueryCallableStatement.class.getName());
4748
private boolean lastReadWasNull = false;
4849

4950
private Object getParameterAndTrackNull(int parameterIndex) throws SQLException {

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryConnection.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,8 @@
9292
*/
9393
public class BigQueryConnection extends BigQueryNoOpsConnection {
9494

95-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
95+
private static final BigQueryJdbcCustomLogger LOG =
96+
new BigQueryJdbcCustomLogger(BigQueryConnection.class.getName());
9697
String connectionClassName = this.toString();
9798
private final String connectionId;
9899
private static final String DEFAULT_JDBC_TOKEN_VALUE = "Google-BigQuery-JDBC-Driver";

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryDatabaseMetaData.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -91,7 +91,8 @@
9191
* @see BigQueryStatement
9292
*/
9393
class BigQueryDatabaseMetaData implements DatabaseMetaData {
94-
final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
94+
static final BigQueryJdbcCustomLogger LOG =
95+
new BigQueryJdbcCustomLogger(BigQueryDatabaseMetaData.class.getName());
9596
private static final String DATABASE_PRODUCT_NAME = "Google BigQuery";
9697
private static final String DATABASE_PRODUCT_VERSION = "2.0";
9798
private static final String DRIVER_NAME = "GoogleJDBCDriverForGoogleBigQuery";

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryJdbcCustomLogger.java‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,6 @@ protected BigQueryJdbcCustomLogger(String name, String resourceBundleName) {
3030

3131
public BigQueryJdbcCustomLogger(String name) {
3232
this(name, null);
33-
this.setParent(BigQueryJdbcRootLogger.getRootLogger());
3433
}
3534

3635
private void logWithCaller(Level level, Supplier<String> msgSupplier) {

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryPooledConnection.java‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,8 @@
3131
import javax.sql.StatementEventListener;
3232

3333
class BigQueryPooledConnection implements PooledConnection {
34-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
34+
private static final BigQueryJdbcCustomLogger LOG =
35+
new BigQueryJdbcCustomLogger(BigQueryPooledConnection.class.getName());
3536

3637
private String id; // Mainly for internal use
3738
private Connection bqConnection;
@@ -165,7 +166,8 @@ public void removeStatementEventListener(StatementEventListener arg0) {
165166
// This class notifies the listeners or calls the listner notification methods
166167
// provided by the pooled connection.
167168
static class BigQueryPooledConnectionWrapper implements Connection {
168-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
169+
private static final BigQueryJdbcCustomLogger LOG =
170+
new BigQueryJdbcCustomLogger(BigQueryPooledConnectionWrapper.class.getName());
169171
private Connection bqConnectionDelegate;
170172
private BigQueryPooledConnection pooledConnection;
171173
private boolean closed = false;

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryStatement.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,8 @@
102102
*/
103103
public class BigQueryStatement extends BigQueryNoOpsStatement {
104104

105-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
105+
private static final BigQueryJdbcCustomLogger LOG =
106+
new BigQueryJdbcCustomLogger(BigQueryStatement.class.getName());
106107
public static final int DEFAULT_BUFFER_SIZE = BigQuerySettings.DEFAULT_NUM_BUFFERED_ROWS * 2;
107108
// Bounds in-memory ArrowRecordBatch buffering per ResultSet (~15-20 MB of in-flight batches),
108109
// keeping the gRPC ReadRows stream saturated while preventing unbounded heap accumulation.

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/DataSource.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,8 @@
4343
* registered with a naming service based on the Java™ Naming and Directory (JNDI) API.
4444
*/
4545
public class DataSource implements javax.sql.DataSource {
46-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
46+
private static final BigQueryJdbcCustomLogger LOG =
47+
new BigQueryJdbcCustomLogger(DataSource.class.getName());
4748
private String URL;
4849
static final ImmutableSet<Integer> VALID_JOB_CREATION_MODES = ImmutableSet.of(1, 2);
4950

‎java-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/PooledConnectionListener.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,8 @@
2323
import javax.sql.PooledConnection;
2424

2525
public class PooledConnectionListener implements ConnectionEventListener {
26-
private final BigQueryJdbcCustomLogger LOG = new BigQueryJdbcCustomLogger(this.toString());
26+
private static final BigQueryJdbcCustomLogger LOG =
27+
new BigQueryJdbcCustomLogger(PooledConnectionListener.class.getName());
2728
private String id; // Mainly for internal use
2829
private LinkedBlockingDeque<PooledConnection> connectionPool;
2930
private Long connectionPoolSize = 0L;

‎java-bigquery-jdbc/src/test/java/com/google/cloud/bigquery/jdbc/BigQueryJdbcCustomLoggerTest.java‎

Lines changed: 70 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,8 @@
2020
import static org.junit.jupiter.api.Assertions.assertNotSame;
2121
import static org.junit.jupiter.api.Assertions.assertSame;
2222
import static org.junit.jupiter.api.Assertions.assertTrue;
23+
import static org.mockito.Mockito.doReturn;
24+
import static org.mockito.Mockito.mock;
2325

2426
import com.google.cloud.bigquery.Field;
2527
import com.google.cloud.bigquery.FieldList;
@@ -37,6 +39,7 @@
3739
import java.util.logging.Handler;
3840
import java.util.logging.Level;
3941
import java.util.logging.LogRecord;
42+
import java.util.logging.Logger;
4043
import org.apache.arrow.vector.util.JsonStringArrayList;
4144
import org.apache.arrow.vector.util.JsonStringHashMap;
4245
import org.junit.jupiter.api.AfterEach;
@@ -49,6 +52,8 @@ public class BigQueryJdbcCustomLoggerTest extends BigQueryJdbcLoggingBaseTest {
4952
private BigQueryJdbcCustomLogger logger;
5053
private TestHandler testHandler;
5154

55+
private static final int OBJECT_COUNT = 1_000;
56+
5257
private static class TestHandler extends Handler {
5358
private final List<LogRecord> records = new ArrayList<>();
5459

@@ -579,4 +584,69 @@ public void testNestedArrayInJsonStructConnectionIdPropagation() throws Exceptio
579584
"Log from Nested JSON Array",
580585
() -> nestedArray.LOG.fine("Log from Nested JSON Array"));
581586
}
587+
588+
@Test
589+
public void testLoggerIsParentedToDriverRootLogger() {
590+
assertSame(
591+
BigQueryJdbcRootLogger.getRootLogger(),
592+
new BigQueryJdbcCustomLogger("ParentCheck").getParent());
593+
}
594+
595+
@Test
596+
public void testCreatingStatementsDoesNotRegisterChildLoggers() throws Exception {
597+
BigQueryConnection connection = mock(BigQueryConnection.class);
598+
doReturn("leak-test-connection").when(connection).getConnectionId();
599+
doReturn(BigQueryConnection.SessionState.empty()).when(connection).getSessionStateSnapshot();
600+
601+
Logger rootLogger = BigQueryJdbcRootLogger.getRootLogger();
602+
// Warm up so that any one-time, class-level logger is registered before we measure.
603+
new BigQueryStatement(connection);
604+
int childrenBefore = childLoggerCount(rootLogger);
605+
606+
for (int i = 0; i < OBJECT_COUNT; i++) {
607+
new BigQueryStatement(connection);
608+
}
609+
610+
assertEquals(
611+
childrenBefore,
612+
childLoggerCount(rootLogger),
613+
"Creating "
614+
+ OBJECT_COUNT
615+
+ " statements must not register additional child loggers on the driver root logger");
616+
}
617+
618+
@Test
619+
public void testCreatingDatabaseMetaDataDoesNotRegisterChildLoggers()
620+
throws ReflectiveOperationException {
621+
BigQueryConnection connection = mock(BigQueryConnection.class);
622+
doReturn("leak-test-connection").when(connection).getConnectionId();
623+
624+
Logger rootLogger = BigQueryJdbcRootLogger.getRootLogger();
625+
new BigQueryDatabaseMetaData(connection);
626+
int childrenBefore = childLoggerCount(rootLogger);
627+
628+
for (int i = 0; i < OBJECT_COUNT; i++) {
629+
new BigQueryDatabaseMetaData(connection);
630+
}
631+
632+
assertEquals(
633+
childrenBefore,
634+
childLoggerCount(rootLogger),
635+
"Creating "
636+
+ OBJECT_COUNT
637+
+ " DatabaseMetaData objects must not register additional child loggers on the driver"
638+
+ " root logger");
639+
}
640+
641+
/**
642+
* Reads the JDK-internal {@code Logger.kids} list. This field is private to {@code java.logging},
643+
* so the surefire {@code argLine} opens {@code java.util.logging} to the test classpath.
644+
*/
645+
private static int childLoggerCount(Logger logger) throws ReflectiveOperationException {
646+
// Qualified because this file already imports com.google.cloud.bigquery.Field.
647+
java.lang.reflect.Field kids = Logger.class.getDeclaredField("kids");
648+
kids.setAccessible(true);
649+
List<?> children = (List<?>) kids.get(logger);
650+
return children == null ? 0 : children.size();
651+
}
582652
}

0 commit comments

Comments
 (0)