Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qcfuO-00G54E-06 for pgsql-bugs@arkaria.postgresql.org; Sun, 03 Sep 2023 05:44:29 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1qcfuK-00FNZv-RD for pgsql-bugs@arkaria.postgresql.org; Sun, 03 Sep 2023 05:44:24 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qcfuJ-00FNZn-1p for pgsql-bugs@lists.postgresql.org; Sun, 03 Sep 2023 05:44:24 +0000 Received: from wout4-smtp.messagingengine.com ([64.147.123.20]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qcfu7-002gf2-R2 for pgsql-bugs@lists.postgresql.org; Sun, 03 Sep 2023 05:44:21 +0000 Received: from compute3.internal (compute3.nyi.internal [10.202.2.43]) by mailout.west.internal (Postfix) with ESMTP id 63AD732004ED; Sun, 3 Sep 2023 01:44:07 -0400 (EDT) Received: from mailfrontend2 ([10.202.2.163]) by compute3.internal (MEProxy); Sun, 03 Sep 2023 01:44:08 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=paquier.xyz; h= cc:cc:content-type:content-type:date:date:from:from:in-reply-to :in-reply-to:message-id:mime-version:references:reply-to:sender :subject:subject:to:to; s=fm1; t=1693719846; x=1693806246; bh=3+ v3xPIqa7z9rXY1/lS4lnWu2bB5cuFgA38srAN1hkA=; b=ekgyvdmLbplP5uW9jy UjICAhuZ7IAFgNNzGMlQwPUx1z5ot/LEtYlV4tjQSmbEeRDbVcVi54IrE0YroFCI iWu8YXyGP2AMyKiIYAFBgr7zNauLebMwaMZcUOfz7gLI3H6/iAs7HRO22FGwzCkx J8B47W1imQuJQps6aKHZYuyXCa7dnsa++IUOpAd2nRocvoOsTzkVDuHsDQFVxH7Q sat8j3KLviZWk7/vLJGee27Ec6qiD6prKT6LdC4PkdEf9GoFIeaElBD/yyZ2l2L4 bh5zFLoh/30vBbpf4kcYx1yJ47yMaLftrl+n2FYNcWyQ/qt+a0JjtcAdC36o9BNK DioA== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= messagingengine.com; h=cc:cc:content-type:content-type:date:date :feedback-id:feedback-id:from:from:in-reply-to:in-reply-to :message-id:mime-version:references:reply-to:sender:subject :subject:to:to:x-me-proxy:x-me-proxy:x-me-sender:x-me-sender :x-sasl-enc; s=fm1; t=1693719846; x=1693806246; bh=3+v3xPIqa7z9r XY1/lS4lnWu2bB5cuFgA38srAN1hkA=; b=RfzxVyA5YH9StRUedONaiQc/Ko0oR dBVmdIX8Yhr3HfkO6X1W772IfFkfhrjaj0x8Si4647UOi620H07wsHF9djbp61b8 b0XSk7FdiS0UKZaj+O5Ugye8MNfrKL5vy0Bs2+zOw3bGwwJsBHNh1r/B1b5ot89N 40kUDXnMMWhk8gw34oNUn6uab2JxeIYZqxgPTU9JwDRNuISZee4h/TYuSI+3Q+sL NQbUMFp0s4PZSavQNV31vbhQLsOtjrQ9OXgToXTQj5gPRzpgR8BVP4pzu5vZNpOR 2WjV07PqkTZT4oEBXEFCMesSBoZ27MVPr6DJIXWt7K0l8dF5Ay6+zDu8Q== X-ME-Sender: X-ME-Received: X-ME-Proxy-Cause: gggruggvucftvghtrhhoucdtuddrgedviedrudeghedguddttdcutefuodetggdotefrod ftvfcurfhrohhfihhlvgemucfhrghsthforghilhdpqfgfvfdpuffrtefokffrpgfnqfgh necuuegrihhlohhuthemuceftddtnecusecvtfgvtghiphhivghnthhsucdlqddutddtmd enfghrlhcuvffnffculdejtddmnecujfgurhepfffhvfevuffkfhggtggujgesghdtreer tddtvdenucfhrhhomhepofhitghhrggvlhcurfgrqhhuihgvrhcuoehmihgthhgrvghlse hprghquhhivghrrdighiiiqeenucggtffrrghtthgvrhhnpeetleeifedufffhhfdtteel geeggeffhfekueevteeigfduudevudetgfegiedvjeenucevlhhushhtvghrufhiiigvpe dtnecurfgrrhgrmhepmhgrihhlfhhrohhmpehmihgthhgrvghlsehprghquhhivghrrdig hiii X-ME-Proxy: Feedback-ID: i0fe9450f:Fastmail Received: by mail.messagingengine.com (Postfix) with ESMTPA; Sun, 3 Sep 2023 01:44:03 -0400 (EDT) Date: Sun, 3 Sep 2023 14:43:57 +0900 From: Michael Paquier To: Sergei Kornilov Cc: Noah Misch , Tom Lane , Kyotaro Horiguchi , exclusion@gmail.com, pgsql-bugs@lists.postgresql.org, Thomas Munro Subject: Re: BUG #17928: Standby fails to decode WAL on termination of primary Message-ID: References: <1641161693655508@ske52ucy55r5y36k.iva.yp-c.yandex.net> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="Kcq9ATppbwVD8gFM" Content-Disposition: inline In-Reply-To: List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --Kcq9ATppbwVD8gFM Content-Type: multipart/mixed; boundary="97jrThmcc8UJq5uB" Content-Disposition: inline --97jrThmcc8UJq5uB Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Sun, Sep 03, 2023 at 08:42:55AM +0900, Michael Paquier wrote: > I think that's just a mistake I did, as there should not even be a > need for having to specify "server/" for the header path. If you > switch scan_header() in Utils.pm to use --includedir-server rather > than --includedir, does it work correctly for you?=20 In short, I mean something like the v4 attached. Feel free to use it for your tests. -- Michael --97jrThmcc8UJq5uB Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v4-0001-Add-TAP-tests-for-end-of-WAL-conditions.patch" Content-Transfer-Encoding: quoted-printable =46rom 8a8dd8252dd3b096d1c652ab78671d6457ecc95a Mon Sep 17 00:00:00 2001 =46rom: Thomas Munro Date: Tue, 15 Aug 2023 17:37:53 +1200 Subject: [PATCH v4 1/3] Add TAP tests for end-of-WAL conditions. XXX --- src/test/recovery/meson.build | 1 + src/test/recovery/t/038_end_of_wal.pl | 415 ++++++++++++++++++++++++++ 2 files changed, 416 insertions(+) create mode 100644 src/test/recovery/t/038_end_of_wal.pl diff --git a/src/test/recovery/meson.build b/src/test/recovery/meson.build index e7328e4894..10407668d4 100644 --- a/src/test/recovery/meson.build +++ b/src/test/recovery/meson.build @@ -43,6 +43,7 @@ tests +=3D { 't/035_standby_logical_decoding.pl', 't/036_truncated_dropped.pl', 't/037_invalid_database.pl', + 't/038_end_of_wal.pl', ], }, } diff --git a/src/test/recovery/t/038_end_of_wal.pl b/src/test/recovery/t/03= 8_end_of_wal.pl new file mode 100644 index 0000000000..fefb5b6034 --- /dev/null +++ b/src/test/recovery/t/038_end_of_wal.pl @@ -0,0 +1,415 @@ +# Copyright (c) 2023, PostgreSQL Global Development Group +# +# Test ways of detecting end of WAL. + +use strict; +use warnings; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; +use Fcntl qw(SEEK_SET); + +use integer; # causes / operator to use integer math + +# Values that could be extracted from the source tree +my $RECORD_HEADER_SIZE =3D 24; +my $XLP_PAGE_MAGIC =3D 0xd113; +my $XLP_FIRST_IS_CONTRECORD =3D 0x1; + +# Values queried from the server +my $WAL_SEGMENT_SIZE; +my $WAL_BLOCK_SIZE; + +sub wal_segment_path +{ + my $node =3D shift; + my $tli =3D shift; + my $segment =3D shift; + my $wal_path =3D sprintf("%s/pg_wal/%08X%08X%08X", + $node->data_dir, + $tli, + 0, + $segment); + return $wal_path; +} + +sub lsn_to_segment_and_offset +{ + my $lsn =3D shift; + return ($lsn / $WAL_SEGMENT_SIZE, $lsn % $WAL_SEGMENT_SIZE); +} + +sub get_log_size +{ + my $node =3D shift; + return (stat $node->logfile)[7]; +} + +sub write_wal +{ + my $node =3D shift; + my $tli =3D shift; + my $lsn =3D shift; + my $data =3D shift; + + my ($segment, $offset) =3D lsn_to_segment_and_offset($lsn); + my $path =3D wal_segment_path($node, $tli, $segment); + + open my $fh, "+<:raw", $path or die; + seek($fh, $offset, SEEK_SET) or die; + print $fh $data; + close $fh; +} + +sub emit_message +{ + my $node =3D shift; + my $size =3D shift; + return int($node->safe_psql('postgres', "select pg_logical_emit_message(t= rue, '', repeat('a', $size)) - '0/0'")); +} + +sub get_insert_lsn +{ + my $node =3D shift; + return int($node->safe_psql('postgres', "select pg_current_wal_insert_lsn= () - '0/0'")); +} + +sub get_int_setting +{ + my $node =3D shift; + my $name =3D shift; + return int($node->safe_psql('postgres', "select setting from pg_settings = where name =3D '$name'")); +} + +sub format_lsn +{ + my $lsn =3D shift; + return sprintf("%X/%X", $lsn >> 32, $lsn & 0xffffffff); +} + +sub start_of_page +{ + my $lsn =3D shift; + return $lsn & ~($WAL_BLOCK_SIZE - 1); +} + +sub start_of_next_page +{ + my $lsn =3D shift; + return start_of_page($lsn) + $WAL_BLOCK_SIZE; +} + +sub record_header +{ + my $xl_tot_len =3D shift; + my $xl_xid =3D shift || 0; + my $xl_prev =3D shift || 0; + my $xl_info =3D shift || 0; + my $xl_rmid =3D shift || 0; + my $xl_crc =3D shift || 0; + + # struct XLogRecord + return pack("IIQCCBBI", + $xl_tot_len, + $xl_xid, + $xl_prev, + $xl_info, + $xl_rmid, + 0, + 0, + $xl_crc); +} + +sub page_header +{ + my $xlp_magic =3D shift; + my $xlp_info =3D shift || 0; + my $xlp_tli =3D shift || 0; + my $xlp_pageaddr =3D shift || 0; + my $xlp_rem_len =3D shift || 0; + + # struct XLogPageHeaderData + return pack("SSIQI", + $xlp_magic, + $xlp_info, + $xlp_tli, + $xlp_pageaddr, + $xlp_rem_len); +} + +# Make sure we are far away enough from the end of a page that we could in= sert +# a couple of small records. +sub advance_out_of_record_splitting_zone +{ + my $node =3D shift; + + my $end_lsn =3D get_insert_lsn($node); + my $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; + while ($page_offset >=3D $WAL_BLOCK_SIZE - 2000) + { + $end_lsn =3D emit_message($node, 2000); + $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; + } + return $end_lsn; +} + +# Advance so close to the end of a page that an XLogRecordHeader wouldn't = fit. +sub advance_to_record_splitting_zone +{ + my $node =3D shift; + + my $end_lsn =3D get_insert_lsn($node); + my $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; + + # get fairly close to the end of a page in big steps + while ($page_offset <=3D $WAL_BLOCK_SIZE - 512) + { + $end_lsn =3D emit_message($node, $WAL_BLOCK_SIZE - $page_offset - 256); + $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; + } + + # calibrate our message size so that we can get closer 8 bytes at + # a time (XXX something better is surely possible) + my $message_size =3D $WAL_BLOCK_SIZE - 80; + while ($page_offset <=3D $WAL_BLOCK_SIZE - $RECORD_HEADER_SIZE) + { + $end_lsn =3D emit_message($node, $message_size); + + my $old_offset =3D $page_offset; + $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; + + # adjust the message size until it causes 8 bytes changes in + # offset + my $delta =3D $page_offset - $old_offset; + if ($delta > 8) + { + $message_size -=3D 8; + } + elsif ($delta <=3D 0) + { + $message_size +=3D 8; + } + } + return $end_lsn; +} + + +my $node =3D PostgreSQL::Test::Cluster->new("node"); +$node->init; +$node->append_conf('postgresql.conf', + q[wal_level =3D minimal + autovacuum =3D off + checkpoint_timeout =3D '30min' +]); +$node->start; +$node->safe_psql('postgres', "create table t as select 42"); + +$WAL_SEGMENT_SIZE =3D get_int_setting($node, 'wal_segment_size'); +$WAL_BLOCK_SIZE =3D get_int_setting($node, 'wal_block_size'); + + +my $end_lsn; +my $prev_lsn; +my $log_size; + +########################################################################### +note "Single-page end-of-WAL detection"; +########################################################################### + +# xl_tot_len is 0 (a common case, we hit trailing zeroes) +$end_lsn =3D advance_out_of_record_splitting_zone($node); +$node->stop('immediate'); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid record length at .*: expected at least 24,= got 0", + $log_size), + "xl_tot_len zero"); + +# xl_tot_len is < 24 (presumably recycled garbage) +$end_lsn =3D advance_out_of_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(23)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid record length at .*: expected at least 24,= got 23", + $log_size), + "xl_tot_len short"); + +# need more pages, but xl_prev check fails first +$end_lsn =3D advance_out_of_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + 0xdeadbeef)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("record with incorrect prev-link 0/DEADBEEF at .*", + $log_size), + "xl_prev bad"); + +# xl_crc check fails +advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 10); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn - 8, '!'); # corrupt a byte in that record +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("incorrect resource manager data checksum in record= at .*", + $log_size), + "xl_crc bad"); + + +########################################################################### +note "Multi-page end-of-WAL detection, header is not split"; +########################################################################### + +# good xl_prev, we hit zero page next (zero magic) +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +#my $prev_lsn =3D emit_message($node, 0); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + $prev_lsn)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid magic number 0000 .* LSN .*", $log_size), + "xlp_magic zero"); + +# good xl_prev, we hit garbage page next (bad magic) +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + $prev_lsn)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header(0xcafe, + 0, + 1, + 0)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid magic number CAFE .* LSN .*", $log_size), + "xlp_magic bad"); + +# good xl_prev, we hit typical recycled page (good xlp_magic, bad xlp_page= addr) +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + $prev_lsn)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + 0, + 1, + 0xbaaaaaad)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $l= og_size), + "xlp_pageaddr bad"); + +# good xl_prev, xlp_magic, xlp_pageaddr, but bogus xlp_info +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 42, + $prev_lsn)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + 0x1234, + 1, + start_of_next_page($end_lsn))); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid info bits 1234 in .*, LSN .*,", $log_size), + "xlp_info bad"); + +# good xl_prev, xlp_magic, xlp_pageaddr, but xlp_info doesn't mention cont= record +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 42, + $prev_lsn)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + 0, + 1, + start_of_next_page($end_lsn))); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("there is no contrecord flag at .*", $log_size), + "xlp_info lacks XLP_FIRST_IS_CONTRECORD"); + +# good xl_prev, xlp_magic, xlp_pageaddr, xlp_info but xlp_rem_len doesn't = add up +$prev_lsn =3D advance_out_of_record_splitting_zone($node); +$end_lsn =3D emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 42, + $prev_lsn)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + $XLP_FIRST_IS_CONTRECORD, + 1, + start_of_next_page($end_lsn), + 123456)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_s= ize), + "xlp_rem_len bad"); + + +########################################################################### +note "Multi-page, but header is split, so page checks are done first"; +########################################################################### + +# xlp_prev is bad and xl_tot_len is too big, but we'll check xlp_magic fir= st +$end_lsn =3D advance_to_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + 0xdeadbeef)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid magic number 0000 .* LSN .*", $log_size), + "xlp_magic zero (split record header)"); + +# and we'll also check xlp_pageaddr before any header checks +$end_lsn =3D advance_to_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + 0xdeadbeef)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + $XLP_FIRST_IS_CONTRECORD, + 1, + 0xbaaaaaad)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $l= og_size), + "xlp_pageaddr bad (split record header)"); + +# we'll also discover that xlp_rem_len doesn't add up before any +# header checks +$end_lsn =3D advance_to_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + 0xdeadbeef)); +write_wal($node, 1, start_of_next_page($end_lsn), + page_header($XLP_PAGE_MAGIC, + $XLP_FIRST_IS_CONTRECORD, + 1, + start_of_next_page($end_lsn), + 123456)); +$log_size =3D get_log_size($node); +$node->start; +ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_s= ize), + "xlp_rem_len bad (split record header)"); + +done_testing(); --=20 2.40.1 --97jrThmcc8UJq5uB Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v4-0002-Don-t-trust-unvalidated-xl_tot_len.patch" Content-Transfer-Encoding: quoted-printable =46rom 4db94cbdf5075b84a2c8ccc257d90d3671624413 Mon Sep 17 00:00:00 2001 =46rom: Thomas Munro Date: Mon, 14 Aug 2023 17:06:42 +1200 Subject: [PATCH v4 2/3] Don't trust unvalidated xl_tot_len. xl_tot_len comes first in a WAL record. Usually we don't trust it to be the true length until we've validated the record header. If the record header was split across two pages, previously we wouldn't do the validation until after we'd already tried to allocate enough memory to hold the record, which was bad because it might actually be garbage bytes from a recycled WAL file, so we could try to allocate a lot of memory. Release 15 made it worse. Since 70b4f82a4b5, we'd at least generate an end-of-WAL condition if the garbage 4 byte value happened to be > 1GB, but we'd still try to allocate up to 1GB of memory bogusly otherwise. That was an improvement, but unfortunately release 15 tries to allocate another object before that, so you could get a FATAL error and recovery could fail. We can fix both variants of the problem more fundamentally in old and new branches using pre-existing page-level validation. Whenever a record header spans a page boundary, we just need to defer all memory allocation based on xl_tot_len until we've read the following page. At that point we know that its first sector is not recycled data, by checking its xlp_pageaddr, and that its xlp_rem_len agrees with xl_tot_len on the preceding page. That is strong evidence that xl_tot_len was truly the start of a record that was logged. This problem was most likely to occur on a standby, because walreceiver.c recycles WAL files without zeroing out trailing regions of each page. We should fix that too, but that wouldn't protect us from rare crash scenarios where the trailing zeroes don't make it to disk. Back-patch to 12. This failure mode is rare, and 11 is about to go out of support, so we decided not to change its final release. Reported-by: Alexander Lakhin Discussion: https://postgr.es/m/17928-aa92416a70ff44a2%40postgresql.org --- src/backend/access/transam/xlogreader.c | 110 +++++++++++++----------- 1 file changed, 61 insertions(+), 49 deletions(-) diff --git a/src/backend/access/transam/xlogreader.c b/src/backend/access/t= ransam/xlogreader.c index c9f9f6e98f..d5ed139131 100644 --- a/src/backend/access/transam/xlogreader.c +++ b/src/backend/access/transam/xlogreader.c @@ -203,18 +203,6 @@ allocate_recordbuf(XLogReaderState *state, uint32 recl= ength) =20 #ifndef FRONTEND =20 - /* - * Note that in much unlucky circumstances, the random data read from a - * recycled segment can cause this routine to be called with a size - * causing a hard failure at allocation. For a standby, this would cause - * the instance to stop suddenly with a hard failure, preventing it to - * retry fetching WAL from one of its sources which could allow it to move - * on with replay without a manual restart. If the data comes from a past - * recycled segment and is still valid, then the allocation may succeed - * but record checks are going to fail so this would be short-lived. If - * the allocation fails because of a memory shortage, then this is not a - * hard failure either per the guarantee given by MCXT_ALLOC_NO_OOM. - */ if (!AllocSizeIsValid(newSize)) return false; =20 @@ -669,41 +657,26 @@ restart: } else { - /* XXX: more validation should be done here */ - if (total_len < SizeOfXLogRecord) - { - report_invalid_record(state, - "invalid record length at %X/%X: expected at least %u, got %u", - LSN_FORMAT_ARGS(RecPtr), - (uint32) SizeOfXLogRecord, total_len); - goto err; - } + /* We'll validate the header once we have the next page. */ gotheader =3D false; } =20 /* - * Find space to decode this record. Don't allow oversized allocation if - * the caller requested nonblocking. Otherwise, we *have* to try to - * decode the record now because the caller has nothing else to do, so - * allow an oversized record to be palloc'd if that turns out to be - * necessary. + * Try to find space to decode this record, if we can do so without + * calling palloc. If we can't, we'll try again below after we've + * validated that total_len isn't garbage bytes from a recycled WAL page. */ decoded =3D XLogReadRecordAlloc(state, total_len, - !nonblocking /* allow_oversized */ ); - if (decoded =3D=3D NULL) + false /* allow_oversized */ ); + if (decoded =3D=3D NULL && nonblocking) { /* - * There is no space in the decode buffer. The caller should help - * with that problem by consuming some records. + * There is no space in the circular decode buffer, and the caller is + * only reading ahead. The caller should consume existing records to + * make space. */ - if (nonblocking) - return XLREAD_WOULDBLOCK; - - /* We failed to allocate memory for an oversized record. */ - report_invalid_record(state, - "out of memory while trying to decode a record of length %u", tot= al_len); - goto err; + return XLREAD_WOULDBLOCK; } =20 len =3D XLOG_BLCKSZ - RecPtr % XLOG_BLCKSZ; @@ -718,16 +691,11 @@ restart: assembled =3D true; =20 /* - * Enlarge readRecordBuf as needed. + * We always have space for a couple of pages, enough to validate a + * boundary-spanning record header. */ - if (total_len > state->readRecordBufSize && - !allocate_recordbuf(state, total_len)) - { - /* We treat this as a "bogus data" condition */ - report_invalid_record(state, "record length %u at %X/%X too long", - total_len, LSN_FORMAT_ARGS(RecPtr)); - goto err; - } + Assert(state->readRecordBufSize >=3D XLOG_BLCKSZ * 2); + Assert(state->readRecordBufSize >=3D len); =20 /* Copy the first fragment of the record from the first page. */ memcpy(state->readRecordBuf, @@ -824,8 +792,35 @@ restart: goto err; gotheader =3D true; } - } while (gotlen < total_len); =20 + /* + * We might need a bigger buffer. We have validated the record + * header, in the case that it split over a page boundary. We've + * also cross-checked total_len against xlp_rem_len on the second + * page, and verified xlp_pageaddr on both. + */ + if (total_len > state->readRecordBufSize) + { + char save_copy[XLOG_BLCKSZ * 2]; + + /* + * Save and restore the data we already had. It can't be more + * than two pages. + */ + Assert(gotlen <=3D lengthof(save_copy)); + Assert(gotlen <=3D state->readRecordBufSize); + memcpy(save_copy, state->readRecordBuf, gotlen); + if (!allocate_recordbuf(state, total_len)) + { + /* We treat this as a "bogus data" condition */ + report_invalid_record(state, "record length %u at %X/%X too long", + total_len, LSN_FORMAT_ARGS(RecPtr)); + goto err; + } + memcpy(state->readRecordBuf, save_copy, gotlen); + buffer =3D state->readRecordBuf + gotlen; + } + } while (gotlen < total_len); Assert(gotheader); =20 record =3D (XLogRecord *) state->readRecordBuf; @@ -867,6 +862,25 @@ restart: state->NextRecPtr -=3D XLogSegmentOffset(state->NextRecPtr, state->segcx= t.ws_segsize); } =20 + /* + * If we got here without a DecodedXLogRecord, it means we needed to + * validate total_len before trusting it, but by now now we've done that. + */ + if (decoded =3D=3D NULL) + { + Assert(!nonblocking); + decoded =3D XLogReadRecordAlloc(state, + total_len, + true /* allow_oversized */ ); + if (decoded =3D=3D NULL) + { + /* We failed to allocate memory for an oversized record. */ + report_invalid_record(state, + "out of memory while trying to decode a record of length %u", to= tal_len); + goto err; + } + } + if (DecodeXLogRecord(state, decoded, record, RecPtr, &errormsg)) { /* Record the location of the next record. */ @@ -895,8 +909,6 @@ restart: state->decode_queue_head =3D decoded; return XLREAD_SUCCESS; } - else - return XLREAD_FAIL; =20 err: if (assembled) --=20 2.40.1 --97jrThmcc8UJq5uB Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v4-0003-Adjust-few-things-on-top-of-Thomas-patch-series.patch" Content-Transfer-Encoding: quoted-printable =46rom 2a7d5d6a660bdbb04b50515e9b09bee4e8f694d8 Mon Sep 17 00:00:00 2001 =46rom: Michael Paquier Date: Sun, 3 Sep 2023 14:38:27 +0900 Subject: [PATCH v4 3/3] Adjust few things on top of Thomas' patch series --- src/backend/access/transam/xlogreader.c | 10 +- src/test/perl/PostgreSQL/Test/Utils.pm | 43 +++ src/test/recovery/t/038_end_of_wal.pl | 386 +++++++++++++----------- 3 files changed, 253 insertions(+), 186 deletions(-) diff --git a/src/backend/access/transam/xlogreader.c b/src/backend/access/t= ransam/xlogreader.c index d5ed139131..5bc7639a00 100644 --- a/src/backend/access/transam/xlogreader.c +++ b/src/backend/access/transam/xlogreader.c @@ -192,6 +192,9 @@ XLogReaderFree(XLogReaderState *state) * XLOG_BLCKSZ, and make sure it's at least 5*Max(BLCKSZ, XLOG_BLCKSZ) to = start * with. (That is enough for all "normal" records, but very large commit = or * abort records might need more space.) + * + * Note: This routine should *never* be called for xl_tot_len until the he= ader + * of the record has been fully validated. */ static bool allocate_recordbuf(XLogReaderState *state, uint32 reclength) @@ -201,13 +204,6 @@ allocate_recordbuf(XLogReaderState *state, uint32 recl= ength) newSize +=3D XLOG_BLCKSZ - (newSize % XLOG_BLCKSZ); newSize =3D Max(newSize, 5 * Max(BLCKSZ, XLOG_BLCKSZ)); =20 -#ifndef FRONTEND - - if (!AllocSizeIsValid(newSize)) - return false; - -#endif - if (state->readRecordBuf) pfree(state->readRecordBuf); state->readRecordBuf =3D diff --git a/src/test/perl/PostgreSQL/Test/Utils.pm b/src/test/perl/Postgre= SQL/Test/Utils.pm index 617caa022f..9de34a2260 100644 --- a/src/test/perl/PostgreSQL/Test/Utils.pm +++ b/src/test/perl/PostgreSQL/Test/Utils.pm @@ -71,6 +71,7 @@ our @EXPORT =3D qw( chmod_recursive check_pg_config dir_symlink + scan_server_header system_or_bail system_log run_log @@ -702,6 +703,48 @@ sub chmod_recursive =20 =3Dpod =20 +=3Ditem scan_server_header(header_path, regexp) + +Returns an array that stores all the matches of the given regular expressi= on +within the PostgreSQL installation's C. This can be used to +retrieve specific value patterns from the installation's header files. + +=3Dcut + +sub scan_server_header +{ + my ($header_path, $regexp) =3D @_; + + my ($stdout, $stderr); + my $result =3D IPC::Run::run [ 'pg_config', '--includedir-server' ], '>', + \$stdout, '2>', \$stderr + or die "could not execute pg_config"; + chomp($stdout); + $stdout =3D~ s/\r$//; + + open my $header_h, '<', "$stdout/$header_path" or die "$!"; + + my @match =3D undef; + while (<$header_h>) + { + my $line =3D $_; + + if ($line =3D~ /^$regexp/) + { + # Found match, so store all the results. + @match =3D @{^CAPTURE}; + last; + } + } + + close $header_h; + die "could not find match in header $header_path\n" + unless @match; + return @match; +} + +=3Dpod + =3Ditem check_pg_config(regexp) =20 Return the number of matches of the given regular expression diff --git a/src/test/recovery/t/038_end_of_wal.pl b/src/test/recovery/t/03= 8_end_of_wal.pl index fefb5b6034..aa5eec7c03 100644 --- a/src/test/recovery/t/038_end_of_wal.pl +++ b/src/test/recovery/t/038_end_of_wal.pl @@ -1,6 +1,7 @@ # Copyright (c) 2023, PostgreSQL Global Development Group # -# Test ways of detecting end of WAL. +# Test detecting end of WAL replay. This test suite generates fake +# WAL records able to trigger various failure scenarios at replay. =20 use strict; use warnings; @@ -9,42 +10,44 @@ use PostgreSQL::Test::Utils; use Test::More; use Fcntl qw(SEEK_SET); =20 -use integer; # causes / operator to use integer math +use integer; # causes / operator to use integer math =20 -# Values that could be extracted from the source tree +# Header size of record header. my $RECORD_HEADER_SIZE =3D 24; -my $XLP_PAGE_MAGIC =3D 0xd113; -my $XLP_FIRST_IS_CONTRECORD =3D 0x1; + +# Fields retrieved from code headers. +my @scan_result =3D scan_server_header('access/xlog_internal.h', + '#define\s+XLOG_PAGE_MAGIC\s+(\w+)'); +my $XLP_PAGE_MAGIC =3D hex($scan_result[0]); +@scan_result =3D scan_server_header('access/xlog_internal.h', + '#define\s+XLP_FIRST_IS_CONTRECORD\s+(\w+)'); +my $XLP_FIRST_IS_CONTRECORD =3D hex($scan_result[0]); =20 # Values queried from the server my $WAL_SEGMENT_SIZE; my $WAL_BLOCK_SIZE; +my $TLI; =20 +# Build path of a WAL segment. sub wal_segment_path { my $node =3D shift; my $tli =3D shift; my $segment =3D shift; - my $wal_path =3D sprintf("%s/pg_wal/%08X%08X%08X", - $node->data_dir, - $tli, - 0, - $segment); + my $wal_path =3D + sprintf("%s/pg_wal/%08X%08X%08X", $node->data_dir, $tli, 0, $segment); return $wal_path; } =20 +# Calculate from a LSN (in bytes) its segment number and its offset. sub lsn_to_segment_and_offset { my $lsn =3D shift; return ($lsn / $WAL_SEGMENT_SIZE, $lsn % $WAL_SEGMENT_SIZE); } =20 -sub get_log_size -{ - my $node =3D shift; - return (stat $node->logfile)[7]; -} - +# Write some arbitrary data in WAL for the given segment at offset. +# This should be called while the cluster is offline. sub write_wal { my $node =3D shift; @@ -61,30 +64,37 @@ sub write_wal close $fh; } =20 +# Emit a WAL record of arbitrary size. Returns the end LSN of the +# record inserted, in bytes. sub emit_message { my $node =3D shift; my $size =3D shift; - return int($node->safe_psql('postgres', "select pg_logical_emit_message(t= rue, '', repeat('a', $size)) - '0/0'")); + return int( + $node->safe_psql( + 'postgres', + "SELECT pg_logical_emit_message(true, '', repeat('a', $size)) - '0/0'" + )); } =20 +# Get the current insert LSN of a node, in bytes. sub get_insert_lsn { my $node =3D shift; - return int($node->safe_psql('postgres', "select pg_current_wal_insert_lsn= () - '0/0'")); + return int( + $node->safe_psql( + 'postgres', "SELECT pg_current_wal_insert_lsn() - '0/0'")); } =20 +# Get GUC value, converted to an int. sub get_int_setting { my $node =3D shift; my $name =3D shift; - return int($node->safe_psql('postgres', "select setting from pg_settings = where name =3D '$name'")); -} - -sub format_lsn -{ - my $lsn =3D shift; - return sprintf("%X/%X", $lsn >> 32, $lsn & 0xffffffff); + return int( + $node->safe_psql( + 'postgres', + "SELECT setting FROM pg_settings WHERE name =3D '$name'")); } =20 sub start_of_page @@ -99,7 +109,10 @@ sub start_of_next_page return start_of_page($lsn) + $WAL_BLOCK_SIZE; } =20 -sub record_header +# Build a fake WAL record header based on the data given by the caller. +# This needs to follow the format of the C structure XLogRecord. To +# be inserted with write_wal(). +sub build_record_header { my $xl_tot_len =3D shift; my $xl_xid =3D shift || 0; @@ -108,19 +121,22 @@ sub record_header my $xl_rmid =3D shift || 0; my $xl_crc =3D shift || 0; =20 - # struct XLogRecord + # This needs to follow the structure XLogRecord: + # I for xl_tot_len + # I for xl_xid + # Q for xl_prev + # C for xl_info + # C for xl_rmid + # BB for two bytes of padding + # I for xl_crc return pack("IIQCCBBI", - $xl_tot_len, - $xl_xid, - $xl_prev, - $xl_info, - $xl_rmid, - 0, - 0, - $xl_crc); + $xl_tot_len, $xl_xid, $xl_prev, $xl_info, $xl_rmid, 0, 0, $xl_crc); } =20 -sub page_header +# Build a fake WAL page header, based on the data given by the caller +# This needs to follow the format of the C structure XLogPageHeaderData. +# To be inserted with write_wal(). +sub build_page_header { my $xlp_magic =3D shift; my $xlp_info =3D shift || 0; @@ -128,32 +144,37 @@ sub page_header my $xlp_pageaddr =3D shift || 0; my $xlp_rem_len =3D shift || 0; =20 - # struct XLogPageHeaderData + # This needs to follow the structure XLogPageHeaderData: + # S for xlp_magic + # S for xlp_info + # I for xlp_tli + # Q for xlp_pageaddr + # I for xlp_rem_len return pack("SSIQI", - $xlp_magic, - $xlp_info, - $xlp_tli, - $xlp_pageaddr, - $xlp_rem_len); + $xlp_magic, $xlp_info, $xlp_tli, $xlp_pageaddr, $xlp_rem_len); } =20 # Make sure we are far away enough from the end of a page that we could in= sert -# a couple of small records. +# a couple of small records. This inserts a few records of a fixed size, = until +# the threshold gets close enough to the end of the WAL page inserting rec= ords +# to. sub advance_out_of_record_splitting_zone { my $node =3D shift; =20 + my $page_threshold =3D $WAL_BLOCK_SIZE / 4; my $end_lsn =3D get_insert_lsn($node); my $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; - while ($page_offset >=3D $WAL_BLOCK_SIZE - 2000) + while ($page_offset >=3D $WAL_BLOCK_SIZE - $page_threshold) { - $end_lsn =3D emit_message($node, 2000); + $end_lsn =3D emit_message($node, $page_threshold); $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; } return $end_lsn; } =20 -# Advance so close to the end of a page that an XLogRecordHeader wouldn't = fit. +# Advance so close to the end of a page that an XLogRecordHeader would not +# fit on it. sub advance_to_record_splitting_zone { my $node =3D shift; @@ -161,15 +182,15 @@ sub advance_to_record_splitting_zone my $end_lsn =3D get_insert_lsn($node); my $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; =20 - # get fairly close to the end of a page in big steps + # Get fairly close to the end of a page in big steps while ($page_offset <=3D $WAL_BLOCK_SIZE - 512) { $end_lsn =3D emit_message($node, $WAL_BLOCK_SIZE - $page_offset - 256); $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; } =20 - # calibrate our message size so that we can get closer 8 bytes at - # a time (XXX something better is surely possible) + # Calibrate our message size so that we can get closer 8 bytes at + # a time. my $message_size =3D $WAL_BLOCK_SIZE - 80; while ($page_offset <=3D $WAL_BLOCK_SIZE - $RECORD_HEADER_SIZE) { @@ -178,8 +199,8 @@ sub advance_to_record_splitting_zone my $old_offset =3D $page_offset; $page_offset =3D $end_lsn % $WAL_BLOCK_SIZE; =20 - # adjust the message size until it causes 8 bytes changes in - # offset + # Adjust the message size until it causes 8 bytes changes in + # offset, enough to be able to split a record header. my $delta =3D $page_offset - $old_offset; if ($delta > 8) { @@ -193,223 +214,230 @@ sub advance_to_record_splitting_zone return $end_lsn; } =20 - +# Setup a new node. The configuration chosen here minimizes the number +# of arbitrary records that could get generated in a cluster. Enlarging +# checkpoint_timeout avoids noise with checkpoint activity. wal_level +# set to "minimal" avoids random standby snapshot records. Autovacuum +# could also trigger randomly, generating random WAL activity of its own. my $node =3D PostgreSQL::Test::Cluster->new("node"); $node->init; -$node->append_conf('postgresql.conf', - q[wal_level =3D minimal +$node->append_conf( + 'postgresql.conf', + q[wal_level =3D minimal autovacuum =3D off checkpoint_timeout =3D '30min' ]); $node->start; -$node->safe_psql('postgres', "create table t as select 42"); +$node->safe_psql('postgres', "CREATE TABLE t AS SELECT 42"); =20 $WAL_SEGMENT_SIZE =3D get_int_setting($node, 'wal_segment_size'); $WAL_BLOCK_SIZE =3D get_int_setting($node, 'wal_block_size'); - +$TLI =3D $node->safe_psql('postgres', + "SELECT timeline_id FROM pg_control_checkpoint();"); =20 my $end_lsn; my $prev_lsn; -my $log_size; =20 ########################################################################### note "Single-page end-of-WAL detection"; ########################################################################### =20 -# xl_tot_len is 0 (a common case, we hit trailing zeroes) +# xl_tot_len is 0 (a common case, we hit trailing zeroes). $end_lsn =3D advance_out_of_record_splitting_zone($node); $node->stop('immediate'); -$log_size =3D get_log_size($node); +my $log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("invalid record length at .*: expected at least 24,= got 0", - $log_size), - "xl_tot_len zero"); +ok( $node->log_contains( + "invalid record length at .*: expected at least 24, got 0", $log_size + ), + "xl_tot_len zero"); =20 -# xl_tot_len is < 24 (presumably recycled garbage) +# xl_tot_len is < 24 (presumably recycled garbage). $end_lsn =3D advance_out_of_record_splitting_zone($node); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(23)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, build_record_header(23)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("invalid record length at .*: expected at least 24,= got 23", - $log_size), - "xl_tot_len short"); +ok( $node->log_contains( + "invalid record length at .*: expected at least 24, got 23", + $log_size), + "xl_tot_len short"); =20 -# need more pages, but xl_prev check fails first +# Need more pages, but xl_prev check fails first. $end_lsn =3D advance_out_of_record_splitting_zone($node); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - 0xdeadbeef)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, 0xdeadbeef)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("record with incorrect prev-link 0/DEADBEEF at .*", - $log_size), - "xl_prev bad"); +ok( $node->log_contains( + "record with incorrect prev-link 0/DEADBEEF at .*", $log_size), + "xl_prev bad"); =20 -# xl_crc check fails +# xl_crc check fails. advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 10); $node->stop('immediate'); -write_wal($node, 1, $end_lsn - 8, '!'); # corrupt a byte in that record -$log_size =3D get_log_size($node); +# Corrupt a byte in that record, breaking its CRC. +write_wal($node, $TLI, $end_lsn - 8, '!'); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("incorrect resource manager data checksum in record= at .*", - $log_size), - "xl_crc bad"); +ok( $node->log_contains( + "incorrect resource manager data checksum in record at .*", $log_size + ), + "xl_crc bad"); =20 =20 ########################################################################### note "Multi-page end-of-WAL detection, header is not split"; ########################################################################### =20 -# good xl_prev, we hit zero page next (zero magic) +# This series of tests requires a valid xl_prev set in the record header +# written to WAL. + +# Good xl_prev, we hit zero page next (zero magic). $prev_lsn =3D advance_out_of_record_splitting_zone($node); -#my $prev_lsn =3D emit_message($node, 0); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - $prev_lsn)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, $prev_lsn)); +$log_size =3D -s $node->logfile; $node->start; ok($node->log_contains("invalid magic number 0000 .* LSN .*", $log_size), - "xlp_magic zero"); + "xlp_magic zero"); =20 -# good xl_prev, we hit garbage page next (bad magic) +# Good xl_prev, we hit garbage page next (bad magic). $prev_lsn =3D advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - $prev_lsn)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header(0xcafe, - 0, - 1, - 0)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, $prev_lsn)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header(0xcafe, 0, 1, 0)); +$log_size =3D -s $node->logfile; $node->start; ok($node->log_contains("invalid magic number CAFE .* LSN .*", $log_size), - "xlp_magic bad"); + "xlp_magic bad"); =20 -# good xl_prev, we hit typical recycled page (good xlp_magic, bad xlp_page= addr) +# Good xl_prev, we hit typical recycled page (good xlp_magic, bad +# xlp_pageaddr). $prev_lsn =3D advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - $prev_lsn)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - 0, - 1, - 0xbaaaaaad)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, $prev_lsn)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header($XLP_PAGE_MAGIC, 0, 1, 0xbaaaaaad)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $l= og_size), - "xlp_pageaddr bad"); +ok( $node->log_contains( + "unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $log_size), + "xlp_pageaddr bad"); =20 -# good xl_prev, xlp_magic, xlp_pageaddr, but bogus xlp_info +# Good xl_prev, xlp_magic, xlp_pageaddr, but bogus xlp_info. $prev_lsn =3D advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 42, - $prev_lsn)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - 0x1234, - 1, - start_of_next_page($end_lsn))); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 42, $prev_lsn)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header( + $XLP_PAGE_MAGIC, 0x1234, 1, start_of_next_page($end_lsn))); +$log_size =3D -s $node->logfile; $node->start; ok($node->log_contains("invalid info bits 1234 in .*, LSN .*,", $log_size), - "xlp_info bad"); + "xlp_info bad"); =20 -# good xl_prev, xlp_magic, xlp_pageaddr, but xlp_info doesn't mention cont= record +# Good xl_prev, xlp_magic, xlp_pageaddr, but xlp_info doesn't mention +# continuation record. $prev_lsn =3D advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 42, - $prev_lsn)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - 0, - 1, - start_of_next_page($end_lsn))); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 42, $prev_lsn)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header($XLP_PAGE_MAGIC, 0, 1, start_of_next_page($end_lsn))); +$log_size =3D -s $node->logfile; $node->start; ok($node->log_contains("there is no contrecord flag at .*", $log_size), - "xlp_info lacks XLP_FIRST_IS_CONTRECORD"); + "xlp_info lacks XLP_FIRST_IS_CONTRECORD"); =20 -# good xl_prev, xlp_magic, xlp_pageaddr, xlp_info but xlp_rem_len doesn't = add up +# Good xl_prev, xlp_magic, xlp_pageaddr, xlp_info but xlp_rem_len doesn't = add +# up. $prev_lsn =3D advance_out_of_record_splitting_zone($node); $end_lsn =3D emit_message($node, 0); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 42, - $prev_lsn)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - $XLP_FIRST_IS_CONTRECORD, - 1, - start_of_next_page($end_lsn), - 123456)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 42, $prev_lsn)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header( + $XLP_PAGE_MAGIC, $XLP_FIRST_IS_CONTRECORD, + 1, start_of_next_page($end_lsn), + 123456)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_s= ize), - "xlp_rem_len bad"); +ok( $node->log_contains( + "invalid contrecord length 123456 .* at .*", $log_size), + "xlp_rem_len bad"); =20 =20 ########################################################################### note "Multi-page, but header is split, so page checks are done first"; ########################################################################### =20 -# xlp_prev is bad and xl_tot_len is too big, but we'll check xlp_magic fir= st +# xlp_prev is bad and xl_tot_len is too big, but we'll check xlp_magic fir= st. $end_lsn =3D advance_to_record_splitting_zone($node); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - 0xdeadbeef)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, 0xdeadbeef)); +$log_size =3D -s $node->logfile; $node->start; ok($node->log_contains("invalid magic number 0000 .* LSN .*", $log_size), - "xlp_magic zero (split record header)"); + "xlp_magic zero (split record header)"); =20 -# and we'll also check xlp_pageaddr before any header checks +# And we'll also check xlp_pageaddr before any header checks. $end_lsn =3D advance_to_record_splitting_zone($node); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - 0xdeadbeef)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - $XLP_FIRST_IS_CONTRECORD, - 1, - 0xbaaaaaad)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, 0xdeadbeef)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header( + $XLP_PAGE_MAGIC, $XLP_FIRST_IS_CONTRECORD, 1, 0xbaaaaaad)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $l= og_size), - "xlp_pageaddr bad (split record header)"); +ok( $node->log_contains( + "unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $log_size), + "xlp_pageaddr bad (split record header)"); =20 -# we'll also discover that xlp_rem_len doesn't add up before any -# header checks +# We'll also discover that xlp_rem_len doesn't add up before any +# header checks, $end_lsn =3D advance_to_record_splitting_zone($node); $node->stop('immediate'); -write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, - 0, - 0xdeadbeef)); -write_wal($node, 1, start_of_next_page($end_lsn), - page_header($XLP_PAGE_MAGIC, - $XLP_FIRST_IS_CONTRECORD, - 1, - start_of_next_page($end_lsn), - 123456)); -$log_size =3D get_log_size($node); +write_wal($node, $TLI, $end_lsn, + build_record_header(2 * 1024 * 1024 * 1024, 0, 0xdeadbeef)); +write_wal( + $node, $TLI, + start_of_next_page($end_lsn), + build_page_header( + $XLP_PAGE_MAGIC, $XLP_FIRST_IS_CONTRECORD, + 1, start_of_next_page($end_lsn), + 123456)); +$log_size =3D -s $node->logfile; $node->start; -ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_s= ize), - "xlp_rem_len bad (split record header)"); +ok( $node->log_contains( + "invalid contrecord length 123456 .* at .*", $log_size), + "xlp_rem_len bad (split record header)"); =20 done_testing(); --=20 2.40.1 --97jrThmcc8UJq5uB-- --Kcq9ATppbwVD8gFM Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmT0HR0ACgkQnvQgOdby QH0HFA//ZnRNcqUyyB36J/9NDF59l9Bf/Ti6luV5NvWlSr4eCmKBFB8heKo23Lmz BIzAw3jz+BPRYZXOcBG3svcDAjQsYFxSj60Cz7IElhSpAtIZ+iwyS9FDljbrkdDy VktuynhnuL9/msoK8hIf4T7WCz5150nmBeRDumUNUB2yZEmFyfn/Mqf029q9QkJk 9hlUR0XOzy8uK+/gu8rzlr8PzmOQKnm1/EoBgvei4POCD1HWTFYOi8bfFv9Tr+b2 QuoN5kHOiANaHKufIx5G87MVi3ncfk0xM2MIFRLvhlcsCoIdtGUFjYReBg8zCd8/ oaGlmlDn+RV6JYLrdjCu3OO8FWFGuFdeAqPODPd8CnkO/RJB0RICiFi7691LFomT XidS7b0pXcWeALmPRORLnvYKTCdCuo1tkXWnr8dv6oS7XRXl3Eu1rtbD6AtS3ISf miHUmRwI7tj0DdgTgwoz0OhWUi6VEBmIgPSB8G8ydVrQj9cOM4T5kP02LKWdoXZG pLunNISkOn8JdpWS1AK2Unfky6fXOrBej2cExw88CAWfWpKeZX9iRbT2iSuoY+mH Ud3/LpOHaffiHTYQ/rgm9Mj1qx0vG7I4GEQPFW4q1gvTFEY1ruzDyHR+SfkGHFBN BrHa7dPmQMIA6lkrULSu5n2zvL9U+CUk8fdUDCb8/cEXlID46Vs= =r4tD -----END PGP SIGNATURE----- --Kcq9ATppbwVD8gFM--