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

2021-08-21 Thread [email protected]
Hello all,

I think I have identified a major performance issue between V11.2 and 13.4 with 
respect to exception handling in UDFs. I have the following simplified query 
that pivots data and makes use of a UDF to convert data to a specific type, in 
this case, float:


select "iccqa_iccassmt_fk"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DEPTH (CM)') ,null) as "iccqa_DEPTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'LENGTH (CM)') ,null) as "iccqa_LENGTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'WIDTH (CM)') ,null) as "iccqa_WIDTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DRAIN PRESENT') ,null) as "iccqa_DRAIN_PRESENT"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'MEASUREMENTS TAKEN') ,null) as "iccqa_MEASUREMENTS_TAKEN"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'SIGNS AND SYMPTOMS OF INFECTION') ,null) as 
"iccqa_SIGNS_AND_SYMPTOMS_OF_INFECTION"
from  (
-- 'A pivoted view of ICC QA assessments'
select VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_iccassmt_fk" as 
"iccqa_iccassmt_fk" -- The key identifying an ICC assessment.
 , VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" as 
"iccqar_ques_code" -- The question long code from the meta-data.
 , max(VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ans_val") as 
"iccqar_ans_val" -- The official answer, if applicable) from the meta-data.
  from VNAHGEDW_FACTS.AssessmentICCQA_Raw
where VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" in ('DEPTH (CM)', 
'LENGTH (CM)', 'WIDTH (CM)'
   , 'DRAIN 
PRESENT', 'MEASUREMENTS TAKEN', 'SIGNS AND SYMPTOMS OF INFECTION'
   ) group by 1, 2
) T
 group by 1
;


The UDF is simple as follows:


CREATE OR REPLACE FUNCTION TILDA.toFloat(str varchar, val real)
RETURNS real AS $$
BEGIN
  RETURN case when str is null then val else str::real end;
EXCEPTION WHEN OTHERS THEN
  RETURN val;
END;
$$ LANGUAGE plpgsql COST 1 IMMUTABLE;



It works as a coalesce but with a conversion. I think I have identified some 
large performance difference with the exception handling. It so happens that 
with the last 3 columns ('DRAIN PRESENT', 'MEASUREMENTS TAKEN' and 'SIGNS AND 
SYMPTOMS OF INFECTION'), the data is VERY dirty. There is a mix of 0/1, YES/NO, 
and other mistyped stuff. This means these 3 columns throw lots of exceptions 
in the UDF. To illustrate, I simply break this into 2 queries.



select "iccqa_iccassmt_fk"
 , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DEPTH (CM)') ,null))::real as "iccqa_DEPTH_CM"
 , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'LENGTH (CM)') ,null))::real as "iccqa_LENGTH_CM"
 , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'WIDTH (CM)') ,null))::real as "iccqa_WIDTH_CM"
-- , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DRAIN PRESENT') ,null))::real as "iccqa_DRAIN_PRESENT"
-- , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'MEASUREMENTS TAKEN') ,null))::real as "iccqa_MEASUREMENTS_TAKEN"
-- , (Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'SIGNS AND SYMPTOMS OF INFECTION') ,null))::real as 
"iccqa_SIGNS_AND_SYMPTOMS_OF_INFECTION"
from  (
-- 'A pivoted view of ICC QA assessments'
select VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_iccassmt_fk" as 
"iccqa_iccassmt_fk" -- The key identifying an ICC assessment.
 , VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" as 
"iccqar_ques_code" -- The question long code from the meta-data.
 , max(VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ans_val") as 
"iccqar_ans_val" -- The official answer, if applicable) from the meta-data.
  from VNAHGEDW_FACTS.AssessmentICCQA_Raw
where VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" in ('DEPTH (CM)', 
'LENGTH (CM)', 'WIDTH (CM)'
   , 'DRAIN 
PRESENT', 'MEASUREMENTS TAKEN', 'SIGNS AND SYMPTOMS OF INFECTION'
   )
group by 1, 2
) T
 group by 1
;


The performance is as expected.


HashAggregate  (cost=448463.70..448467.20 rows=200 width=16) (actual 
time=6760.797..9585.397 rows=677899 loops=1)
  Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk
  Batches: 1  Memory Usage: 147489kB
  Buffers: shared hit=158815
  ->  HashAggregate  (cost=405997.87..417322.09 rows=1132422 width=56) (actual 
time=4576.514..5460.770 rows=2374628 loops=1)
Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk, 
assessmenticcqa_raw.iccqar_ques_code
Batches: 1  Memory Usage: 368657kB
Buffers: shared hit=158815
->  Seq Scan on assessmenticcqa_raw  (cost=0.00..3882

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

2021-08-21 Thread [email protected]
OK... I apologize for the long email before. Right after I sent it, I thought 
of a much simpler use-case to illustrate the issue which doesn't depend on any 
special data I have access o and complex pivoting. It's as raw as I can make it.

I create a table with 1M rows and 2 columns. Column "a" is a random string, 
while column "b" is a random integer as a string. Then I use a UDF that 
converts strings to floats and handles an exception if the incoming string is 
not parsable as a float. Then I do a simple select of each column. In the "a" 
case, the UDF throws and catches lots of exceptions. In the "b" case, the 
conversion is clean and exceptions are not thrown.


create table sampletest (a varchar, b varchar);

insert into sampletest (a, b)
select substr(md5(random()::text), 0, 15), 
(1*random())::integer::varchar
from generate_series(1,100);

CREATE OR REPLACE FUNCTION toFloat(str varchar, val real)
RETURNS real AS $$
BEGIN
  RETURN case when str is null then val else str::real end;
EXCEPTION WHEN OTHERS THEN
  RETURN val;
END;
$$ LANGUAGE plpgsql COST 1 IMMUTABLE;

select MAX(toFloat(a, null)) as "a" from sampletest;

select MAX(toFloat(b, null)) as "b" from sampletest;



On purpose, I am doing a max(toFloat) instead of toFloat(max) to exercise the 
UDF 1M times.


V13.4 "a" scenario (exceptions)
-
Aggregate  (cost=14778.40..14778.41 rows=1 width=4) (actual 
time=774098.537..774098.538 rows=1 loops=1)
  Buffers: shared hit=6373
  ->  Seq Scan on sampletest  (cost=0.00..11975.60 rows=560560 width=32) 
(actual time=0.011..285.458 rows=100 loops=1)
Buffers: shared hit=6370
Planning Time: 0.066 ms
Execution Time: 774,098.563 ms


V13.4 "b" scenario (no exceptions)
-
Aggregate  (cost=14778.40..14778.41 rows=1 width=4) (actual 
time=1510.200..1510.201 rows=1 loops=1)
  Buffers: shared hit=6385
  ->  Seq Scan on sampletest  (cost=0.00..11975.60 rows=560560 width=32) 
(actual time=0.024..115.196 rows=100 loops=1)
Buffers: shared hit=6370
Planning:
  Buffers: shared hit=26
Planning Time: 0.361 ms
Execution Time: 1,530.659 ms


V11.2 "a" scenario (exceptions)
-
Aggregate  (cost=21658.00..21658.01 rows=1 width=4) (actual 
time=26528.286..26528.286 rows=1 loops=1)
  Buffers: shared hit=6393
  ->  Seq Scan on sampletest  (cost=0.00..16562.00 rows=1019200 width=15) 
(actual time=0.037..190.633 rows=100 loops=1)
Buffers: shared hit=6370
Planning Time: 1.182 ms
Execution Time: 26,530.492 ms


V11.2 "b" scenario (no exceptions)
-
Aggregate  (cost=21658.00..21658.01 rows=1 width=4) (actual 
time=1856.116..1856.116 rows=1 loops=1)
  Buffers: shared hit=6370
  ->  Seq Scan on sampletest  (cost=0.00..16562.00 rows=1019200 width=8) 
(actual time=0.014..88.152 rows=100 loops=1)
Buffers: shared hit=6370
Planning Time: 0.098 ms
Execution Time: 1,856.152 ms





Summary:

  *   Scenario V11.2/a: 26.6s
  *   Scenario V11.2/b: 1.9s
  *   Scenario V13.4/a: 774.1s
  *   Scenario V13.4/b: 1.5s

Conclusion:

  *   The no-exception scenario performs 20% better on 13.4 vs 11.2 (nice for a 
straight scan!)
  *   On 11.2, exceptions add an overhead of over 14x (1.9s vs 26.6s). I did 
not expect exceptions to add such a large overhead. Why is that?
  *   Between 11.2 and 13.4, the no-exceptions scenario "b" performs 30x slower 
(26.6s vs 774.1s).

Thank you!
Laurent Hasson.



From: [email protected] 
Sent: Saturday, August 21, 2021 03:57
To: [email protected]
Subject: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4

Hello all,

I think I have identified a major performance issue between V11.2 and 13.4 with 
respect to exception handling in UDFs. I have the following simplified query 
that pivots data and makes use of a UDF to convert data to a specific type, in 
this case, float:


select "iccqa_iccassmt_fk"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DEPTH (CM)') ,null) as "iccqa_DEPTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'LENGTH (CM)') ,null) as "iccqa_LENGTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'WIDTH (CM)') ,null) as "iccqa_WIDTH_CM"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'DRAIN PRESENT') ,null) as "iccqa_DRAIN_PRESENT"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'MEASUREMENTS TAKEN') ,null) as "iccqa_MEASUREMENTS_TAKEN"
 , Tilda.toFloat(MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 
'SIGNS AND SYMPTOMS OF INFECTION') ,null) as 
"iccqa_SIGNS_AND_SYMPTOMS_OF_INFECTION"
from  (
-- 'A pivoted view of ICC QA assessments'
select VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_iccassmt_fk" as 
"iccqa

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

2021-08-21 Thread Tom Lane
"[email protected]"  writes:
> OK... I apologize for the long email before. Right after I sent it, I thought 
> of a much simpler use-case to illustrate the issue which doesn't depend on 
> any special data I have access o and complex pivoting. It's as raw as I can 
> make it.
> I create a table with 1M rows and 2 columns. Column "a" is a random string, 
> while column "b" is a random integer as a string. Then I use a UDF that 
> converts strings to floats and handles an exception if the incoming string is 
> not parsable as a float. Then I do a simple select of each column. In the "a" 
> case, the UDF throws and catches lots of exceptions. In the "b" case, the 
> conversion is clean and exceptions are not thrown.

I tried this script on a few different versions and got
these psql-measured timings for the test queries:

HEAD:
Time: 12234.297 ms (00:12.234)
Time: 3029.643 ms (00:03.030)

v14:
Time: 12519.038 ms (00:12.519)
Time: 3211.315 ms (00:03.211)

v13:
Time: 12132.026 ms (00:12.132)
Time: 3114.582 ms (00:03.115)

v12:
Time: 11787.554 ms (00:11.788)
Time: 3520.875 ms (00:03.521)

v11:
Time: 13066.495 ms (00:13.066)
Time: 3503.790 ms (00:03.504)

v10:
Time: 15890.844 ms (00:15.891)
Time: 4999.843 ms (00:05.000)

(Caveats: these are assert-enabled debug builds, so they're all
slower than production builds, but the overhead should be pretty
uniform across branches I think.  Also, I wasn't trying hard to
eliminate noise, e.g. I didn't do multiple runs.  So I wouldn't
trust these results to be reproducible to better than 10% or so.)

The overhead of an EXCEPTION block is definitely high, and more
so when an exception actually occurs, but these are known facts
and my results are not out of line with my expectations.  Yours
are though, so something is drastically slowing the exception-
recovery path in your installation.  Do you have any extensions
loaded?

regards, tom lane




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

2021-08-21 Thread Mladen Gogala
I know that 14 is a beta version but the performance is significantly 
worse than v13 (I assume it's 13.4). Head revision is better than v14 
but still worse than v13.  Can you expand a bit on the difference? Where 
does the difference come from? Are there any differences in the 
execution plan?  I am looking at the first query, taking slightly more 
than 12s.


Regards

On 8/21/21 11:04 AM, Tom Lane wrote:

HEAD:
Time: 12234.297 ms (00:12.234)
Time: 3029.643 ms (00:03.030)

v14:
Time: 12519.038 ms (00:12.519)
Time: 3211.315 ms (00:03.211)

v13:
Time: 12132.026 ms (00:12.132)
Time: 3114.582 ms (00:03.115)


--
Mladen Gogala
Database Consultant
Tel: (347) 321-1217
https://dbwhisperer.wordpress.com





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

2021-08-21 Thread [email protected]



-Original Message-
From: Tom Lane  
Sent: Saturday, August 21, 2021 11:05
To: [email protected]
Cc: [email protected]
Subject: Re: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4

"[email protected]"  writes:
> OK... I apologize for the long email before. Right after I sent it, I thought 
> of a much simpler use-case to illustrate the issue which doesn't depend on 
> any special data I have access o and complex pivoting. It's as raw as I can 
> make it.
> I create a table with 1M rows and 2 columns. Column "a" is a random string, 
> while column "b" is a random integer as a string. Then I use a UDF that 
> converts strings to floats and handles an exception if the incoming string is 
> not parsable as a float. Then I do a simple select of each column. In the "a" 
> case, the UDF throws and catches lots of exceptions. In the "b" case, the 
> conversion is clean and exceptions are not thrown.

I tried this script on a few different versions and got these psql-measured 
timings for the test queries:

HEAD:
Time: 12234.297 ms (00:12.234)
Time: 3029.643 ms (00:03.030)

v14:
Time: 12519.038 ms (00:12.519)
Time: 3211.315 ms (00:03.211)

v13:
Time: 12132.026 ms (00:12.132)
Time: 3114.582 ms (00:03.115)

v12:
Time: 11787.554 ms (00:11.788)
Time: 3520.875 ms (00:03.521)

v11:
Time: 13066.495 ms (00:13.066)
Time: 3503.790 ms (00:03.504)

v10:
Time: 15890.844 ms (00:15.891)
Time: 4999.843 ms (00:05.000)

(Caveats: these are assert-enabled debug builds, so they're all slower than 
production builds, but the overhead should be pretty uniform across branches I 
think.  Also, I wasn't trying hard to eliminate noise, e.g. I didn't do 
multiple runs.  So I wouldn't trust these results to be reproducible to better 
than 10% or so.)

The overhead of an EXCEPTION block is definitely high, and more so when an 
exception actually occurs, but these are known facts and my results are not out 
of line with my expectations.  Yours are though, so something is drastically 
slowing the exception- recovery path in your installation.  Do you have any 
extensions loaded?

regards, tom lane


--

So you mean that on average, the 4x overhead of exceptions is around what you'd 
expect?

As for results in general, yes, your numbers look pretty uniform across 
versions. On my end, comparing V11.2 vs V13.4 shows a much different picture!

I have a few extensions installed: plpgsql, fuzzystrmatch, pg_trgm and 
tablefunc. Same on either versions of the db installs I have, and same 
extension versions.

V11.2:
extname  
|extowner|extnamespace|extrelocatable|extversion|extconfig|extcondition|
-|||--|--|-||
plpgsql  |  10|  11|false |1.0   |NULL |NULL
|
fuzzystrmatch|  10|2200|true  |1.1   |NULL |NULL
|
pg_trgm  |  10|2200|true  |1.3   |NULL |NULL
|
tablefunc|  10|2200|true  |1.0   |NULL |NULL
|

V13.4
oid  |extname  
|extowner|extnamespace|extrelocatable|extversion|extconfig|extcondition|
-|-|||--|--|-||
13428|plpgsql  |  10|  11|false |1.0   |NULL 
|NULL|
16676|fuzzystrmatch|  10|2200|true  |1.1   |NULL 
|NULL|
16677|pg_trgm  |  10|2200|true  |1.4   |NULL 
|NULL|
16678|tablefunc|  10|2200|true  |1.0   |NULL 
|NULL|

Thank you,
Laurent.




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

2021-08-21 Thread Tom Lane
Mladen Gogala  writes:
> I know that 14 is a beta version but the performance is significantly 
> worse than v13 (I assume it's 13.4). Head revision is better than v14 
> but still worse than v13.  Can you expand a bit on the difference?

[ shrug... ]  I don't see any meaningful differences between those
numbers --- they're within 3% or so across versions, which is less
than the margin of error considering I wasn't trying to control
for outside effects like CPU speed stepping.  Microbenchmarks like
this one are notoriously noisy.  Maybe there's some real difference
there, but these numbers aren't to be trusted that much.

What I was looking for was some evidence matching Laurent's report of
the exception-recovery path being 500X slower than non-exception.
That would have been obvious even with the sloppiest of measurements
... but I'm not seeing it.

regards, tom lane




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

2021-08-21 Thread Tom Lane
"[email protected]"  writes:
> So you mean that on average, the 4x overhead of exceptions is around what 
> you'd expect?

Doesn't surprise me any, no.  Exception recovery has to clean up after
a wide variety of possible errors, with only minimal assumptions about
what the system state had been.  So it's expensive.  More to the point,
the overhead's been broadly the same for quite some time.

> As for results in general, yes, your numbers look pretty uniform across 
> versions. On my end, comparing V11.2 vs V13.4 shows a much different picture!

I'm baffled why that should be so.  I do not think any of the extensions
you mention add any exception-recovery overhead, especially not in
sessions that haven't used them.

As an additional test, I checked out 11.2 exactly, and got timings
that pretty much matched my previous test of v11 branch tip.  So that
eliminates the theory that we broke something since 11.2 in a patch
that was also back-patched into that branch.

regards, tom lane




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

2021-08-21 Thread Justin Pryzby
On Sat, Aug 21, 2021 at 02:17:26PM -0400, Tom Lane wrote:
> "[email protected]"  writes:
> > So you mean that on average, the 4x overhead of exceptions is around what 
> > you'd expect?
> 
> Doesn't surprise me any, no.  Exception recovery has to clean up after
> a wide variety of possible errors, with only minimal assumptions about
> what the system state had been.  So it's expensive.  More to the point,
> the overhead's been broadly the same for quite some time.
> 
> > As for results in general, yes, your numbers look pretty uniform across 
> > versions. On my end, comparing V11.2 vs V13.4 shows a much different 
> > picture!
> 
> I'm baffled why that should be so.  I do not think any of the extensions
> you mention add any exception-recovery overhead, especially not in
> sessions that haven't used them.

Laurent, did you install binaries for v13.4 or compile it ?

What about these ?

SHOW shared_preload_libraries;
SHOW session_preload_libraries;
SHOW local_preload_libraries;

Would you try to reproduce the issue with a fresh database:
CREATE DATABASE udftest; ...

Or a fresh instance created with initdb.

As I recall, you're running postgres under a windows VM - I'm not sure if
that's relevant.

-- 
Justin




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

2021-08-21 Thread Maciek Sakrejda
I happen to have a stock 13.3 and 11.12 on Ubuntu here so I thought I'd
contribute numbers in case it's helpful:

v13.3:
Time: 4368.413 ms (00:04.368)
Time: 837.046 ms

v11.12:
Time: 5178.595 ms (00:05.179)
Time: 1027.857 ms (00:01.028)

So I'm also seeing a slight improvement in 13, not a degradation.
auto_explain and pg_stat_statements are installed in both; otherwise
they're pretty vanilla.


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

2021-08-21 Thread Justin Pryzby
On Sat, Aug 21, 2021 at 02:19:50PM -0500, Justin Pryzby wrote:
> As I recall, you're running postgres under a windows VM - I'm not sure if
> that's relevant.

I tried under a couple hyperv VMs but could not reproduce the issue (only an
~8x difference "with exceptions").

Which hypervisor are you using ?

I don't know if any of it matters, but would you also send:

SELECT version();
SELECT * FROM pg_config();

And maybe the CPU info ?

-- 
Justin




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

2021-08-21 Thread [email protected]


   >  -Original Message-
   >  From: Tom Lane 
   >  Sent: Saturday, August 21, 2021 14:05
   >  To: Mladen Gogala 
   >  Cc: [email protected]
   >  Subject: Re: Big Performance drop of Exceptions in UDFs between V11.2
   >  and 13.4
   >  
   >  Mladen Gogala  writes:
   >  > I know that 14 is a beta version but the performance is significantly
   >  > worse than v13 (I assume it's 13.4). Head revision is better than v14
   >  > but still worse than v13.  Can you expand a bit on the difference?
   >  
   >  [ shrug... ]  I don't see any meaningful differences between those
   >  numbers --- they're within 3% or so across versions, which is less than
   >  the margin of error considering I wasn't trying to control for outside
   >  effects like CPU speed stepping.  Microbenchmarks like this one are
   >  notoriously noisy.  Maybe there's some real difference there, but these
   >  numbers aren't to be trusted that much.
   >  
   >  What I was looking for was some evidence matching Laurent's report of
   >  the exception-recovery path being 500X slower than non-exception.
   >  That would have been obvious even with the sloppiest of measurements
   >  ... but I'm not seeing it.
   >  
   >regards, tom lane
   >  

Hello Tom,

The difference for the Exceptions-scenario between V11.2 and V13.4 that I 
observed was 30x.
It is the difference on V13.4 between the Exceptions and no-exceptions 
scenarios that is 500x+.

Just to clarify.

I am following up with Justin's suggestions and will respond with updated info 
soon.

Thank you!
Laurent Hasson.


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

2021-08-21 Thread [email protected]



   >  -Original Message-
   >  From: Justin Pryzby 
   >  Sent: Saturday, August 21, 2021 15:20
   >  To: Tom Lane 
   >  Cc: [email protected]; [email protected]
   >  Subject: Re: Big Performance drop of Exceptions in UDFs between V11.2
   >  and 13.4
   >  
   >  On Sat, Aug 21, 2021 at 02:17:26PM -0400, Tom Lane wrote:
   >  > "[email protected]"  writes:
   >  > > So you mean that on average, the 4x overhead of exceptions is
   >  around what you'd expect?
   >  >
   >  > Doesn't surprise me any, no.  Exception recovery has to clean up after
   >  > a wide variety of possible errors, with only minimal assumptions about
   >  > what the system state had been.  So it's expensive.  More to the
   >  > point, the overhead's been broadly the same for quite some time.
   >  >
   >  > > As for results in general, yes, your numbers look pretty uniform
   >  across versions. On my end, comparing V11.2 vs V13.4 shows a much
   >  different picture!
   >  >
   >  > I'm baffled why that should be so.  I do not think any of the
   >  > extensions you mention add any exception-recovery overhead,
   >  especially
   >  > not in sessions that haven't used them.
   >  
   >  Laurent, did you install binaries for v13.4 or compile it ?
   >  
   >  What about these ?
   >  
   >  SHOW shared_preload_libraries;
   >  SHOW session_preload_libraries;
   >  SHOW local_preload_libraries;
   >  
   >  Would you try to reproduce the issue with a fresh database:
   >  CREATE DATABASE udftest; ...
   >  
   >  Or a fresh instance created with initdb.
   >  
   >  As I recall, you're running postgres under a windows VM - I'm not sure if
   >  that's relevant.
   >  
   >  --
   >  Justin

Hello Justin,

- I used the standard installer from 
https://www.enterprisedb.com/downloads/postgres-postgresql-downloads for 
Windows X64 and upgraded from 13.3, which itself was pg_upgraded from 11.2.
- Yes, windows VM on VMWARE.
- No entries from shared_preload_libraries, session_preload_libraries or 
local_preload_libraries.
- Version is "PostgreSQL 13.4, compiled by Visual C++ build 1914, 64-bit".
- I created a new database and reran the scenarios without much of a change.
- I think I am going to install a whole fresh new instance from scratch and see 
if there may have been some weird stuff happening with the upgrade path I took?

Thank you,
Laurent Hasson.







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

2021-08-21 Thread Justin Pryzby
Could you send SELECT * FROM pg_config()
and try to find the CPU model ?

I think it's possible the hypervisor is trapping and emulating unhandled CPU
instructions.

Actually, it would be interesting to see if the performance differs between
11.2 and 11.13.  It's possible that EDB compiled 11.13 on a newer CPU (or a
newer compiler) than 11.2 was compiled.

If you test that, it should be on a separate VM, unless the existing data dir
can be restored from backup.  Once you've started a cluster with updated
binaries, you should avoid downgrading the binaries.




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

2021-08-21 Thread [email protected]


   >  -Original Message-
   >  From: Justin Pryzby 
   >  Sent: Saturday, August 21, 2021 18:17
   >  To: [email protected]
   >  Cc: Tom Lane ; [email protected]
   >  Subject: Re: Big Performance drop of Exceptions in UDFs between V11.2
   >  and 13.4
   >  
   >  Could you send SELECT * FROM pg_config() and try to find the CPU
   >  model ?
   >  
   >  I think it's possible the hypervisor is trapping and emulating unhandled
   >  CPU instructions.
   >  
   >  Actually, it would be interesting to see if the performance differs
   >  between
   >  11.2 and 11.13.  It's possible that EDB compiled 11.13 on a newer CPU
   >  (or a newer compiler) than 11.2 was compiled.
   >  
   >  If you test that, it should be on a separate VM, unless the existing data
   >  dir can be restored from backup.  Once you've started a cluster with
   >  updated binaries, you should avoid downgrading the binaries.



Hello all,

OK, I was able to do a clean install of 13.4 on the VM. All stock settings, no 
extensions loaded, pure clean straight out of the install.

create table sampletest (a varchar, b varchar);
-- truncate table sampletest;
insert into sampletest (a, b)
select substr(md5(random()::text), 0, 15), 
(1*random())::integer::varchar
  from generate_series(1,100);

CREATE OR REPLACE FUNCTION toFloat(str varchar, val real)
RETURNS real AS $$
BEGIN
  RETURN case when str is null then val else str::real end;
EXCEPTION WHEN OTHERS THEN
  RETURN val;
END;
$$ LANGUAGE plpgsql COST 1 IMMUTABLE;


explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(b, null)) as "b" from 
sampletest

Aggregate  (cost=21370.00..21370.01 rows=1 width=4) (actual 
time=1780.561..1780.563 rows=1 loops=1)
  Buffers: shared hit=6387
  ->  Seq Scan on sampletest  (cost=0.00..16370.00 rows=100 width=8) 
(actual time=0.053..97.329 rows=100 loops=1)
Buffers: shared hit=6370
Planning:
  Buffers: shared hit=36
Planning Time: 2.548 ms
Execution Time: 1,810.330 ms


explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(a, null)) as "a" from 
sampletest

Aggregate  (cost=21370.00..21370.01 rows=1 width=4) (actual 
time=863243.876..863243.877 rows=1 loops=1)
  Buffers: shared hit=6373
  ->  Seq Scan on sampletest  (cost=0.00..16370.00 rows=100 width=15) 
(actual time=0.009..301.553 rows=100 loops=1)
Buffers: shared hit=6370
Planning:
  Buffers: shared hit=44
Planning Time: 0.469 ms
Execution Time: 863,243.911 ms


So I am still able to reproduce this on a different VM and a clean install of 
13.4 ☹


SELECT * FROM pg_config();

BINDIR  C:/PROGRA~1/POSTGR~1/13/bin
DOCDIR  C:/PROGRA~1/POSTGR~1/13/doc
HTMLDIR C:/PROGRA~1/POSTGR~1/13/doc
INCLUDEDIR  C:/PROGRA~1/POSTGR~1/13/include
PKGINCLUDEDIR   C:/PROGRA~1/POSTGR~1/13/include
INCLUDEDIR-SERVER   C:/PROGRA~1/POSTGR~1/13/include/server
LIBDIR  C:/PROGRA~1/POSTGR~1/13/lib
PKGLIBDIR   C:/PROGRA~1/POSTGR~1/13/lib
LOCALEDIR   C:/PROGRA~1/POSTGR~1/13/share/locale
MANDIR  C:/Program Files/PostgreSQL/13/man
SHAREDIRC:/PROGRA~1/POSTGR~1/13/share
SYSCONFDIR  C:/Program Files/PostgreSQL/13/etc
PGXSC:/Program Files/PostgreSQL/13/lib/pgxs/src/makefiles/pgxs.mk
CONFIGURE   --enable-thread-safety --enable-nls --with-ldap --with-openssl 
--with-uuid --with-libxml --with-libxslt --with-icu --with-tcl --with-perl 
--with-python
CC  not recorded
CPPFLAGSnot recorded
CFLAGS  not recorded
CFLAGS_SL   not recorded
LDFLAGS not recorded
LDFLAGS_EX  not recorded
LDFLAGS_SL  not recorded
LIBSnot recorded
VERSION PostgreSQL 13.4


And here is SYSINFO:

C:\Users\LHASSON>systeminfo

Host Name: PRODDB
OS Name:   Microsoft Windows Server 2012 R2 Standard
OS Version:6.3.9600 N/A Build 9600
OS Manufacturer:   Microsoft Corporation
OS Configuration:  Member Server
OS Build Type: Multiprocessor Free
Original Install Date: 2015-09-19, 18:19:41
System Boot Time:  2021-07-22, 11:45:09
System Manufacturer:   VMware, Inc.
System Model:  VMware Virtual Platform
System Type:   x64-based PC
Processor(s):  4 Processor(s) Installed.
   [01]: Intel64 Family 6 Model 79 Stepping 1 
GenuineIntel ~2397 Mhz
   [02]: Intel64 Family 6 Model 79 Stepping 1 
GenuineIntel ~2397 Mhz
   [03]: Intel64 Family 6 Model 79 Stepping 1 
GenuineIntel ~2397 Mhz
   [04]: Intel64 Family 6 Model 79 Stepping 1 
GenuineIntel ~2397 Mhz
BIOS Version:  Phoenix Technologies LTD 6.00, 2020-05-28
Windows Directory: C:\Windows
System Directory:  C:\Windows\system32
Boot Device:   \Device\HarddiskVolume1
System Locale: en-us;English (United States)
Input Locale:  en-us;English (United States)
Time Zone: (UTC-05:00) Eastern Time (US & Canada)
To

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

2021-08-21 Thread [email protected]


   >  -Original Message-
   >  From: [email protected] 
   >  Sent: Saturday, August 21, 2021 19:02
   >  To: Justin Pryzby 
   >  Cc: Tom Lane ; [email protected]
   >  Subject: RE: Big Performance drop of Exceptions in UDFs between V11.2
   >  and 13.4
   >  
   >  
   >  
   > >  -Original Message-
   > >  From: Justin Pryzby 
   > >  Sent: Saturday, August 21, 2021 18:17
   > >  To: [email protected]
   > >  Cc: Tom Lane ; pgsql-
   >  [email protected]
   > >  Subject: Re: Big Performance drop of Exceptions in UDFs between
   >  V11.2
   > >  and 13.4
   > >
   > >  Could you send SELECT * FROM pg_config() and try to find the CPU
   > >  model ?
   > >
   > >  I think it's possible the hypervisor is trapping and emulating
   >  unhandled
   > >  CPU instructions.
   > >
   > >  Actually, it would be interesting to see if the performance differs
   > >  between
   > >  11.2 and 11.13.  It's possible that EDB compiled 11.13 on a newer
   >  CPU
   > >  (or a newer compiler) than 11.2 was compiled.
   > >
   > >  If you test that, it should be on a separate VM, unless the existing
   >  data
   > >  dir can be restored from backup.  Once you've started a cluster with
   > >  updated binaries, you should avoid downgrading the binaries.
   >  
   >  
   >  
   >  Hello all,
   >  
   >  OK, I was able to do a clean install of 13.4 on the VM. All stock 
settings,
   >  no extensions loaded, pure clean straight out of the install.
   >  
   >  create table sampletest (a varchar, b varchar);
   >  -- truncate table sampletest;
   >  insert into sampletest (a, b)
   >  select substr(md5(random()::text), 0, 15),
   >  (1*random())::integer::varchar
   >from generate_series(1,100);
   >  
   >  CREATE OR REPLACE FUNCTION toFloat(str varchar, val real) RETURNS
   >  real AS $$ BEGIN
   >RETURN case when str is null then val else str::real end; EXCEPTION
   >  WHEN OTHERS THEN
   >RETURN val;
   >  END;
   >  $$ LANGUAGE plpgsql COST 1 IMMUTABLE;
   >  
   >  
   >  explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(b, null)) as
   >  "b" from sampletest
   >  
   >  Aggregate  (cost=21370.00..21370.01 rows=1 width=4) (actual
   >  time=1780.561..1780.563 rows=1 loops=1)
   >Buffers: shared hit=6387
   >->  Seq Scan on sampletest  (cost=0.00..16370.00 rows=100
   >  width=8) (actual time=0.053..97.329 rows=100 loops=1)
   >  Buffers: shared hit=6370
   >  Planning:
   >Buffers: shared hit=36
   >  Planning Time: 2.548 ms
   >  Execution Time: 1,810.330 ms
   >  
   >  
   >  explain (analyze,buffers,COSTS,TIMING) select MAX(toFloat(a, null)) as
   >  "a" from sampletest
   >  
   >  Aggregate  (cost=21370.00..21370.01 rows=1 width=4) (actual
   >  time=863243.876..863243.877 rows=1 loops=1)
   >Buffers: shared hit=6373
   >->  Seq Scan on sampletest  (cost=0.00..16370.00 rows=100
   >  width=15) (actual time=0.009..301.553 rows=100 loops=1)
   >  Buffers: shared hit=6370
   >  Planning:
   >Buffers: shared hit=44
   >  Planning Time: 0.469 ms
   >  Execution Time: 863,243.911 ms
   >  
   >  
   >  So I am still able to reproduce this on a different VM and a clean install
   >  of 13.4 ☹
   >  
   >  
   >  SELECT * FROM pg_config();
   >  
   >  BINDIRC:/PROGRA~1/POSTGR~1/13/bin
   >  DOCDIRC:/PROGRA~1/POSTGR~1/13/doc
   >  HTMLDIR   C:/PROGRA~1/POSTGR~1/13/doc
   >  INCLUDEDIRC:/PROGRA~1/POSTGR~1/13/include
   >  PKGINCLUDEDIR C:/PROGRA~1/POSTGR~1/13/include
   >  INCLUDEDIR-SERVER C:/PROGRA~1/POSTGR~1/13/include/server
   >  LIBDIRC:/PROGRA~1/POSTGR~1/13/lib
   >  PKGLIBDIR C:/PROGRA~1/POSTGR~1/13/lib
   >  LOCALEDIR C:/PROGRA~1/POSTGR~1/13/share/locale
   >  MANDIRC:/Program Files/PostgreSQL/13/man
   >  SHAREDIR  C:/PROGRA~1/POSTGR~1/13/share
   >  SYSCONFDIRC:/Program Files/PostgreSQL/13/etc
   >  PGXS  C:/Program Files/PostgreSQL/13/lib/pgxs/src/makefiles/pgxs.mk
   >  CONFIGURE --enable-thread-safety --enable-nls --with-ldap --with-
   >  openssl --with-uuid --with-libxml --with-libxslt --with-icu --with-tcl 
--with-
   >  perl --with-python
   >  CCnot recorded
   >  CPPFLAGS  not recorded
   >  CFLAGSnot recorded
   >  CFLAGS_SL not recorded
   >  LDFLAGS   not recorded
   >  LDFLAGS_EXnot recorded
   >  LDFLAGS_SLnot recorded
   >  LIBS  not recorded
   >  VERSION   PostgreSQL 13.4
   >  
   >  
   >  And here is SYSINFO:
   >  
   >  C:\Users\LHASSON>systeminfo
   >  
   >  Host Name: PRODDB
   >  OS Name:   Microsoft Windows Server 2012 R2 Standard
   >  OS Version:6.3.9600 N/A Build 9600
   >  OS Manufacturer:   Microsoft Corporation
   >  OS Configuration:  Member Server
   >  OS Build Type: Multiprocessor Free
   >  Original Ins