pgreplay
pgreplay copied to clipboard
laurenz
Tests are failing after installation
Hi there,
I successfully installed pgReplay on M1 Mac Mini. However, before investigating time in using it, I wanted to run the tests to ensure that my installation is really successful.
It didn't work as intended:
laurentmeyer@Laurents-Mini pgreplay % make test
cd test && ./runtest.sh
Testing stderr log parsing ...
ok
Testing CSV log parsing ...
ok
Testing replay ...
unexpected output, difference to expected:
0a1,2
> Execution is 10 seconds behind schedule
>
make: *** [test] Error 1
laurentmeyer@Laurents-Mini pgreplay % make test
cd test && ./runtest.sh
Testing stderr log parsing ...
ok
Testing CSV log parsing ...
ok
Testing replay ...
unexpected output, difference to expected:
0a1,2
> Execution is 10 seconds behind schedule
>
make: *** [test] Error 1
Did I do something wrong? I checked:
- that the connection with db is working
- that the path in the test runner are corresponding to actual bin on my machine
I see the same thing when testing here with PostgreSQL v15. I haven't looked at the regression tests in a long time, perhaps they have rotted. Could you test if pgreplay works for you? It would be interesting to know if there is a real problem or if only the tests need attention.
- So I run the tests on 12 too and got stuck at the same point.
- However, I followed you advice and gave the software a go.
I have a rather simple logfile:
2022-06-18 19:17:16.075 CEST|||62ae089c.61d3|LOG: starting PostgreSQL 12.11 (Ubuntu 12.11-0ubuntu0.20.04.1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, 64-bit
2022-06-18 19:17:16.075 CEST|||62ae089c.61d3|LOG: listening on IPv4 address "127.0.0.1", port 5432
2022-06-18 19:17:16.076 CEST|||62ae089c.61d3|LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-06-18 19:17:16.087 CEST|||62ae089c.61d5|LOG: database system was shut down at 2022-06-18 19:17:15 CEST
2022-06-18 19:17:16.092 CEST|||62ae089c.61d3|LOG: database system is ready to accept connections
2022-06-18 19:17:16.665 CEST|[unknown]|[unknown]|62ae089c.61dc|LOG: connection received: host=[local]
2022-06-18 19:17:17.173 CEST|[unknown]|[unknown]|62ae089d.61df|LOG: connection received: host=[local]
2022-06-18 19:17:17.173 CEST|postgres|template1|62ae089d.61df|LOG: connection authorized: user=postgres database=template1 application_name=psql
2022-06-18 19:17:17.177 CEST|postgres|template1|62ae089d.61df|LOG: statement:
2022-06-18 19:17:17.177 CEST|postgres|template1|62ae089d.61df|LOG: disconnection: session time: 0:00:00.004 user=postgres database=template1 host=[local]
2022-06-18 19:17:17.687 CEST|[unknown]|[unknown]|62ae089d.61e2|LOG: connection received: host=[local]
2022-06-18 19:17:17.688 CEST|postgres|template1|62ae089d.61e2|LOG: connection authorized: user=postgres database=template1 application_name=psql
2022-06-18 19:17:17.688 CEST|postgres|template1|62ae089d.61e2|LOG: statement:
2022-06-18 19:17:17.689 CEST|postgres|template1|62ae089d.61e2|LOG: disconnection: session time: 0:00:00.001 user=postgres database=template1 host=[local]
2022-06-18 19:17:18.198 CEST|[unknown]|[unknown]|62ae089e.61e5|LOG: connection received: host=[local]
2022-06-18 19:17:18.199 CEST|postgres|template1|62ae089e.61e5|LOG: connection authorized: user=postgres database=template1 application_name=psql
2022-06-18 19:17:18.200 CEST|postgres|template1|62ae089e.61e5|LOG: statement:
2022-06-18 19:17:18.200 CEST|postgres|template1|62ae089e.61e5|LOG: disconnection: session time: 0:00:00.001 user=postgres database=template1 host=[local]
2022-06-18 19:17:34.595 CEST|[unknown]|[unknown]|62ae08ae.61f2|LOG: connection received: host=[local]
2022-06-18 19:17:34.596 CEST|postgres|postgres|62ae08ae.61f2|LOG: connection authorized: user=postgres database=postgres application_name=psql
2022-06-18 19:18:01.058 CEST|postgres|postgres|62ae08ae.61f2|LOG: statement: SELECT pg_catalog.quote_ident(datname) FROM pg_catalog.pg_database WHERE substring(pg_catalog.quote_ident(datname),1,2)='po'
LIMIT 1000
2022-06-18 19:18:01.593 CEST|[unknown]|[unknown]|62ae08c9.6614|LOG: connection received: host=[local]
2022-06-18 19:18:01.594 CEST|postgres|postgres|62ae08c9.6614|LOG: connection authorized: user=postgres database=postgres application_name=psql
2022-06-18 19:18:01.595 CEST|postgres|postgres|62ae08ae.61f2|LOG: disconnection: session time: 0:00:26.999 user=postgres database=postgres host=[local]
2022-06-18 19:18:06.539 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: CREATE TABLE CUSTOMERS(
ID INT NOT NULL,
NAME VARCHAR (20) NOT NULL,
AGE INT NOT NULL,
ADDRESS CHAR (25) ,
SALARY DECIMAL (18, 2),
PRIMARY KEY (ID)
);
2022-06-18 19:18:19.308 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (1, 'Ramesh', 32, 'Ahmedabad', 2000.00 );
2022-06-18 19:18:19.310 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (2, 'Khilan', 25, 'Delhi', 1500.00 );
2022-06-18 19:18:19.312 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (3, 'kaushik', 23, 'Kota', 2000.00 );
2022-06-18 19:18:19.313 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (4, 'Chaitali', 25, 'Mumbai', 6500.00 );
2022-06-18 19:18:19.315 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (5, 'Hardik', 27, 'Bhopal', 8500.00 );
2022-06-18 19:18:20.474 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS (ID,NAME,AGE,ADDRESS,SALARY)
VALUES (6, 'Komal', 22, 'MP', 4500.00 );
2022-06-18 19:18:30.222 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: INSERT INTO CUSTOMERS
VALUES (7, 'Muffy', 24, 'Indore', 10000.00 );
2022-06-18 19:18:38.918 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: SELECT ID, NAME, SALARY FROM CUSTOMERS;
2022-06-18 19:18:47.579 CEST|postgres|postgres|62ae08c9.6614|LOG: statement: SELECT * FROM CUSTOMERS;
and when I try to replay it; I get the following (I created the target replayed db beforehand):
Parse statistics
================
Log lines read: 49
Total SQL statements processed: 0
Simple SQL statements processed: 0
Parametrized SQL statements processed: 0
Named prepared SQL statements executions processed: 0
Cancel requests processed: 0
Fast-path function calls ignored: 0
Duration of recorded workload: 0.000 seconds
Replay statistics
=================
Speed factor for replay: 1.000
Total run time: 0.000 seconds
Maximum lag behind schedule: 0 seconds
Calls to the server: 0
(0.000 calls per second)
Total number of connections: 0
Maximum number of concurrent connections: 0
Average number of concurrent connections: 0.000
SQL statements executed: 0
It is not really what I expected; did I miss something?
Strange. When I copy & paste your logfile from above, it works for me:
Parse statistics
================
Log lines read: 49
Total SQL statements processed: 11
Simple SQL statements processed: 11
Parametrized SQL statements processed: 0
Named prepared SQL statements executions processed: 0
Cancel requests processed: 0
Fast-path function calls ignored: 0
Duration of recorded workload: 1 minutes 30.406 seconds
I called pgreplay like this:
pgreplay -j <logfilename>
and it replayed the statements against my postgres database.
About the tests, they certainly need to be revisited and fixed. But that is not a very high priority for me at this point.
Hello, I did a regression test on pg15.1 and found a problem: I guess it may be related to the process (role) of playing back data files. I rolled back pg to 12.0 and there is still a new problem: about session id
I would like to ask which pg version can perfectly pass the regression test of pgreplay?
I finally got around to fixing this problem.
The cause for the error was that the regression tests need login roles postgres and hansi, but I discovered another problem along the way.
I have improved the documentation for the regression tests.