Re: SELECT constant; takes 15x longer on 9.0? - Mailing list pgsql-hackers

Tom Lane <tgl@sss.pgh.pa.us> writes:
> Josh Berkus <josh@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