Parsing database changelogs got much slower in versions following 4.21.1

[metamben]

Search first

• I searched and no similar issues were found

Description

In Metabase we are trying to upgrade Liquibase from 4.11.0 to 4.23.2. Unfortunately, running the DB migration tests takes about six times longer.

Profiling revealed the parsing of the migration file as the bottleneck (see metabase/metabase#33891 for details).

Steps To Reproduce

1. Unzip the attached file
2. In that folder, run mvn clean package exec:java and observe how long the parsing takes
3. In pom.xml, change the liquibase version to 4.21.1
4. Run mvn clean package exec:java and observe how much less time the parsing takes

liquibase-4.23-slow-parse.zip

Expected/Desired Behavior

No obvious slowdown or a work around to get about the same speed as 4.11.0.

Liquibase Version

4.23.2

Database Vendor & Version

N/A

Liquibase Integration

API

Liquibase Extensions

No response

OS and/or Infrastructure Type/Provider

MacOS Ventura 13.5.2 (22G91)

Additional Context

No response

Are you willing to submit a PR?

• I'm willing to submit a PR (Thank you!)

[tati-qalified]

Hello @metamben, thank you for bringing this issue to our attention. It's definitely something we're interested in improving. I was able to reproduce what you reported, and I'll be forwarding this ticket to the development team so they can evaluate how to move forward.
Thank you
Tatiana

[Mahoney]

Perhaps unsurprisingly, the commit where the performance degraded was 831135b

Parsing my changelog the first time jumps from 492ms to 1,011ms. More importantly, subsequent parsing jumps from 41ms to 370ms. We have a lot of integration tests, each of which applies the changelog to a DB, so that extra 330ms a run quickly adds up.

[erasmussen-first]

While looking for something else, I happened to be walking the code with 4.23.2 and observed that in src/main/java/liquibase/util/StringUtil.java, processMultiLineSQL() appears to be called 2-3 times per SQL string while parsing SQL from a sql or sqlFile tag in a changeset. I have not delved into that sufficiently to file a solid bug report, but it looks like something that could reduce performance. Maybe it is related to this.

[filipelautert]

Thanks for the sample code @metamben , @Mahoney for the merge and for the multiple calls insight from @erasmussen-first ! I think it's fixed now - at least my results with the artifacts from #5090 are almost same as 4.21.1. It was a tricky bug - hard to find, easy to fix.
could you try the artifacts from that build too?

4.21.1
out. 20, 2023 10:40:15 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 0 parsing took 938 ms
out. 20, 2023 10:40:16 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 1 parsing took 161 ms
out. 20, 2023 10:40:16 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 2 parsing took 145 ms

4.23.0
out. 20, 2023 10:41:53 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 0 parsing took 2582 ms
out. 20, 2023 10:41:56 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 1 parsing took 1536 ms
out. 20, 2023 10:41:57 AM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 2 parsing took 1468 ms



0-SNASHOT
out. 20, 2023 2:37:18 PM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 0 parsing took 926 ms
out. 20, 2023 2:37:18 PM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 1 parsing took 181 ms
out. 20, 2023 2:37:19 PM liquibase.changelog
INFORMAÇÕES: Reading resource: migrations/000_migrations.yaml
round 2 parsing took 156 ms

[Mahoney]

Thanks, great spot!

Yes, that returns my build to the previous speeds - great work.

(For anyone else wanting to check, you need to declare a new repository https://maven.pkg.github.com/liquibase/liquibase and use org.liquibase:liquibase-core:4957-slow-parsing-database-changelogs-SNAPSHOT as the dependency. You'll need a GitHub access token; see https://docs.github.com/en/packages/working-with-a-github-packages-registry/working-with-the-gradle-registry#using-a-published-package)