On 2020-11-09 21:53, Tom Lane wrote:
Alexey Kondratov <a.kondra...@postgrespro.ru> writes:
After fixing this issue I have noticed that it still dumps blocks
twice
at each timeout (here I set autoprewarm_interval to 15s):
...
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 don't think your 0001 is correct. It would be okay if apw_dump_now()
could be counted on to take negligible time, but we shouldn't assume
that should we?
Yes, it seems so, if I understand you correctly. I had a doubt about
possibility of pg_ctl to exit earlier than a dumping process. Now I
added an explicit wait for dump file into test.
I agree that the "continue" seems a bit bogus, because it's skipping
the ResetLatch call at the bottom of the loop; it's not quite clear
to me whether that's a good thing or not. But the general idea of
the existing code seems to be to loop around and make a fresh
calculation
of how-long-to-wait, and that doesn't seem wrong.
I have left the last patch intact, since it resolves the 'double dump'
issue, but I agree with нщгк point about existing logic of the code,
although it is a bit broken. So I have to think more about how to fix it
in a better way.
0002 seems like a pretty clear bug fix, though I wonder if this is
exactly
what we want to do going forward. It seems like a very large fraction
of
the callers of TimestampDifference would like to have the value in
msec,
which means we're doing a whole lot of expensive and error-prone
arithmetic to break down the difference to sec/usec and then put it
back together again. Let's get rid of that by inventing, say
TimestampDifferenceMilliseconds(...).
Yeah, I get into this problem after a bug in another extension —
pg_wait_sampling. I have attached 0002, which implements
TimestampDifferenceMilliseconds(), so 0003 just uses this new function
to solve the initial issues. If it looks good to you, then we can switch
all similar callers to it.
BTW, I see another bug of a related ilk. Look what
postgres_fdw/connection.c is doing:
TimestampDifference(now, endtime, &secs, µsecs);
/* To protect against clock skew, limit sleep to one
minute. */
cur_timeout = Min(60000, secs * USECS_PER_SEC +
microsecs);
/* Sleep until there's something to do */
wc = WaitLatchOrSocket(MyLatch,
WL_LATCH_SET |
WL_SOCKET_READABLE |
WL_TIMEOUT |
WL_EXIT_ON_PM_DEATH,
PQsocket(conn),
cur_timeout, PG_WAIT_EXTENSION);
WaitLatchOrSocket's timeout is measured in msec not usec. I think the
comment about "clock skew" is complete BS, and the Min() calculation
was
put in as a workaround by somebody observing that the sleep waited too
long, but not understanding why.
I wonder how many troubles one can get with all these unit conversions.
Regards
--
Alexey Kondratov
Postgres Professional https://www.postgrespro.com
Russian Postgres Company
From c79de17014753b311858b4570ca475f713328c62 Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.alek...@gmail.com>
Date: Mon, 9 Nov 2020 19:24:55 +0300
Subject: [PATCH v2 4/4] 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.c
index e5bd130bc8..872c7d51b1 100644
--- a/contrib/pg_prewarm/autoprewarm.c
+++ b/contrib/pg_prewarm/autoprewarm.c
@@ -236,7 +236,9 @@ autoprewarm_main(Datum main_arg)
{
last_dump_time = GetCurrentTimestamp();
apw_dump_now(true, false);
- continue;
+
+ /* We have to sleep even after a successful dump */
+ delay_in_ms = autoprewarm_interval * 1000;
}
/* Sleep until the next dump time. */
--
2.19.1
From c38c07708d57d6dec5a8a1697ca9c9810ad4d7ce Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.alek...@gmail.com>
Date: Mon, 9 Nov 2020 19:12:00 +0300
Subject: [PATCH v2 3/4] 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 | 8 +++-----
1 file changed, 3 insertions(+), 5 deletions(-)
diff --git a/contrib/pg_prewarm/autoprewarm.c b/contrib/pg_prewarm/autoprewarm.c
index d3dec6e3ec..e5bd130bc8 100644
--- a/contrib/pg_prewarm/autoprewarm.c
+++ b/contrib/pg_prewarm/autoprewarm.c
@@ -222,16 +222,14 @@ autoprewarm_main(Datum main_arg)
{
long delay_in_ms = 0;
TimestampTz next_dump_time = 0;
- long secs = 0;
- int usecs = 0;
/* Compute the next dump time. */
next_dump_time =
TimestampTzPlusMilliseconds(last_dump_time,
autoprewarm_interval * 1000);
- TimestampDifference(GetCurrentTimestamp(), next_dump_time,
- &secs, &usecs);
- delay_in_ms = secs + (usecs / 1000);
+ delay_in_ms =
+ TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
+ next_dump_time);
/* Perform a dump if it's time. */
if (delay_in_ms <= 0)
--
2.19.1
From 23a8a967e806b76f3ed2f9078d6c9afdc7a8dc48 Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.alek...@gmail.com>
Date: Mon, 9 Nov 2020 22:29:48 +0300
Subject: [PATCH v2 2/4] Implement TimestampDifferenceMilliseconds()
Many callers of TimestampDifference() actually want a difference
in milliseconds. This new function allows them to get rid of
unnecessary (and frequently unsafe) calculations of milliseconds from
seconds and microseconds.
---
src/backend/utils/adt/timestamp.c | 20 ++++++++++++++++++++
src/include/utils/timestamp.h | 2 ++
2 files changed, 22 insertions(+)
diff --git a/src/backend/utils/adt/timestamp.c b/src/backend/utils/adt/timestamp.c
index ea0ada704f..7b28f070cc 100644
--- a/src/backend/utils/adt/timestamp.c
+++ b/src/backend/utils/adt/timestamp.c
@@ -1666,6 +1666,26 @@ TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
}
}
+/*
+ * TimestampDifferenceMilliseconds -- convert the difference between two
+ * timestamps into integer milliseconds.
+ *
+ * Both inputs must be ordinary finite timestamps (in current usage,
+ * they'll be results from GetCurrentTimestamp()).
+ *
+ * We expect start_time <= stop_time. If not, we return zero.
+ */
+long
+TimestampDifferenceMilliseconds(TimestampTz start_time, TimestampTz stop_time)
+{
+ TimestampTz diff = stop_time - start_time;
+
+ if (diff <= 0)
+ return 0;
+ else
+ return (long) (diff / 1000);
+}
+
/*
* TimestampDifferenceExceeds -- report whether the difference between two
* timestamps is >= a threshold (expressed in milliseconds)
diff --git a/src/include/utils/timestamp.h b/src/include/utils/timestamp.h
index 16c3fd8ec9..d45bf2bb7b 100644
--- a/src/include/utils/timestamp.h
+++ b/src/include/utils/timestamp.h
@@ -72,6 +72,8 @@ extern TimestampTz GetSQLCurrentTimestamp(int32 typmod);
extern Timestamp GetSQLLocalTimestamp(int32 typmod);
extern void TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
long *secs, int *microsecs);
+extern long TimestampDifferenceMilliseconds(TimestampTz start_time,
+ TimestampTz stop_time);
extern bool TimestampDifferenceExceeds(TimestampTz start_time,
TimestampTz stop_time,
int msec);
--
2.19.1
From 52a77a5250f765c79ccda3af00906505c0163141 Mon Sep 17 00:00:00 2001
From: Alexey Kondratov <kondratov.alek...@gmail.com>
Date: Mon, 9 Nov 2020 19:04:10 +0300
Subject: [PATCH v2 1/4] pg_prewarm: add tap test for autoprewarm feature
---
contrib/pg_prewarm/Makefile | 2 +
contrib/pg_prewarm/t/001_autoprewarm.pl | 59 +++++++++++++++++++++++++
2 files changed, 61 insertions(+)
create mode 100644 contrib/pg_prewarm/t/001_autoprewarm.pl
diff --git a/contrib/pg_prewarm/Makefile b/contrib/pg_prewarm/Makefile
index 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.pl
new file mode 100644
index 0000000000..744c443169
--- /dev/null
+++ b/contrib/pg_prewarm/t/001_autoprewarm.pl
@@ -0,0 +1,59 @@
+#
+# 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;
+
+# Wait up to 180s for pg_prewarm to dump blocks.
+sub wait_for_dump
+{
+ my $path = shift;
+
+ foreach my $i (0 .. 1800)
+ {
+ last if -e $path;
+ usleep(100_000);
+ }
+}
+
+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_for_dump($blocks_path);
+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;
+
+wait_for_dump($blocks_path);
+ok(-e $blocks_path, 'file autoprewarm.blocks should be present in the PGDATA after clean shutdown');
base-commit: 8f113698b63b15a4e0a4b15d3ee37238c1d1821d
--
2.19.1
