Seeing what Storm does

Predictable SQL is only reassuring if you can look at it. The SQL log shows every statement where it executes, TRACE makes the output executable, and per-call summaries show what each request cost the database.

01The task

A query misbehaves in one corner of the application. You want to see the exact SQL that corner runs, reproduce it in a database client, and confirm the fix, without turning on firehose logging for the whole system.

02Statements, scoped by type

Storm logs statements where they execute, under the st.orm.sql logger. Raise the log level; there is no other switch, nothing to annotate, and nothing about the execution changes: compiled query plans and the template cache stay in effect, so what you observe is the path that runs in production. Each entity and projection has its own child logger, so the logging follows the type you are investigating rather than the whole datasource:

# application.yml: the log level is the only switch
logging:
  level:
    st.orm.sql.UserView: DEBUG   # one type, not the firehose

-- Every executed statement logs once, prefixed with what it does and targets
-- SQL (SELECT UserView):
SELECT u.id, u.email FROM "user" u WHERE u.email = ?

03Copy-paste executable SQL

At DEBUG the log shows the statement as sent, placeholders included. At TRACE the bound values are rendered into it, producing SQL you can paste into a client to inspect the result set or check the plan with EXPLAIN:

# TRACE renders the bound values into the statement
logging:
  level:
    st.orm.sql.UserView: TRACE

-- Paste it straight into your database client, EXPLAIN and all
SELECT u.id, u.email FROM "user" u WHERE u.email = 'alice@example.com'

Values are database values: credentials, personal data, whatever your entities carry. That is why they appear only at TRACE, the level nobody enables in production by accident; DEBUG is the level to leave available for on-demand diagnosis.

04What one call cost

Individual statements answer what ran; they do not answer what a unit of work cost, and that total is the part you act on. With one property, every way work enters the application (HTTP requests, @Scheduled tasks, Kafka, RabbitMQ, JMS and SQS listeners) reports as a single summary: one row per distinct statement, heaviest first, with a statement that resolved a reference marked fetch. A statement run many times cheaply ranks above one slow statement when it cost more in total, which is what puts an N+1 at the top instead of burying it under the slowest single query:

# One summary per unit of work: requests, @Scheduled tasks,
# Kafka/Rabbit/JMS/SQS listeners: every way work enters the app
storm:
  sql-log:
    enabled: true
    threshold:
      statements: 50      # production guardrail: report only
      duration: 500ms    # the calls that exceed a threshold

SQL (GET /owners): 12 statements, 8 fetches, 214 ms in database, 678 ms total
   96 ms  6408 rows  7x  Visit         SELECT v.id, … FROM visit v WHERE v.pet_id = ?
   28 ms     8 rows  8x  City   fetch  SELECT c.id, c.name FROM city c WHERE c.id = ?
   18 ms   112 rows  4x  Pet           SELECT p.id, … FROM pet p WHERE p.owner_id = ?

The summary carries no parameter values, so it is safe to log in production, and the thresholds turn it into a guardrail that stays silent until a call exceeds one. For a narrower boundary than a request, wrap a block with sqlLog("importOwners") { }.

05Beyond logging

Two things sit next to the log. In tests, SqlCapture turns statement counts, origins and durations into assertions, so what you observed while debugging becomes a regression test. In production, Storm reports queries and transactions as Micrometer observations, alongside JMX metrics for the template cache, entity cache, and dirty checking. The storm.origin tag makes the cost of resolving references a quantity you can chart and alert on. See Metrics.

06Keep going

The reference documentation covers the mechanics in depth: