CodeGym /Courses /Spring Test /SQL log in data tests

SQL log in data tests

Spring Test
Level 15, Lesson 3
Available

1. The role of the SQL log in @DataJpaTest

If you have ever looked at a failed JPA test and thought, “Okay... what exactly went wrong?”, then you are already ready for the SQL log. In data tests, we verify persistence behavior, and it always turns into SQL in the end. And when a test fails, it is useful to see not only “Exception happened”, but also “which query exactly was being executed and why the database said no”.

Think of JPA as a very diligent waiter. You say, “Bring me an article, save it, update the title,” and the waiter goes off to the kitchen (the database) and comes back with the result. Sometimes it brings back the wrong thing (a mapping error), sometimes the kitchen refuses to cook (constraint violation), and sometimes the waiter never went to the kitchen at all because you forgot to ask it to “take the order out” (flush()). The SQL log is a way to peek into the kitchen and see what was really cooked and at what moment the chef dropped the ladle.

A useful idea: the SQL log is needed not to “become a DBA in 10 minutes”, but to stop guessing in tests. JPA has a lot of hidden magic, and instead of hating magic, it is better to make it observable.

A small diagram of what we want to highlight:

flowchart TD
    T["JUnit test (@DataJpaTest)"] --> PC["Persistence Context managed entities"]
    PC --> |"flush()"| SQL["SQL statements (insert/update/select)"]
    SQL --> DB["(Database)"]
    DB -->|constraints / errors| EX["Exception"]
    DB -->|data| R["Result set"]
    R --> T

2. Two sources of SQL in Spring Boot

When beginners first enable SQL output, they often do it however they can, and then wonder why the console turned into a waterfall of text. In Spring Boot, there are usually two popular paths: a quick and rough one (spring.jpa.show-sql=true) and a slightly more mature one (logging through Hibernate categories). Both are useful if you understand what you want from them.

spring.jpa.show-sql=true is like turning on a light bulb that says, “show me the SQL right now.” It prints queries in a fairly straightforward way, often with a prefix like Hibernate:. This is convenient for a first introduction and quick investigations. But this mode has its quirks: it often writes somewhere other than your usual logs (it may write to stdout), is harder to control by level, and the formatting is not always the most readable.

Hibernate logging through logging.level... is a more “command-oriented” path, because you control the log level the same way you control all other application logs. Plus, you can enable the queries themselves (SQL) separately, the parameter values separately (bind parameters), and errors separately. This approach is often nicer when you want to “enable SQL for just one test class” and then turn it off calmly.

There is another important detail: SQL strings often look like ... values (?, ?, ?) — with question marks instead of values. That is normal: JDBC uses prepared statements. Sometimes it is enough to see the mere fact of INSERT/UPDATE/SELECT. And sometimes you need to understand which values actually went into the parameters (especially when you are catching null in a not-null column). Then you enable bind parameter logging. It is powerful, but noisy — and in real production doing that is dangerous (you may accidentally log sensitive data). In tests, you can usually allow a bit more honesty.

For the working path below, let us take the logger-based option through logging.level.org.hibernate.SQL=DEBUG: it fits better into the normal test logs and is convenient to enable precisely for one class. show-sql, bind logs, and application-test.yml are useful as alternatives, but they do not have to take up half the attention.

3. Enabling the SQL log for one test

For a normal investigation in @DataJpaTest, one default path is enough: enable Hibernate SQL as a regular logger directly in the test annotation. Then the queries go through the same channel as the rest of the test logs, so they are easy to turn on locally and just as easy to remove.

import org.springframework.boot.test.autoconfigure.orm.jpa.DataJpaTest;

// Recommended default: SQL goes as part of the regular logs of this test class
@DataJpaTest(properties = {
        "logging.level.org.hibernate.SQL=DEBUG",
        "spring.jpa.properties.hibernate.format_sql=true"
})
class ArticleRepositoryDataJpaTest {
}

format_sql=true here only makes the output easier to read. That is already enough to connect the test line with insert/update/select and quickly understand where exactly JPA went to the DB.

4. How to read the log: “test line → SQL → effect in the DB”

Enabling the SQL log is only half the victory. The other half is learning to read it so that it answers the question “why did the test fail” instead of turning into meaningless noise. Good news: in data tests, the patterns are very repetitive. If you understand where flush happens in the test, where clear happens, and where a repeated read happens, you start literally “seeing” SQL with your eyes.

It is useful to keep in mind a simple table of “action in the test → what usually happens at the SQL level”:

What you do in the test What you (usually) see in the SQL log Why this happens
entityManager.persist(article) Often nothing (or very little) The object became managed, but SQL may be deferred until flush()
repository.save(article) May be nothing until flush() save() does not have to write to the DB immediately; JPA may accumulate changes
entityManager.flush() insert / update This is “take the order to the kitchen”: the changes are actually sent to the DB
You changed fields of a managed entity Nothing immediately JPA remembers that the object is dirty
flush() after the change update ... JPA performs dirty checking and forms an UPDATE
entityManager.find(...) without clear() Often no select JPA may return the same object from the 1st level cache
clear() + find(...) select ... The context is empty, so you need to actually read from the DB

Below, draftArticle("...") is shorthand for the same minimally valid Article, where the required fields and Category are already assembled by a helper. For the SQL log, we care not about the setup itself, but about the trace of insert/update/select.

Now let us reinforce this with a small but illustrative step-by-step test. It is written specifically so that, from the code, you can see exactly what we expect to see in the log.

import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.autoconfigure.orm.jpa.DataJpaTest;
import org.springframework.boot.test.autoconfigure.orm.jpa.TestEntityManager;

// Enable SQL output locally so this test reads like a scenario + an “X-ray”
@DataJpaTest(properties = "spring.jpa.show-sql=true")
class ArticleSqlLogDataJpaTest {

    @Autowired TestEntityManager entityManager;

    @Test
    void sqlLog_showsInsertUpdateSelect() {
        // The fixture creates a valid article by default
        var article = draftArticle("java-basics");

        // Persist on its own may not produce SQL — so we call flush() right away
        entityManager.persist(article);
        entityManager.flush(); // expect INSERT

        // Change the managed entity: UPDATE will happen only on flush()
        article.setTitle("Updated title");
        entityManager.flush(); // expect UPDATE

        // We want a “real” SELECT from the DB, not from the persistence context
        entityManager.clear();
        entityManager.find(article.getClass(), article.getId()); // expect SELECT
    }
}

Yes, there is “magic” in draftArticle(...) — we use a test fixture so we do not have to spell out all the required article fields every time. In the logs (in a simplified form) you will usually see something very similar to:

Hibernate: insert into articles (...) values (?, ?, ?, ...)
Hibernate: update articles set title=? ... where id=?
Hibernate: select a1_0.id, a1_0.title, a1_0.slug ... from articles a1_0 where a1_0.id=?

Three log lines — and we already have an “X-ray” of the behavior. If the test fails, you immediately understand at which step the problem occurred: on insert, update, or select.

Another useful micro-technique: leave small comments in the test like “expect INSERT”. This is not for beauty. It makes the test readable as a scenario and greatly simplifies matching “test line → SQL line”.

If the standard log is not enough

Sometimes other modes are needed, but it is better to enable them only for a specific problem, not by default:

— spring.jpa.show-sql=true — the fastest way to look at SQL, but it is managed more roughly and often writes to stdout;

— a parameter log such as logging.level.org.hibernate.orm.jdbc.bind=TRACE — useful when you are hunting for null or incorrect bind values; the category name depends on the Hibernate version, and this mode is very noisy;

— application-test.yml — convenient if the same SQL log is needed for a whole set of tests rather than one local investigation.

5. Data test failure cases from the SQL log

Now comes the detective part. But without hats and magnifying glasses — only JUnit, JPA, and your inner voice whispering, “Why did it fail right now?” In each case, we will deliberately keep the test short so that the log is easy to read. When a test turns into a “universal scenario for everything”, the SQL log becomes unreadable. So we will be disciplined, even though it is very tempting to be creative.

Case 1: unique on slug — the error happens “not where” you expect

A ContentHub classic: slug must be unique. We save one article with slug = "same-slug", and everything is fine. Then we save a second one with the same slug — and we expect the error to appear “on the second persist line”. But more often it appears... on flush(). Because it is flush() that actually sends SQL to the database.

import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.autoconfigure.orm.jpa.DataJpaTest;
import org.springframework.boot.test.autoconfigure.orm.jpa.TestEntityManager;

import static org.assertj.core.api.Assertions.assertThatThrownBy;

@DataJpaTest(properties = "spring.jpa.show-sql=true")
class ArticleSlugUniqueSqlLogTest {

    @Autowired TestEntityManager entityManager;

    @Test
    void duplicateSlug_failsOnFlush() {
        // Insert #1 succeeds
        entityManager.persist(draftArticle("same-slug"));
        entityManager.flush(); // INSERT #1

        // Insert #2 with the same slug must explode on flush(), not on persist()
        entityManager.persist(draftArticle("same-slug"));
        assertThatThrownBy(entityManager::flush) // INSERT #2 -> boom
                // What matters here is the fact that the second INSERT fails;
                // the exact exception type depends on the provider and wrappers.
                .isInstanceOf(Exception.class);
    }
}

If the SQL log is enabled, you will see something like this:

Hibernate: insert into articles (...) values (?, ?, ?, ...)
Hibernate: insert into articles (...) values (?, ?, ?, ...)
-- then the unique constraint violation exception

And here the log gives you the most valuable thing: confirmation that the problem is indeed in the second insert, and not somewhere else. Even if the stack trace is huge and wrapped in several exceptions, the SQL log shows the real sequence of events.

An important nuance: the error text may differ between databases. Somewhere it will be “duplicate key”, somewhere “unique index violation”. Do not get stuck on the wording. Your job as the test author is to understand which query violated the invariant and prove that the invariant is really enforced by the database.

Case 2: not null — inserting an “almost correct” article and a mysterious null

The second popular scenario: an article looks “almost normal”, but somewhere you forgot a field that cannot be null in the database. For example, title. In Java, this is easy to miss because the object “was created”, setters work, and the compiler does not complain. But the database is not a psychologist; it does not believe in potential.

import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.autoconfigure.orm.jpa.DataJpaTest;
import org.springframework.boot.test.autoconfigure.orm.jpa.TestEntityManager;

import static org.assertj.core.api.Assertions.assertThatThrownBy;

@DataJpaTest(properties = "spring.jpa.show-sql=true")
class ArticleNotNullSqlLogTest {

    @Autowired TestEntityManager entityManager;

    @Test
    void nullTitle_failsOnInsertFlush() {
        // Create a valid object and break exactly one rule — title becomes null
        var article = draftArticle("java-basics");
        article.setTitle(null);

        entityManager.persist(article);
        // The error will arrive exactly on flush(), because that is when the INSERT goes to the DB
        assertThatThrownBy(entityManager::flush)
                .isInstanceOf(Exception.class);
    }
}

The SQL log helps in a simple way here: you see that there really was an insert. That matters because beginners sometimes think, “JPA is smart, so it probably did not insert anything.” But it did — and the database refused it.

If you enabled parameter logging (bind), you can even see which parameter was sent as null. This is especially useful when the object is large and there are many not-null constraints, and one stack trace does not always make it clear which field was actually empty.

This is exactly where you start appreciating draftArticle(...) as a fixture: it should create the most valid object possible by default. And the test should break exactly one rule so that the investigation stays short.

Case 3: “Where is my UPDATE?” — the test fails because flush() was omitted

This scenario is especially tricky because it is not “about a database constraint”, but about our flush discipline. You updated a field on a managed entity and are sure that “well, it changed, so it must have changed in the database.” Then you do clear() and read it again — and see the old value. The test fails, and you feel cheated. But in fact, you forgot to ask the waiter to take the changes to the kitchen.

import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.autoconfigure.orm.jpa.DataJpaTest;
import org.springframework.boot.test.autoconfigure.orm.jpa.TestEntityManager;

import static org.assertj.core.api.Assertions.assertThat;

@DataJpaTest(properties = "spring.jpa.show-sql=true")
class ArticleUpdateSqlLogTest {

    @Autowired TestEntityManager entityManager;

    @Test
    void updateIsNotInDbWithoutFlush() {
        var article = draftArticle("java-basics");
        entityManager.persist(article);
        entityManager.flush(); // INSERT

        // Change a field on the managed entity...
        article.setTitle("Changed only in memory");
        // ...and then “lose” the changes because we clear the context BEFORE flush()
        entityManager.clear(); // we cleared the context before flush()

        // Read from the DB honestly: the old title is still there because there was no UPDATE
        var reloaded = entityManager.find(article.getClass(), article.getId());
        assertThat(reloaded.getTitle()).isEqualTo("Java Basics");
    }
}

If you look at the SQL log, the investigation happens almost by itself. You will see insert, then select — and no update in between. That is the answer to the question “why did the database not see the change”.

Hibernate: insert into articles (...) values (?, ?, ?, ...)
Hibernate: select ... from articles ... where id=?

It becomes obvious: for the update to reach the DB, we should have done a second flush() after changing the field, and left clear() after it.

This case is a great example of how the SQL log turns “it seems JPA is broken” into “aha, I missed a step in the scenario”.

6. The SQL log is not an assertion

When you first see the SQL log, there is a temptation: “Oh! Let us check that there was exactly one INSERT and exactly one SELECT.” It sounds logical, but in most ordinary data tests this is a bad idea. SQL is an implementation detail of your persistence layer, and it may change because of things that do not break business behavior: a dialect change, a Hibernate upgrade, a change in naming strategy, even small mapping changes.

For now, our goal is to learn to make JPA behavior observable and honest, not to tie tests to the exact text of queries. Therefore, the SQL log is a tool for diagnosis and understanding, while assertions are built on more stable things: rereading the data, the fact that a constraint was violated, the presence of a record, and the correctness of fields.

A good internal formula for today sounds like this: “I read SQL with my eyes, but I check behavior through the repository and reread it.” The log helps explain the failure, not become the goal of the test.

7. Typical mistakes when reading the SQL log

For almost everyone, the SQL log first causes two reactions: either “Wow, now I understand everything!”, or “What is all this noise, I understand nothing!” Usually the problem is neither you nor JPA, but a few typical habits that make the log useless. If you catch them in advance, you will investigate failures much more calmly — and, importantly, faster.

Mistake #1: enable the SQL log for the entire test suite and drown in it.
If you enabled show-sql or the Hibernate SQL log globally, the console turns into a 300-season series: interesting, yes, but not enough life to watch it all. It is better to enable the SQL log only for one test class or for a short investigation period. Then you read a few lines and immediately connect them with the steps of the scenario.

Mistake #2: expect SQL after persist() and wonder why it is not there.
persist() makes the object managed, but it does not have to send the insert immediately. JPA may accumulate changes until flush(). So “silence in the log” after persist() is often normal, not a bug. If you want to see the moment of actual writing, put flush() at the point in the scenario where you expect DB behavior.

Mistake #3: forget about clear() and wait for a select that will not happen.
If you called find() and did not see a select, that does not mean JPA “does not read the database”. It may already know this object and return it from the persistence context. For a fair reread, do clear(), then read again. Then the select will usually appear, and the log will start matching your mental scenario.

Mistake #4: read the exception without tying it to a specific SQL step.
In JPA and Spring, exceptions are often wrapped in layers: JDBC → Hibernate → Spring. As a result, the stack trace is long, and “where did it fail” is not obvious. The SQL log fixes this, but only if you consciously look: which query was the last one before the error, and on which flush (or read) it was triggered.

Mistake #5: try to “test SQL” instead of testing the result in the DB.
The SQL log may change even if your behavior remains correct. So it is better to keep the log as an explanation tool, and the check as an honest read-back through clear and a reread. If the test starts depending on the SQL text, it becomes fragile and will break over things that are not even a product regression.

1
Task
Spring Test, level 15, lesson 3
Locked
Local SQL log for `insert` and `select`
Local SQL log for `insert` and `select`
1
Task
Spring Test, level 15, lesson 3
Locked
Local SQL log for `insert`, `update`, and `select`
Local SQL log for `insert`, `update`, and `select`
Comments
TO VIEW ALL COMMENTS OR TO MAKE A COMMENT,
GO TO FULL VERSION