How to improve performance of Liquibase on Greenplum database

Question

I'm evaluating the use of Liquibase (3.3.2) against a Greenplum (Postgres on steroids) database using postgresql 8.4-701.jdbc4 and am running into performance issues when trying to add one changeset (create table) against an existing schema containing many partitioned tables. I'm in hour three currently, with no idea how much longer this will take. Is the JdbcSnapshot process a one-time thing? Or am I going to encounter this type of performance when deploying every changeset?

To apply changes, I'm executing:

mvn resources:resources liquibase:update

pom.xml:

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.cobalt.bi</groupId>
    <artifactId>liquibase</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <packaging>jar</packaging>

    <name>liquibase</name>
    <description>liquibase</description>

    <dependencies>

<dependency>
    <groupId>postgresql</groupId>
    <artifactId>postgresql</artifactId>
    <version>9.1-901.jdbc4</version>
</dependency>


        <dependency>
            <groupId>com.oracle</groupId>
            <artifactId>ojdbc14</artifactId>
            <version>10.2.0.4.0</version>
        </dependency>

        <dependency>
            <groupId>org.liquibase</groupId>
            <artifactId>liquibase-core</artifactId>
            <version>3.3.2</version>
            <scope>test</scope>
        </dependency>

    </dependencies>

    <build>
          <plugins>

            <plugin>
                <groupId>org.liquibase</groupId>
                <artifactId>liquibase-maven-plugin</artifactId>
                <version>3.0.2</version>
                <configuration>
                  <promptOnNonLocalDatabase>false</promptOnNonLocalDatabase>
                  <propertyFileWillOverride>true</propertyFileWillOverride>
                  <propertyFile>target/classes/liquibase.properties</propertyFile>
                </configuration>

                <executions>
                  <execution>
                    <phase>process-resources</phase>
                    <goals>
                      <goal>update</goal>
                    </goals>
                  </execution>
                </executions>
            </plugin>
          </plugins>

          <filters>
            <filter>${user.home}/.liquibase.properties</filter>
          </filters>

          <resources>
            <resource>
              <directory>src/main/resources</directory>
              <filtering>true</filtering>
            </resource>
          </resources>

    </build>

</project>

$HOME/.liquibase.properties:

db.fmXX.user=szalwinb
db.fmXX.database=fmd1
db.fmXX.host=host-name-for-gp-db
db.fmXX.port=5432

liquibase.verbose: true
liquibase.dropFirst: false
liquibase.changeLogFile: src/main/resources/db/master.xml
liquibase.contexts:
liquibase.driver: org.postgresql.Driver
liquibase.url: jdbc:postgresql://${db.fmXX.host}:${db.fmXX.port}/${db.fmXX.database}
liquibase.username: ${db.fmXX.user}
liquibase.password: ${db.fmXX.user}
liquibase.defaultCatalogName: ${db.fmXX.user}
liquibase.defaultSchemaName: ${db.fmXX.user}
liquibase.logging: debug

Looking at the stack trace using JConsole, I see:

Name: main
State: RUNNABLE
Total blocked: 0  Total waited: 0

Stack trace: 
java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.read(SocketInputStream.java:152)
java.net.SocketInputStream.read(SocketInputStream.java:122)
org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
org.postgresql.core.PGStream.ReceiveChar(PGStream.java:259)
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1620)
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
   - locked org.postgresql.core.v3.QueryExecutorImpl@11d1532d
org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:479)
org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:353)
org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:252)
org.postgresql.jdbc2.AbstractJdbc2DatabaseMetaData.getTables(AbstractJdbc2DatabaseMetaData.java:2062)
liquibase.snapshot.JdbcDatabaseSnapshot$CachingDatabaseMetaData.getTables(JdbcDatabaseSnapshot.java:173)
liquibase.snapshot.jvm.TableSnapshotGenerator.snapshotObject(TableSnapshotGenerator.java:33)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:59)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.jvm.JdbcSnapshotGenerator.snapshot(JdbcSnapshotGenerator.java:62)
liquibase.snapshot.SnapshotGeneratorChain.snapshot(SnapshotGeneratorChain.java:42)
liquibase.snapshot.DatabaseSnapshot.include(DatabaseSnapshot.java:75)
liquibase.snapshot.DatabaseSnapshot.replaceObject(DatabaseSnapshot.java:144)
liquibase.snapshot.DatabaseSnapshot.replaceObject(DatabaseSnapshot.java:157)
liquibase.snapshot.DatabaseSnapshot.includeNestedObjects(DatabaseSnapshot.java:107)
liquibase.snapshot.DatabaseSnapshot.include(DatabaseSnapshot.java:94)
liquibase.snapshot.SnapshotGeneratorFactory.createSnapshot(SnapshotGeneratorFactory.java:128)
liquibase.snapshot.SnapshotGeneratorFactory.createSnapshot(SnapshotGeneratorFactory.java:121)
liquibase.snapshot.SnapshotGeneratorFactory.createSnapshot(SnapshotGeneratorFactory.java:109)
liquibase.snapshot.SnapshotGeneratorFactory.has(SnapshotGeneratorFactory.java:99)
liquibase.snapshot.SnapshotGeneratorFactory.hasDatabaseChangeLogLockTable(SnapshotGeneratorFactory.java:171)
liquibase.database.AbstractJdbcDatabase.hasDatabaseChangeLogLockTable(AbstractJdbcDatabase.java:749)
liquibase.database.AbstractJdbcDatabase.checkDatabaseChangeLogLockTable(AbstractJdbcDatabase.java:775)
liquibase.lockservice.LockServiceImpl.acquireLock(LockServiceImpl.java:95)
liquibase.lockservice.LockServiceImpl.waitForLock(LockServiceImpl.java:62)
liquibase.Liquibase.update(Liquibase.java:123)
org.liquibase.maven.plugins.LiquibaseUpdate.doUpdate(LiquibaseUpdate.java:31)
org.liquibase.maven.plugins.AbstractLiquibaseUpdateMojo.performLiquibaseTask(AbstractLiquibaseUpdateMojo.java:24)
org.liquibase.maven.plugins.AbstractLiquibaseMojo.execute(AbstractLiquibaseMojo.java:328)
org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:132)
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:120)
org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:347)
org.apache.maven.DefaultMaven.execute(DefaultMaven.java:154)
org.apache.maven.cli.MavenCli.execute(MavenCli.java:582)
org.apache.maven.cli.MavenCli.doMain(MavenCli.java:214)
org.apache.maven.cli.MavenCli.main(MavenCli.java:158)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:606)
org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)

Examining the database server logs, I see this query be executed for every table.

2015-02-16 10:14:41.232988 PST,"szalwinb","fmd1",p21417,th632498080,"172.30.133.118","60261",2015-02-16 07:05:46 PST,93508959,con1317174,cmd41041,seg-1,,dx1748316,x93508959,sx1,"LOG","00000","execute <unnamed>: SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME,  CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema'  WHEN true THEN CASE  WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind   WHEN 'r' THEN 'SYSTEM TABLE'   WHEN 'v' THEN 'SYSTEM VIEW'   WHEN 'i' THEN 'SYSTEM INDEX'   ELSE NULL   END  WHEN n.nspname = 'pg_toast' THEN CASE c.relkind   WHEN 'r' THEN 'SYSTEM TOAST TABLE'   WHEN 'i' THEN 'SYSTEM TOAST INDEX'   ELSE NULL   END  ELSE CASE c.relkind   WHEN 'r' THEN 'TEMPORARY TABLE'   WHEN 'i' THEN 'TEMPORARY INDEX'   ELSE NULL   END  END  WHEN false THEN CASE c.relkind  WHEN 'r' THEN 'TABLE'  WHEN 'i' THEN 'INDEX'  WHEN 'S' THEN 'SEQUENCE'  WHEN 'v' THEN 'VIEW'  ELSE NULL  END  ELSE NULL  END  AS TABLE_TYPE, d.description AS REMARKS  FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c  LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0)  LEFT JOIN pg_catalog.pg_class dc ON (d.classoid=dc.oid AND dc.relname='pg_class')  LEFT JOIN pg_catalog.pg_namespace dn ON (dn.oid=dc.relnamespace AND dn.nspname='pg_catalog')  WHERE c.relnamespace = n.oid  AND n.nspname LIKE 'szalwin'  AND c.relname LIKE 'customers_1_prt_p_20140708'  AND (false  OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) )  ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME",,,,,,"SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME,  CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema'  WHEN true THEN CASE  WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind   WHEN 'r' THEN 'SYSTEM TABLE'   WHEN 'v' THEN 'SYSTEM VIEW'   WHEN 'i' THEN 'SYSTEM INDEX'   ELSE NULL   END  WHEN n.nspname = 'pg_toast' THEN CASE c.relkind   WHEN 'r' THEN 'SYSTEM TOAST TABLE'   WHEN 'i' THEN 'SYSTEM TOAST INDEX'   ELSE NULL   END  ELSE CASE c.relkind   WHEN 'r' THEN 'TEMPORARY TABLE'   WHEN 'i' THEN 'TEMPORARY INDEX'   ELSE NULL   END  END  WHEN false THEN CASE c.relkind  WHEN 'r' THEN 'TABLE'  WHEN 'i' THEN 'INDEX'  WHEN 'S' THEN 'SEQUENCE'  WHEN 'v' THEN 'VIEW'  ELSE NULL  END  ELSE NULL  END  AS TABLE_TYPE, d.description AS REMARKS  FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c  LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0)  LEFT JOIN pg_catalog.pg_class dc ON (d.classoid=dc.oid AND dc.relname='pg_class')  LEFT JOIN pg_catalog.pg_namespace dn ON (dn.oid=dc.relnamespace AND dn.nspname='pg_catalog')  WHERE c.relnamespace = n.oid  AND n.nspname LIKE 'szalwinb'  AND c.relname LIKE 'customers_1_prt_p_20140708'  AND (false  OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) )  ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME ",0,,"postgres.c",2625,

How did you call liquibase? With what command? The snapshot thing is supposed to run when you do a `diff/diffChangeLog`(http://www.liquibase.org/documentation/diff.html) on an existing database. Then liquibase will try to find out what is already in your database and write a changelog. I am not 100% sure if there are other paths (besides the diff command) that would lead to a snapshot being taken. But normally this should not be necessary because liquibase will track the changes in a special table that it creates. — Jens, Feb 17 '15 at 09:43
Seems like there are other paths which lead to taking snapshots even with `update` command. I guess I have no clue why liquibase is taking these snapshots and therefore can't really help... — Jens, Feb 18 '15 at 16:16
Thanks for taking a peek. I'll try to do a little code diving and see if can figure out why the snapshot needs to be created. — bruce szalwinski, Feb 19 '15 at 04:56
Consider to add an answer to your question when you found useful info on this. :-) — Jens, Feb 19 '15 at 09:13

score 2 · Accepted Answer · answered Feb 26 '15 at 05:31

Operator error. The dependencies section of the pom was requesting one version of liquibase while the build/plugin section was requesting a different, and earlier version. I updated the pom.xml to use the same version in both sections and all is well.

[INFO] ------------------------------------------------------------------------
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 01:55 min
[INFO] Finished at: 2015-02-25T21:26:33-08:00
[INFO] Final Memory: 12M/648M
[INFO] ------------------------------------------------------------------------

you could mark your own answer as the accepted one, so that people will find the solution easier. — Lorinc Nyitrai, Mar 05 '15 at 13:12

score 1 · Answer 2 · answered Feb 25 '15 at 22:52

Liquibase does do a snapshot on startup in order to determine if the databasechangelog table exists and if it is correctly defined. The snapshot logic should be confined to only looking at that one table, however. It shouldn't be spiraling into snapshotting everything.

It may be a postgres-specific or even greenplumb-specific issue. I created https://liquibase.jira.com/browse/CORE-2259 to look into it more.

How to improve performance of Liquibase on Greenplum database

2 Answers2