Re: profiling pgbench

On Wed, Nov 24, 2010 at 2:34 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
> On Wed, Nov 24, 2010 at 5:33 PM, Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:
>>
>> I've played a bit with hash_search_with_hash_value and found that most
>> of the time is spent on shared hash tables, not private ones.  And the
>> time attributed to it for the shared hash tables mostly seems to be
>> due to the time it takes to fight cache lines away from other CPUs.  I
>> suspect the same thing is true of LWLockAcquire.
>
> How do you get stats on that?

I replicated hash_search_with_hash_value function definition many
times with different names, and changed different parts of the code to
invoke different function names. (I don't trust profilers to
correctly distribute times over call graphs. I think most of them
just assume all function calls take the same time, and don't
separately measure the time of calls coming from different parts of
the code.)

Then I took one of them that is heavily used and leaves the hash table
unchanged, and had it invoke the same call several times in a row.
The profiling confirmed that it was called 3 times more often, but the
time spent in it increased by far less than 3 times, I think the
increase in time in that function was only 10% or so (and in
non-profiling code, the total run time did not increase by a
noticeable amount).

The only way I could explain this, other than redundant calls being
optimized away (which the profiler call-counts disputes), is caching
effects.

--- a/src/backend/storage/buffer/buf_table.c
+++ b/src/backend/storage/buffer/buf_table.c
@@ -95,7 +95,21 @@ BufTableLookup(BufferTag *tagPtr, uint32 hashcode)
BufferLookupEnt *result;

result = (BufferLookupEnt *)
- hash_search_with_hash_value(SharedBufHash,
+ hash_search_with_hash_value5(SharedBufHash,
+
(void *) tagPtr,
+
hashcode,
+
HASH_FIND,
+ NULL);
+
+ result = (BufferLookupEnt *)
+ hash_search_with_hash_value5(SharedBufHash,
+
(void *) tagPtr,
+
hashcode,
+
HASH_FIND,
+ NULL);
+
+ result = (BufferLookupEnt *)
+ hash_search_with_hash_value5(SharedBufHash,

(void *) tagPtr,

hashcode,

HASH_FIND,

> How big is a typical cache line on modern CPUs?

That I don't know. I'm more of an experimentalist.

Cheers,

Jeff