0

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.

We've set archive_mode to on, and 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 pg_clog is 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.

Improve this question
2
  • 1
    That sounds like a file system or even harddisk problem.
    – user1822
    Dec 8, 2020 at 15:26
  • It's possible that this happened on the production server due to the Upcloud storage backend issue, yes. What to do about it, is the question.
    – JK Laiho
    Dec 9, 2020 at 7:50

2 Answers 2

Reset to default
1

If only pg_statistic is affected, you might get out of this cheap:

Set allow_system_table_mods = on in postgresql.conf and restart PostgreSQL. Then run

TRUNCATE pg_catalog.pg_statistic;
ANALYZE;

Don't forget to reset allow_system_table_mods when you are done.

But you shouldn't ever trust a PostgreSQL database cluster that has had database corruption. Create a new cluster, export the old one with pg_dumpall and import it into the new cluster. Then discard the cluster that had data corruption.

You might want to create the new cluster with --data-checksums so that you get an error message if data change while on disk.

Now you should investigate the possible causes. Upgrade to the latest minor release and test your hardware for problems.

Improve this answer
6
  • Sadly, this had no effect that I could see. Nothing new was printed in the logs, nor did the previous error message stop. (The server was in the latter state when doing this, after the manual creation of the 004B file).
    – JK Laiho
    Dec 9, 2020 at 16:16
  • Are you telling me that you truncated pg_statistic and still got error messages about it? Or did you get errors about another table?
    – Laurenz Albe
    Dec 9, 2020 at 17:15
  • The former. Just tried it again on the disposable server (Barman recovery target). I have a tail -f running on the log file. Every 15 seconds, the second error msg in my post is printed. I sudo as the postgres user, run psql and then TRUNCATE pg_catalog.pg_statistic;. Confirmed: the table is now empty. Then, ANALYZE;. The table now has rows again. All through this time, the exact same error message is printed every 15 seconds in the tailed log, no change whatsoever. (That error refers to template0.pg_catalog.pg_statistic but I assume your instructions take that into account.)
    – JK Laiho
    Dec 10, 2020 at 9:53
  • Now did the same TRUNCATE/ANALYZE process while connected to the actual recovered production database, rather than the postgres DB. No change in the error log output. There's no way to connect to template0 that I know of so I could try this there (if that would even be advisable).
    – JK Laiho
    Dec 10, 2020 at 9:58
  • 1
    You should hire an expert to analyze this. Q&A is not the correct format for this.
    – Laurenz Albe
    Dec 10, 2020 at 10:16
0

The target DB was stopped, and after Barman had finished rsyncing the contents of the data directory there, I restarted the server.

You rsynced data from a running server over the top of a cold server? That is not a supported way of doing things, unless the running server was put into backup mode first, and then the cold server went through recovery. You say barman did this for you, I don't think I've heard of barman being used in this way. Could you give the full command line of all the barman commands used for this process?

Improve this answer
1
  • The Barman thing was just for context in case the error discovery process was relevant. Probably wasn't. And no, I restored from the server that hosts Barman, which receives WAL files from the actual production server.
    – JK Laiho
    Dec 9, 2020 at 7:11

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.