Pyranid Logo

Core Concepts

Logging and Diagnostics

Pyranid provides tooling for runtime insight into SQL execution.

For many applications, it's important to understand exactly what queries are being run to keep on top of potential performance problems.

Further, it's often useful to mark specific queries for special processing - for example, you might want to log particularly slow or "special" SQL, or you might want to flag a query as needing Custom ResultSet Mapping.

Statement Logging

You may customize your Database with a StatementLogger.

Reasons you might do this include:

  • Writing queries and timing information to your logging system
  • Picking out slow queries for special logging/reporting
  • Collecting a set of queries executed across a unit of work for bulk analysis (e.g. a ThreadLocal<T> or ScopedValue<T> scoped to a single web request)
Database database = Database.withDataSource(dataSource)
  .statementLogger(new StatementLogger() {
    Duration SLOW_QUERY_THRESHOLD = Duration.ofMillis(500);

    @Override
    public void log(@NonNull StatementLog statementLog) {
      if(statementLog.getTotalDuration().compareTo(SLOW_QUERY_THRESHOLD) > 0)
        out.printf("Slow query: %s\n", statementLog);
    }
  }).build();

StatementLogger failures are intentionally fail-fast. If your logger throws after a statement otherwise succeeds, that exception propagates to the caller. Inside a Pyranid transaction, logger failures participate in normal transaction failure handling and cause rollback. If the statement itself failed, the logger failure is attached as a suppressed exception to the primary failure.

Keep logger implementations lightweight and failure-safe. If logging must never affect database writes, catch and handle exceptions inside your logger implementation, or use MetricsCollector for best-effort observability.

StatementContext::toString() and StatementLog::toString() use StatementContext::getRedactedParameters(). Values wrapped with Parameters::secure(...) render as their mask:

// Configure a simple StatementLogger that writes to stdout
Database database = Database.withDataSource(dataSource)
  .statementLogger(statementLog -> System.out.println(statementLog))
  .build();

database.query("INSERT INTO api_credential (account_id, token_hash) VALUES (:accountId, :tokenHash)")
  .bind("accountId", "acct_123")
  .bind("tokenHash", Parameters.secure("token_hash_abc123"))
  .execute();

The logged StatementLog includes a redacted parameter display:

parameters=[acct_123, <redacted>]

Custom loggers can choose raw or display-safe parameters explicitly:

// Raw values, trusted code only
statementLog.getStatementContext().getParameters();

// Safe display values
statementLog.getStatementContext().getRedactedParameters();

Pyranid exception messages use the same bounded parameter display. Under the default ParameterRedactor::none(), non-secure, non-batch values render verbatim; wrap sensitive bind values with Parameters::secure(...) or configure Database.Builder::parameterRedactor(...) when exception text may leave a trusted boundary.

StatementLog instances give you access to the following for each SQL statement executed:

References:

Statement Identifiers

Use Query::id(Object) to tag statements.

This is useful for tagging queries that should be handled specially. Why might you do this?

  • To mark a query as "hot" so we don't pollute logs with it
  • To mark a query as "known to be slow" so we don't flag slow query alerts for it
  • Your InstanceProvider might key on it to provide custom instances (e.g. during resultset mapping)

For example:

// This query fires every 3 seconds - 
// let's give it a special identifier so we know not to log it.
Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> {
  // Safely "claim" some messages off the queue
  List<Message> messages = database.transaction(() ->
      Optional.of(database.query("""
        UPDATE message_queue
        SET message_status_id = :processing
        WHERE id IN (
          SELECT id
          FROM message_queue
          WHERE message_status_id = :unprocessed
          ORDER BY created_at
          LIMIT :limit
          FOR UPDATE
          SKIP LOCKED
        )
        RETURNING *
        """)
        .id("message-queue-claim")
        .bind("unprocessed", MessageStatusId.UNPROCESSED)
        .bind("processing", MessageStatusId.PROCESSING)
        .bind("limit", BATCH_SIZE)
        .fetchList(Message.class)))
      .orElseThrow();

  // Implementation not shown
  processMessages(messages);
}, 0, 3, TimeUnit.SECONDS);

A corresponding Database setup:

// Ensure our StatementLogger implementation takes HOT_QUERY into account 
Database database = Database.withDataSource(dataSource)
  .statementLogger(new StatementLogger() {
    @Override
    public void log(@NonNull StatementLog statementLog) {
      // Log everything except "message-queue-claim"
      Statement statement = statementLog.getStatementContext().getStatement();
      if(!statement.getId().equals("message-queue-claim"))
        out.println(statementLog);
    }
  }).build();

References:

Database Metadata

The JDBC standard defines a DatabaseMetaData type, which provides comprehensive vendor-specific information about a database as a whole.

Pyranid exposes a Database::readDatabaseMetaData(DatabaseMetaDataReader) method which acquires a transient DatabaseMetaData instance on its own newly-borrowed JDBC Connection (managed by Pyranid internally).

The Connection does not participate in the active transaction, if one exists.

The Connection is automatically closed as soon as the closure completes.

Database database = Database.withDataSource(...).build();

database.readDatabaseMetaData(databaseMetaData -> {
  // e.g. "PostgreSQL"
  out.println(databaseMetaData.getDatabaseProductName());
});

Caution!

Your code should not retain a reference to the DatabaseMetaData instance outside the scope of the closure.

References:

Previous
Error Handling
Next
Metrics Collection