[prev in list] [next in list] [prev in thread] [next in thread]
List: postgresql-general
Subject: Re: How to investigate what postgres is spending time on
From: Chris Travers <chris.travers () gmail ! com>
Date: 2018-09-23 13:26:15
Message-ID: CAKt_ZfvFodk2LTYPKYH1Rr+gv_zqhSGxGU1YY0mSp8c9Ap2F_w () mail ! gmail ! com
[Download RAW message or body]
On Sun, Sep 23, 2018 at 1:15 PM Kim Rose Carlsen <krc@hiper.dk> wrote:
> Hi
>
>
> I have some simple INSERT / UPDATE queries, that takes a long time the
> first time they are run in out test environment, but I'm not sure what
> postgres is doing and what I can do to help it. Whats common is that the
> table contains many rows in the order of about 20 millions.
>
>
> Query:
>
> INSERT INTO communication.request_parameter (request_id,
> template_version_parameter_id, parameter_value)
> VALUES (1222, 1211, 122) RETURNING request_parameter_id
>
> Row from pg_stat_statements:
> -----------+------------+------------+---------------------------------------------- \
> ----------------+------------+------------------+------------+------------+--------- \
> -----------+--------------------+------------+------------+------------+------------ \
> +------------+------------+------------+------------+------------+------------+------------+------------+------------+-
> userid | dbid | queryid | query \
> | calls | total_time | min_time | max_time | mean_time | \
> stddev_time | rows | shared_blk | shared_blk | shared_blk | shared_blk \
> | local_blks | local_blks | local_blks | local_blks | temp_blks_ | temp_blks_ | \
> blk_read_t | blk_write_ |
> -----------+------------+------------+---------------------------------------------- \
> ----------------+------------+------------------+------------+------------+--------- \
> -----------+--------------------+------------+------------+------------+------------ \
> +------------+------------+------------+------------+------------+------------+------------+------------+------------+-
> 16385 | 16389 | 2064198912 | INSERT INTO communication.request_parameter \
> (request_id, tem | 98 | 646.393451 | 0.036666 | 638.712758 | \
> 6.59585154081633 | 64.1818799227704 | 98 | 2850 | 24 | 21 \
> | 0 | 0 | 0 | 0 | 0 | 0 | 0 \
> | 0 | 0 |
> Description of table:
> # \d communication.request_parameter
> Table
> "communication.request_parameter"
> Column | Type | Collation | Nullable
> >
> Default
>
> -------------------------------+-------------------+-----------+----------+-------------------------------------------------------------------------------
> request_parameter_id | integer | | not null
> >
> nextval('communication.request_parameter_request_parameter_id_seq'::regclass)
> request_id | integer | | not null
> >
> template_version_parameter_id | integer | | not null
> >
> parameter_value | character varying | |
> >
> Indexes:
> "request_parameter_pkey" PRIMARY KEY, btree (request_parameter_id)
> "request_parameter_parameter_value_idx" btree (parameter_value)
> "request_parameter_request_id_idx" btree (request_id)
> "request_parameter_template_version_parameter_id_idx" btree
> (template_version_parameter_id)
> Foreign-key constraints:
> "request_parameter_request_id_fkey" FOREIGN KEY (request_id)
> REFERENCES communication.request(request_id)
> "request_parameter_template_version_parameter_id_fkey" FOREIGN KEY
> (template_version_parameter_id) REFERENCES
> communication.template_version_parameter(template_version_parameter_id)
>
> This only happens in testing, and on a cold bootet database. The test
> database is constructed with pg_dump and restore on fresh postgres
> installation.
>
Sounds like warming up the cache, but still in a test environment you may
want to add auto_explain to your list of preloads and perhaps set it to
dump explain analyze when it hits a certain threshold. Note that while
dumping the query plans has very little overhead, timing the query plan
nodes does impact performance in a negative way.
>
>
> Best Regards
> Kim Carlsen
>
>
--
Best Wishes,
Chris Travers
Efficito: Hosted Accounting and ERP. Robust and Flexible. No vendor
lock-in.
http://www.efficito.com/learn_more
[Attachment #3 (text/html)]
<div dir="ltr"><br><br><div class="gmail_quote"><div dir="ltr">On Sun, Sep 23, 2018 \
at 1:15 PM Kim Rose Carlsen <<a href="mailto:krc@hiper.dk">krc@hiper.dk</a>> \
wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 \
.8ex;border-left:1px #ccc solid;padding-left:1ex">
<div dir="ltr">
<div id="m_-7687313927751469150divtagdefaultwrapper" \
style="font-size:10pt;color:#000000;font-family:Calibri,Helvetica,sans-serif" \
dir="ltr"> <p style="margin-top:0;margin-bottom:0">Hi</p>
<p style="margin-top:0;margin-bottom:0"><br>
</p>
<p style="margin-top:0;margin-bottom:0">I have some simple INSERT / UPDATE queries, \
that takes a long time the first time they are run in out test environment, but \
I'm not sure what postgres is doing and what I can do to help it. Whats common is \
that the table contains many rows in the order of about 20 millions.</p>
<p style="margin-top:0;margin-bottom:0"><br>
</p>
<p style="margin-top:0;margin-bottom:0">Query:<br>
</p>
<p style="margin-top:0;margin-bottom:0"></p>
<div>INSERT INTO communication.request_parameter (request_id, \
template_version_parameter_id, parameter_value) <br>
VALUES (1222, 1211, 122) RETURNING request_parameter_id</div>
<div><br>
</div>
<div>
<pre><pre>Row from pg_stat_statements:<br>-----------+------------+------------+------ \
--------------------------------------------------------+------------+---------------- \
--+------------+------------+--------------------+--------------------+------------+-- \
----------+------------+------------+------------+------------+------------+------------+------------+------------+------------+------------+------------+-
userid | dbid | queryid | query \
| calls | total_time | min_time | max_time | mean_time | \
stddev_time | rows | shared_blk | shared_blk | shared_blk | shared_blk | \
local_blks | local_blks | local_blks | local_blks | temp_blks_ | temp_blks_ | \
blk_read_t | blk_write_ |
-----------+------------+------------+------------------------------------------------ \
--------------+------------+------------------+------------+------------+------------- \
-------+--------------------+------------+------------+------------+------------+----- \
-------+------------+------------+------------+------------+------------+------------+------------+------------+-
16385 | 16389 | 2064198912 | INSERT INTO communication.request_parameter \
(request_id, tem | 98 | 646.393451 | 0.036666 | 638.712758 | \
6.59585154081633 | 64.1818799227704 | 98 | 2850 | 24 | 21 \
| 0 | 0 | 0 | 0 | 0 | 0 | 0 \
| 0 | 0 | </pre></pre> Description of table:<br>
</div>
<div>
<div></div>
<div># \d communication.request_parameter<br>
\
Table "communication.request_parameter"<br> Column \
| Type | Collation | Nullable | \
Default \
<br>
-------------------------------+-------------------+-----------+----------+-------------------------------------------------------------------------------<br>
request_parameter_id | integer | \
| not null | nextval('communication.request_parameter_request_parameter_id_seq'::regclass)<br>
request_id | integer | \
| not null | <br> template_version_parameter_id | integer | \
| not null | <br> parameter_value | character varying | \
| | <br> Indexes:<br>
"request_parameter_pkey" PRIMARY KEY, btree \
(request_parameter_id)<br>
"request_parameter_parameter_value_idx" btree (parameter_value)<br>
"request_parameter_request_id_idx" btree (request_id)<br>
"request_parameter_template_version_parameter_id_idx" btree \
(template_version_parameter_id)<br> Foreign-key constraints:<br>
"request_parameter_request_id_fkey" FOREIGN KEY (request_id) \
REFERENCES communication.request(request_id)<br> \
"request_parameter_template_version_parameter_id_fkey" FOREIGN KEY \
(template_version_parameter_id) REFERENCES \
communication.template_version_parameter(template_version_parameter_id)<br> </div>
<div><br>
</div>
<div>This only happens in testing, and on a cold bootet database. The test database \
is constructed with pg_dump and restore on fresh postgres \
installation.</div></div></div></div></blockquote><div><br></div><div>Sounds like \
warming up the cache, but still in a test environment you may want to add \
auto_explain to your list of preloads and perhaps set it to dump explain analyze when \
it hits a certain threshold. Note that while dumping the query plans has very \
little overhead, timing the query plan nodes does impact performance in a negative \
way. </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px \
#ccc solid;padding-left:1ex"><div dir="ltr"><div \
id="m_-7687313927751469150divtagdefaultwrapper" \
style="font-size:10pt;color:#000000;font-family:Calibri,Helvetica,sans-serif" \
dir="ltr"><div> <div><br>
</div>
<div><br>
</div>
</div>
<p></p>
<p style="margin-top:0;margin-bottom:0">Best Regards<br>
</p>
<div id="m_-7687313927751469150Signature">
<div id="m_-7687313927751469150divtagdefaultwrapper" \
style="font-size:10pt;color:#000000;background-color:#ffffff;font-family:Calibri,Arial,Helvetica,sans-serif">
<div style="font-family:Tahoma;font-size:13px">Kim Carlsen<br>
<br>
</div>
</div>
</div>
</div>
</div>
</blockquote></div><br clear="all"><div><br></div>-- <br><div dir="ltr" \
class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr">Best \
Wishes,<div>Chris Travers</div><div><br></div><div>Efficito: Hosted Accounting and \
ERP. Robust and Flexible. No vendor lock-in.</div><div><a \
href="http://www.efficito.com/learn_more" \
target="_blank">http://www.efficito.com/learn_more</a></div></div></div></div>
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic