PostgreSQL backup in custom format ( -F c) fails during pg_restore ( copy command in log )

Question

We have a PostgreSQL custom format ( -F c ) database backup ~1Gb in size that could not be restored on two of our users machines. The error that occurs is

:pg_restore: [archiver (db)] error returned by PQputCopyData and in logs there is error in Copy command.

All reports we found with errors in Copy command during pg_restore were related to textual (sql ) backup which is not the case.

Any ideas?

Below is the information that describe the issue in more details:

1. File integrity is ok checked with "Microsoft File Checksum Integrity Verifier"

2. Backup and restore and restore are performed with PostgreSQL 9.6.5 64 bit.

3. Backup format of pg_dump is called

pg_dump -U username -F c -Z 9  mydatabase >  myarchive

4. Database on client is created with:

CREATE DATABASE mydatabase  WITH TEMPLATE = template0 ENCODING = 'UTF8'  OWNER=user;

5. Pg_resote call:

pg_restore.exe  -U user --dbname=mydatabase   --verbose --no-owner --role=user 

6. Example of logs, there are repeating rows with random table errors:

2020-12-07 13:40:56 GMT LOG:  checkpoints are occurring too frequently (21 seconds apart)
2020-12-07 13:40:56 GMT HINT:  Consider increasing the configuration parameter "max_wal_size".
2020-12-07 13:40:57 GMT ERROR:  extra data after last expected column
2020-12-07 13:40:57 GMT CONTEXT:  COPY substance, line 21511: "21743    \N  2   1d8c29d2d4dc17ccec4a29710c2f190a    e98906e08d4cf1ac23bc4a5a26f83e73    1d8c29d2d4dc17ccec4a297..."
2020-12-07 13:40:57 GMT STATEMENT:  COPY substance (id, text_id, storehouse_id, i_tb_id, i_twod_tb_id, tb_id, twod_tb_id, o_smiles, i_smiles_id, i_twod_smiles_id, smiles_id, twod_smiles_id, substance_type)
2020-12-07 13:40:57 GMT FATAL:  invalid frontend message type 48
2020-12-07 13:40:57 GMT LOG:  PID 105976 in cancel request did not match any process

or

2020-12-07 14:35:42 GMT LOG:  checkpoints are occurring too frequently (16 seconds apart)
2020-12-07 14:35:42 GMT HINT:  Consider increasing the configuration parameter "max_wal_size".
2020-12-07 14:35:59 GMT LOG:  checkpoints are occurring too frequently (17 seconds apart)
2020-12-07 14:35:59 GMT HINT:  Consider increasing the configuration parameter "max_wal_size".
2020-12-07 14:36:09 GMT ERROR:  invalid byte sequence for encoding "UTF8": 0x00
2020-12-07 14:36:09 GMT CONTEXT:  COPY scalar_calculation, line 3859209
2020-12-07 14:36:09 GMT STATEMENT:  COPY scalar_calculation (calculator_id, smiles_id, mean_value, remark) FROM stdin;
2020-12-07 14:36:09 GMT FATAL:  invalid frontend message type 49
2020-12-07 14:36:10 GMT LOG:  PID 109816 in cancel request did not match any process

Answer 1

I am seeing similar behavior on windows 10 pro machines with PG 11.x.

I used pg_dump as suggested above and restored to said machines with psql and had no error.

I also noted that the error shifted around using pg_restore with different "-j" settings. For instance without the setting or "-j 1" pg_restore always fails on the same table and record. Changing to "-j 4" results in that table succeeding to apply the record without error but it occurs on another table.

Changing a particular column to null in the record satisfies the entire restore.

Using pgAdmin 4 to run the restore never produces the error. Copying the exact command displayed in pgAdmin reproduces the same error:

pg_restore: [archiver (db)] Error while PROCESSING TOC:
pg_restore: [archiver (db)] Error from TOC entry 32780; 0 5435293 TABLE DATA REDACTED_TABLE_NAME postgres
pg_restore: [archiver (db)] COPY failed for table "REDACTED_TABLE_NAME": ERROR:  extra data after last expected column
CONTEXT:  COPY mi_gmrfutil, line 117: "REDACTED PLAIN TEXT  \N  REDACTED PLAIN TEXT \N  \N  \N  \N  \N  \N  REDACTED PLAIN TEXT \N  \N  REDACTED PLAIN TEXT \N  ..."
pg_restore: FATAL:  invalid frontend message type 49

I tried using pg_restore version 14 with the same outcome.