pgjdbc/pgjdbc GitHub issues and pull requests (mirror)  
help / color / mirror / Atom feed
From: davecramer (@davecramer) <[email protected]>
To: pgjdbc/pgjdbc <[email protected]>
Subject: Re: [pgjdbc/pgjdbc] issue #3511: Performance Regression in JDBC Driver 42.7.5 - getCrossReference
Date: Wed, 28 May 2025 20:15:43 +0000
Message-ID: <[email protected]> (raw)
In-Reply-To: <[email protected]>
References: <[email protected]>

Cool so what I can see is almost a 10x regression
42.7.4
line 290 2025-05-28 14:46:41.139 EDT [89769] LOG:  execute S_1: COMMIT
line 1.     2025-05-28 14:46:40.191 EDT [89769] LOG:  execute S_3: BEGIN

total time is 948ms

42.7.5
line 290 2025-05-28 14:49:58.798 EDT [89903] LOG:  execute S_1: COMMIT
line 1.     2025-05-28 14:49:49.320 EDT [89903] LOG:  execute S_3: BEGIN
9478ms

Here are the salient differences:

1. Deployment ID Change:
   • In 42.7.4: '8457996979'
   • In 42.7.5: '8458185965'
  This appears in the database changelog entry.

2. SQL Query Format Changes:
   • In 42.7.4: The SQL queries use plain column names like TABLE_CAT, TABLE_SCHEM, etc.
   • In 42.7.5: The SQL queries use quoted column names like "TABLE_CAT", "TABLE_SCHEM", etc.

3. Database Reference Change:
   • In 42.7.4: Using NULL AS TABLE_CAT in the queries
   • In 42.7.5: Using current_database() AS "TABLE_CAT" and adding a condition current_database() = 'hippo_db_test'


Seems adding the condition is the culprit:

```
postgres=# explain analyze SELECT NULL::text AS PKTABLE_CAT, pkn.nspname AS PKTABLE_SCHEM, pkc.relname AS PKTABLE_NAME, pka.attname AS PKCOLUMN_NAME, NULL::text AS FKTABLE_CAT, fkn.nspname AS FKTABLE_SCHEM, fkc.relname AS FKTABLE_NAME, fka.attname AS FKCOLUMN_NAME, pos.n AS KEY_SEQ, CASE con.confupdtype  WHEN 'c' THEN 0 WHEN 'n' THEN 2 WHEN 'd' THEN 4 WHEN 'r' THEN 1 WHEN 'p' THEN 1 WHEN 'a' THEN 3 ELSE NULL END AS UPDATE_RULE, CASE con.confdeltype  WHEN 'c' THEN 0 WHEN 'n' THEN 2 WHEN 'd' THEN 4 WHEN 'r' THEN 1 WHEN 'p' THEN 1 WHEN 'a' THEN 3 ELSE NULL END AS DELETE_RULE, con.conname AS FK_NAME, pkic.relname AS PK_NAME, CASE  WHEN con.condeferrable AND con.condeferred THEN 5 WHEN con.condeferrable THEN 6 ELSE 7 END AS DEFERRABILITY  FROM  pg_catalog.pg_namespace pkn, pg_catalog.pg_class pkc, pg_catalog.pg_attribute pka,  pg_catalog.pg_namespace fkn, pg_catalog.pg_class fkc, pg_catalog.pg_attribute fka,  pg_catalog.pg_constraint con,  pg_catalog.generate_series(1, 32) pos(n),  pg_catalog.pg_class pkic WHERE pkn.oid = pkc.relnamespace AND pkc.oid = pka.attrelid AND pka.attnum = con.confkey[pos.n] AND con.confrelid = pkc.oid  AND fkn.oid = fkc.relnamespace AND fkc.oid = fka.attrelid AND fka.attnum = con.conkey[pos.n] AND con.conrelid = fkc.oid  AND con.contype = 'f' AND (pkic.relkind = 'i' OR pkic.relkind = 'I') AND pkic.oid = con.conindid  AND fkn.nspname = 'hippo' AND fkc.relname = 'care_program_x_visit' ORDER BY pkn.nspname,pkc.relname, con.conname,pos.n;
                                                                                 QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=37.02..37.02 rows=1 width=592) (actual time=3.696..3.698 rows=0.00 loops=1)
   Sort Key: pkn.nspname, pkc.relname, con.conname, pos.n
   Sort Method: quicksort  Memory: 25kB
   Buffers: shared hit=8 read=6
   ->  Nested Loop  (cost=1.51..37.01 rows=1 width=592) (actual time=1.425..1.427 rows=0.00 loops=1)
         Join Filter: (fkn.oid = fkc.relnamespace)
         Buffers: shared hit=2 read=3
         ->  Nested Loop  (cost=1.51..35.92 rows=1 width=460) (actual time=1.425..1.426 rows=0.00 loops=1)
               Buffers: shared hit=2 read=3
               ->  Nested Loop  (cost=1.24..35.56 rows=1 width=400) (actual time=1.425..1.426 rows=0.00 loops=1)
                     Buffers: shared hit=2 read=3
                     ->  Nested Loop  (cost=0.96..27.25 rows=1 width=355) (actual time=1.425..1.426 rows=0.00 loops=1)
                           Join Filter: (pka.attnum = con.confkey[pos.n])
                           Buffers: shared hit=2 read=3
                           ->  Function Scan on generate_series pos  (cost=0.00..0.32 rows=32 width=4) (actual time=0.013..0.015 rows=32.00 loops=1)
                           ->  Materialize  (cost=0.96..25.50 rows=3 width=385) (actual time=0.044..0.044 rows=0.00 loops=32)
                                 Storage: Memory  Maximum Storage: 17kB
                                 Buffers: shared hit=2 read=3
                                 ->  Nested Loop  (cost=0.96..25.48 rows=3 width=385) (actual time=1.399..1.400 rows=0.00 loops=1)
                                       Buffers: shared hit=2 read=3
                                       ->  Nested Loop  (cost=0.68..24.34 rows=1 width=327) (actual time=1.399..1.399 rows=0.00 loops=1)
                                             Buffers: shared hit=2 read=3
                                             ->  Nested Loop  (cost=0.40..15.95 rows=1 width=267) (actual time=1.399..1.399 rows=0.00 loops=1)
                                                   Buffers: shared hit=2 read=3
                                                   ->  Nested Loop  (cost=0.27..15.75 rows=1 width=207) (actual time=1.399..1.399 rows=0.00 loops=1)
                                                         Buffers: shared hit=2 read=3
                                                         ->  Seq Scan on pg_constraint con  (cost=0.00..7.43 rows=1 width=135) (actual time=1.398..1.398 rows=0.00 loops=1)
                                                               Filter: (contype = 'f'::"char")
                                                               Rows Removed by Filter: 194
                                                               Buffers: shared hit=2 read=3
                                                         ->  Index Scan using pg_class_oid_index on pg_class pkc  (cost=0.27..8.29 rows=1 width=72) (never executed)
                                                               Index Cond: (oid = con.confrelid)
                                                               Index Searches: 0
                                                   ->  Index Scan using pg_namespace_oid_index on pg_namespace pkn  (cost=0.13..0.18 rows=1 width=68) (never executed)
                                                         Index Cond: (oid = pkc.relnamespace)
                                                         Index Searches: 0
                                             ->  Index Scan using pg_class_oid_index on pg_class pkic  (cost=0.27..8.30 rows=1 width=68) (never executed)
                                                   Index Cond: (oid = con.conindid)
                                                   Filter: ((relkind = 'i'::"char") OR (relkind = 'I'::"char"))
                                                   Index Searches: 0
                                       ->  Index Scan using pg_attribute_relid_attnum_index on pg_attribute pka  (cost=0.28..1.06 rows=8 width=70) (never executed)
                                             Index Cond: (attrelid = pkc.oid)
                                             Index Searches: 0
                     ->  Index Scan using pg_attribute_relid_attnum_index on pg_attribute fka  (cost=0.28..8.30 rows=1 width=70) (never executed)
                           Index Cond: ((attrelid = con.conrelid) AND (attnum = (con.conkey)[pos.n]))
                           Index Searches: 0
               ->  Index Scan using pg_class_oid_index on pg_class fkc  (cost=0.27..0.32 rows=1 width=72) (never executed)
                     Index Cond: (oid = fka.attrelid)
                     Filter: (relname = 'care_program_x_visit'::name)
                     Index Searches: 0
         ->  Seq Scan on pg_namespace fkn  (cost=0.00..1.05 rows=1 width=68) (never executed)
               Filter: (nspname = 'hippo'::name)
 Planning:
   Buffers: shared hit=53
 Planning Time: 5.336 ms
 Execution Time: 3.806 ms
(56 rows)
```
```
postgres=# explain analyze SELECT current_database() AS "PKTABLE_CAT", pkn.nspname AS "PKTABLE_SCHEM", pkc.relname AS "PKTABLE_NAME", pka.attname AS "PKCOLUMN_NAME", current_database() AS "FKTABLE_CAT", fkn.nspname AS "FKTABLE_SCHEM", fkc.relname AS "FKTABLE_NAME", fka.attname AS "FKCOLUMN_NAME", pos.n AS "KEY_SEQ", CASE con.confupdtype  WHEN 'c' THEN 0 WHEN 'n' THEN 2 WHEN 'd' THEN 4 WHEN 'r' THEN 1 WHEN 'p' THEN 1 WHEN 'a' THEN 3 ELSE NULL END AS "UPDATE_RULE", CASE con.confdeltype  WHEN 'c' THEN 0 WHEN 'n' THEN 2 WHEN 'd' THEN 4 WHEN 'r' THEN 1 WHEN 'p' THEN 1 WHEN 'a' THEN 3 ELSE NULL END AS "DELETE_RULE", con.conname AS "FK_NAME", pkic.relname AS "PK_NAME", CASE  WHEN co                                                                                       "DEFERRABILITY"  FROM  pg_catalog.pg_namespace pkn, pg_catalog.pg_class pkc, pg_catalog.pg_attribute pka,  pg_catalog.pg_names                                                                                                                                                             s pkic WHERE pkn.oid = pkc.relnamespace AND pkc.oid = pka.attrelid AND pka.attnum = con.confkey[pos.n] AND con.confrelid = pkc.oid  AND fkn.oid = fkc.relnamespace AND fkc.oid = fka.attrelid AND fka.attnum = con.conkey[pos.n] AND con.conrelid = fkc.oid  AND con.contype = 'f' AND (pkic.relkind = 'i' OR pkic.relkind = 'I') AND pkic.oid = con.conindid  AND current_database() = 'hippo_db_test' AND fkn.nspname = 'hippo' AND fkc.relname = 'care_program_x_visit' ORDER BY pkn.nspname,pkc.relname, con.conname,pos.n;
                                                                                QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=36.99..36.99 rows=1 width=656) (actual time=0.299..0.301 rows=0.00 loops=1)
   Sort Key: pkn.nspname, pkc.relname, con.conname, pos.n
   Sort Method: quicksort  Memory: 25kB
   ->  Result  (cost=1.51..36.98 rows=1 width=656) (actual time=0.293..0.295 rows=0.00 loops=1)
         One-Time Filter: (current_database() = 'hippo_db_test'::name)
         ->  Nested Loop  (cost=1.51..36.94 rows=1 width=520) (never executed)
               ->  Nested Loop  (cost=1.38..36.75 rows=1 width=460) (never executed)
                     Join Filter: (fkn.oid = fkc.relnamespace)
                     ->  Nested Loop  (cost=1.11..36.42 rows=1 width=408) (never executed)
                           ->  Nested Loop  (cost=0.83..28.12 rows=1 width=363) (never executed)
                                 Join Filter: (pka.attnum = con.confkey[pos.n])
                                 ->  Function Scan on generate_series pos  (cost=0.00..0.32 rows=32 width=4) (never executed)
                                 ->  Materialize  (cost=0.83..26.36 rows=3 width=393) (never executed)
                                       ->  Nested Loop  (cost=0.83..26.35 rows=3 width=393) (never executed)
                                             ->  Nested Loop  (cost=0.55..25.21 rows=1 width=335) (never executed)
                                                   ->  Nested Loop  (cost=0.27..16.81 rows=1 width=275) (never executed)
                                                         ->  Nested Loop  (cost=0.27..15.75 rows=1 width=207) (never executed)
                                                               ->  Seq Scan on pg_constraint con  (cost=0.00..7.43 rows=1 width=135) (never executed)
                                                                     Filter: (contype = 'f'::"char")
                                                               ->  Index Scan using pg_class_oid_index on pg_class pkc  (cost=0.27..8.29 rows=1 width=72) (never executed)
                                                                     Index Cond: (oid = con.confrelid)
                                                                     Index Searches: 0
                                                         ->  Seq Scan on pg_namespace fkn  (cost=0.00..1.05 rows=1 width=68) (never executed)
                                                               Filter: (nspname = 'hippo'::name)
                                                   ->  Index Scan using pg_class_oid_index on pg_class pkic  (cost=0.27..8.30 rows=1 width=68) (never executed)
                                                         Index Cond: (oid = con.conindid)
                                                         Filter: ((relkind = 'i'::"char") OR (relkind = 'I'::"char"))
                                                         Index Searches: 0
                                             ->  Index Scan using pg_attribute_relid_attnum_index on pg_attribute pka  (cost=0.28..1.06 rows=8 width=70) (never executed)
                                                   Index Cond: (attrelid = pkc.oid)
                                                   Index Searches: 0
                           ->  Index Scan using pg_attribute_relid_attnum_index on pg_attribute fka  (cost=0.28..8.30 rows=1 width=70) (never executed)
                                 Index Cond: ((attrelid = con.conrelid) AND (attnum = (con.conkey)[pos.n]))
                                 Index Searches: 0
                     ->  Index Scan using pg_class_oid_index on pg_class fkc  (cost=0.27..0.32 rows=1 width=72) (never executed)
                           Index Cond: (oid = fka.attrelid)
                           Filter: (relname = 'care_program_x_visit'::name)
                           Index Searches: 0
               ->  Index Scan using pg_namespace_oid_index on pg_namespace pkn  (cost=0.13..0.18 rows=1 width=68) (never executed)
                     Index Cond: (oid = pkc.relnamespace)
                     Index Searches: 0
 Planning:
   Buffers: shared hit=53
 Planning Time: 53.300 ms
 Execution Time: 0.369 ms
```



view thread (24+ messages)  latest in thread

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: github://pgjdbc/pgjdbc
  Cc: [email protected], [email protected]
  Subject: Re: [pgjdbc/pgjdbc] issue #3511: Performance Regression in JDBC Driver 42.7.5 - getCrossReference
  In-Reply-To: <<[email protected]>>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox