pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
dbt2 performance regresses from 9.1.6 to 9.2.1
6+ messages / 4 participants
[nested] [flat]

* dbt2 performance regresses from 9.1.6 to 9.2.1
@ 2012-10-31 22:48 Dong Ye <yed@vmware.com>
  0 siblings, 0 replies; 6+ messages in thread

From: Dong Ye @ 2012-10-31 22:48 UTC (permalink / raw)
  To: pgsql-performance

Hi there,

I work for VMware with our Postgres performance team. We recently came across a dbt2 performance regression from 9.1.6 to 9.2.1. We have done some profiling and don't see anything obvious. Would like to get some suggestions from the community where to investigate further.

The average notpm is 61384.24 with 9.1.6 and 57381.43 with 9.2.1.
Plotting notps over time shows that the slowdown of 9.2.1 is evident across the entire run period.
Since we also observed sustained 80+% CPU utilization during both runs, we suspected this is a CPU bottleneck issue.
So we run oprofile hoping that the profiles may suggest one is using CPU less productively than the other; but nothing jumped out to that explanation.
The profiling results are posted on http://pgsql.privatepaste.com/3fa3ae0627 (9.1.6 run) and http://pgsql.privatepaste.com/930bb51374 (9.2.1 run).


Specs:

HP ML360 G6:
2x Xeon E5520 (4-core/processor, Hyperthreading disabled)
12GB DRAM
HP P410i RAID controller (256MB battery-backed cache)
- One 10k-rpm SAS: to mount /
- One SSD: to mount pgdata and wal

SUSE Linux Enterprise Server 11 SP1 64-bit (kernel version: 2.6.32.59-0.7-default)

postgresql.conf:
max_connections = 100			
shared_buffers = 5600MB 
temp_buffers = 8193kB 
work_mem = 4096kB 
maintenance_work_mem = 400MB 
wal_buffers = -1 
checkpoint_segments = 300
logging_collector = on		        
datestyle = 'iso, mdy'
lc_messages = 'C'			
lc_monetary = 'C'			
lc_numeric = 'C'			
lc_time = 'C'				
default_text_search_config = 'pg_catalog.english'
log_destination = 'csvlog'
log_directory = 'pg_log'
log_filename = 'postgresql-%a'
log_rotation_age = 1440
log_truncate_on_rotation = on

dbt2-0.40 was used:
40 warehouse
20 db connections 
use no thinktime
use prepared statement
buffer warmup before measurement run (warmup is done through disabling sequential scan and count(*) all tables and indexes).
measurement run lasts 20 minutes

We used postgresql91-9.1.6 and postgresql92-9.2.1 openSUSE builds:
http://download.opensuse.org/repositories/server:/database:/postgresql/openSUSE_12.1/x86_64/


Thanks,
Dong





^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* dbt2 performance regresses from 9.1.6 to 9.2.1
@ 2012-10-31 22:51 Dong Ye <yed@vmware.com>
  2012-11-02 11:27 ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Ants Aasma <ants@cybertec.at>
  0 siblings, 1 reply; 6+ messages in thread

From: Dong Ye @ 2012-10-31 22:51 UTC (permalink / raw)
  To: pgsql-performance

Hi there,

I work for VMware with our Postgres performance team. We recently came across a dbt2 performance regression from 9.1.6 to 9.2.1. We have done some profiling and don't see anything obvious. Would like to get some suggestions from the community where to investigate further.

The average notpm is 61384.24 with 9.1.6 and 57381.43 with 9.2.1.
Plotting notps over time shows that the slowdown of 9.2.1 is evident across the entire run period.
Since we also observed sustained 80+% CPU utilization during both runs, we suspected this is a CPU bottleneck issue.
So we run oprofile hoping that the profiles may suggest one is using CPU less productively than the other; but nothing jumped out to that explanation.
The profiling results are posted on http://pgsql.privatepaste.com/3fa3ae0627 (9.1.6 run) and http://pgsql.privatepaste.com/930bb51374 (9.2.1 run).


Specs:

HP ML360 G6:
2x Xeon E5520 (4-core/processor, Hyperthreading disabled)
12GB DRAM
HP P410i RAID controller (256MB battery-backed cache)
- One 10k-rpm SAS: to mount /
- One SSD: to mount pgdata and wal

SUSE Linux Enterprise Server 11 SP1 64-bit (kernel version: 2.6.32.59-0.7-default)

postgresql.conf:
max_connections = 100			
shared_buffers = 5600MB 
temp_buffers = 8193kB 
work_mem = 4096kB 
maintenance_work_mem = 400MB 
wal_buffers = -1 
checkpoint_segments = 300
logging_collector = on		        
datestyle = 'iso, mdy'
lc_messages = 'C'			
lc_monetary = 'C'			
lc_numeric = 'C'			
lc_time = 'C'				
default_text_search_config = 'pg_catalog.english'
log_destination = 'csvlog'
log_directory = 'pg_log'
log_filename = 'postgresql-%a'
log_rotation_age = 1440
log_truncate_on_rotation = on

dbt2-0.40 was used:
40 warehouse
20 db connections 
use no thinktime
use prepared statement
buffer warmup before measurement run (warmup is done through disabling sequential scan and count(*) all tables and indexes).
measurement run lasts 20 minutes

We used postgresql91-9.1.6 and postgresql92-9.2.1 openSUSE builds:
http://download.opensuse.org/repositories/server:/database:/postgresql/openSUSE_12.1/x86_64/


Thanks,
Dong





^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: dbt2 performance regresses from 9.1.6 to 9.2.1
  2012-10-31 22:51 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
@ 2012-11-02 11:27 ` Ants Aasma <ants@cybertec.at>
  2012-11-04 22:23   ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
  0 siblings, 1 reply; 6+ messages in thread

From: Ants Aasma @ 2012-11-02 11:27 UTC (permalink / raw)
  To: Dong Ye <yed@vmware.com>; +Cc: pgsql-performance

On Thu, Nov 1, 2012 at 12:51 AM, Dong Ye <yed@vmware.com> wrote:
> The average notpm is 61384.24 with 9.1.6 and 57381.43 with 9.2.1.
> Plotting notps over time shows that the slowdown of 9.2.1 is evident across the entire run period.
> Since we also observed sustained 80+% CPU utilization during both runs, we suspected this is a CPU bottleneck issue.
> So we run oprofile hoping that the profiles may suggest one is using CPU less productively than the other; but nothing jumped out to that explanation.
> The profiling results are posted on http://pgsql.privatepaste.com/3fa3ae0627 (9.1.6 run) and http://pgsql.privatepaste.com/930bb51374 (9.2.1 run).

You are using prepared statements, this makes me think that this
regression might be due to support for parameter specific plans for
prepared statements. [1] Can you run the test on both versions without
prepared statements and see if the regressions remains.

I compared the profile results, I'll reproduce the results here incase
they ring any other bells for someone. Here are top 20 functions that
take more time under 9.2:

                                Function  Diff  v9.2%  v9.1%
                     postgres.copyObject  3.48 1.2436 0.3569
              postgres.check_stack_depth  1.92 0.7244 0.3774
 postgres.eval_const_expressions_mutator  1.87 0.3473 0.1853
                                jbd./jbd  1.82 0.4127 0.2271
              libc-2.14.1.so._int_malloc  1.75 1.4938 0.8540
           libc-2.14.1.so.__strlen_sse42  1.72 0.7098 0.4124
vmlinux-2.6.32.59-0.7-default.copy_user_generic_string  1.70 0.5130 0.3017
            postgres.MemoryContextCreate  1.68 0.3206 0.1914
  postgres.MemoryContextAllocZeroAligned  1.64 1.5443 0.9443
                libc-2.14.1.so._int_free  1.60 0.7182 0.4476
         postgres.expression_tree_walker  1.60 0.8350 0.5235
                     postgres.XLogInsert  1.58 2.7251 1.7210
                              ext3./ext3  1.55 0.2065 0.1335
           libc-2.14.1.so.__strcpy_ssse3  1.50 0.3061 0.2046
        postgres.expression_tree_mutator  1.41 0.3461 0.2447
      libc-2.14.1.so.__memcpy_ssse3_back  1.40 1.2379 0.8830
                  postgres.AllocSetAlloc  1.39 4.6567 3.3467
            postgres.LockAcquireExtended  1.39 0.2799 0.2015
             postgres.MemoryContextAlloc  1.38 1.0151 0.7373
                 postgres.AllocSetDelete  1.33 0.2130 0.1600

And top 10 functions present under 9.2 but not present with 9.1:
                              Function
              postgres._copyList.isra.15 0.341
       postgres._SPI_execute_plan.isra.4 0.224
               postgres.grouping_planner 0.220
                  postgres.IndexOnlyNext 0.213
                  postgres.GetCachedPlan 0.189
            postgres.MemoryContextStrdup 0.171
                      postgres.list_copy 0.165
              postgres.index_getnext_tid 0.155
         postgres.MemoryContextSetParent 0.128
          postgres.cost_qual_eval_walker 0.127

I have no idea why is XLogInsert taking so much longer on 9.2.

[1] http://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=e6faf910

Ants Aasma
-- 
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de




^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: dbt2 performance regresses from 9.1.6 to 9.2.1
  2012-10-31 22:51 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
  2012-11-02 11:27 ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Ants Aasma <ants@cybertec.at>
@ 2012-11-04 22:23   ` Dong Ye <yed@vmware.com>
  2012-11-05 14:32     ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Claudio Freire <klaussfreire@gmail.com>
  0 siblings, 1 reply; 6+ messages in thread

From: Dong Ye @ 2012-11-04 22:23 UTC (permalink / raw)
  To: Ants Aasma <ants@cybertec.at>; +Cc: pgsql-performance

> You are using prepared statements, this makes me think that this
> regression might be due to support for parameter specific plans for
> prepared statements. [1] Can you run the test on both versions without
> prepared statements and see if the regressions remains.

Without prepare statement, we got 48837.33 avg notpm with 9.1.6 and 43264.54 avg notpm with 9.2.1.
notps over time shows the slowdown of 9.2.1 is evident during the entire course of the run.
Their profiles are posted on http://pgsql.privatepaste.com/b770f72967 (9.1.6) and http://pgsql.privatepaste.com/6fa8b7f174 (9.2.1).

Thanks,
Dong




^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: dbt2 performance regresses from 9.1.6 to 9.2.1
  2012-10-31 22:51 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
  2012-11-02 11:27 ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Ants Aasma <ants@cybertec.at>
  2012-11-04 22:23   ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
@ 2012-11-05 14:32     ` Claudio Freire <klaussfreire@gmail.com>
  2012-11-07 11:43       ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Heikki Linnakangas <hlinnakangas@vmware.com>
  0 siblings, 1 reply; 6+ messages in thread

From: Claudio Freire @ 2012-11-05 14:32 UTC (permalink / raw)
  To: Dong Ye <yed@vmware.com>; +Cc: Ants Aasma <ants@cybertec.at>; pgsql-performance

On Sun, Nov 4, 2012 at 7:23 PM, Dong Ye <yed@vmware.com> wrote:
>> You are using prepared statements, this makes me think that this
>> regression might be due to support for parameter specific plans for
>> prepared statements. [1] Can you run the test on both versions without
>> prepared statements and see if the regressions remains.
>
> Without prepare statement, we got 48837.33 avg notpm with 9.1.6 and 43264.54 avg notpm with 9.2.1.
> notps over time shows the slowdown of 9.2.1 is evident during the entire course of the run.
> Their profiles are posted on http://pgsql.privatepaste.com/b770f72967 (9.1.6) and http://pgsql.privatepaste.com/6fa8b7f174 (9.2.1).

You know... it does look as if 9.2.1 is generating a lot more pressure
into the memory allocator (AllocSetAlloc notably higher).




^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: dbt2 performance regresses from 9.1.6 to 9.2.1
  2012-10-31 22:51 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
  2012-11-02 11:27 ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Ants Aasma <ants@cybertec.at>
  2012-11-04 22:23   ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
  2012-11-05 14:32     ` Re: dbt2 performance regresses from 9.1.6 to 9.2.1 Claudio Freire <klaussfreire@gmail.com>
@ 2012-11-07 11:43       ` Heikki Linnakangas <hlinnakangas@vmware.com>
  0 siblings, 0 replies; 6+ messages in thread

From: Heikki Linnakangas @ 2012-11-07 11:43 UTC (permalink / raw)
  To: Dong Ye <yed@vmware.com>; +Cc: Claudio Freire <klaussfreire@gmail.com>; Ants Aasma <ants@cybertec.at>; pgsql-performance

On 05.11.2012 16:32, Claudio Freire wrote:
> On Sun, Nov 4, 2012 at 7:23 PM, Dong Ye<yed@vmware.com>  wrote:
>>> You are using prepared statements, this makes me think that this
>>> regression might be due to support for parameter specific plans for
>>> prepared statements. [1] Can you run the test on both versions without
>>> prepared statements and see if the regressions remains.
>>
>> Without prepare statement, we got 48837.33 avg notpm with 9.1.6 and 43264.54 avg notpm with 9.2.1.
>> notps over time shows the slowdown of 9.2.1 is evident during the entire course of the run.
>> Their profiles are posted on http://pgsql.privatepaste.com/b770f72967 (9.1.6) and http://pgsql.privatepaste.com/6fa8b7f174 (9.2.1).
>
> You know... it does look as if 9.2.1 is generating a lot more pressure
> into the memory allocator (AllocSetAlloc notably higher).

Did you check the access plans of the queries? 9.2 planner might choose 
a slightly worse plan. Or perhaps index-only scans are hurting 
performance with the DBT-2 queries.

- Heikki




^ permalink  raw  reply  [nested|flat] 6+ messages in thread


end of thread, other threads:[~2012-11-07 11:43 UTC | newest]

Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2012-10-31 22:48 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
2012-10-31 22:51 dbt2 performance regresses from 9.1.6 to 9.2.1 Dong Ye <yed@vmware.com>
2012-11-02 11:27 ` Ants Aasma <ants@cybertec.at>
2012-11-04 22:23   ` Dong Ye <yed@vmware.com>
2012-11-05 14:32     ` Claudio Freire <klaussfreire@gmail.com>
2012-11-07 11:43       ` Heikki Linnakangas <hlinnakangas@vmware.com>

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