profiling pgbench

From: Robert Haas <robertmhaas(at)gmail(dot)com>
To: pgsql-hackers(at)postgresql(dot)org
Subject: profiling pgbench
Date: 2010-11-24 20:24:43
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-hackers

I did some profiling of pgbench -j 36 -c 36 -T 500 banging on my
two-core desktop box - with synchronous_commit turned off to keep the
fsyncs from dominating the profile - and got these results:

29634 4.7124 postgres base_yyparse
27906 4.4377 postgres AllocSetAlloc
17751 2.8228 postgres SearchCatCache
13029 2.0719 postgres hash_search_with_hash_value
11253 1.7895 postgres core_yylex
9957 1.5834 memcmp
9237 1.4689 __strcmp_sse2
8628 1.3720 postgres ScanKeywordLookup
7984 1.2696 postgres GetSnapshotData
7144 1.1361 postgres MemoryContextAllocZeroAligned
6898 1.0969 postgres XLogInsert
6440 1.0241 postgres LWLockAcquire

Full report and call graph attached. The opannotate results are 2MB
bzip'd, so I'm not attaching those; send me an email off-list if you
want them.

I'd like to get access to a box with (a lot) more cores, to see
whether the lock stuff moves up in the profile. A big chunk of that
hash_search_with_hash_value overhead is coming from
LockAcquireExtended. The __strcmp_sse2 is almost entirely parsing
overhead. In general, I'm not sure there's much hope for reducing the
parsing overhead, although ScanKeywordLookup() can certainly be done
better. XLogInsert() is spending a lot of time doing CRC's.
LWLockAcquire() is dropping cycles in many different places.

Robert Haas
The Enterprise PostgreSQL Company

Attachment Content-Type Size
pgbench36-callgraph.txt.bz2 application/x-bzip2 75.9 KB
pgbench36-opreport.txt.bz2 application/x-bzip2 11.2 KB


Browse pgsql-hackers by date

  From Date Subject
Next Message Marti Raudsepp 2010-11-24 20:28:49 Re: function(contants) evaluated for every row
Previous Message Peter Eisentraut 2010-11-24 20:22:15 Re: Per-column collation