fix(bigquery-jdbc): lazy caller inference and zero-overhead coercion logging

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

@@ -42,28 +42,81 @@ private void logWithCaller(Level level, Throwable thrown, Supplier<String> msgSu
       return;
     }
 
-    StackTraceElement[] stackTrace = new Throwable().getStackTrace();
-    String sourceClass = "unknown";
-    String sourceMethod = "unknown";
-
-    for (StackTraceElement element : stackTrace) {
-      String className = element.getClassName();
-      if (!className.equals(BigQueryJdbcCustomLogger.class.getName())
-          && !className.startsWith("com.google.cloud.bigquery.exception.")) {
-        sourceClass = className;
-        sourceMethod = element.getMethodName();
-        break;
+    LogRecord record = new BigQueryJdbcLogRecord(level, msgSupplier.get());
+    record.setThrown(thrown);
+    log(record);
+  }
+
+  static class BigQueryJdbcLogRecord extends LogRecord {
+    private boolean callerInferred = false;
+    private String sourceClass;
+    private String sourceMethod;
+
+    public BigQueryJdbcLogRecord(Level level, String msg) {
+      super(level, msg);
+    }
+
+    synchronized boolean isCallerInferred() {
+      return callerInferred;
+    }
+
+    @Override
+    public synchronized String getSourceClassName() {
+      inferCaller();
+      return sourceClass;
+    }
+
+    @Override
+    public synchronized void setSourceClassName(String sourceClassName) {
+      super.setSourceClassName(sourceClassName);
+      this.sourceClass = sourceClassName;
+      this.callerInferred = true;
+    }
+
+    @Override
+    public synchronized String getSourceMethodName() {
+      inferCaller();
+      return sourceMethod;
+    }
+
+    @Override
+    public synchronized void setSourceMethodName(String sourceMethodName) {
+      super.setSourceMethodName(sourceMethodName);
+      this.sourceMethod = sourceMethodName;
+      this.callerInferred = true;
+    }
+
+    private synchronized void inferCaller() {
+      if (callerInferred) {
+        return;
+      }
+      callerInferred = true;
+      StackTraceElement[] stackTrace = new Throwable().getStackTrace();
+      sourceClass = "unknown";
+      sourceMethod = "unknown";
+
+      for (StackTraceElement element : stackTrace) {
+        String className = element.getClassName();
+        if (isDriverClass(className) && !isLoggerClass(className)) {
+          sourceClass = className;
+          sourceMethod = element.getMethodName();
+          break;
+        }
       }
+      super.setSourceClassName(sourceClass);
+      super.setSourceMethodName(sourceMethod);
+    }
+
+    private static boolean isDriverClass(String className) {
+      return className.startsWith("com.google.cloud.bigquery.jdbc.")
+          || className.startsWith("com.google.cloud.bigquery.exception.");
     }
 
-    if (thrown == null) {
-      logp(level, sourceClass, sourceMethod, msgSupplier);
-    } else {
-      LogRecord record = new LogRecord(level, msgSupplier.get());
-      record.setSourceClassName(sourceClass);
-      record.setSourceMethodName(sourceMethod);
-      record.setThrown(thrown);
-      log(record);
+    private static boolean isLoggerClass(String className) {
+      return className.equals("com.google.cloud.bigquery.jdbc.BigQueryJdbcCustomLogger")
+          || className.equals("com.google.cloud.bigquery.jdbc.BigQueryJdbcResultSetLogger")
+          || className.startsWith("com.google.cloud.bigquery.jdbc.BigQueryJdbcRootLogger")
+          || className.equals(BigQueryJdbcLogRecord.class.getName());
     }
   }
 

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

@@ -67,8 +67,8 @@
  */
 @InternalApi
 class BigQueryTypeCoercer {
-  private static final BigQueryJdbcCustomLogger LOG =
-      new BigQueryJdbcCustomLogger(BigQueryTypeCoercer.class.getName());
+  private static final BigQueryJdbcResultSetLogger LOG =
+      BigQueryJdbcResultSetLogger.getLogger(BigQueryTypeCoercer.class);
 
   /** A {@link BigQueryTypeCoercer} instance with all the inbuilt {@link BigQueryCoercion}s */
   static BigQueryTypeCoercer INSTANCE;
@@ -108,8 +108,9 @@ <T> T coerceTo(Class<T> targetClass, Object value, BigQueryJdbcResultSetLogger l
       return targetClass.cast(value);
     }
     BigQueryCoercion<Object, T> coercion = findCoercion(sourceClass, targetClass);
-    BigQueryJdbcCustomLogger effectiveLog = log != null ? log : LOG;
-    effectiveLog.finest("%s coercion for %s", coercion, value);
+    BigQueryJdbcResultSetLogger effectiveLog = log != null ? log : LOG;
+    effectiveLog.finestTrace(
+        "coerceTo", () -> String.format("%s coercion for %s", coercion, value));
     // Value is null case & no explicit coercion
     if (sourceClass == Void.class && coercion == null) {
       return null;

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

@@ -93,6 +93,31 @@ public void testLogWithCallerInference() {
     assertEquals(BigQueryJdbcCustomLoggerTest.class.getName(), record.getSourceClassName());
   }
 
+  @Test
+  public void testLazyCallerInference() {
+    logger.fine("Lazy log message");
+
+    List<LogRecord> records = testHandler.getRecords();
+    assertEquals(1, records.size());
+    LogRecord record = records.get(0);
+
+    assertTrue(record instanceof BigQueryJdbcCustomLogger.BigQueryJdbcLogRecord);
+    BigQueryJdbcCustomLogger.BigQueryJdbcLogRecord lazyRecord =
+        (BigQueryJdbcCustomLogger.BigQueryJdbcLogRecord) record;
+
+    // Verify stack walk has not been executed yet
+    assertTrue(!lazyRecord.isCallerInferred());
+
+    // Trigger stack walk
+    String className = record.getSourceClassName();
+    String methodName = record.getSourceMethodName();
+
+    // Verify stack walk has executed and correct caller was inferred
+    assertTrue(lazyRecord.isCallerInferred());
+    assertEquals(BigQueryJdbcCustomLoggerTest.class.getName(), className);
+    assertEquals("testLazyCallerInference", methodName);
+  }
+
   @Test
   public void testHotPathLoggerLogToDefaultWhenContextIsNull() {
     BigQueryJdbcCustomLogger hotpathLogger =