Prev: Remaining Streaming Replication Open Items
Next: pgsql: Check compulsory parameters in recovery.conf in standby_mode, per
From: "David E. Wheeler" on 6 Apr 2010 13:00
On Apr 6, 2010, at 7:28 AM, Tom Lane wrote:

> There's something wrong with your test setup. Or, if you'd like me to
> think that there isn't, provide a self-contained test case. I ran a
> small program that does
>
> for (i = 0; i < 10000; i++)
> {
> res = PQexec(conn, "SELECT 'DBD::Pg ping test'");
> PQclear(res);
> }
>
> and I only see a few percent difference between HEAD and 8.4.3,
> on two different machines. (It does appear that HEAD is a bit slower
> for this, which might or might not be something to worry about.)

I'm going to see if I can replicate it on a second box today.

Best,

David


--
Sent via pgsql-hackers mailing list (pgsql-hackers(a)postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

From: Tom Lane on 6 Apr 2010 13:17
Tom Lane <tgl(a)sss.pgh.pa.us> writes:
> Josh Berkus <josh(a)agliodbs.com> writes:
>> Continuing the performance test:

>> DBD, like a number of monitoring systems, does "pings" on the database
>> which look like this:

>> SELECT 'DBD::Pg ping test';

>> In our test, which does 5801 of these pings during the test, they take
>> an average of 15x longer to execute on 9.0 as 8.4 ( 0.77ms vs. 0.05ms ).

> There's something wrong with your test setup. Or, if you'd like me to
> think that there isn't, provide a self-contained test case.

I did some comparisons and oprofile work against this test case:

> for (i = 0; i < [lots]; i++)
> {
> res = PQexec(conn, "SELECT 'DBD::Pg ping test'");
> PQclear(res);
> }

In assert-enabled builds, HEAD seems about 10% slower than 8.4 branch
tip, but as far as I can tell this is all debug overhead associated with
a slightly larger number of catcache entries that are present
immediately after startup. In non-assert-enabled builds there's a
difference of a percent or so, which appears to be due to increased
lexer overhead; oprofile shows these top routines in HEAD:

samples % image name symbol name
49787 7.0533 postgres base_yyparse
35510 5.0307 postgres AllocSetAlloc
29135 4.1275 postgres hash_search_with_hash_value
24541 3.4767 postgres core_yylex
15231 2.1578 postgres PostgresMain
14710 2.0840 postgres hash_seq_search
14340 2.0315 postgres LockReleaseAll
13878 1.9661 postgres MemoryContextAllocZeroAligned
10047 1.4234 postgres ScanKeywordLookup
9866 1.3977 postgres LWLockAcquire
9434 1.3365 postgres LockAcquireExtended
8347 1.1825 postgres hash_any
7954 1.1268 postgres ExecInitExpr
7326 1.0379 postgres MemoryContextAlloc
7243 1.0261 postgres AllocSetFree
6787 0.9615 postgres MemoryContextAllocZero
6501 0.9210 postgres internal_flush
5956 0.8438 postgres LWLockRelease

versus these in 8.4:

samples % image name symbol name
51795 7.2589 postgres AllocSetAlloc
37742 5.2894 postgres base_yyparse
32558 4.5629 postgres hash_search_with_hash_value
17250 2.4175 postgres hash_seq_search
14933 2.0928 postgres AllocSetFree
14902 2.0885 postgres MemoryContextAllocZeroAligned
13219 1.8526 postgres LockReleaseAll
12974 1.8183 postgres SearchCatCache
10885 1.5255 postgres PostgresMain
10592 1.4844 postgres ResourceOwnerReleaseInternal
10462 1.4662 postgres base_yylex
10007 1.4025 postgres hash_any
9553 1.3388 postgres MemoryContextAllocZero
8758 1.2274 postgres LWLockAcquire
8237 1.1544 postgres exec_simple_query
7410 1.0385 postgres LockAcquire
7315 1.0252 postgres MemoryContextCreate
7262 1.0177 postgres MemoryContextAlloc
7220 1.0119 postgres LWLockRelease

The only thing that seems to have changed by more than the noise level
is that core_yylex (formerly base_yylex) got slower. I suppose this is
due to changing over to a re-entrant scanner. The flex manual claims
that %option reentrant doesn't cost any performance --- so I suspect
that what we are seeing here is additional per-call overhead and not a
slowdown that would be important for lexing long queries. I don't think
there's anything to worry about there for nontrivial queries.

I also tried reconnecting to the server for each query. In that
situation HEAD seems to be about 10% slower than 8.4 even without
asserts, which might be an artifact of the changes to eliminate the
"flat" authentication files. I'm not particularly concerned about that
either, since if you're looking for performance, reconnecting to issue a
trivial query is not what you should be doing.

So I'm not sure where your 15x is coming from, but I don't see it.

regards, tom lane

--
Sent via pgsql-hackers mailing list (pgsql-hackers(a)postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

From: Merlin Moncure on 6 Apr 2010 13:47
On Tue, Apr 6, 2010 at 12:08 PM, David E. Wheeler <david(a)kineticode.com> wrote:
> On Apr 6, 2010, at 2:32 AM, Takahiro Itagaki wrote:
>
>>> In our test, which does 5801 of these pings during the test, they take
>>> an average of 15x longer to execute on 9.0 as 8.4 ( 0.77ms vs. 0.05ms ).
>>>
>>> Any clue why this would be?
>>
>> Did you use the same configure options between them?
>
> Yes.
>
>> For example, --enable-debug or --enable-cassert.


hmm. ssl? (I don't see any interesting difference in time either
btw). can you log in w/psql and confirm the difference there w/timing
switch?

merlin

--
Sent via pgsql-hackers mailing list (pgsql-hackers(a)postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

From: "David E. Wheeler" on 6 Apr 2010 13:52
On Apr 6, 2010, at 9:08 AM, David E. Wheeler wrote:

>> For example, --enable-debug or --enable-cassert.
>
> No.

Oh FFS! I was looking at the wrong build script. It was indeed built with --enable-cassert --enable-debug. Grrr.

Well, that's likely the culprit right there. I'm rebuilding without those now and hopefully my tests will be back down to 45s.

Many apologies for the noise and wasted time.

Best,

David
--
Sent via pgsql-hackers mailing list (pgsql-hackers(a)postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

From: "David E. Wheeler" on 6 Apr 2010 14:04
On Apr 6, 2010, at 10:17 AM, Tom Lane wrote:

> So I'm not sure where your 15x is coming from, but I don't see it.

By stupidly having configured with --enable-cassert --enable-debug without realizing it. I've just rebuilt without them and run the tests again using the default postgresql.conf and I'm back down to 57s and 46s over two runs.

Sorry for the wasted time. I knew there had to a be a simple answer.

Best,

David
--
Sent via pgsql-hackers mailing list (pgsql-hackers(a)postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

First  |  Prev  |  Next  |  Last
Pages: 1 2 3 4 5
Prev: Remaining Streaming Replication Open Items
Next: pgsql: Check compulsory parameters in recovery.conf in standby_mode, per