Re: Any better plan for this query?..

From: Dimitri <dimitrik(dot)fr(at)gmail(dot)com>
To: Euler Taveira de Oliveira <euler(at)timbira(dot)com>
Cc: Kenneth Marshall <ktm(at)rice(dot)edu>, PostgreSQL Performance <pgsql-performance(at)postgresql(dot)org>
Subject: Re: Any better plan for this query?..
Date: 2009-05-07 08:41:26
Message-ID: 5482c80a0905070141q3c4ecb1me0f935407aba04c5@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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(at)timbira(dot)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/
>

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Simon Riggs 2009-05-07 08:54:18 Re: Transparent table partitioning in future version of PG?
Previous Message Dimitri 2009-05-07 08:20:46 Re: Any better plan for this query?..