We have a database server running PostgreSQL 9.5 on a Ubuntu 16.04 LTS box, with the total data size just under 30 GB.
archive_command is rsyncing WAL files to another server that is running Barman. To prepare for an eventual PostgreSQL upgrade using
pg_upgrade, we've set up a disposable server instance also running PostgreSQL 9.5 that we're using as the target for
barman recover. The idea is to get a snapshot of the DB there that we can test
pg_upgrade on, to a PostgreSQL 12 instance running on the same server.
It is in this process, doing
barman recover to the disposable server, that I discovered an issue. The target DB was stopped, and after Barman had finished rsyncing the contents of the data directory there, I restarted the server. It came online just fine and accepted queries as usual, but this error started appearing in the log file:
2020-12-08 12:05:20 EET ERROR: could not access status of transaction 79509466 2020-12-08 12:05:20 EET DETAIL: Could not open file "pg_clog/004B": No such file or directory. 2020-12-08 12:05:20 EET CONTEXT: automatic vacuum of table "template0.pg_catalog.pg_statistic"
It got printed four times on server startup, and then again every 60 seconds.
I first assumed that this was an issue with Barman or the data on its server, but since no operational problems could be found there, I turned my eye to the production server itself. Lo and behold, ever since the Oct 21, that error has appeared on the production server. So this was never about something being wrong about the backup or restoration process, it was the actual production data that was wrong!
This has gone unnoticed. Nothing happened on the server (a VPS on Upcloud) on Oct 21 that we can discern: all of our web applications–for which we have robust error alerts–relying on the server have kept working normally throughout. Nobody can remember any manual operations having been run there on the day. It's possible that this was an issue with the VPS provider, who on Oct 28 reported having detected a storage backend problem, which was quickly resolved afterwards. This was a week after our problem first appeared in the logs, but I suppose that the symptoms may have started earlier.
Alphabetically the first file inside
004C. Based on some googled advice, I tried creating a 256k file of all zeroes called
004B. After I did, the error changed to:
2020-12-08 13:35:25 EET CONTEXT: automatic vacuum of table "template0.pg_catalog.pg_statistic" 2020-12-08 13:35:40 EET ERROR: found xmax 79509466 from before relfrozenxid 80163082
(This was on the disposable server that was the
barman recover target, I haven't dared touch production.) This gets printed at 15 second intervals.
I have no idea how to further analyze, let alone fix this issue. Everything is working normally as far as our database clients are concerned, but this needs to be corrected. Any help is appreciated. Note that my knowledge of PostgreSQL data storage internals is close to zero.