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,
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] ------------------------------------------------------------------------