Обсуждение: incorrect results and different plan with 2 very similar queries
Greetings,
There is a report on the pgjdbc github JDBC Driver shows erratic behavior when filtering on CURRENT_DATE · pgjdbc/pgjdbc · Discussion #3184 (github.com)
Here are the plans.
JDBC - Nested Loop (incorrect result)
Sort (cost=1071.31..1071.60 rows=114 width=83) (actual time=2.894..2.912 rows=330 loops=1)
Sort Key: p.partno
Sort Method: quicksort Memory: 70kB
-> Nested Loop Left Join (cost=9.46..1067.42 rows=114 width=83) (actual time=0.082..2.446 rows=330 loops=1)
-> Bitmap Heap Scan on part p (cost=9.18..295.79 rows=114 width=29) (actual time=0.064..0.502 rows=330 loops=1)
Recheck Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 28))
Heap Blocks: exact=181
-> Bitmap Index Scan on i_42609 (cost=0.00..9.15 rows=114 width=0) (actual time=0.041..0.041 rows=344 loops=1)
Index Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 28))
-> Index Scan using i_39773 on part_fa_entity pfe (cost=0.29..6.76 rows=1 width=65) (actual time=0.005..0.005 rows=1 loops=330)
Index Cond: ((partno)::text = (p.partno)::text)
Planning Time: 0.418 ms
Execution Time: 2.971 ms
JDBC - Hash Right (correct result)
Sort (cost=1352.35..1352.94 rows=238 width=83) (actual time=5.214..5.236 rows=345 loops=1)
Sort Key: p.partno
Sort Method: quicksort Memory: 73kB
-> Hash Right Join (cost=472.00..1342.95 rows=238 width=83) (actual time=0.654..4.714 rows=345 loops=1)
Hash Cond: ((pfe.partno)::text = (p.partno)::text)
-> Seq Scan on part_fa_entity pfe (cost=0.00..837.27 rows=12827 width=65) (actual time=0.009..2.191 rows=12827 loops=1)
-> Hash (cost=469.03..469.03 rows=238 width=29) (actual time=0.623..0.624 rows=345 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 30kB
-> Bitmap Heap Scan on part p (cost=18.14..469.03 rows=238 width=29) (actual time=0.073..0.532 rows=345 loops=1)
Recheck Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 29))
Heap Blocks: exact=186
-> Bitmap Index Scan on i_42609 (cost=0.00..18.08 rows=238 width=0) (actual time=0.049..0.049 rows=359 loops=1)
Index Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 29))
Planning Time: 0.304 ms
Execution Time: 5.292 ms
AppX - Nested Loop (correct result)
Sort (cost=1071.31..1071.60 rows=114 width=83) (actual time=3.083..3.102 rows=330 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.average_price_func, pfe.fsv, pfe.fsv_func, p.status
Sort Key: p.partno
Sort Method: quicksort Memory: 71kB
-> Nested Loop Left Join (cost=9.46..1067.42 rows=114 width=83) (actual time=0.069..2.471 rows=330 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.average_price_func, pfe.fsv, pfe.fsv_func, p.status
-> Bitmap Heap Scan on .part p (cost=9.18..295.79 rows=114 width=29) (actual time=0.054..0.308 rows=330 loops=1)
Output: p.min_safety_stock, p.manual_safety_stock, p.extended_stateno_i, p.partno, p.partmatch, p.partseqno_i, p.description, p.remarks, p.specification, p.ata_chapter, p.vendor, p.weight, p.storetime, p.alert_qty, p.measure_unit, p.waste_code, p.reord_level, p.safety_stock, p.max_purch, p.ac_typ, p.mat_class, p.mat_type, p.country_origin, p.reorder, p.tool, p.repairable, p.avg_ta_time, p.default_supplier, p.default_repair, p.special_contract, p.fixed_asset, p.reorder_last_mutator, p.reorder_last_mutation, p.max_shop_visit, p.shop_visit_reset_condition, p.special_measure_unit, p.manufacturer, p.pma, p.resource_type_id, p.counter_template_groupno_i, p.mutation, p.mutator, p.status, p.mutation_time, p.created_by, p.created_date
Recheck Cond: (p.mutation >= ((CURRENT_DATE - `1971-12-31`::date) - 28))
Heap Blocks: exact=181
-> Bitmap Index Scan on i_42609 (cost=0.00..9.15 rows=114 width=0) (actual time=0.033..0.034 rows=341 loops=1)
Index Cond: (p.mutation >= ((CURRENT_DATE - `1971-12-31`::date) - 28))
-> Index Scan using i_39773 on .part_fa_entity pfe (cost=0.29..6.76 rows=1 width=65) (actual time=0.005..0.006 rows=1 loops=330)
Output: pfe.part_fa_entityno_i, pfe.partno, pfe.entityno_i, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.avg_repair_cost_func, pfe.fa_qty, pfe.fa_open_iv_qty, pfe.fa_start_qty, pfe.fa_start_price, pfe.fa_start_price_2, pfe.mutation, pfe.mutator, pfe.status, pfe.mutation_time, pfe.created_by, pfe.created_date, pfe.average_price_func, pfe.fa_start_price_func, pfe.fsv, pfe.fsv_func
Index Cond: ((pfe.partno)::text = (p.partno)::text)
Planning Time: 0.361 ms
Execution Time: 3.157 ms
AppX - Hash Join (correct result)
Sort (cost=1352.35..1352.94 rows=238 width=83) (actual time=5.361..5.384 rows=345 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.average_price_func, pfe.fsv, pfe.fsv_func, p.status
Sort Key: p.partno
Sort Method: quicksort Memory: 73kB
-> Hash Right Join (cost=472.00..1342.95 rows=238 width=83) (actual time=0.594..4.669 rows=345 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.average_price_func, pfe.fsv, pfe.fsv_func, p.status
Inner Unique: true
Hash Cond: ((pfe.partno)::text = (p.partno)::text)
-> Seq Scan on amos.part_fa_entity pfe (cost=0.00..837.27 rows=12827 width=65) (actual time=0.006..1.581 rows=12827 loops=1)
Output: pfe.part_fa_entityno_i, pfe.partno, pfe.entityno_i, pfe.average_price, pfe.sales_price, pfe.purch_price, pfe.average_price_2, pfe.avg_repair_cost, pfe.avg_repair_cost_func, pfe.fa_qty, pfe.fa_open_iv_qty, pfe.fa_start_qty, pfe.fa_start_price, pfe.fa_start_price_2, pfe.mutation, pfe.mutator, pfe.status, pfe.mutation_time, pfe.created_by, pfe.created_date, pfe.average_price_func, pfe.fa_start_price_func, pfe.fsv, pfe.fsv_func
-> Hash (cost=469.03..469.03 rows=238 width=29) (actual time=0.564..0.566 rows=345 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, p.status
Buckets: 1024 Batches: 1 Memory Usage: 30kB
-> Bitmap Heap Scan on amos.part p (cost=18.14..469.03 rows=238 width=29) (actual time=0.075..0.488 rows=345 loops=1)
Output: p.partseqno_i, p.partno, p.partmatch, p.status
Recheck Cond: (p.mutation >= ((CURRENT_DATE - `1971-12-31`::date) - 29))
Heap Blocks: exact=186
-> Bitmap Index Scan on i_42609 (cost=0.00..18.08 rows=238 width=0) (actual time=0.035..0.035 rows=356 loops=1)
Index Cond: (p.mutation >= ((CURRENT_DATE - `1971-12-31`::date) - 29))
Planning Time: 0.379 ms
Execution Time: 5.443 ms
Dave Cramer
On Thu, 28 Mar 2024 at 10:33, Dave Cramer <davecramer@gmail.com> wrote: > There is a report on the pgjdbc github JDBC Driver shows erratic behavior when filtering on CURRENT_DATE · pgjdbc/pgjdbc· Discussion #3184 (github.com) > > Here are the plans. > > JDBC - Nested Loop (incorrect result) > > Index Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 28)) > JDBC - Hash Right (correct result) > > Recheck Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 29)) I don't see any version details or queries, but going by the conditions above, the queries don't appear to be the same, so different results aren't too surprising and not a demonstration that there's any sort of bug. David
Dave Cramer
On Wed, 27 Mar 2024 at 17:57, David Rowley <dgrowleyml@gmail.com> wrote:
On Thu, 28 Mar 2024 at 10:33, Dave Cramer <davecramer@gmail.com> wrote:
> There is a report on the pgjdbc github JDBC Driver shows erratic behavior when filtering on CURRENT_DATE · pgjdbc/pgjdbc · Discussion #3184 (github.com)
>
> Here are the plans.
>
> JDBC - Nested Loop (incorrect result)
>
> Index Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 28))
> JDBC - Hash Right (correct result)
>
> Recheck Cond: (mutation >= ((CURRENT_DATE - '1971-12-31'::date) - 29))
I don't see any version details or queries, but going by the
conditions above, the queries don't appear to be the same, so
different results aren't too surprising and not a demonstration that
there's any sort of bug.
Sorry, you are correct. Version is 12.14. Here is the query
SELECT p.partseqno_i
, p.partno
, p.partmatch
, pfe.average_price
, pfe.sales_price
, pfe.purch_price
, pfe.average_price_2
, pfe.avg_repair_cost
, pfe.average_price_func
, pfe.fsv
, pfe.fsv_func
, p.status
FROM part p
LEFT JOIN part_fa_entity pfe ON (p.partno = pfe.partno)
WHERE 1=1
AND (p.mutation >= (CURRENT_DATE - '1971-12-31'::date)-27) ORDER BY p.partno Dave
David
On 3/27/24 23:10, Dave Cramer wrote: > Dave Cramer > > > On Wed, 27 Mar 2024 at 17:57, David Rowley <dgrowleyml@gmail.com> wrote: > >> On Thu, 28 Mar 2024 at 10:33, Dave Cramer <davecramer@gmail.com> wrote: >>> There is a report on the pgjdbc github JDBC Driver shows erratic >> behavior when filtering on CURRENT_DATE · pgjdbc/pgjdbc · Discussion #3184 ( >> github.com) >>> >>> Here are the plans. >>> >>> JDBC - Nested Loop (incorrect result) >>> >>> Index Cond: (mutation >= ((CURRENT_DATE - >> '1971-12-31'::date) - 28)) >> >>> JDBC - Hash Right (correct result) >>> >>> Recheck Cond: (mutation >= ((CURRENT_DATE - >> '1971-12-31'::date) - 29)) >> >> I don't see any version details or queries, but going by the >> conditions above, the queries don't appear to be the same, so >> different results aren't too surprising and not a demonstration that >> there's any sort of bug. >> > > Sorry, you are correct. Version is 12.14. Here is the query > > SELECT > p.partseqno_i > , p.partno > , p.partmatch > , pfe.average_price > , pfe.sales_price > , pfe.purch_price > , pfe.average_price_2 > , pfe.avg_repair_cost > , pfe.average_price_func > , pfe.fsv > , pfe.fsv_func > , p.status > > FROM part p > LEFT JOIN part_fa_entity pfe ON (p.partno = pfe.partno) > WHERE 1=1 > AND (p.mutation >= (CURRENT_DATE - '1971-12-31'::date)-27) ORDER BY p.partno > I guess the confusing bit is that the report does not claim that those queries are expected to produce the same result, but that the parameter value affects which plan gets selected, and one of those plans produces incorrect result. I think the simplest explanation might be that one of the indexes on part_fa_entity is corrupted and fails to lookup some rows by partno. That would explain why the plan with seqscan works fine, but nestloop with index scan is missing these rows. They might try a couple things: 1) set enable_nestloop=off, see if the results get correct 2) try bt_index_check on i_39773, might notice some corruption 3) rebuild the index If it's not this, they'll need to build a reproducer. It's really difficult to deduce what's going on just from query plans for different parameter values. regards -- Tomas Vondra EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company