Parsing line error about pgreplay HOT 12 CLOSED

Perhaps the log is not in csvlog format.
Can you show me the offending log line?

from pgreplay.

Thank you, that helps.

-bash-4.2$ /usr/pgsql-13/bin/pgreplay -f -c -o /home/postgres/postgres.replay.log /home/postgres/postgres.log
Warning: COPY statement ignored in line 605
Warning: COPY statement ignored in line 1174

Parse statistics
================

Log lines read: 1401267
Total SQL statements processed: 1401147
Simple SQL statements processed: 1401147
(includes 2 ignored copy statements)
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: 51 minutes 53.218 seconds

After parsing, how do we monitor pgreplay -r <postgres.replay.log> while the command is running?

It looks like the command is stuck.

from pgreplay.

You could look at pg_stat_activity to see if statements are being executed. pgreplay does not say much while it is replaying.

With the -j option you can have pgreplay skip idle times.

If you start it with -d 1, you will get debugging messages.

from pgreplay.

Thank you.

I am running into locking issue during pgreplay -r. I used pgbench to create data and workload. Forcing the blocking_pid connection is ending the entire pgreplay process! Any inputs what's going on here?

-[ RECORD 1 ]-------------------------+------------------------------------------------------------------------
blocked_pid                           | 14631
blocked_user                          | postgres
blocking_pid                          | 14636
blocking_user                         | postgres
blocked_statement                     | UPDATE pgbench_branches SET bbalance = bbalance + -1215 WHERE bid = 20;
current_statement_in_blocking_process | UPDATE pgbench_branches SET bbalance = bbalance + -2933 WHERE bid = 20;

from pgreplay.

You probably ran into this limitation:

While pgreplay makes sure that commands are sent to the server in the order in which they were originally executed, there is no way to guarantee that they will be executed in the same order during replay: Network delay, processor contention and other factors may cause a later command to "overtake" an earlier one. While this does not matter if the commands don't affect each other, it can lead to SQL statements hitting locks unexpectedly, causing replay to deadlock and "hang". This is particularly likely if many different sessions change the same data repeatedly in short intervals.

You can work around this problem by canceling the waiting statement with pg_cancel_backend. Replay should continue normally after that.

from pgreplay.

Thank you. I keep canceling statements, but I see going through a lot of locks. I also hit another issue. pg_cancel_backend is not helping in this case. It exits the entire pgreplay command. Here is the snippet from log file.

2022-12-14 11:27:28 PST [9424]: [7-1] host=[local],user=user_rw,db=testdbrel,app_name=commerceWeb:StatusController.statusRead STATEMENT:  /* insert test.core.tbl */ insert into tbl (id, fk_mid, name, pid, pk_tid) values ($1, $2, $3, $4, $5)
2022-12-14 11:27:28 PST [9424]: [8-1] host=[local],user=user_rw,db=testdbrel,app_name=[unknown] ERROR:  current transaction is aborted, commands ignored until end of transaction block
2022-12-14 11:27:28 PST [9424]: [9-1] host=[local],user=user_rw,db=testdbrel,app_name=[unknown] STATEMENT:  /* delete test.core.tbl */ delete from dogs where pk_dogid=$1
2022-12-14 11:27:28 PST [9424]: [10-1] host=[local],user=user_rw,db=testdbrel,app_name=[unknown] ERROR:  prepared statement "S_7" does not exist

from pgreplay.

That log doesn't really tell me a lot... I see no canceled query there.
If you are running a workload like pgbench, pgreplay is pretty useless. You are fairly likely to run into the limitation quoted above.

from pgreplay.

The above error is not from pgbench. It was a realtime workload on the source database. Those are the only entries in the log file, pgreplay hangs after printing those log files.

Here is the output from pgreplay command using -d 1

---------------------------
---------------------------
Item: time       = 724259090.058000
      session id = 0x7176771913597846752
      type       = exec_prepared
      name       = S_3
---------------------------
---------------------------
Item: time       = 724259090.058000
      session id = 0x7176771913597846752
      type       = exec_prepared
      name       = S_1
---------------------------
Error sending prepared statement execution: no connection to the server

from pgreplay.

That error would mean that the connection has died. If I get that right, parsing and executing S_3 worked, but executing S_1 gave that error message. What is strange is that they are logged at the exact same time on the same session...
What do you find in the server log at that time?
Can you perhaps generate a (small!) replay file that exhibits the problem and send it to me (laurenz.albe at cybertec.at)?

from pgreplay.

Hi, were you able to replicate the issue? Please let me know if you need anything esle from me. Thanks.

from pgreplay.

No, I have not been able to reproduce this.
If your problem at this point is still "no connection to server", please look at the PostgreSQL server log and check if you find any corresponding error messages there. I guess we should figure out why the connection was lost.

from pgreplay.

Note that I am on vacation until Jan 9, so I may not react instantly.

from pgreplay.