pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedSimple update query is slow
3+ messages / 2 participants
[nested] [flat]
* Simple update query is slow
@ 2020-11-21 20:27 Nandakumar M <m.nanda92@gmail.com>
2020-11-21 20:48 ` Re: Simple update query is slow Nandakumar M <m.nanda92@gmail.com>
0 siblings, 1 reply; 3+ messages in thread
From: Nandakumar M @ 2020-11-21 20:27 UTC (permalink / raw)
To: Pgsql Performance <pgsql-performance@lists.postgresql.org>
Hi,
I noticed something strange in our PG server. I have a table named
'timetable' that has only one bigint column and one row.
Once in every 5 seconds this row is updated to the current time epoch
value in milliseconds.
The update query seems to be taking considerable time (avg 50
milliseconds). When I tried generating the explain (analyze,buffers)
for the query, the planning time + execution time is always less than
0.1 millisecond. However the query time as shown when /timing of psql
is enabled shows approx 30 milliseconds (I am connecting via psql from
the localhost).
Please find the details below.
postgres=> select version();
version
----------------------------------------------------------------------------------------------------------------
PostgreSQL 9.4.15 on x86_64-unknown-linux-gnu, compiled by gcc (GCC)
4.4.7 20120313 (Red Hat 4.4.7-18), 64-bit
(1 row)
Time: 0.572 ms
postgres=> \d+ timetable
Table "public.timetable"
Column | Type | Modifiers | Storage | Stats target | Description
--------+--------+-----------+---------+--------------+-------------
time | bigint | | plain | |
postgres=> table timetable ;
time
------------
1605988584
(1 row)
Time: 0.402 ms
postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------
Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
time=0.064..0.064 rows=0 loops=1)
Buffers: shared hit=5
-> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
(actual time=0.029..0.029 rows=1 loops=1)
Output: ("time" + 0), ctid
Buffers: shared hit=4
Planning time: 0.054 ms
Execution time: 0.093 ms
(7 rows)
Time: 27.685 ms
Sometimes this shoots up to even a few hundred milliseconds.
postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------
Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
time=0.048..0.048 rows=0 loops=1)
Buffers: shared hit=5
-> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
(actual time=0.027..0.028 rows=1 loops=1)
Output: ("time" + 0), ctid
Buffers: shared hit=4
Planning time: 0.063 ms
Execution time: 0.084 ms
(7 rows)
Time: 291.090 ms
I guess the problem here may somehow be linked to frequent updates to
the one row. However I want to understand what exactly is going wrong
here. Also I don't understand the discrepancy between planning +
execution time from explain analyze and the time taken by the query as
reported in pg log and in psql console.
Kindly help me on this.
Regards,
Nanda
^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: Simple update query is slow
2020-11-21 20:27 Simple update query is slow Nandakumar M <m.nanda92@gmail.com>
@ 2020-11-21 20:48 ` Nandakumar M <m.nanda92@gmail.com>
2020-11-22 17:30 ` Re: Simple update query is slow Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 1 reply; 3+ messages in thread
From: Nandakumar M @ 2020-11-21 20:48 UTC (permalink / raw)
To: Pgsql Performance <pgsql-performance@lists.postgresql.org>
Hi,
Just realised that the time difference between explain analyze plan
and /timing result is due to the implicit commit.
Sorry about that.
Regards,
Nanda
On Sun, 22 Nov 2020 at 01:57, Nandakumar M <m.nanda92@gmail.com> wrote:
>
> Hi,
>
> I noticed something strange in our PG server. I have a table named
> 'timetable' that has only one bigint column and one row.
>
> Once in every 5 seconds this row is updated to the current time epoch
> value in milliseconds.
>
> The update query seems to be taking considerable time (avg 50
> milliseconds). When I tried generating the explain (analyze,buffers)
> for the query, the planning time + execution time is always less than
> 0.1 millisecond. However the query time as shown when /timing of psql
> is enabled shows approx 30 milliseconds (I am connecting via psql from
> the localhost).
>
>
> Please find the details below.
>
> postgres=> select version();
> version
> ----------------------------------------------------------------------------------------------------------------
> PostgreSQL 9.4.15 on x86_64-unknown-linux-gnu, compiled by gcc (GCC)
> 4.4.7 20120313 (Red Hat 4.4.7-18), 64-bit
> (1 row)
>
> Time: 0.572 ms
>
>
>
>
>
> postgres=> \d+ timetable
> Table "public.timetable"
> Column | Type | Modifiers | Storage | Stats target | Description
> --------+--------+-----------+---------+--------------+-------------
> time | bigint | | plain | |
>
>
>
>
>
>
> postgres=> table timetable ;
> time
> ------------
> 1605988584
> (1 row)
>
> Time: 0.402 ms
>
>
>
>
>
> postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
> QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------
> Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
> time=0.064..0.064 rows=0 loops=1)
> Buffers: shared hit=5
> -> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
> (actual time=0.029..0.029 rows=1 loops=1)
> Output: ("time" + 0), ctid
> Buffers: shared hit=4
> Planning time: 0.054 ms
> Execution time: 0.093 ms
> (7 rows)
>
> Time: 27.685 ms
>
>
> Sometimes this shoots up to even a few hundred milliseconds.
>
> postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
> QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------
> Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
> time=0.048..0.048 rows=0 loops=1)
> Buffers: shared hit=5
> -> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
> (actual time=0.027..0.028 rows=1 loops=1)
> Output: ("time" + 0), ctid
> Buffers: shared hit=4
> Planning time: 0.063 ms
> Execution time: 0.084 ms
> (7 rows)
>
> Time: 291.090 ms
>
>
>
>
> I guess the problem here may somehow be linked to frequent updates to
> the one row. However I want to understand what exactly is going wrong
> here. Also I don't understand the discrepancy between planning +
> execution time from explain analyze and the time taken by the query as
> reported in pg log and in psql console.
>
> Kindly help me on this.
>
> Regards,
> Nanda
^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: Simple update query is slow
2020-11-21 20:27 Simple update query is slow Nandakumar M <m.nanda92@gmail.com>
2020-11-21 20:48 ` Re: Simple update query is slow Nandakumar M <m.nanda92@gmail.com>
@ 2020-11-22 17:30 ` Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 0 replies; 3+ messages in thread
From: Justin Pryzby @ 2020-11-22 17:30 UTC (permalink / raw)
To: Nandakumar M <m.nanda92@gmail.com>; +Cc: Pgsql Performance <pgsql-performance@lists.postgresql.org>
On Sun, Nov 22, 2020 at 02:18:10AM +0530, Nandakumar M wrote:
> Just realised that the time difference between explain analyze plan
> and /timing result is due to the implicit commit.
Can you run with SET client_min_messages=debug; and SET log_lock_waits=on;
Oh, but your server is too old for that...
On Sun, 22 Nov 2020 at 01:57, Nandakumar M <m.nanda92@gmail.com> wrote:
>
> Hi,
>
> I noticed something strange in our PG server. I have a table named
> 'timetable' that has only one bigint column and one row.
>
> Once in every 5 seconds this row is updated to the current time epoch
> value in milliseconds.
>
> The update query seems to be taking considerable time (avg 50
> milliseconds). When I tried generating the explain (analyze,buffers)
> for the query, the planning time + execution time is always less than
> 0.1 millisecond. However the query time as shown when /timing of psql
> is enabled shows approx 30 milliseconds (I am connecting via psql from
> the localhost).
>
>
> Please find the details below.
>
> postgres=> select version();
> version
> ----------------------------------------------------------------------------------------------------------------
> PostgreSQL 9.4.15 on x86_64-unknown-linux-gnu, compiled by gcc (GCC)
> 4.4.7 20120313 (Red Hat 4.4.7-18), 64-bit
> (1 row)
>
> Time: 0.572 ms
>
>
>
>
>
> postgres=> \d+ timetable
> Table "public.timetable"
> Column | Type | Modifiers | Storage | Stats target | Description
> --------+--------+-----------+---------+--------------+-------------
> time | bigint | | plain | |
>
>
>
>
>
>
> postgres=> table timetable ;
> time
> ------------
> 1605988584
> (1 row)
>
> Time: 0.402 ms
>
>
>
>
>
> postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
> QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------
> Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
> time=0.064..0.064 rows=0 loops=1)
> Buffers: shared hit=5
> -> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
> (actual time=0.029..0.029 rows=1 loops=1)
> Output: ("time" + 0), ctid
> Buffers: shared hit=4
> Planning time: 0.054 ms
> Execution time: 0.093 ms
> (7 rows)
>
> Time: 27.685 ms
>
>
> Sometimes this shoots up to even a few hundred milliseconds.
>
> postgres=> explain (analyze,buffers,verbose) update timetable set time = time+0;
> QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------
> Update on public.timetable (cost=0.00..4.01 rows=1 width=14) (actual
> time=0.048..0.048 rows=0 loops=1)
> Buffers: shared hit=5
> -> Seq Scan on public.timetable (cost=0.00..4.01 rows=1 width=14)
> (actual time=0.027..0.028 rows=1 loops=1)
> Output: ("time" + 0), ctid
> Buffers: shared hit=4
> Planning time: 0.063 ms
> Execution time: 0.084 ms
> (7 rows)
>
> Time: 291.090 ms
>
> I guess the problem here may somehow be linked to frequent updates to
> the one row. However I want to understand what exactly is going wrong
> here. Also I don't understand the discrepancy between planning +
> execution time from explain analyze and the time taken by the query as
> reported in pg log and in psql console.
^ permalink raw reply [nested|flat] 3+ messages in thread
end of thread, other threads:[~2020-11-22 17:30 UTC | newest]
Thread overview: 3+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2020-11-21 20:27 Simple update query is slow Nandakumar M <m.nanda92@gmail.com>
2020-11-21 20:48 ` Nandakumar M <m.nanda92@gmail.com>
2020-11-22 17:30 ` Justin Pryzby <pryzby@telsasoft.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox