Message-ID: <gh-pgjdbc-pgjdbc-3511-c2644337258@github.com>
From: "rdhzl (@rdhzl)" <noreply+rdhzl@github.com>
To: "pgjdbc/pgjdbc" <noreply+pgjdbc-pgjdbc@github.com>
Date: Fri, 07 Feb 2025 23:48:02 +0000
Subject: Re: [pgjdbc/pgjdbc] issue #3511: Performance Regression in JDBC Driver 42.7.5 - getCrossReference
In-Reply-To: <gh-pgjdbc-pgjdbc-3511@github.com>
References: <gh-pgjdbc-pgjdbc-3511@github.com>
List-Id: <gh-pgjdbc-pgjdbc.github.com>
X-GitHub-Author-Login: rdhzl
X-GitHub-Comment-Id: 2644337258
X-GitHub-Comment-Type: issue_comment
X-GitHub-Issue: 3511
X-GitHub-Repo: pgjdbc/pgjdbc
X-GitHub-Type: comment
X-GitHub-Url: https://github.com/pgjdbc/pgjdbc/issues/3511#issuecomment-2644337258
Content-Type: text/plain; charset=utf-8

I could be muddying the waters here, but he's what I can provide. We recreate our test database as part of our automated test runs and we do that mostly via Liquibase. We don't populate the tables as part of this process so all tables are empty until tests run.

Here's our slightly obfuscated Liquibase that illustrates the issue:

```
    <!-- Property
        <property name="first_table_t" value="105" />
    -->

    <changeSet id="create-sequence" author="author">
        <createSequence schemaName="schema" sequenceName="seq_first_table" minValue="1" maxValue="1099511627775" cycle="true"/>
    </changeSet>

    <changeSet id="create-table" author="author">
        <createTable schemaName="schema" tableName="first_table">
            <column name="id"
                    defaultValueComputed="schema.next_id('schema.seq_first_table', ${first_table_t}, 1)"
                    type="BIGINT">
                <constraints primaryKey="true"/>
            </column>
            <column name="second_table_id" type="BIGINT">
                <constraints foreignKeyName="first_table_second_table_id_fkey"
                             referencedTableSchemaName="schema"
                             referencedTableName="second_table"
                             referencedColumnNames="id"
                             unique="true"
                             nullable="false"/>
            </column>
            <column name="completion_date" type="TIMESTAMPTZ">
                <constraints nullable="false" />
            </column>
            <column name="created_at" type="TIMESTAMPTZ" defaultValueComputed="NOW()">
                <constraints nullable="false" />
            </column>
            <column name="created_by_id" type="BIGINT">
                <constraints foreignKeyName="first_table_created_by_id_fkey"
                             referencedTableSchemaName="schema"
                             referencedTableName="user"
                             referencedColumnNames="id"/>
            </column>
            <column name="modified_at" type="TIMESTAMPTZ" defaultValueComputed="NOW()">
                <constraints nullable="false" />
            </column>
            <column name="modified_by_id" type="BIGINT">
                <constraints foreignKeyName="first_table_modified_by_id_fkey"
                             referencedTableSchemaName="schema"
                             referencedTableName="user"
                             referencedColumnNames="id"/>
            </column>
            <column name="status" type="VARCHAR(128)">
                <constraints nullable="false" />
            </column>
            <column name="invoice_id" type="VARCHAR(64)"></column>
        </createTable>
    </changeSet>

    <!-- *** SLOW QUERY -->
    <changeSet id="fix-index" author="author">
        <preConditions onFail="MARK_RAN">
            <not>
                <indexExists schemaName="schema" tableName="first_table" indexName="first_table_modified_by_id_idx"></indexExists>
            </not>
        </preConditions>
        <createIndex schemaName="schema" tableName="first_table" indexName="first_table_modified_by_id_idx">
            <column name="modified_by_id"></column>
        </createIndex>
    </changeSet>
```

Here's our slightly obfuscated SQL output from Liquibase:

```
CREATE SEQUENCE  IF NOT EXISTS schema.seq_first_table MINVALUE 1 MAXVALUE 1099511627775 CYCLE;

CREATE TABLE schema.first_table
  (
     id              BIGINT DEFAULT schema.Next_id('schema.seq_first_table', 105, 1
     ) NOT NULL,
     second_table_id        BIGINT NOT NULL,
     completion_date TIMESTAMP WITH time zone NOT NULL,
     created_at      TIMESTAMP WITH time zone DEFAULT Now() NOT NULL,
     created_by_id   BIGINT,
     modified_at     TIMESTAMP WITH time zone DEFAULT Now() NOT NULL,
     modified_by_id  BIGINT,
     status          VARCHAR(128) NOT NULL,
     invoice_id      VARCHAR(64),
     CONSTRAINT first_table_pkey PRIMARY KEY (id),
     CONSTRAINT first_table_second_table_id_fkey FOREIGN KEY (second_table_id) REFERENCES
     schema.second_table(id),
     CONSTRAINT first_table_created_by_id_fkey FOREIGN KEY (created_by_id)
     REFERENCES schema."user"(id),
     CONSTRAINT first_table_modified_by_id_fkey FOREIGN KEY (modified_by_id)
     REFERENCES schema."user"(id),
     UNIQUE (second_table_id)
  ); 
  
 //*** SLOW QUERY
 CREATE INDEX first_table_modified_by_id_idx ON schema.first_table(modified_by_id);
```

//Output/timings with JDBC driver 42.7.4
```
Running Changeset: db.changelog-vXYZ.0.xml::create-sequence::author
[2025-02-07 18:15:21] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::create-sequence::author
[2025-02-07 18:15:21] INFO [liquibase.changelog] Sequence seq_first_table created
[2025-02-07 18:15:21] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::create-sequence::author ran successfully in 0ms
Running Changeset: db.changelog-vXYZ.0.xml::create-table::author
[2025-02-07 18:15:21] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::create-table::author
[2025-02-07 18:15:21] INFO [liquibase.changelog] Table first_table created
[2025-02-07 18:15:21] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::create-table::author ran successfully in 3ms
Running Changeset: db.changelog-vXYZ.0.xml::fix-index::author
[2025-02-07 18:15:21] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::fix-index::author
[2025-02-07 18:15:21] INFO [liquibase.snapshot] Creating snapshot
[2025-02-07 18:15:30] INFO [liquibase.changelog] Index first_table_modified_by_id_idx created
[2025-02-07 18:15:30] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::fix-index::author ran successfully in 9420ms
``` 

//Output/timings with JDBC driver 42.7.5
```
Running Changeset: db.changelog-vXYZ.0.xml::create-sequence::author
[2025-02-07 18:09:33] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::create-sequence::author
[2025-02-07 18:09:33] INFO [liquibase.changelog] Sequence seq_first_table created
[2025-02-07 18:09:33] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::create-sequence::author ran successfully in 1ms
Running Changeset: db.changelog-vXYZ.0.xml::create-table::author
[2025-02-07 18:09:33] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::create-table::author
[2025-02-07 18:09:33] INFO [liquibase.changelog] Table first_table created
[2025-02-07 18:09:33] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::create-table::author ran successfully in 2ms
Running Changeset: db.changelog-vXYZ.0.xml::fix-index::author
[2025-02-07 18:09:33] INFO [liquibase.ui] Running Changeset: db.changelog-vXYZ.0.xml::fix-index::author
[2025-02-07 18:09:33] INFO [liquibase.snapshot] Creating snapshot
[2025-02-07 18:09:54] INFO [liquibase.changelog] Index first_table_modified_by_id_idx created
[2025-02-07 18:09:54] INFO [liquibase.changelog] ChangeSet db.changelog-vXYZ.0.xml::fix-index::author ran successfully in 21515ms
```

So this index creation takes over twice as long with the newer driver. This is one of the few instances in our Liquibase where we aren't creating indexes concurrently, and via Liquibase's `<sql>` tag, so that could be a nuance.

Generally our entire schema recreation process takes 45 seconds with the 42.7.4 driver and about 1 min 30 seconds with the 42.7.5 driver.

I'm working with Postgres 16 but we've seen similar results with Postgres 15.

Hopefully this is useful. If I can provide more information let me know, but there are limits to what I'm able to share. 

Thanks for your efforts!