Re: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4

[Ranier Vilela <ranier.vf@xxxxxxxxx>]

Em sáb., 28 de ago. de 2021 às 22:55, ldh@xxxxxxxxxxxxxxxxxx <ldh@xxxxxxxxxxxxxxxxxx> escreveu:

   >  -----Original Message-----
   >  From: Tom Lane <tgl@xxxxxxxxxxxxx>
   >  Sent: Saturday, August 28, 2021 15:51
   >  To: ldh@xxxxxxxxxxxxxxxxxx
   >  Cc: Andrew Dunstan <andrew@xxxxxxxxxxxx>; Justin Pryzby
   >  <pryzby@xxxxxxxxxxxxx>; Ranier Vilela <ranier.vf@xxxxxxxxx>; pgsql-
   >  performance@xxxxxxxxxxxxxx
   >  Subject: Re: Big Performance drop of Exceptions in UDFs between V11.2
   >  and 13.4
   > 
   >  "ldh@xxxxxxxxxxxxxxxxxx" <ldh@xxxxxxxxxxxxxxxxxx> writes:
   >  > SET lc_messages = 'C';
   >  > show lc_messages; --> OK 'C'
   > 
   >  > explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(b, null)) as
   >  > "b" from sampletest ...
   >  > Execution Time: 175.600 ms
   > 
   >  > explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(a, null)) as
   >  > "a" from sampletest ...
   >  > Execution Time: 88031.585 ms
   > 
   >  > Doesn't seem to make a difference unless I misunderstood what you
   >  were asking for regarding the locale?
   > 
   >  Hmm.  This suggests that whatever effect Andrew found with NLS is
   >  actually not the explanation for your problem.  So I'm even more
   >  confused than before.
   > 
   >                    regards, tom lane

I am so sorry to hear... So, curious on my end: is this something that you are not able to reproduce on your environments? On my end, I did reproduce it on different VMs and my local laptop, across windows Server 2012 and Windows 10, so I'd figure it would be pretty easy to reproduce?

What does reproduction have to do with solving the problem?
Can you tell how many commits there are between the affected versions?

I retested this case with HEAD, and it seems to me that NLS does affect it.

postgres=# create table sampletest (a varchar, b varchar);
CREATE TABLE
postgres=# insert into sampletest (a, b)
postgres-# select substr(md5(random()::text), 0, 15), (100000000*random())::integer::varchar
postgres-#   from generate_series(1,100000);
INSERT 0 100000
postgres=#
postgres=# CREATE OR REPLACE FUNCTION toFloat(str varchar, val real)
postgres-# RETURNS real AS $$
postgres$# BEGIN
postgres$#   RETURN case when str is null then val else str::real end;
postgres$# EXCEPTION WHEN OTHERS THEN
postgres$#   RETURN val;
postgres$# END;
postgres$# $$ LANGUAGE plpgsql COST 1 IMMUTABLE;
CREATE FUNCTION
postgres=# explain (analyze,buffers,COSTS,TIMING)
postgres-# select MAX(toFloat(b, null)) as "b" from sampletest;
                                                       QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=1477.84..1477.85 rows=1 width=4) (actual time=386.990..386.991 rows=1 loops=1)
   Buffers: shared hit=643 read=1
   ->  Seq Scan on sampletest  (cost=0.00..1197.56 rows=56056 width=32) (actual time=0.032..17.325 rows=100000 loops=1)
         Buffers: shared hit=637
 Planning:
   Buffers: shared hit=13 read=13
 Planning Time: 0.967 ms
 Execution Time: 387.989 ms
(8 rows)


postgres=# explain (analyze,buffers,COSTS,TIMING)
postgres-# select MAX(toFloat(a, null)) as "a" from sampletest;
                                                       QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=1477.84..1477.85 rows=1 width=4) (actual time=1812.556..1812.557 rows=1 loops=1)
   Buffers: shared hit=639 read=1
   ->  Seq Scan on sampletest  (cost=0.00..1197.56 rows=56056 width=32) (actual time=0.026..20.866 rows=100000 loops=1)
         Buffers: shared hit=637
 Planning Time: 0.152 ms
 Execution Time: 1812.587 ms
(6 rows)


postgres=# SET lc_messages = 'C';
SET
postgres=# drop table sampletest;
DROP TABLE
postgres=# create table sampletest (a varchar, b varchar);
CREATE TABLE
postgres=# insert into sampletest (a, b)
postgres-# select substr(md5(random()::text), 0, 15), (100000000*random())::integer::varchar
postgres-#   from generate_series(1,100000);
INSERT 0 100000
postgres=#
postgres=# CREATE OR REPLACE FUNCTION toFloat(str varchar, val real)
postgres-# RETURNS real AS $$
postgres$# BEGIN
postgres$#   RETURN case when str is null then val else str::real end;
postgres$# EXCEPTION WHEN OTHERS THEN
postgres$#   RETURN val;
postgres$# END;
postgres$# $$ LANGUAGE plpgsql COST 1 IMMUTABLE;
CREATE FUNCTION
postgres=# explain (analyze,buffers,COSTS,TIMING)
postgres-# select MAX(toFloat(b, null)) as "b" from sampletest;
                                                       QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=1477.84..1477.85 rows=1 width=4) (actual time=278.993..278.994 rows=1 loops=1)
   Buffers: shared hit=637
   ->  Seq Scan on sampletest  (cost=0.00..1197.56 rows=56056 width=32) (actual time=0.029..16.837 rows=100000 loops=1)
         Buffers: shared hit=637
 Planning:
   Buffers: shared hit=4
 Planning Time: 0.181 ms
 Execution Time: 279.023 ms
(8 rows)


postgres=# explain (analyze,buffers,COSTS,TIMING)
postgres-# select MAX(toFloat(a, null)) as "a" from sampletest;
                                                       QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=2137.00..2137.01 rows=1 width=4) (actual time=1783.434..1783.435 rows=1 loops=1)
   Buffers: shared hit=637
   ->  Seq Scan on sampletest  (cost=0.00..1637.00 rows=100000 width=15) (actual time=0.016..21.098 rows=100000 loops=1)
         Buffers: shared hit=637
 Planning:
   Buffers: shared hit=6
 Planning Time: 1.020 ms
 Execution Time: 1783.464 ms
(8 rows)

With NLS:

Float_b:

Planning Time: 0.967 ms
Execution Time: 387.989 ms

Float_a:

Planning Time: 0.152 ms
Execution Time: 1812.587 ms

Without NLS:

Float_b:

Planning Time: 0.181 ms
Execution Time: 279.023 ms

Float_a:

Planning Time: 1.020 ms
Execution Time: 1783.464 ms

regards,

Ranier Vilela