Skip to content

Commit 4233faf

Browse files
authored
fix(bqjdbc): optimize formatter in BigQueryJdbcRootLogger (#12877)
- Replaced `String.format` with `StringBuilder` and Guava's Strings for faster padding. - Eliminated `Thread.getAllStackTraces()` (which triggered heavy JVM safepoints) by using `Thread.currentThread()` and `Thread.enumerate()` fallbacks. - Cached PROCESS_ID instead of parsing it dynamically on every log line. - Swapped in `ThreadLocal<SimpleDateFormat>` to safely reuse expensive date formatters.
1 parent 4860366 commit 4233faf

2 files changed

Lines changed: 132 additions & 38 deletions

File tree

java-bigquery/google-cloud-bigquery-jdbc/src/main/java/com/google/cloud/bigquery/jdbc/BigQueryJdbcRootLogger.java

Lines changed: 58 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616

1717
package com.google.cloud.bigquery.jdbc;
1818

19+
import com.google.common.base.Strings;
1920
import java.io.IOException;
2021
import java.lang.management.ManagementFactory;
2122
import java.nio.file.Files;
@@ -24,7 +25,6 @@
2425
import java.nio.file.StandardCopyOption;
2526
import java.text.SimpleDateFormat;
2627
import java.util.Date;
27-
import java.util.Optional;
2828
import java.util.logging.ConsoleHandler;
2929
import java.util.logging.FileHandler;
3030
import java.util.logging.Formatter;
@@ -49,6 +49,32 @@ class BigQueryJdbcRootLogger {
4949
private static Path currentLogPath = null;
5050
private static int fileCounter = 0;
5151

52+
static final String PROCESS_ID = ManagementFactory.getRuntimeMXBean().getName().split("@")[0];
53+
54+
private static final ThreadLocal<SimpleDateFormat> DATE_FORMATTER =
55+
ThreadLocal.withInitial(() -> new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"));
56+
57+
static String getThreadName(long threadId) {
58+
Thread current = Thread.currentThread();
59+
if (current.getId() == threadId) {
60+
return current.getName();
61+
}
62+
ThreadGroup rootGroup = current.getThreadGroup();
63+
while (rootGroup.getParent() != null) {
64+
rootGroup = rootGroup.getParent();
65+
}
66+
67+
int count = rootGroup.activeCount();
68+
Thread[] threads = new Thread[count * 2];
69+
int actualCount = rootGroup.enumerate(threads);
70+
for (int i = 0; i < actualCount; i++) {
71+
if (threads[i].getId() == threadId) {
72+
return threads[i].getName();
73+
}
74+
}
75+
return "";
76+
}
77+
5278
static {
5379
logger.setUseParentHandlers(false);
5480
storageLogger.setUseParentHandlers(true);
@@ -62,49 +88,43 @@ class BigQueryJdbcRootLogger {
6288

6389
public static Formatter getFormatter() {
6490
return new Formatter() {
65-
private static final String PATTERN = "yyyy-MM-dd HH:mm:ss.SSS";
66-
private static final String FORMAT =
67-
"%1$s %2$5s %3$d --- [%4$-7.15s] %5$-50s %6$-20s: %7$s%8$s";
6891
private static final int MAX_THREAD_NAME_LENGTH = 15;
6992

70-
/**
71-
* Returns the thread for the given thread id.
72-
*
73-
* @param threadId ID for the thread being logged.
74-
* @return returns the thread
75-
*/
76-
Optional<Thread> getThread(long threadId) {
77-
return Thread.getAllStackTraces().keySet().stream()
78-
.filter(thread -> thread.getId() == threadId)
79-
.findFirst();
80-
}
81-
8293
@Override
8394
public String format(LogRecord record) {
84-
String date = new SimpleDateFormat(PATTERN).format(new Date(record.getMillis()));
85-
String threadName =
86-
getThread(record.getThreadID())
87-
.map(Thread::getName)
88-
.map(
89-
name ->
90-
name.length() > MAX_THREAD_NAME_LENGTH
91-
? name.substring(name.length() - MAX_THREAD_NAME_LENGTH)
92-
: name)
93-
.orElse("");
94-
long processId =
95-
Long.parseLong(ManagementFactory.getRuntimeMXBean().getName().split("@")[0]);
95+
String date = DATE_FORMATTER.get().format(new Date(record.getMillis()));
96+
97+
long threadId = record.getThreadID();
98+
String threadName = getThreadName(threadId);
99+
100+
if (threadName.length() > MAX_THREAD_NAME_LENGTH) {
101+
threadName = threadName.substring(threadName.length() - MAX_THREAD_NAME_LENGTH);
102+
}
103+
96104
String sourceClassName = record.getLoggerName();
97105
String sourceMethodName = record.getSourceMethodName();
98-
return String.format(
99-
FORMAT,
100-
date,
101-
record.getLevel().getName(),
102-
processId,
103-
threadName,
104-
sourceClassName,
105-
sourceMethodName,
106-
record.getMessage(),
107-
System.lineSeparator());
106+
107+
// Expected log format: yyyy-MM-dd HH:mm:ss.SSS LEVEL PID --- [THREAD] CLASS METHOD: MESSAGE
108+
// Example: 2026-04-22 10:16:00.123 INFO 12345 --- [main ]
109+
// com.google.cloud.bigquery.jdbc.BigQueryConnection connect : Connection
110+
// successful
111+
StringBuilder sb = new StringBuilder(256);
112+
sb.append(date)
113+
.append(" ")
114+
.append(Strings.padStart(record.getLevel().getName(), 5, ' '))
115+
.append(" ")
116+
.append(PROCESS_ID)
117+
.append(" --- [")
118+
.append(Strings.padEnd(threadName, 7, ' '))
119+
.append("] ")
120+
.append(Strings.padEnd(sourceClassName != null ? sourceClassName : "", 50, ' '))
121+
.append(" ")
122+
.append(Strings.padEnd(sourceMethodName != null ? sourceMethodName : "", 20, ' '))
123+
.append(": ")
124+
.append(record.getMessage())
125+
.append(System.lineSeparator());
126+
127+
return sb.toString();
108128
}
109129
};
110130
}
Lines changed: 74 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,74 @@
1+
/*
2+
* Copyright 2026 Google LLC
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package com.google.cloud.bigquery.jdbc;
18+
19+
import static org.junit.jupiter.api.Assertions.assertEquals;
20+
import static org.junit.jupiter.api.Assertions.assertNotNull;
21+
import static org.junit.jupiter.api.Assertions.assertTrue;
22+
23+
import java.util.logging.Formatter;
24+
import java.util.logging.Level;
25+
import java.util.logging.LogRecord;
26+
import org.junit.jupiter.api.Test;
27+
28+
public class BigQueryJdbcRootLoggerTest {
29+
30+
@Test
31+
public void testGetFormatterFormat() {
32+
Formatter formatter = BigQueryJdbcRootLogger.getFormatter();
33+
assertNotNull(formatter);
34+
35+
LogRecord record = new LogRecord(Level.INFO, "Test message");
36+
record.setMillis(1713715200000L);
37+
record.setLoggerName("TestLogger");
38+
record.setSourceMethodName("testMethod");
39+
40+
String formatted = formatter.format(record);
41+
42+
assertTrue(formatted.contains("INFO"));
43+
assertTrue(formatted.contains("Test message"));
44+
assertTrue(formatted.contains("TestLogger"));
45+
assertTrue(formatted.contains("testMethod"));
46+
assertTrue(formatted.contains("---"));
47+
}
48+
49+
@Test
50+
public void testThreadNameTruncation() {
51+
Formatter formatter = BigQueryJdbcRootLogger.getFormatter();
52+
LogRecord record = new LogRecord(Level.INFO, "Test message");
53+
54+
String formatted = formatter.format(record);
55+
int startIndex = formatted.indexOf("--- [") + 5;
56+
int endIndex = formatted.indexOf("]", startIndex);
57+
String threadPart = formatted.substring(startIndex, endIndex).trim();
58+
59+
assertTrue(threadPart.length() <= 15);
60+
}
61+
62+
@Test
63+
public void testGetThreadName() {
64+
Thread current = Thread.currentThread();
65+
String name = BigQueryJdbcRootLogger.getThreadName(current.getId());
66+
assertEquals(current.getName(), name);
67+
}
68+
69+
@Test
70+
public void testGetThreadNameNotFound() {
71+
String name = BigQueryJdbcRootLogger.getThreadName(-1);
72+
assertEquals("", name);
73+
}
74+
}

0 commit comments

Comments
 (0)