# How to log all generated SQL by Liquibase?

**URL:** <https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021>\
**Category:** General Discussion\
**Created:** [January 19, 2024, 11:16am UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021 "2024-01-19T11:16:12Z")\
**Posts on this page:** 11\
**Page:** 1

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 19, 2024, 11:16am UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/1 "2024-01-19T11:16:12Z")

</div>

Hi everyone,

I’m using liquibase-core 4.25.1, Spring Boot in some outdated version 4 and Log4j2 included by Spring Boot. Some of my Liquibase migrations fail with possibly SQL syntax errors, but I don’t see the actual generated SQL in the exception message at all. It only mentions some syntax error and possible root causes to check, but without the actual SQL it’s not of much help. I didn’t generate that SQL on my own, but was just using `indexExists` from Liquibase.

```xml
<changeSet author="dbr" id="0.9.7-HRP-143-aaaaj" dbms="db2i">
    <preConditions onFail="MARK_RAN">
        <not>
            <indexExists tableName="AC_COSTCENTER" indexName="AC_COSTCENTER_UX"/>
        </not>
    </preConditions>
    <createIndex indexName="AC_COSTCENTER_UX" tableName="AC_COSTCENTER" unique="true">
        <column name="COMPANY_ID"/>
        <column name="KEY"/>
    </createIndex>
</changeSet>

```

From my understanding Liquibase should be able to log the SQL at some log level below INFO. Though, whatever I try I don’t get ANY log messages from Liquibase below that level. I’m able to switch between ERROR and INFO, so my configs are appliedat leats partly, but I don’t get anything below INFO and therefore most likely no SQL.

The following is my property for Spring Boot and according to different sources this should even work with my older Spring Boot. As I’m able to switch between ERROR and INFO, I guess it works in general.

> logging.level.liquibase=TRACE

- [Liquibase logging level in Spring Boot - Stack Overflow](https://stackoverflow.com/a/30053646/2055163)
- [Liquibase's logging level is unaffected by general logging configuration · Issue #2916 · spring-projects/spring-boot · GitHub](https://github.com/spring-projects/spring-boot/issues/2916)

The following is Log4j2, but not sure about if the logger name is correct etc. Switching between ERROR and INFO seems to work here as well, e.g. with INFO in Spring Boot and ERROR in Log4j2, I only get the error messages etc. But again, nothing below INFO.

```xml
<Loggers>
	<Root level="WARN">
		<AppenderRef ref="console" />
		<AppenderRef ref="file" />
	</Root>
	<Logger name="liquibase" level="TRACE" />
	<Logger name="net.veda.appmediator" level="WARN" />
</Loggers>

```

**So how do I get the SQL logged or anything below INFO to check my settings?**

Thanks!

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 19, 2024, 4:16pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/2 "2024-01-19T16:16:44Z")

</div>

> [@veda-tschoening](#):
>
> `<Logger name="liquibase" level="TRACE" />`

For some reason, that line doesn’t work at all. When I switch `TRACE` to `ERROR` I still get `INFO` logged. OTOH, the following with explicit logger names does have an effect:

```auto
<Logger name="liquibase.changelog" level="ALL" />
<Logger name="liquibase.command" level="ALL" />
<Logger name="liquibase.executor" level="ALL" />
<Logger name="liquibase.lockservice" level="ALL" />
<Logger name="liquibase.ui" level="ALL" />
<Logger name="liquibase.util" level="ALL" />

```

For whichever line I switch `ALL` to `ERROR`, the corresponding `INFO` logs disappear. Though, the line containing `executor` doesn’t seem to have any effect, nothing is logged with that logger name.

---

<div class="post-metadata">

**Author:** ![daryldoak](https://sea2.discourse-cdn.com/flex020/user_avatar/forum.liquibase.org/daryldoak/32/764_2.png) [@daryldoak](https://forum.liquibase.org/u/daryldoak)\
**Post date:** [January 19, 2024, 4:43pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/3 "2024-01-19T16:43:03Z")

</div>

You need to set sql-log-level. Details can be found here:

> **[log-level](https://docs.liquibase.com/parameters/log-level.html)**
>
> Reference information for the log-level parameter. The log-level parameter controls the amount of messages that are generated when running Liquibase commands.

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 19, 2024, 5:06pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/4 "2024-01-19T17:06:02Z")

</div>

I’ve tried that already and it doesn’t work, there’s no additional logging output, regardless of the configured log level. Though, what I needed to do to get additional output below `INFO` is setting the following property:

> -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager

> <https://github.com/liquibase/liquibase/issues/2396#issuecomment-1245888636>
>
> \<!--- This environment context section helps us quickly review your PR. 
> …Please take a minute to fill-out this information. --\>
> \## Environment
> 
> \*\*Liquibase Version\*\*: 4.7.1
> 
> \*\*Liquibase Integration & Version\*\*: \<Pick one: CLI, maven, gradle, spring boot, servlet, etc.\>
> 
> \*\*Liquibase Extension(s) & Version\*\*: 
> 
> \*\*Database Vendor & Version\*\*:
> 
> \*\*Operating System Type & Version\*\*:
> 
> 
> \## Description
> 
> Since 4.7.1 every changeset is logged to SOUT, and it seems like there is no way to turn it off. For us that means that tests logs are complete unusable during to hight amount of tests & changesets. 
> 
> \## Steps To Reproduce
> 
> Just run the migration.
> 
> \## Actual Behavior
> 
> For every change set a message in system out is appeared: 
> 
> \`\`\`
> Running Changeset: db/changelog/db.changelog-file.xml::version::author
> \`\`\`
> 
> \## Expected/Desired Behavior
> 
> No message in SOUT. A way to completely replace \`ConsoleUIService\` with \`LoggerUIService\` so every message could be controlled by logger implementation

Now I get more output from more loggers with e.g. `DEBUG`, but still no SQL at all. Though, I’m able to disable individual loggers until I get no output at all anymore, so the SQL is simply not there. When looking at the code, there’s already a default log level for SQL, so with a proper log manager in place the system property to override that shuldn’t be necessary anway.

```java
SHOW_AT_LOG_LEVEL = builder.define("logLevel", Level.class)
                .setDescription("Level to log SQL statements to")
                .setValueHandler(ConfigurationValueConverter.LOG_LEVEL)
                .setDefaultValue(Level.FINE)
                .build();

```

```xml
<Logger name="liquibase.changelog" level="ERROR" />
<Logger name="liquibase.command" level="ERROR" />
<Logger name="liquibase.configuration" level="ERROR" />
<Logger name="liquibase.executor" level="ERROR" />
<Logger name="liquibase.ext" level="ERROR" />
<Logger name="liquibase.lockservice" level="ERROR" />
<Logger name="liquibase.parser" level="ERROR" />
<Logger name="liquibase.servicelocator" level="ERROR" />
<Logger name="liquibase.snapshot" level="ERROR" />
<Logger name="liquibase.ui" level="ERROR" />
<Logger name="liquibase.util" level="ERROR" />

```

`ERROR` means no logs anymore, `ALL` logs with level DEBUG, but no SQL. And even witht he log manager, the parent-child relationship of logger names known for log4j still don’t work for some reason:

```
<Logger name="liquibase" level="ERROR" />

```

That line on its own has no effect at all. The following line in my Spring Boot application does have an effect as well:

```
logging.level.liquibase=TRACE

```

So the problem really seems to be that SQL logs aren’t generated at all. There isn’t anything more log related I could set up and enable.

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 19, 2024, 5:30pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/5 "2024-01-19T17:30:43Z")

</div>

The following is the code in Liquibase:

```auto
Level sqlLogLevel = SqlConfiguration.SHOW_AT_LOG_LEVEL.getCurrentValue();
log.log(sqlLogLevel, statement, null);

```

So the system property really only influences the log level used, but if anything is actually logged at all depends on the logging backend and its configuration and stuff. And the “liquibase.executor” for some reasons doesn’t provide anything of use in my case.

```auto
2024-01-19 18:29:09.347 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:09.954 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:10.633 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:12.083 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:12.779 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:12.779 DEBUG LAP3738 --- [main] l.executor : Lock Database
2024-01-19 18:29:13.710 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:14.617 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:14.742 DEBUG LAP3738 --- [main] l.executor : Changeset db/migration/0.9.7/db2i-01-init.xml::0.9.7-HRP-143-aaaaj::dbr
2024-01-19 18:29:18.774 ERROR LAP3738 --- [main] l.changelog : ChangeSet db/migration/0.9.7/db2i-01-init.xml::0.9.7-HRP-143-aaaaj::dbr encountered an exception.
2024-01-19 18:29:18.871 DEBUG LAP3738 --- [main] l.executor : Release Database Lock
2024-01-19 18:29:19.560 DEBUG LAP3738 --- [main] l.executor : Changelog query completed.
2024-01-19 18:29:20.182 ERROR LAP3738 --- [main] o.s.b.SpringApplication : Application run failed

```

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 20, 2024, 5:12pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/6 "2024-01-20T17:12:06Z")

</div>

Looks like SQL logging simply doesn’t work currently, I’m not the only one seeing this:

> <https://github.com/liquibase/liquibase/issues/1674>
>
> \## Environment
> \*\*Liquibase Version\*\*:
> 4.0.0 or above
> \*\*Liquibase Integration & V…ersion\*\*: \<Pick one: CLI, maven, gradle, spring boot, servlet, etc.\>
> CLI, spring boot
> \*\*Database Vendor & Version\*\*:
> Any
> \*\*Operating System Type & Version\*\*:
> Any
> 
> \## Description
> Liquibase 3.x can log SQL statements executed if logging on \`liquibase.executor.jvm.JdbcExecutor\` enabled.
> In 4.x there was a major refactor in commit https://github.com/liquibase/liquibase/commit/3773a7635fcc649d2f1aacf798ed93a0a58bd1e2 
> It removed explicit logging of SQL statements in favor of \`SqlListener\`. Now liquibase.executor.jvm.JdbcExecutor barely logs anything. Instead, it could send SQL statements to an SqlListener if specified.
> Neither I found any documentation about these SqlListeners, nor traces in source code for any uses or public api.
> 
> The only way i can enable logging is to add an own SqlListener to \`Scope.getCurrentScope()\` by using reflection.
> I think Liquibase as a schema evolver tool should have logging capability what it really does with the database.
> 
> \## Steps To Reproduce
> Run Liquibase update with root logger set to FINE/TRACE level.
> 
> \## Actual Behavior
> No SQL statement show up in log
> 
> \`\`\`
> INFO \[main\] \[\] liquibase.lockservice - Successfully acquired change log lock
> INFO \[main\] \[\] liquibase.changelog - Reading from SCHEMA.DATABASECHANGELOG
> \`\`\`
> 
> \## Expected/Desired Behavior
> Executed SQL statements show up in log
> 
> \`\`\`
> INFO \[main\] \[\] liquibase.lockservice - Successfully acquired change log lock
> DEBUG \[main\] \[\] liquibase.sql - SELECT MD5SUM FROM SCHEMA.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL AND ROWNUM=1
> DEBUG \[main\] \[\] liquibase.sql - SELECT COUNT(\*) FROM SCHEMA.DATABASECHANGELOG
> INFO \[main\] \[\] liquibase.changelog - Reading from SCHEMA.DATABASECHANGELOG
> DEBUG \[main\] \[\] liquibase.sql - SELECT \* FROM SCHEMA.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC
> \`\`\`

---

<div class="post-metadata">

**Author:** ![daryldoak](https://sea2.discourse-cdn.com/flex020/user_avatar/forum.liquibase.org/daryldoak/32/764_2.png) [@daryldoak](https://forum.liquibase.org/u/daryldoak)\
**Post date:** [January 22, 2024, 2:34pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/7 "2024-01-22T14:34:57Z")

</div>

Very strange, We’re using 4.25.0 and are seeing the sql that executed using sql-log-level=INFO:

```auto
Starting Liquibase at 13:38:39 (version 4.25.0 #3966 built at 2023-11-10 23:07:29 UTC)

[2024-01-22 13:40:22] INFO [liquibase.ui] Running Changeset: com/X/commercial/scoring/filed/oracle/3.x/db.changelog-3.0.0-cleanup.xml::cleanup-app-log-180days::X
[2024-01-22 13:40:22] INFO [liquibase.executor] DELETE FROM APP_LOG WHERE MESSAGE_DATETIME < (SYSDATE - 180)
[2024-01-22 13:40:22] INFO [liquibase.executor] 0 row(s) affected
[2024-01-22 13:40:22] INFO [liquibase.changelog] Custom SQL executed
[2024-01-22 13:40:22] INFO [liquibase.changelog] ChangeSet com/X/commercial/scoring/filed/oracle/3.x/db.changelog-3.0.0-cleanup.xml::cleanup-app-log-180days::X ran successfully in 19ms
[2024-01-22 13:40:22] INFO [liquibase.executor] UPDATE CLSCF.DATABASECHANGELOG SET COMMENTS = 'delete records from app_log which are over 180 days old', CONTEXTS = NULL, DATEEXECUTED = SYSTIMESTAMP, DEPLOYMENT_ID = '5930818037', EXECTYPE = 'RERAN', LABELS = NULL, MD5SUM = '9:ffbd0180947edaaff1c0920125d8a049', ORDEREXECUTED = 7674 WHERE ID = 'cleanup-app-log-180days' AND AUTHOR = 'X' AND FILENAME = 'com/X/commercial/scoring/filed/oracle/3.x/db.changelog-3.0.0-cleanup.xml'
[2024-01-22 13:40:22] INFO [liquibase.executor] 1 row(s) affected

```

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 22, 2024, 3:59pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/8 "2024-01-22T15:59:20Z")

</div>

So whats your logging framework and stuff? I’m using log4j2 as the backend and it’s jul-bridge, especially for Liquibase. But SLF4J is available as well, forwarded to log4j2 again from my understanding.

Additionally, do you have log output like the following? I don’t see it in your excerpt, but if you don’t have it, that might be another hint for something broken for me.

> l.executor : Changelog query completed.

---

<div class="post-metadata">

**Author:** ![veda-tschoening](https://avatars.discourse-cdn.com/v4/letter/v/65b543/32.png) [@veda-tschoening](https://forum.liquibase.org/u/veda-tschoening)\
**Post date:** [January 22, 2024, 6:01pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/9 "2024-01-22T18:01:03Z")

</div>

I’m finally able to see the SQL! 🙂 I needed to set the following system properties, the log setting in Spring Boot and create individual loggers.

```auto
-Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager
-Dlog4j2.disable.jmx=true
-Dliquibase.sql.logLevel=DEBUG

```

```auto
logging.level.liquibase=TRACE

```

Setting the LogManager is necessary because otherwise not all log messages are forwarded at all, the executor for example was missing. With a set LogManager I got some warning about JMX and therefore simply disabled it.

The log level for SQL needs to be set explicitly because the default of FINE doesn’t seem to be properly mapped into the JUL world. When I configure TRACE, `liquibase.ui` was partly logging warnings about TRACE not being supported and INFO will be used. But that’s the only warning I got within a lot of other log statements, while I assume TRACE not being supported at all for all other log statements as well. Not sure why `liquibase.ui` logged that instead of e.g. the executor…

> WARNING: Unknown log level TRACE. Defaulting to ‘INFO’

Last but not least, all the loggers need to be defined explicitly in my case to individuall configure log levels. Having e.g. only the first line and the others commented, I still get all other log messages because of level TRACE in the Spring Boot config. That shouldn’t be the case in a proper parent-client naming relationship.

```auto
<Logger name="liquibase" level="ERROR" />
<Logger name="liquibase.changelog" level="INFO" />
<Logger name="liquibase.command" level="ERROR" />
<Logger name="liquibase.configuration" level="ERROR" />
<Logger name="liquibase.database" level="ERROR" />
<Logger name="liquibase.executor" level="ERROR" />
<Logger name="liquibase.ext" level="ERROR" />
<Logger name="liquibase.integration" level="ERROR" />
<Logger name="liquibase.lockservice" level="ERROR" />
<Logger name="liquibase.parser" level="ERROR" />
<Logger name="liquibase.servicelocator" level="ERROR" />
<Logger name="liquibase.snapshot" level="ERROR" />
<Logger name="liquibase.ui" level="ERROR" />
<Logger name="liquibase.util" level="ERROR" />

```

```auto
2024-01-22 DEBUG l.executor : Changeset db/migration/[...].xml::[...]
2024-01-22 DEBUG l.executor : CREATE TABLE "[...]".[...]
2024-01-22 DEBUG l.executor : 0 row(s) affected
2024-01-22 INFO l.changelog : Table BRANCH created
2024-01-22 INFO l.changelog : ChangeSet db/migration/[...].xml::[...] ran successfully in 7029ms
2024-01-22 DEBUG l.executor : INSERT INTO "[...]".DATABASECHANGELOG ("ID", AUTHOR, FILENAME, DATEEXECUTED, ORDEREXECUTED, MD5SUM, DESCRIPTION, COMMENTS, EXECTYPE, CONTEXTS, LABELS, LIQUIBASE, DEPLOYMENT_ID) VALUES ('[...]', '[...]', 'db/migration/[...].xml', CURRENT TIMESTAMP, 2, '9:513f549e75cd3aacb010696f1ae9cd38', 'createTable tableName=BRANCH', '', 'EXECUTED', NULL, NULL, '4.25.1', '5946791675')
2024-01-22 DEBUG l.executor : 1 row(s) affected
2024-01-22 DEBUG l.executor : Changelog query completed.

```

---

<div class="post-metadata">

**Author:** ![daryldoak](https://sea2.discourse-cdn.com/flex020/user_avatar/forum.liquibase.org/daryldoak/32/764_2.png) [@daryldoak](https://forum.liquibase.org/u/daryldoak)\
**Post date:** [January 23, 2024, 2:31pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/10 "2024-01-23T14:31:24Z")

</div>

I’m running the Liquibase CLI via Linux.

---

<div class="post-metadata">

**Author:** ![hpichereau](https://avatars.discourse-cdn.com/v4/letter/h/258eb7/32.png) [@hpichereau](https://forum.liquibase.org/u/hpichereau)\
**Post date:** [December 3, 2024, 3:53pm UTC](https://forum.liquibase.org/t/how-to-log-all-generated-sql-by-liquibase/9021/11 "2024-12-03T15:53:25Z")

</div>

If using Logback, adding `<logger name="liquibase.executor" level="DEBUG" />` worked for me.
