Thread: Different execution time from psql and JDBC

Dear postgresql community,

I have a quite complex statement. When I execute it directly via
psql, the execution time is approx. 2000 ms.

When I execute it via JDBC (Apache Cocoon), the execution time
is either 600..1000 ms or approx. 10.000 ms, based on a certain
value in a table.


An interesting point is that the value has a big impact on the
JDBC execution time, but the psql execution time is not affected
at all.


Is there a way to output the query plan (like EXPLAIN ANALYZE)
in the log files? How can I trace down the problem?

Of course I can attach the query if this helps.

Thanks a lot in advance!

-- Andreas

Andreas Hartmann wrote:
> Dear postgresql community,
>
> I have a quite complex statement. When I execute it directly via
> psql, the execution time is approx. 2000 ms.
>
> When I execute it via JDBC (Apache Cocoon), the execution time
> is either 600..1000 ms or approx. 10.000 ms, based on a certain
> value in a table.
>
>
> An interesting point is that the value has a big impact on the
> JDBC execution time, but the psql execution time is not affected
> at all.

This suggests to me the problem is with a parametered query. If in psql
I have two queries:
   SELECT * FROM people WHERE surname='Huxton';
   SELECT * FROM people WHERE surname='Smith';
If the statistics suggest there are many Smiths, then I might get two
different plans.
With a parameterised query:
   SELECT * FROM people WHERE surname=?
The planner has to come up with one plan that will suit all cases.

You can simulate this with PREPARE ... EXECUTE from psql - see if that
does it.

> Is there a way to output the query plan (like EXPLAIN ANALYZE)
> in the log files? How can I trace down the problem?

You can turn on DEBUG_PRINT_PARSE - see the runtime configuration for
details. This doesn't exactly produce an EXPLAIN but it will let you
compare the two plans.

--
   Richard Huxton
   Archonet Ltd

Richard Huxton wrote:
> Andreas Hartmann wrote:
>
>> Dear postgresql community,
>>
>> I have a quite complex statement. When I execute it directly via
>> psql, the execution time is approx. 2000 ms.
>>
>> When I execute it via JDBC (Apache Cocoon), the execution time
>> is either 600..1000 ms or approx. 10.000 ms, based on a certain
>> value in a table.
>>
>>
>> An interesting point is that the value has a big impact on the
>> JDBC execution time, but the psql execution time is not affected
>> at all.
>
>
> This suggests to me the problem is with a parametered query. If in psql
> I have two queries:
>   SELECT * FROM people WHERE surname='Huxton';
>   SELECT * FROM people WHERE surname='Smith';
> If the statistics suggest there are many Smiths, then I might get two
> different plans.
> With a parameterised query:
>   SELECT * FROM people WHERE surname=?
> The planner has to come up with one plan that will suit all cases.
>
> You can simulate this with PREPARE ... EXECUTE from psql - see if that
> does it.

Thanks for your answer!

Actually I found the cause of the two results differing so much.

The query is executed using a set of values (IN (x1, x2, ..., xn))
I use a LIMIT..OFFSET query to get the value set to invoke the described
query on. With psql, I used always the same set, but with the JDBC
application the query was invoked on different sets, resulting in
different execution times.

When I repeated the test with psql using the correct data, I could
reproduce the difference.


But what bothers me is the overhead generated by the JDBC connection:

                    JDBC        psql
data set A         1000 ms      300 ms
data set B         6000 ms     2000 ms

The JDBC execution times are determined using profiling in my application.
psql seems to be approx. 3 times faster than JDBC ...
Can I do something about this?


>> Is there a way to output the query plan (like EXPLAIN ANALYZE)
>> in the log files? How can I trace down the problem?
>
>
> You can turn on DEBUG_PRINT_PARSE - see the runtime configuration for
> details. This doesn't exactly produce an EXPLAIN but it will let you
> compare the two plans.

Yes, I've tried that, but the verbose query plan was too complicated.
But you're right, I could at least use diff to compare them.

Thanks again!

-- Andreas