Re: pgbench cpu overhead (was Re: lazy vxid locks, v1)

On 07/24/2011 03:50 AM, Jeff Janes wrote:
> On Mon, Jun 13, 2011 at 7:03 AM, Stefan Kaltenbrunner
> <stefan(at)kaltenbrunner(dot)cc> wrote:
>> On 06/13/2011 01:55 PM, Stefan Kaltenbrunner wrote:
>>
>> [...]
>>
>>> all those tests are done with pgbench running on the same box - which
>>> has a noticable impact on the results because pgbench is using ~1 core
>>> per 8 cores of the backend tested in cpu resoures - though I don't think
>>> it causes any changes in the results that would show the performance
>>> behaviour in a different light.
>>
>> actuall testing against sysbench with the very same workload shows the
>> following performance behaviour:
>>
>> with 40 threads(aka the peak performance point):
>>
>> pgbench: 223308 tps
>> sysbench: 311584 tps
>>
>> with 160 threads (backend contention dominated):
>>
>> pgbench: 57075
>> sysbench: 43437
>>
>>
>> so it seems that sysbench is actually significantly less overhead than
>> pgbench and the lower throughput at the higher conncurency seems to be
>> cause by sysbench being able to stress the backend even more than
>> pgbench can.
>>
>>
>> for those curious - the profile for pgbench looks like:
>>
>> samples % symbol name
>> 29378 41.9087 doCustom
>> 17502 24.9672 threadRun
>> 7629 10.8830 pg_strcasecmp
>> 5871 8.3752 compareVariables
>> 2568 3.6633 getVariable
>> 2167 3.0913 putVariable
>> 2065 2.9458 replaceVariable
>> 1971 2.8117 parseVariable
>> 534 0.7618 xstrdup
>> 278 0.3966 xrealloc
>> 137 0.1954 xmalloc
>
> Hi Stefan,
>
> How was this profile generated? I get a similar profile using
> --enable-profiling and gprof, but I find it not believable. The
> complete absence of any calls to libpq is not credible. I don't know
> about your profiler, but with gprof they should be listed in the call
> graph even if they take a negligible amount of time. So I think
> pgbench is linking to libpq libraries that do not themselves support
> profiling (I have no idea how that could happen though). If the calls
> graphs are not getting recorded correctly, surely the timing can't be
> reliable either.

hmm - the profile was generated using oprofile, but now that you are
mentioning this aspect, I suppose that this was a profile run without
opcontrol --seperate=lib...
I'm not currently in a position to retest that - but maybe you could do
a run?

>
> (I also tried profiling pgbench with "perf", but in that case I get
> nothing other than kernel and libc calls showing up. I don't know
> what that means)
>
> To support this, I've dummied up doCustom so that does all the work of
> deciding what needs to happen, executing the metacommands,
> interpolating the variables into the SQL string, but then simply
> refrains from calling the PQ functions to send and receive the query
> and response. (I had to make a few changes around the select loop in
> threadRun to support this).
>
> The result is that the dummy pgbench is charged with only 57% more CPU
> time than the stock one, but it gets over 10 times as many
> "transactions" done. I think this supports the notion that the CPU
> bottleneck is not in pgbench.c, but somewhere in the libpq or the
> kernel.

interesting - iirc we actually had some reports about current libpq
behaviour causing scaling issues on some OSes - see
http://archives.postgresql.org/pgsql-hackers/2009-06/msg00748.php and
some related threads. Iirc the final patch for that was never applied
though and the original author lost interest, I think that I was able to
measure some noticable performance gains back in the days but I don't
think I still have the numbers somewhere.

Stefan