Re: Any better plan for this query?.. - Mailing list pgsql-performance

From Dimitri
Subject Re: Any better plan for this query?..
Date
Msg-id 5482c80a0905070141q3c4ecb1me0f935407aba04c5@mail.gmail.com
Whole thread Raw
In response to Any better plan for this query?..  (Dimitri <dimitrik.fr@gmail.com>)
Responses Re: Any better plan for this query?..  (Alvaro Herrera <alvherre@commandprompt.com>)
List pgsql-performance
The problem with "gprof" - it'll profile all stuff from the beginning
to the end, and a lot of function executions unrelated to this query
will be profiled...

As well when you look on profiling technology - all such kind of
solutions are based on the system clock frequency and have their
limits on time resolution. On my system this limit is 0.5ms, and it's
too big comparing to the query execution time :-)

So, what I've done - I changed little bit a reference key criteria from
= '0000000001' to < '0000000051', so instead of 20 rows I have 1000
rows on output now, it's still slower than InnoDB (12ms vs 9ms), but
at least may be profiled (well, we also probably moving far from the
problem as time may be spent mostly on the output traffic now, but
I've tried anyway) - I've made a loop of 100 iterations of this query
which is reading but not printing data. The total execution time of
this loop is 1200ms, and curiously under profiling was not really
changed. Profiler was able to catch 733ms of total execution time (if
I understand well, all functions running faster than 0.5ms are remain
un-profiled). The top profiler output is here:

Excl.     Incl.      Name
User CPU  User CPU
 sec.      sec.
0.733     0.733      <Total>
0.103     0.103      memcpy
0.045     0.045      slot_deform_tuple
0.037     0.040      AllocSetAlloc
0.021     0.021      AllocSetFree
0.018     0.037      pfree
0.018     0.059      appendBinaryStringInfo
0.017     0.031      heap_fill_tuple
0.017     0.017      _ndoprnt
0.016     0.016      nocachegetattr
0.015     0.065      heap_form_minimal_tuple
0.015     0.382      ExecProcNode
0.015     0.015      strlen
0.014     0.037      ExecScanHashBucket
0.014     0.299      printtup
0.013     0.272      ExecHashJoin
0.011     0.011      enlargeStringInfo
0.011     0.086      index_getnext
0.010     0.010      hash_any
0.009     0.076      FunctionCall1
0.009     0.037      MemoryContextAlloc
0.008     0.008      LWLockAcquire
0.007     0.069      pq_sendcountedtext
0.007     0.035      ExecProject
0.007     0.127      ExecScan
...

Curiously "memcpy" is in top. Don't know if it's impacted in many
cases, but probably it make sense to see if it may be optimized, etc..

Rgds,
-Dimitri



On 5/7/09, Euler Taveira de Oliveira <euler@timbira.com> wrote:
> Dimitri escreveu:
>> BTW, is there already an integrated profiled within a code? or do I
>> need external tools?..
>>
> Postgres provides support for profiling. Add --enable-profiling flag. Use
> gprof to get the profile.
>
>
> --
>   Euler Taveira de Oliveira
>   http://www.timbira.com/
>

pgsql-performance by date:

Previous
From: Dimitri
Date:
Subject: Re: Any better plan for this query?..
Next
From: Simon Riggs
Date:
Subject: Re: Transparent table partitioning in future version of PG?