Fwd: Query with high planning time compared to execution time

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

Fwd: Query with high planning time compared to execution time

swift1984
Hi,

I'm running a performance test for our application and encountered a particular query with high planning time compared to the execution. Please refer to attached explain.out for the explain analyze output.


The test was performed with Jmeter sending requests to the database, query was generated by Hibernate which consists of a 133 table UNION. Also attached are some diagnostic info (database version, database settings, table definitions and maintenance related information).

Due to the extremely large query text, I'm choosing to provide information via attachments instead of pasting in the email body.

Below are some additional OS information on the database server:
CPU: 8
RAM: 24GB
Disk: SSD
OS: CentOS Linux release 7.4.1708 (Core)

[root@kvrh7os202 ~]# uname -a
Linux kvrh7os202.comptel.com 3.10.0-693.21.1.el7.x86_64 #1 SMP Wed Mar 7 19:03:37 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
[root@kvrh7os202 ~]#

Things I tried:
1. Setting random_page_cost = 1.1 and effective_io_concurrency = 200 - no effect on planning time
2. Create materialized view for big UNION query - planning time reduced significantly but not a viable solution

What are my other options to improve the query planning time?



Regards,
Richard Lee

explain.out (99K) Download Attachment
diag_info.zip (105K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

Tomas Vondra-4
On 11/02/2018 10:36 AM, Richard Lee wrote:

> Hi,
>
> I'm running a performance test for our application and encountered a
> particular query with high planning time compared to the execution.
> Please refer to attached explain.out for the explain analyze output.
>
> Formatted explain: https://explain.depesz.com/s/R834
>
> The test was performed with Jmeter sending requests to the database,
> query was generated by Hibernate which consists of a 133 table UNION.
> Also attached are some diagnostic info (database version, database
> settings, table definitions and maintenance related information).
>
> Due to the extremely large query text, I'm choosing to provide
> information via attachments instead of pasting in the email body.
>
> Below are some additional OS information on the database server:
> CPU: 8
> RAM: 24GB
> Disk: SSD
> OS: CentOS Linux release 7.4.1708 (Core)
>
> [root@kvrh7os202 ~]# uname -a
> Linux kvrh7os202.comptel.com <http://kvrh7os202.comptel.com>
> 3.10.0-693.21.1.el7.x86_64 #1 SMP Wed Mar 7 19:03:37 UTC 2018 x86_64
> x86_64 x86_64 GNU/Linux
> [root@kvrh7os202 ~]#
>
> Things I tried:
> 1. Setting random_page_cost = 1.1 and effective_io_concurrency = 200 -
> no effect on planning time
> 2. Create materialized view for big UNION query - planning time reduced
> significantly but not a viable solution
>

Those changes likely affect the query costing and execution, but the
number of plans to consider is probably not going to change much. So
planning taking about the same time is kinda expected here.

> What are my other options to improve the query planning time?
>

Can you do a bit of profiling, to determine which part of the query
planning process is slow here? That is:

1) make sure you have the debug symbols installed
2) do `perf record`
3) run the benchmark for a while (a minute or so)
4) stop the perf record using Ctrl-C
5) generate a profile using `perf report` and share the result

Possibly do the same thing with `perf record -g` to collect call-graph
information, but that's probably going way larger.

regards

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

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

legrand legrand
Tomas Vondra-4 wrote
> On 11/02/2018 10:36 AM, Richard Lee wrote:
> [...]
>
>> What are my other options to improve the query planning time?
>>
>
> Can you do a bit of profiling, to determine which part of the query
> planning process is slow here?
> [...]

After planning profiling, (or in //), you can try to limit the number of
plans
that the planner has to evaluate:

setting enable_mergejoin to off, or some others from
https://www.postgresql.org/docs/10/static/runtime-config-query.html
but you will have to check that the chosen plan is still good

An other way is maybe reducing the number of indexes (you have so many
ones ...). Usually, needed indexes are PK, UK, indexes for FK, and a "few"
more.

Could you provide the SQL query to check that ?

Regards
PAscal  




--
Sent from: http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

swift1984
In reply to this post by Tomas Vondra-4
Hi,

Debug symbols can only be enabled during configure? How about when Postgresql is running?

Regards,
Richard Lee

On Fri, Nov 2, 2018 at 9:55 PM Tomas Vondra <[hidden email]> wrote:
On 11/02/2018 10:36 AM, Richard Lee wrote:
> Hi,
>
> I'm running a performance test for our application and encountered a
> particular query with high planning time compared to the execution.
> Please refer to attached explain.out for the explain analyze output.
>
> Formatted explain: https://explain.depesz.com/s/R834
>
> The test was performed with Jmeter sending requests to the database,
> query was generated by Hibernate which consists of a 133 table UNION.
> Also attached are some diagnostic info (database version, database
> settings, table definitions and maintenance related information).
>
> Due to the extremely large query text, I'm choosing to provide
> information via attachments instead of pasting in the email body.
>
> Below are some additional OS information on the database server:
> CPU: 8
> RAM: 24GB
> Disk: SSD
> OS: CentOS Linux release 7.4.1708 (Core)
>
> [root@kvrh7os202 ~]# uname -a
> Linux kvrh7os202.comptel.com <http://kvrh7os202.comptel.com>
> 3.10.0-693.21.1.el7.x86_64 #1 SMP Wed Mar 7 19:03:37 UTC 2018 x86_64
> x86_64 x86_64 GNU/Linux
> [root@kvrh7os202 ~]#
>
> Things I tried:
> 1. Setting random_page_cost = 1.1 and effective_io_concurrency = 200 -
> no effect on planning time
> 2. Create materialized view for big UNION query - planning time reduced
> significantly but not a viable solution
>

Those changes likely affect the query costing and execution, but the
number of plans to consider is probably not going to change much. So
planning taking about the same time is kinda expected here.

> What are my other options to improve the query planning time?
>

Can you do a bit of profiling, to determine which part of the query
planning process is slow here? That is:

1) make sure you have the debug symbols installed
2) do `perf record`
3) run the benchmark for a while (a minute or so)
4) stop the perf record using Ctrl-C
5) generate a profile using `perf report` and share the result

Possibly do the same thing with `perf record -g` to collect call-graph
information, but that's probably going way larger.

regards

--
Tomas Vondra                  http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

Justin Pryzby
On Mon, Nov 05, 2018 at 11:36:46AM +0800, Richard Lee wrote:
> Hi,
>
> Debug symbols can only be enabled during configure? How about when
> Postgresql is running?

If you're running from RPMs (maybe from yum.postgresql.org), you can install
postgresql10-debuginfo (maybe using: "debuginfo-install postgresql10").

Just be sure it installs the debuginfo for exactly the same RPM (rather than
installing a new minor version, for example).

If you compiled it yourself, you can probably point GDB to the un-stripped
binaries.  Again, assuming you have binaries from exactly the same source
version, no additional patches, etc.

Justin

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

swift1984
Hi,

I managed to install postgresql10-debuginfo:
[root@kvrh7os202 /]# yum install -y postgresql10-debuginfo.x86_64

Executed perf-record and perf-report:
-bash-4.2$ perf record -g -- psql -U sri sri < /var/lib/pgsql/10/data/pg_log/1-b10/query.txt
< ... snipped ... >
 Planning time: 1817.355 ms
 Execution time: 31.849 ms
(480 rows)

[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.025 MB perf.data (136 samples) ]
-bash-4.2$
-bash-4.2$ perf report -g > perf_report_20181105_1452.out

Please refer to the attached for the perf report output (not sure if it was done correctly).

Regards,
Richard Lee

On Mon, Nov 5, 2018 at 12:10 PM Justin Pryzby <[hidden email]> wrote:
On Mon, Nov 05, 2018 at 11:36:46AM +0800, Richard Lee wrote:
> Hi,
>
> Debug symbols can only be enabled during configure? How about when
> Postgresql is running?

If you're running from RPMs (maybe from yum.postgresql.org), you can install
postgresql10-debuginfo (maybe using: "debuginfo-install postgresql10").

Just be sure it installs the debuginfo for exactly the same RPM (rather than
installing a new minor version, for example).

If you compiled it yourself, you can probably point GDB to the un-stripped
binaries.  Again, assuming you have binaries from exactly the same source
version, no additional patches, etc.

Justin

perf_report_20181105_1452.out (146K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

Justin Pryzby
On Mon, Nov 05, 2018 at 03:04:29PM +0800, Richard Lee wrote:
> Executed perf-record and perf-report:
> -bash-4.2$ perf record -g -- psql -U sri sri <
> /var/lib/pgsql/10/data/pg_log/1-b10/query.txt
> < ... snipped ... >

That's showing perf output for the psql client.  What you want is output for
the server process (essentially all the client does is move data between the
user to the server).

https://wiki.postgresql.org/wiki/Profiling_with_perf

Justin

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: Query with high planning time compared to execution time

swift1984
Hi,

Ah, apologize for the mistake. The entire will take several hours to complete and the problem query won't be executed until about halfway through the benchmark. Should I do `perf record` when the query appears? Or one `perf record` at the start of the test and another one when the query appears? I imagine doing a `perf record` of the entire benchmark will fill the storage (only about 100GB of space on the server).

Regards,
Richard Lee

On Mon, Nov 5, 2018 at 9:55 PM Justin Pryzby <[hidden email]> wrote:
On Mon, Nov 05, 2018 at 03:04:29PM +0800, Richard Lee wrote:
> Executed perf-record and perf-report:
> -bash-4.2$ perf record -g -- psql -U sri sri <
> /var/lib/pgsql/10/data/pg_log/1-b10/query.txt
> < ... snipped ... >

That's showing perf output for the psql client.  What you want is output for
the server process (essentially all the client does is move data between the
user to the server).

https://wiki.postgresql.org/wiki/Profiling_with_perf

Justin