Обсуждение: [HACKERS] Performance issue with postgres9.6

On Fri, Apr 7, 2017 at 5:16 AM, Prakash Itnal <prakash074@gmail.com> wrote:
> Hello,
>
> We currently use psotgres 9.3 in our products. Recently we upgraded to
> postgres 9.6. But with 9.6 we have seen a drastic reduction in throughput.
> After analyzing carefully I found that "planner time" in 9.6 is very high.
> Below are the details:
>
> Scenario:
> 1 Create a table with 100000 rows.
> 2 Execute simple query: select * from subscriber where s_id = 100;
> 3 No update/delete/insert; tried vacuum, full vacuum; by default we enable
> auto-vacuum
>
> 9.3: Avg of "Total runtime" : 0.24ms [actual throughput: 650 TPS]
> 9.6: Avg of Total time: 0.56ms (Avg of "Planning time" : 0.38ms + Avg of
> "Execution time" : 0.18ms) [actual throughput: 80 TPS]

I think your math is off.  Looking at your attachments, planning time
is 0.056ms, not 0.56ms.  This is in no way relevant to performance on
the order of your measured TPS.   How are you measuring TPS?

merlin

On 04/07/2017 06:31 PM, Merlin Moncure wrote:
> On Fri, Apr 7, 2017 at 5:16 AM, Prakash Itnal <prakash074@gmail.com> wrote:
>> Hello,
>>
>> We currently use psotgres 9.3 in our products. Recently we upgraded to
>> postgres 9.6. But with 9.6 we have seen a drastic reduction in throughput.
>> After analyzing carefully I found that "planner time" in 9.6 is very high.
>> Below are the details:
>>
>> Scenario:
>> 1 Create a table with 100000 rows.
>> 2 Execute simple query: select * from subscriber where s_id = 100;
>> 3 No update/delete/insert; tried vacuum, full vacuum; by default we enable
>> auto-vacuum
>>
>> 9.3: Avg of "Total runtime" : 0.24ms [actual throughput: 650 TPS]
>> 9.6: Avg of Total time: 0.56ms (Avg of "Planning time" : 0.38ms + Avg of
>> "Execution time" : 0.18ms) [actual throughput: 80 TPS]
>
> I think your math is off.  Looking at your attachments, planning time
> is 0.056ms, not 0.56ms.  This is in no way relevant to performance on
> the order of your measured TPS.   How are you measuring TPS?
>

Not sure where did you get the 0.056ms? What I see is this in the 9.3 
explains:
 Total runtime: 0.246 ms

and this in those from 9.6:
 Planning time: 0.396 ms
 Execution time: 0.181 ms


That is roughly 0.25ms vs. 0.6ms (0.4+0.2), as reported by Prakash.

Obviously, this "just" 2x slowdown, so it does not match the drop from 
650 to 80 tps. Also, 0.25ms would be ~4000 tps, so I guess this was just 
an example of a query that slowed down.

Prakash, are you using packages (which ones?), or have you compiled from 
sources? Can you provide pg_config output from both versions, and also 
'select * from pg_settings' (the full config)?

It might also be useful to collect profiles, i.e. (1) install debug 
symbols (2) run the query in a loop and (3) collect profiles from that 
one backend using 'perf'.

I assume you're using the same hardware / machine for the tests?

regards

-- 
Tomas Vondra                  http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Tomas Vondra <tomas.vondra@2ndquadrant.com> writes:
> On 04/07/2017 06:31 PM, Merlin Moncure wrote:
>> I think your math is off.  Looking at your attachments, planning time
>> is 0.056ms, not 0.56ms.  This is in no way relevant to performance on
>> the order of your measured TPS.   How are you measuring TPS?

> Not sure where did you get the 0.056ms?

I don't see that either, but:

> What I see is this in the 9.3 explains:
>   Total runtime: 0.246 ms
> and this in those from 9.6:
>   Planning time: 0.396 ms
>   Execution time: 0.181 ms
> That is roughly 0.25ms vs. 0.6ms (0.4+0.2), as reported by Prakash.

9.3's EXPLAIN did not measure planning time at all.  The "Total runtime"
it reports corresponds to "Execution time" in the newer version.  So
these numbers indicate that 9.6 is significantly *faster*, not slower,
than 9.3, at least so far as execution of this one example is concerned.

The OP may well be having some performance issue with 9.6, but the
presented material completely fails to demonstrate it.
        regards, tom lane

On Fri, Apr 7, 2017 at 12:54 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Tomas Vondra <tomas.vondra@2ndquadrant.com> writes:
>> On 04/07/2017 06:31 PM, Merlin Moncure wrote:
>>> I think your math is off.  Looking at your attachments, planning time
>>> is 0.056ms, not 0.56ms.  This is in no way relevant to performance on
>>> the order of your measured TPS.   How are you measuring TPS?
>
>> Not sure where did you get the 0.056ms?
>
> I don't see that either, but:
>
>> What I see is this in the 9.3 explains:
>>   Total runtime: 0.246 ms
>> and this in those from 9.6:
>>   Planning time: 0.396 ms
>>   Execution time: 0.181 ms
>> That is roughly 0.25ms vs. 0.6ms (0.4+0.2), as reported by Prakash.
>
> 9.3's EXPLAIN did not measure planning time at all.  The "Total runtime"
> it reports corresponds to "Execution time" in the newer version.  So
> these numbers indicate that 9.6 is significantly *faster*, not slower,
> than 9.3, at least so far as execution of this one example is concerned.
>
> The OP may well be having some performance issue with 9.6, but the
> presented material completely fails to demonstrate it.

This smells like a problem with the test execution environment itself.
OP (if on linux), try:

pgbench -n -f <(echo "select * from subscriber where s_id = 100") -c 4 -T 10

...where pgbench is run from the database server (if pgbench is not in
the default path, you may have to qualify it).  This should give
apples to apples comparison, or at least rule out certain
environmental considerations like the network stack.

If your client is running on windows, one place to look is the TCP
stack.  In my experience tcp configuration issues are much more common
on windows.  On any reasonably modern hardware can handle thousands
and thousands of transactions per second for simple indexed select.

merlin