From b451e75dc619bca87aa2e3b4a585aedd1526c6b5 Mon Sep 17 00:00:00 2001 From: Joonas Koivunen Date: Thu, 30 Nov 2023 19:31:03 +0200 Subject: [PATCH] test: include cmdline in captured output (#5977) aiming for faster to understand a bunch of `.stdout` and `.stderr` files, see example echo_1.stdout differences: ``` +# echo foobar abbacd + foobar abbacd ``` it can be disabled and is disabled in this PR for some tests; use `pg_bin.run_capture(..., with_command_header=False)` for that. as a bonus this cleans up the echoed newlines from s3_scrubber output which are also saved to file but echoed to test log. Co-authored-by: Alexander Bayandin --- test_runner/fixtures/neon_fixtures.py | 11 +++++-- test_runner/fixtures/utils.py | 17 +++++++++-- test_runner/regress/test_fullbackup.py | 11 ++++--- test_runner/regress/test_import.py | 39 ++++++++++++++++-------- test_runner/regress/test_wal_acceptor.py | 7 ++--- 5 files changed, 60 insertions(+), 25 deletions(-) diff --git a/test_runner/fixtures/neon_fixtures.py b/test_runner/fixtures/neon_fixtures.py index 862aab84dc..188851c39f 100644 --- a/test_runner/fixtures/neon_fixtures.py +++ b/test_runner/fixtures/neon_fixtures.py @@ -1858,7 +1858,8 @@ class PgBin: command: List[str], env: Optional[Env] = None, cwd: Optional[str] = None, - **kwargs: Any, + with_command_header=True, + **popen_kwargs: Any, ) -> str: """ Run one of the postgres binaries, with stderr and stdout redirected to a file. @@ -1871,7 +1872,13 @@ class PgBin: log.info(f"Running command '{' '.join(command)}'") env = self._build_env(env) base_path, _, _ = subprocess_capture( - self.log_dir, command, env=env, cwd=cwd, check=True, **kwargs + self.log_dir, + command, + env=env, + cwd=cwd, + check=True, + with_command_header=with_command_header, + **popen_kwargs, ) return base_path diff --git a/test_runner/fixtures/utils.py b/test_runner/fixtures/utils.py index 1ec18b9f74..cda788b2a4 100644 --- a/test_runner/fixtures/utils.py +++ b/test_runner/fixtures/utils.py @@ -49,7 +49,8 @@ def subprocess_capture( echo_stdout=False, capture_stdout=False, timeout=None, - **kwargs: Any, + with_command_header=True, + **popen_kwargs: Any, ) -> Tuple[str, Optional[str], int]: """Run a process and bifurcate its output to files and the `log` logger @@ -86,13 +87,23 @@ def subprocess_capture( self.captured = "" def run(self): + first = with_command_header for line in self.in_file: + if first: + # do this only after receiving any input so that we can + # keep deleting empty files, or leave it out completly if + # it was unwanted (using the file as input later for example) + first = False + # prefix the files with the command line so that we can + # later understand which file is for what command + self.out_file.write((f"# {' '.join(cmd)}\n\n").encode("utf-8")) + # Only bother decoding if we are going to do something more than stream to a file if self.echo or self.capture: string = line.decode(encoding="utf-8", errors="replace") if self.echo: - log.info(string) + log.info(string.strip()) if self.capture: self.captured += string @@ -107,7 +118,7 @@ def subprocess_capture( p = subprocess.Popen( cmd, - **kwargs, + **popen_kwargs, stdout=subprocess.PIPE, stderr=subprocess.PIPE, ) diff --git a/test_runner/regress/test_fullbackup.py b/test_runner/regress/test_fullbackup.py index 214f1f33a8..a456c06862 100644 --- a/test_runner/regress/test_fullbackup.py +++ b/test_runner/regress/test_fullbackup.py @@ -20,6 +20,7 @@ def test_fullbackup( pg_bin: PgBin, port_distributor: PortDistributor, pg_distrib_dir: Path, + test_output_dir: Path, ): env = neon_env_builder.init_start() @@ -49,10 +50,12 @@ def test_fullbackup( restored_dir_path = env.repo_dir / "restored_datadir" os.mkdir(restored_dir_path, 0o750) query = f"fullbackup {env.initial_tenant} {timeline} {lsn}" - cmd = ["psql", "--no-psqlrc", env.pageserver.connstr(), "-c", query] - result_basepath = pg_bin.run_capture(cmd, env=psql_env) - tar_output_file = result_basepath + ".stdout" - subprocess_capture(env.repo_dir, ["tar", "-xf", tar_output_file, "-C", str(restored_dir_path)]) + tar_output_file = test_output_dir / "fullbackup.tar" + cmd = ["psql", "--no-psqlrc", env.pageserver.connstr(), "-c", query, "-o", str(tar_output_file)] + pg_bin.run_capture(cmd, env=psql_env) + subprocess_capture( + env.repo_dir, ["tar", "-xf", str(tar_output_file), "-C", str(restored_dir_path)] + ) # HACK # fullbackup returns neon specific pg_control and first WAL segment diff --git a/test_runner/regress/test_import.py b/test_runner/regress/test_import.py index d357bd0ee4..8da5f1eec2 100644 --- a/test_runner/regress/test_import.py +++ b/test_runner/regress/test_import.py @@ -163,7 +163,9 @@ def test_import_from_vanilla(test_output_dir, pg_bin, vanilla_pg, neon_env_build assert endpoint.safe_psql("select count(*) from t") == [(300000,)] -def test_import_from_pageserver_small(pg_bin: PgBin, neon_env_builder: NeonEnvBuilder): +def test_import_from_pageserver_small( + pg_bin: PgBin, neon_env_builder: NeonEnvBuilder, test_output_dir: Path +): neon_env_builder.enable_pageserver_remote_storage(RemoteStorageKind.LOCAL_FS) env = neon_env_builder.init_start() @@ -177,7 +179,7 @@ def test_import_from_pageserver_small(pg_bin: PgBin, neon_env_builder: NeonEnvBu num_rows = 3000 lsn = _generate_data(num_rows, endpoint) - _import(num_rows, lsn, env, pg_bin, timeline, env.pg_distrib_dir) + _import(num_rows, lsn, env, pg_bin, timeline, env.pg_distrib_dir, test_output_dir) @pytest.mark.timeout(1800) @@ -185,7 +187,9 @@ def test_import_from_pageserver_small(pg_bin: PgBin, neon_env_builder: NeonEnvBu # the test back after finding the failure cause. # @pytest.mark.skipif(os.environ.get('BUILD_TYPE') == "debug", reason="only run with release build") @pytest.mark.skip("See https://github.com/neondatabase/neon/issues/2255") -def test_import_from_pageserver_multisegment(pg_bin: PgBin, neon_env_builder: NeonEnvBuilder): +def test_import_from_pageserver_multisegment( + pg_bin: PgBin, neon_env_builder: NeonEnvBuilder, test_output_dir: Path +): neon_env_builder.enable_pageserver_remote_storage(RemoteStorageKind.LOCAL_FS) env = neon_env_builder.init_start() @@ -205,7 +209,9 @@ def test_import_from_pageserver_multisegment(pg_bin: PgBin, neon_env_builder: Ne log.info(f"timeline logical size = {logical_size / (1024 ** 2)}MB") assert logical_size > 1024**3 # = 1GB - tar_output_file = _import(num_rows, lsn, env, pg_bin, timeline, env.pg_distrib_dir) + tar_output_file = _import( + num_rows, lsn, env, pg_bin, timeline, env.pg_distrib_dir, test_output_dir + ) # Check if the backup data contains multiple segment files cnt_seg_files = 0 @@ -246,7 +252,8 @@ def _import( pg_bin: PgBin, timeline: TimelineId, pg_distrib_dir: Path, -) -> str: + test_output_dir: Path, +) -> Path: """Test importing backup data to the pageserver. Args: @@ -263,9 +270,9 @@ def _import( # Get a fullbackup from pageserver query = f"fullbackup { env.initial_tenant} {timeline} {lsn}" - cmd = ["psql", "--no-psqlrc", env.pageserver.connstr(), "-c", query] - result_basepath = pg_bin.run_capture(cmd, env=psql_env) - tar_output_file = result_basepath + ".stdout" + tar_output_file = test_output_dir / "fullbackup.tar" + cmd = ["psql", "--no-psqlrc", env.pageserver.connstr(), "-c", query, "-o", str(tar_output_file)] + pg_bin.run_capture(cmd, env=psql_env) # Stop the first pageserver instance, erase all its data env.endpoints.stop_all() @@ -299,7 +306,7 @@ def _import( "--base-lsn", str(lsn), "--base-tarfile", - os.path.join(tar_output_file), + str(tar_output_file), "--pg-version", env.pg_version, ] @@ -315,9 +322,17 @@ def _import( # Take another fullbackup query = f"fullbackup { tenant} {timeline} {lsn}" - cmd = ["psql", "--no-psqlrc", env.pageserver.connstr(), "-c", query] - result_basepath = pg_bin.run_capture(cmd, env=psql_env) - new_tar_output_file = result_basepath + ".stdout" + new_tar_output_file = test_output_dir / "fullbackup-new.tar" + cmd = [ + "psql", + "--no-psqlrc", + env.pageserver.connstr(), + "-c", + query, + "-o", + str(new_tar_output_file), + ] + pg_bin.run_capture(cmd, env=psql_env) # Check it's the same as the first fullbackup # TODO pageserver should be checking checksum diff --git a/test_runner/regress/test_wal_acceptor.py b/test_runner/regress/test_wal_acceptor.py index 05c60eb102..b7eaaf39bc 100644 --- a/test_runner/regress/test_wal_acceptor.py +++ b/test_runner/regress/test_wal_acceptor.py @@ -1,6 +1,5 @@ import filecmp import os -import pathlib import random import shutil import signal @@ -639,7 +638,7 @@ class ProposerPostgres(PgProtocol): def __init__( self, pgdata_dir: str, - pg_bin, + pg_bin: PgBin, tenant_id: TenantId, timeline_id: TimelineId, listen_addr: str, @@ -665,7 +664,7 @@ class ProposerPostgres(PgProtocol): def create_dir_config(self, safekeepers: str): """Create dir and config for running --sync-safekeepers""" - pathlib.Path(self.pg_data_dir_path()).mkdir(exist_ok=True) + Path(self.pg_data_dir_path()).mkdir(exist_ok=True) with open(self.config_file_path(), "w") as f: cfg = [ "synchronous_standby_names = 'walproposer'\n", @@ -691,7 +690,7 @@ class ProposerPostgres(PgProtocol): "PGDATA": self.pg_data_dir_path(), } - basepath = self.pg_bin.run_capture(command, env) + basepath = self.pg_bin.run_capture(command, env, with_command_header=False) log.info(f"postgres --sync-safekeepers output: {basepath}")