From 8a8dd8252dd3b096d1c652ab78671d6457ecc95a Mon Sep 17 00:00:00 2001 From: Thomas Munro Date: Tue, 15 Aug 2023 17:37:53 +1200 Subject: [PATCH v3 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 += { '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/038_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 = 24; +my $XLP_PAGE_MAGIC = 0xd113; +my $XLP_FIRST_IS_CONTRECORD = 0x1; + +# Values queried from the server +my $WAL_SEGMENT_SIZE; +my $WAL_BLOCK_SIZE; + +sub wal_segment_path +{ + my $node = shift; + my $tli = shift; + my $segment = shift; + my $wal_path = sprintf("%s/pg_wal/%08X%08X%08X", + $node->data_dir, + $tli, + 0, + $segment); + return $wal_path; +} + +sub lsn_to_segment_and_offset +{ + my $lsn = shift; + return ($lsn / $WAL_SEGMENT_SIZE, $lsn % $WAL_SEGMENT_SIZE); +} + +sub get_log_size +{ + my $node = shift; + return (stat $node->logfile)[7]; +} + +sub write_wal +{ + my $node = shift; + my $tli = shift; + my $lsn = shift; + my $data = shift; + + my ($segment, $offset) = lsn_to_segment_and_offset($lsn); + my $path = 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 = shift; + my $size = shift; + return int($node->safe_psql('postgres', "select pg_logical_emit_message(true, '', repeat('a', $size)) - '0/0'")); +} + +sub get_insert_lsn +{ + my $node = shift; + return int($node->safe_psql('postgres', "select pg_current_wal_insert_lsn() - '0/0'")); +} + +sub get_int_setting +{ + my $node = shift; + my $name = shift; + return int($node->safe_psql('postgres', "select setting from pg_settings where name = '$name'")); +} + +sub format_lsn +{ + my $lsn = shift; + return sprintf("%X/%X", $lsn >> 32, $lsn & 0xffffffff); +} + +sub start_of_page +{ + my $lsn = shift; + return $lsn & ~($WAL_BLOCK_SIZE - 1); +} + +sub start_of_next_page +{ + my $lsn = shift; + return start_of_page($lsn) + $WAL_BLOCK_SIZE; +} + +sub record_header +{ + my $xl_tot_len = shift; + my $xl_xid = shift || 0; + my $xl_prev = shift || 0; + my $xl_info = shift || 0; + my $xl_rmid = shift || 0; + my $xl_crc = 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 = shift; + my $xlp_info = shift || 0; + my $xlp_tli = shift || 0; + my $xlp_pageaddr = shift || 0; + my $xlp_rem_len = 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 insert +# a couple of small records. +sub advance_out_of_record_splitting_zone +{ + my $node = shift; + + my $end_lsn = get_insert_lsn($node); + my $page_offset = $end_lsn % $WAL_BLOCK_SIZE; + while ($page_offset >= $WAL_BLOCK_SIZE - 2000) + { + $end_lsn = emit_message($node, 2000); + $page_offset = $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 = shift; + + my $end_lsn = get_insert_lsn($node); + my $page_offset = $end_lsn % $WAL_BLOCK_SIZE; + + # get fairly close to the end of a page in big steps + while ($page_offset <= $WAL_BLOCK_SIZE - 512) + { + $end_lsn = emit_message($node, $WAL_BLOCK_SIZE - $page_offset - 256); + $page_offset = $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 = $WAL_BLOCK_SIZE - 80; + while ($page_offset <= $WAL_BLOCK_SIZE - $RECORD_HEADER_SIZE) + { + $end_lsn = emit_message($node, $message_size); + + my $old_offset = $page_offset; + $page_offset = $end_lsn % $WAL_BLOCK_SIZE; + + # adjust the message size until it causes 8 bytes changes in + # offset + my $delta = $page_offset - $old_offset; + if ($delta > 8) + { + $message_size -= 8; + } + elsif ($delta <= 0) + { + $message_size += 8; + } + } + return $end_lsn; +} + + +my $node = PostgreSQL::Test::Cluster->new("node"); +$node->init; +$node->append_conf('postgresql.conf', + q[wal_level = minimal + autovacuum = off + checkpoint_timeout = '30min' +]); +$node->start; +$node->safe_psql('postgres', "create table t as select 42"); + +$WAL_SEGMENT_SIZE = get_int_setting($node, 'wal_segment_size'); +$WAL_BLOCK_SIZE = 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 = advance_out_of_record_splitting_zone($node); +$node->stop('immediate'); +$log_size = 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 = advance_out_of_record_splitting_zone($node); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(23)); +$log_size = 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 = 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 = 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 = emit_message($node, 10); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn - 8, '!'); # corrupt a byte in that record +$log_size = 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 = advance_out_of_record_splitting_zone($node); +#my $prev_lsn = emit_message($node, 0); +$end_lsn = emit_message($node, 0); +$node->stop('immediate'); +write_wal($node, 1, $end_lsn, record_header(2 * 1024 * 1024 * 1024, + 0, + $prev_lsn)); +$log_size = 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 = advance_out_of_record_splitting_zone($node); +$end_lsn = 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 = 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_pageaddr) +$prev_lsn = advance_out_of_record_splitting_zone($node); +$end_lsn = 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 = get_log_size($node); +$node->start; +ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $log_size), + "xlp_pageaddr bad"); + +# good xl_prev, xlp_magic, xlp_pageaddr, but bogus xlp_info +$prev_lsn = advance_out_of_record_splitting_zone($node); +$end_lsn = 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 = 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 = advance_out_of_record_splitting_zone($node); +$end_lsn = 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 = 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 = advance_out_of_record_splitting_zone($node); +$end_lsn = 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 = get_log_size($node); +$node->start; +ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_size), + "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 first +$end_lsn = 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 = 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 = 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 = get_log_size($node); +$node->start; +ok($node->log_contains("unexpected pageaddr 0/BAAAAAAD in .*, LSN .*,", $log_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 = 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 = get_log_size($node); +$node->start; +ok($node->log_contains("invalid contrecord length 123456 .* at .*", $log_size), + "xlp_rem_len bad (split record header)"); + +done_testing(); -- 2.40.1