libpq_pipeline: add PQtrace() support and tests

The libpq_pipeline program recently introduced by commit acb7e4eb
is well equipped to test the PQtrace() functionality, so let's make it
do that.

Author: Álvaro Herrera <alvherre@alvh.no-ip.org>
Discussion: https://postgr.es/m/20210327192812.GA25115@alvherre.pgsql

src/test/modules/libpq_pipeline/libpq_pipeline.c

@@ -23,6 +23,7 @@
 #include "catalog/pg_type_d.h"
 #include "common/fe_memutils.h"
 #include "libpq-fe.h"
+#include "pg_getopt.h"
 #include "portability/instr_time.h"
 
 
@@ -30,6 +31,9 @@ static void exit_nicely(PGconn *conn);
 
 const char *const progname = "libpq_pipeline";
 
+/* Options and defaults */
+char	   *tracefile = NULL;	/* path to PQtrace() file */
+
 
 #define DEBUG
 #ifdef DEBUG
@@ -1209,8 +1213,10 @@ usage(const char *progname)
 {
 	fprintf(stderr, "%s tests libpq's pipeline mode.\n\n", progname);
 	fprintf(stderr, "Usage:\n");
-	fprintf(stderr, "  %s tests", progname);
-	fprintf(stderr, "  %s testname [conninfo [number_of_rows]]\n", progname);
+	fprintf(stderr, "  %s [OPTION] tests\n", progname);
+	fprintf(stderr, "  %s [OPTION] TESTNAME [CONNINFO [NUMBER_OF_ROWS]\n", progname);
+	fprintf(stderr, "\nOptions:\n");
+	fprintf(stderr, "  -t TRACEFILE       generate a libpq trace to TRACEFILE\n");
 }
 
 static void
@@ -1231,37 +1237,54 @@ main(int argc, char **argv)
 {
 	const char *conninfo = "";
 	PGconn	   *conn;
+	FILE	   *trace;
+	char	   *testname;
 	int			numrows = 10000;
 	PGresult   *res;
+	int			c;
 
-	if (strcmp(argv[1], "tests") == 0)
+	while ((c = getopt(argc, argv, "t:")) != -1)
 	{
-		print_test_list();
-		exit(0);
+		switch (c)
+		{
+			case 't':			/* trace file */
+				tracefile = pg_strdup(optarg);
+				break;
+		}
 	}
 
-	/*
-	 * The testname parameter is mandatory; it can be followed by a conninfo
-	 * string and number of rows.
-	 */
-	if (argc < 2 || argc > 4)
+	if (optind < argc)
+	{
+		testname = argv[optind];
+		optind++;
+	}
+	else
 	{
 		usage(argv[0]);
 		exit(1);
 	}
 
-	if (argc >= 3)
-		conninfo = pg_strdup(argv[2]);
+	if (strcmp(testname, "tests") == 0)
+	{
+		print_test_list();
+		exit(0);
+	}
 
-	if (argc >= 4)
+	if (optind < argc)
+	{
+		conninfo = argv[optind];
+		optind++;
+	}
+	if (optind < argc)
 	{
 		errno = 0;
-		numrows = strtol(argv[3], NULL, 10);
+		numrows = strtol(argv[optind], NULL, 10);
 		if (errno != 0 || numrows <= 0)
 		{
-			fprintf(stderr, "couldn't parse \"%s\" as a positive integer\n", argv[3]);
+			fprintf(stderr, "couldn't parse \"%s\" as a positive integer\n", argv[optind]);
 			exit(1);
 		}
+		optind++;
 	}
 
 	/* Make a connection to the database */
@@ -1272,30 +1295,42 @@ main(int argc, char **argv)
 				PQerrorMessage(conn));
 		exit_nicely(conn);
 	}
+
+	/* Set the trace file, if requested */
+	if (tracefile != NULL)
+	{
+		trace = fopen(tracefile, "w+");
+
+		if (trace == NULL)
+			pg_fatal("could not open file \"%s\": %m", tracefile);
+		PQtrace(conn, trace);
+		PQtraceSetFlags(conn,
+						PQTRACE_SUPPRESS_TIMESTAMPS | PQTRACE_REGRESS_MODE);
+	}
+
 	res = PQexec(conn, "SET lc_messages TO \"C\"");
 	if (PQresultStatus(res) != PGRES_COMMAND_OK)
 		pg_fatal("failed to set lc_messages: %s", PQerrorMessage(conn));
 
-	if (strcmp(argv[1], "disallowed_in_pipeline") == 0)
+	if (strcmp(testname, "disallowed_in_pipeline") == 0)
 		test_disallowed_in_pipeline(conn);
-	else if (strcmp(argv[1], "multi_pipelines") == 0)
+	else if (strcmp(testname, "multi_pipelines") == 0)
 		test_multi_pipelines(conn);
-	else if (strcmp(argv[1], "pipeline_abort") == 0)
+	else if (strcmp(testname, "pipeline_abort") == 0)
 		test_pipeline_abort(conn);
-	else if (strcmp(argv[1], "pipelined_insert") == 0)
+	else if (strcmp(testname, "pipelined_insert") == 0)
 		test_pipelined_insert(conn, numrows);
-	else if (strcmp(argv[1], "prepared") == 0)
+	else if (strcmp(testname, "prepared") == 0)
 		test_prepared(conn);
-	else if (strcmp(argv[1], "simple_pipeline") == 0)
+	else if (strcmp(testname, "simple_pipeline") == 0)
 		test_simple_pipeline(conn);
-	else if (strcmp(argv[1], "singlerow") == 0)
+	else if (strcmp(testname, "singlerow") == 0)
 		test_singlerowmode(conn);
-	else if (strcmp(argv[1], "transaction") == 0)
+	else if (strcmp(testname, "transaction") == 0)
 		test_transaction(conn);
 	else
 	{
-		fprintf(stderr, "\"%s\" is not a recognized test name\n", argv[1]);
-		usage(argv[0]);
+		fprintf(stderr, "\"%s\" is not a recognized test name\n", testname);
 		exit(1);
 	}
 

src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl

@@ -4,7 +4,7 @@ use warnings;
 use Config;
 use PostgresNode;
 use TestLib;
-use Test::More tests => 8;
+use Test::More;
 use Cwd;
 
 my $node = get_new_node('main');
@@ -14,15 +14,62 @@ $node->start;
 my $numrows = 10000;
 $ENV{PATH} = "$ENV{PATH}:" . getcwd();
 
-my ($out, $err) = run_command(['libpq_pipeline', 'tests']);
+my ($out, $err) = run_command([ 'libpq_pipeline', 'tests' ]);
 die "oops: $err" unless $err eq '';
 my @tests = split(/\s+/, $out);
 
 for my $testname (@tests)
 {
+	my @extraargs = ();
+	my $cmptrace  = grep(/^$testname$/,
+		qw(simple_pipeline multi_pipelines prepared singlerow
+		  pipeline_abort transaction disallowed_in_pipeline)) > 0;
+
+	# For a bunch of tests, generate a libpq trace file too.
+	my $traceout = "$TestLib::log_path/$testname.trace";
+	if ($cmptrace)
+	{
+		push @extraargs, "-t", $traceout;
+	}
+
+	# Execute the test
 	$node->command_ok(
-		[ 'libpq_pipeline', $testname, $node->connstr('postgres'), $numrows ],
+		[
+			'libpq_pipeline', @extraargs,
+			$testname,        $node->connstr('postgres'),
+			$numrows
+		],
 		"libpq_pipeline $testname");
+
+	# Compare the trace, if requested
+	if ($cmptrace)
+	{
+		my $expected;
+		my $result;
+
+		$expected = slurp_file_eval("traces/$testname.trace");
+		next unless $expected ne "";
+		$result = slurp_file_eval($traceout);
+		next unless $result ne "";
+
+		is($expected, $result, "$testname trace match");
+	}
 }
 
 $node->stop('fast');
+
+done_testing();
+
+sub slurp_file_eval
+{
+	my $filepath = shift;
+	my $contents;
+
+	eval { $contents = slurp_file($filepath); };
+	if ($@)
+	{
+		fail "reading $filepath: $@";
+		return "";
+	}
+	return $contents;
+}

src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	13	Query	 "SELECT 1"
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 4 -1 0
+B	11	DataRow	 1 1 '1'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/multi_pipelines.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	21	Parse	 "" "SELECT $1" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '1' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+F	21	Parse	 "" "SELECT $1" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '1' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	4	ParseComplete
+B	4	BindComplete
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 4 -1 0
+B	11	DataRow	 1 1 '1'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+B	4	ParseComplete
+B	4	BindComplete
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 4 -1 0
+B	11	DataRow	 1 1 '1'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/pipeline_abort.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	42	Query	 "DROP TABLE IF EXISTS pq_pipeline_demo"
+B	123	NoticeResponse	 S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_demo" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00
+B	15	CommandComplete	 "DROP TABLE"
+B	5	ReadyForQuery	 I
+F	83	Query	 "CREATE UNLOGGED TABLE pq_pipeline_demo(id serial primary key, itemno integer);"
+B	17	CommandComplete	 "CREATE TABLE"
+B	5	ReadyForQuery	 I
+F	61	Parse	 "" "INSERT INTO pq_pipeline_demo(itemno) VALUES ($1);" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '1' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	39	Parse	 "" "SELECT no_such_function($1)" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '1' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	61	Parse	 "" "INSERT INTO pq_pipeline_demo(itemno) VALUES ($1);" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '2' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+F	61	Parse	 "" "INSERT INTO pq_pipeline_demo(itemno) VALUES ($1);" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '3' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	4	ParseComplete
+B	4	BindComplete
+B	4	NoData
+B	15	CommandComplete	 "INSERT 0 1"
+B	217	ErrorResponse	 S "ERROR" V "ERROR" C "42883" M "function no_such_function(integer) does not exist" H "No function matches the given name and argument types. You might need to add explicit type casts." P "8" F "SSSS" L "SSSS" R "SSSS" \x00
+B	5	ReadyForQuery	 I
+B	4	ParseComplete
+B	4	BindComplete
+B	4	NoData
+B	15	CommandComplete	 "INSERT 0 1"
+B	5	ReadyForQuery	 I
+F	26	Parse	 "" "SELECT 1; SELECT 2" 0
+F	12	Bind	 "" "" 0 0 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	123	ErrorResponse	 S "ERROR" V "ERROR" C "42601" M "cannot insert multiple commands into a prepared statement" F "SSSS" L "SSSS" R "SSSS" \x00
+B	5	ReadyForQuery	 I
+F	54	Parse	 "" "SELECT 1.0/g FROM generate_series(3, -1, -1) g" 0
+F	12	Bind	 "" "" 0 0 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	4	ParseComplete
+B	4	BindComplete
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 65535 -1 0
+B	32	DataRow	 1 22 '0.33333333333333333333'
+B	32	DataRow	 1 22 '0.50000000000000000000'
+B	32	DataRow	 1 22 '1.00000000000000000000'
+B	70	ErrorResponse	 S "ERROR" V "ERROR" C "22012" M "division by zero" F "SSSS" L "SSSS" R "SSSS" \x00
+B	5	ReadyForQuery	 I
+F	40	Query	 "SELECT itemno FROM pq_pipeline_demo"
+B	31	RowDescription	 1 "itemno" NNNN 2 NNNN 4 -1 0
+B	11	DataRow	 1 1 '3'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/prepared.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	68	Parse	 "select_one" "SELECT $1, '42', $1::numeric, interval '1 sec'" 1 NNNN
+F	16	Describe	 S "select_one"
+F	4	Sync
+B	4	ParseComplete
+B	10	ParameterDescription	 1 NNNN
+B	113	RowDescription	 4 "?column?" NNNN 0 NNNN 4 -1 0 "?column?" NNNN 0 NNNN 65535 -1 0 "numeric" NNNN 0 NNNN 65535 -1 0 "interval" NNNN 0 NNNN 16 -1 0
+B	5	ReadyForQuery	 I
+F	10	Query	 "BEGIN"
+B	10	CommandComplete	 "BEGIN"
+B	5	ReadyForQuery	 T
+F	43	Query	 "DECLARE cursor_one CURSOR FOR SELECT 1"
+B	19	CommandComplete	 "DECLARE CURSOR"
+B	5	ReadyForQuery	 T
+F	16	Describe	 P "cursor_one"
+F	4	Sync
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 4 -1 0
+B	5	ReadyForQuery	 T
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/simple_pipeline.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	21	Parse	 "" "SELECT $1" 1 NNNN
+F	19	Bind	 "" "" 0 1 1 '1' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	4	ParseComplete
+B	4	BindComplete
+B	33	RowDescription	 1 "?column?" NNNN 0 NNNN 4 -1 0
+B	11	DataRow	 1 1 '1'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/singlerow.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	38	Parse	 "" "SELECT generate_series(42, $1)" 0
+F	20	Bind	 "" "" 0 1 2 '44' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	38	Parse	 "" "SELECT generate_series(42, $1)" 0
+F	20	Bind	 "" "" 0 1 2 '45' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	38	Parse	 "" "SELECT generate_series(42, $1)" 0
+F	20	Bind	 "" "" 0 1 2 '46' 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+B	4	ParseComplete
+B	4	BindComplete
+B	40	RowDescription	 1 "generate_series" NNNN 0 NNNN 4 -1 0
+B	12	DataRow	 1 2 '42'
+B	12	DataRow	 1 2 '43'
+B	12	DataRow	 1 2 '44'
+B	13	CommandComplete	 "SELECT 3"
+B	4	ParseComplete
+B	4	BindComplete
+B	40	RowDescription	 1 "generate_series" NNNN 0 NNNN 4 -1 0
+B	12	DataRow	 1 2 '42'
+B	12	DataRow	 1 2 '43'
+B	12	DataRow	 1 2 '44'
+B	12	DataRow	 1 2 '45'
+B	13	CommandComplete	 "SELECT 4"
+B	4	ParseComplete
+B	4	BindComplete
+B	40	RowDescription	 1 "generate_series" NNNN 0 NNNN 4 -1 0
+B	12	DataRow	 1 2 '42'
+B	12	DataRow	 1 2 '43'
+B	12	DataRow	 1 2 '44'
+B	12	DataRow	 1 2 '45'
+B	12	DataRow	 1 2 '46'
+B	13	CommandComplete	 "SELECT 5"
+B	5	ReadyForQuery	 I
+F	4	Terminate

src/test/modules/libpq_pipeline/traces/transaction.trace

+F	27	Query	 "SET lc_messages TO "C""
+B	8	CommandComplete	 "SET"
+B	5	ReadyForQuery	 I
+F	79	Query	 "DROP TABLE IF EXISTS pq_pipeline_tst;CREATE TABLE pq_pipeline_tst (id int)"
+B	122	NoticeResponse	 S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_tst" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00
+B	15	CommandComplete	 "DROP TABLE"
+B	17	CommandComplete	 "CREATE TABLE"
+B	5	ReadyForQuery	 I
+F	24	Parse	 "rollback" "ROLLBACK" 0
+F	13	Parse	 "" "BEGIN" 0
+F	14	Bind	 "" "" 0 0 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	18	Parse	 "" "SELECT 0/0" 0
+F	14	Bind	 "" "" 0 0 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	22	Bind	 "" "rollback" 0 0 1 1
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	46	Parse	 "" "INSERT INTO pq_pipeline_tst VALUES (1)" 0
+F	14	Bind	 "" "" 0 0 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+F	46	Parse	 "" "INSERT INTO pq_pipeline_tst VALUES (2)" 0
+F	14	Bind	 "" "" 0 0 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+F	22	Bind	 "" "rollback" 0 0 1 1
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	46	Parse	 "" "INSERT INTO pq_pipeline_tst VALUES (3)" 0
+F	14	Bind	 "" "" 0 0 1 0
+F	6	Describe	 P ""
+F	9	Execute	 "" 0
+F	4	Sync
+F	4	Sync
+B	4	ParseComplete
+B	4	ParseComplete
+B	4	BindComplete
+B	4	NoData
+B	10	CommandComplete	 "BEGIN"
+B	4	ParseComplete
+B	65	ErrorResponse	 S "ERROR" V "ERROR" C "22012" M "division by zero" F "SSSS" L "SSSS" R "SSSS" \x00
+B	5	ReadyForQuery	 E
+B	145	ErrorResponse	 S "ERROR" V "ERROR" C "25P02" M "current transaction is aborted, commands ignored until end of transaction block" F "SSSS" L "SSSS" R "SSSS" \x00
+B	5	ReadyForQuery	 E
+B	4	BindComplete
+B	4	NoData
+B	13	CommandComplete	 "ROLLBACK"
+B	4	ParseComplete
+B	4	BindComplete
+B	4	NoData
+B	15	CommandComplete	 "INSERT 0 1"
+B	5	ReadyForQuery	 I
+B	5	ReadyForQuery	 I
+F	34	Query	 "SELECT * FROM pq_pipeline_tst"
+B	27	RowDescription	 1 "id" NNNN 1 NNNN 4 -1 0
+B	11	DataRow	 1 1 '3'
+B	13	CommandComplete	 "SELECT 1"
+B	5	ReadyForQuery	 I
+F	4	Terminate