Skip to content

Driver version 3.4.1 flods logs with internal exception on SHOW COLUMNS #1490

Description

@NathanEckert

Describe the bug

In 3.4.1, every DatabaseMetaData.getColumns() call produces between 15 and ~1,100 full stack traces of a caught and recovered DatabricksSQLException: Invalid column index, all printed to java.sql.DriverManager's log writer. In one 20-minute CI run with DriverManager.setLogWriter configured, this
generated 3,496 stack-trace dumps and ~49 MB of logs in a single Maven module. The getColumns call itself succeeds — the output is pure noise, and it drowns out genuinely useful driver diagnostics

To Reproduce

class TestDatabricksMetadataRegressionReproducer {

  private static final String CONNECTION_STRING =
      DatabricksTestConstants.TEST_CONNECTION_STRING_SQL_WAREHOUSE;
  private static final String CATALOG = DatabricksTestConstants.TEST_UNITY_CATALOG_NAME;
  private static final String SCHEMA = DatabricksTestConstants.TEST_SCHEMA_NAME;
  private static final List<String> TABLES =
      List.of(
          DatabricksTestConstants.SALES_TABLE_NAME,
          DatabricksTestConstants.PRODUCTS_TABLE_NAME,
          DatabricksTestConstants.SIMULATIONS_NATIVE_TABLE_NAME);

  private static final String SPAM_MARKER = "Invalid column index";

  @BeforeAll
  static void wakeUpWarehouse() {
    // Wake the warehouse first so the timings below measure metadata calls, not cluster startup
    DatabricksTestConstants.performHealthCheckQuery(CONNECTION_STRING);
  }

  @Test
  void testGetColumnsShouldNotFloodTheDriverManagerLogWriter() throws Exception {
    final StringWriter capturedDriverOutput = new StringWriter();
    final PrintWriter previousLogWriter = DriverManager.getLogWriter();
    DriverManager.setLogWriter(new PrintWriter(capturedDriverOutput, true));

    final Properties properties = new Properties();
    properties.put("PWD", DatabricksTestConstants.AUTH_TOKEN);
    try (final Connection connection = DriverManager.getConnection(CONNECTION_STRING, properties)) {
      final DatabaseMetaData metaData = connection.getMetaData();
      System.out.printf(
          "Driver: %s %s%n", metaData.getDriverName(), metaData.getDriverVersion());

      for (final String table : TABLES) {
        final long start = System.nanoTime();
        int columnCount = 0;
        try (final ResultSet columns = metaData.getColumns(CATALOG, SCHEMA, table, null)) {
          while (columns.next()) {
            ++columnCount;
          }
        }
        final long elapsedMs = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);
        System.out.printf(
            "getColumns(%s.%s.%s): %d columns in %d ms%n",
            CATALOG, SCHEMA, table, columnCount, elapsedMs);
        assertThat(columnCount)
            .as("getColumns(%s) should discover the table columns", table)
            .isPositive();
      }
    } finally {
      DriverManager.setLogWriter(previousLogWriter);
    }

    final String driverOutput = capturedDriverOutput.toString();
    final long spamCount = driverOutput.lines().filter(line -> line.contains(SPAM_MARKER)).count();
    System.out.printf(
        "DriverManager log writer received %d characters, including %d '%s' lines%n",
        driverOutput.length(), spamCount, SPAM_MARKER);

    assertThat(spamCount)
        .as(
            "The driver printed %d caught-and-recovered '%s' stack traces to the DriverManager"
                + " log writer while every getColumns call succeeded. Sample of the captured"
                + " output:%n%s",
            spamCount, SPAM_MARKER, sample(driverOutput))
        .isZero();
  }

  private static String sample(final String driverOutput) {
    final int markerIndex = driverOutput.indexOf(SPAM_MARKER);
    if (markerIndex < 0) {
      return "<no occurrence>";
    }
    final int start = Math.max(0, driverOutput.lastIndexOf('\n', markerIndex) + 1);
    return driverOutput.substring(start, Math.min(driverOutput.length(), start + 2_000));
  }
}

Expected behavior

  • MetadataResultSetBuilder.getRows should not probe out-of bounds, thus avoiding the throw
  • Maybe do not log the full stacktrace of internally caught-and-recovered exceptions to the DriverManager

Client Environment (please complete the following information):

  • OS: Linux
  • Java version: Java 25
  • Java vendor: Azul
  • Driver Version: 3.4.1

Additional context

Possibly related: #1447 (categorizing generic INVALID_STATE telemetry) — these spurious exceptions presumably also pollute telemetry error counts.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions