Thread: incorrect results and different plan with 2 very similar queries

incorrect results and different plan with 2 very similar queries

From
Dave Cramer
Date:
Greetings,


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