From: Alexey Kondratov <a.kondratov@postgrespro.ru>
To: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Cc: Robert Haas <robertmhaas@gmail.com>
Subject: Misuse of TimestampDifference() in the autoprewarm feature of pg_prewarm
Date: Mon, 09 Nov 2020 19:45:18 +0300
Message-ID: <3b1c053a21c07c1ed5e00be3b2b855ef@postgrespro.ru> (raw)
Hi Hackers,
Today I have accidentally noticed that autoprewarm feature of pg_prewarm
used TimestampDifference()'s results in a wrong way.
First, it used *seconds* result from it as a *milliseconds*. It was
causing it to make dump file autoprewarm.blocks ~every second with
default setting of autoprewarm_interval = 300s.
Here is a log part with debug output in this case:
```
2020-11-09 19:09:00.162 MSK [85328] LOG: dumping autoprewarm.blocks
2020-11-09 19:09:01.161 MSK [85328] LOG: dumping autoprewarm.blocks
2020-11-09 19:09:02.160 MSK [85328] LOG: dumping autoprewarm.blocks
2020-11-09 19:09:03.159 MSK [85328] LOG: dumping autoprewarm.blocks
```
After fixing this issue I have noticed that it still dumps blocks twice
at each timeout (here I set autoprewarm_interval to 15s):
```
2020-11-09 19:18:59.692 MSK [85662] LOG: dumping autoprewarm.blocks
2020-11-09 19:18:59.700 MSK [85662] LOG: dumping autoprewarm.blocks
2020-11-09 19:19:14.694 MSK [85662] LOG: dumping autoprewarm.blocks
2020-11-09 19:19:14.704 MSK [85662] LOG: dumping autoprewarm.blocks
```
This happens because at timeout time we were using continue, but
actually we still have to wait the entire autoprewarm_interval after
successful dumping.
I have fixed both issues in the attached patches and also added a
minimalistic tap test as a first one to verify that this automatic
damping still works after refactoring. I put Robert into CC, since he is
an author of this feature.
What do you think?
Regards
--
Alexey Kondratov
Postgres Professional https://www.postgrespro.com
Russian Postgres Company
Attachments:download all (3 files, .tar.gz)v1-0003-pg_prewarm-refactor-autoprewarm-waits.patch (text/x-diff, 892B) download
From 6d4bab7f21c3661dd4dd5a0de7e097b1de3f642c Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.aleksey@gmail.com>
Date: Mon, 9 Nov 2020 19:24:55 +0300
Subject: [PATCH v1 3/3] pg_prewarm: refactor autoprewarm waits
Previously it was dumping twice at every timeout time.
---
contrib/pg_prewarm/autoprewarm.c | 4 +++-
1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/contrib/pg_prewarm/autoprewarm.c b/contrib/pg_prewarm/autoprewarm.cindex b18a065ed5..f52c83de1e 100644--- a/contrib/pg_prewarm/autoprewarm.c+++ b/contrib/pg_prewarm/autoprewarm.c@@ -238,7 +238,9 @@ autoprewarm_main(Datum main_arg)
{
last_dump_time = GetCurrentTimestamp();
apw_dump_now(true, false);
- continue;++ /* We have to sleep even after a successfull dump */+ delay_in_ms = autoprewarm_interval * 1000;
}
/* Sleep until the next dump time. */
--
2.19.1
v1-0002-pg_prewarm-fix-autoprewarm_interval-behaviour.patch (text/x-diff, 1.0K) download
From 8793b8beb6a5c1ae730f1fffb09dff64c83bc631 Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.aleksey@gmail.com>
Date: Mon, 9 Nov 2020 19:12:00 +0300
Subject: [PATCH v1 2/3] pg_prewarm: fix autoprewarm_interval behaviour.
Previously it misused seconds from TimestampDifference() as
milliseconds, so it was dumping autoprewarm.blocks ~every second
event with default autoprewarm_interval = 300s.
---
contrib/pg_prewarm/autoprewarm.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/contrib/pg_prewarm/autoprewarm.c b/contrib/pg_prewarm/autoprewarm.cindex d3dec6e3ec..b18a065ed5 100644--- a/contrib/pg_prewarm/autoprewarm.c+++ b/contrib/pg_prewarm/autoprewarm.c@@ -231,7 +231,7 @@ autoprewarm_main(Datum main_arg)
autoprewarm_interval * 1000);
TimestampDifference(GetCurrentTimestamp(), next_dump_time,
&secs, &usecs);
- delay_in_ms = secs + (usecs / 1000);+ delay_in_ms = secs * 1000 + (usecs / 1000);
/* Perform a dump if it's time. */
if (delay_in_ms <= 0)
--
2.19.1
v1-0001-pg_prewarm-add-tap-test-for-autoprewarm-feature.patch (text/x-diff, 2.4K) download
From 31dc30c97861afae9c34852afc5a5b1c91bbeadc Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.aleksey@gmail.com>
Date: Mon, 9 Nov 2020 19:04:10 +0300
Subject: [PATCH v1 1/3] pg_prewarm: add tap test for autoprewarm feature
---
contrib/pg_prewarm/Makefile | 2 +
contrib/pg_prewarm/t/001_autoprewarm.pl | 51 +++++++++++++++++++++++++
2 files changed, 53 insertions(+)
create mode 100644 contrib/pg_prewarm/t/001_autoprewarm.pl
diff --git a/contrib/pg_prewarm/Makefile b/contrib/pg_prewarm/Makefileindex b13ac3c813..9cfde8c4e4 100644--- a/contrib/pg_prewarm/Makefile+++ b/contrib/pg_prewarm/Makefile@@ -10,6 +10,8 @@ EXTENSION = pg_prewarm
DATA = pg_prewarm--1.1--1.2.sql pg_prewarm--1.1.sql pg_prewarm--1.0--1.1.sql
PGFILEDESC = "pg_prewarm - preload relation data into system buffer cache"
+TAP_TESTS = 1+
ifdef USE_PGXS
PG_CONFIG = pg_config
PGXS := $(shell $(PG_CONFIG) --pgxs)
diff --git a/contrib/pg_prewarm/t/001_autoprewarm.pl b/contrib/pg_prewarm/t/001_autoprewarm.plnew file mode 100644index 0000000000..b564c29931--- /dev/null+++ b/contrib/pg_prewarm/t/001_autoprewarm.pl@@ -0,0 +1,51 @@+#+# Check that pg_prewarm can dump blocks from shared buffers+# to PGDATA/autoprewarm.blocks.+#++use strict;+use Test::More;+use TestLib;+use Time::HiRes qw(usleep);+use warnings;++use PostgresNode;++plan tests => 3;++my $node = get_new_node("node");+$node->init;+$node->append_conf(+ 'postgresql.conf', qq(+shared_preload_libraries = 'pg_prewarm'+pg_prewarm.autoprewarm = 'on'+pg_prewarm.autoprewarm_interval = 1+));+$node->start;++my $blocks_path = $node->data_dir . '/autoprewarm.blocks';++# Check that we can dump blocks on timeout.+# Wait up to 180s for pg_prewarm to dump blocks.+foreach my $i (0 .. 1800)+{+ last if -e $blocks_path;+ usleep(100_000);+}+ok(-e $blocks_path, 'file autoprewarm.blocks should be present in the PGDATA');++# Check that we can dump blocks on shutdown.+$node->stop;+$node->append_conf(+ 'postgresql.conf', qq(+pg_prewarm.autoprewarm_interval = 0+));++# Remove autoprewarm.blocks+unlink($blocks_path) || die "$blocks_path: $!";+ok(!-e $blocks_path, 'sanity check, dump on timeout is turned off');++$node->start;+$node->stop;++ok(-e $blocks_path, 'file autoprewarm.blocks should be present in the PGDATA after clean shutdown');
base-commit: 8f113698b63b15a4e0a4b15d3ee37238c1d1821d
--
2.19.1
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: a.kondratov@postgrespro.ru, pgsql-hackers@lists.postgresql.org, robertmhaas@gmail.com
Subject: Re: Misuse of TimestampDifference() in the autoprewarm feature of pg_prewarm
In-Reply-To: <3b1c053a21c07c1ed5e00be3b2b855ef@postgrespro.ru>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
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