Thread: BUG #6127: pg_restore failing: unexpected message type 0x58 during COPY from stdin

The following bug has been logged online:

Bug reference:      6127
Logged by:          Greg Johnson
Email address:      greg.johnson@interprose.com
PostgreSQL version: pg_dump (Postgr
Operating system:   CentOS release 5.6 (Final)
Description:        pg_restore failing: unexpected message type 0x58 during
COPY from stdin
Details:

I am running into an error loading a backup of the production database..
never had a problem before.

These are dump /restore commands I am using:
pg_dump -Fc -h ackbar -U webar_admin webar -f
/var/portal/backup/db/webar-20110719180003.gz

pg_restore -d webar_dev -U webar_admin  -Fc webar-20110719180003.gz

Both machines have same version of postgres :
[root@awing ~]# pg_dump --version
pg_dump (PostgreSQL) 8.4.8


[root@dev ~]# pg_restore --version
pg_restore (PostgreSQL) 8.4.8

MD5s are the same:
[root@awing db]# md5sum webar-20110719180003.gz
f4ec991e4635cd70a1f85864e04e6214  webar-20110719180003.gz

[root@dev ~]# md5sum webar-20110719180003.gz
f4ec991e4635cd70a1f85864e04e6214  webar-20110719180003.gz

This is the error from dev while trying to restore:
pg_restore: [custom archiver] could not read from input file: end of file

Here is what I found in the pg_log file:
LOG:  checkpoint starting: xlog
LOG:  checkpoint complete: wrote 8147 buffers (3.1%); 0 transaction log
file(s) added, 0 removed, 128 recycled; write=192.644 s, sync=1.613 s,
total=194.269 s
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_big, line 9195632

Here is another log entry:
  TRUNCATE TABLE ONLY form_field_config;
LOG:  statement: COPY form_field_config (form_field_config_id,
form_config_id, identifier, label, field_type, field_group, required,
display_on_summary, new_line, col_span, field_order, searchable,
fk_form_config_id, fk_label, fk_on_delete_action, primary_key,
form_big_column) FROM stdin;
LOG:  checkpoint starting: time
LOG:  checkpoint complete: wrote 160 buffers (0.1%); 0 transaction log
file(s) added, 0 removed, 0 recycled; write=31.811 s, sync=0.066 s,
total=33.898 s
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_config, line 1
STATEMENT:  COPY form_config (form_config_id, customer_id, identifier,
form_config_type, label, description, icon, location, allow_multiple,
created_by, create_date, last_updated_by, last_updated, view_on_update,
view_on_insert, "position", record_label, converted, text_count,
bigint_count, timestamp_count, real_count, boolean_count) FROM stdin;
LOG:  could not send data to client: Broken pipe
STATEMENT:  COPY form_config (form_config_id, customer_id, identifier,
form_config_type, label, description, icon, location, allow_multiple,
created_by, create_date, last_updated_by, last_updated, view_on_update,
view_on_insert, "position", record_label, converted, text_count,
bigint_count, timestamp_count, real_count, boolean_count) FROM stdin;
LOG:  unexpected EOF on client connection
ERROR:  unexpected message type 0x58 during COPY from stdin


Looks like they are happening at different spots..

I have tried 5 different dump/restores and all error out.

There is nothing in /var/log/messages

"Greg Johnson" <greg.johnson@interprose.com> writes:
> I am running into an error loading a backup of the production database..

> ERROR:  unexpected message type 0x58 during COPY from stdin
> CONTEXT:  COPY form_big, line 9195632

This looks like pg_restore is terminating unexpectedly.  What do you see
on the client end of it?

            regards, tom lane

Greg Johnson <greg.johnson@interprose.com> writes:
> On Thu, Jul 21, 2011 at 11:44 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> This looks like pg_restore is terminating unexpectedly.  What do you see
>> on the client end of it?

> pg_restore: [custom archiver] could not read from input file: end of file

Well, that suggests you have a truncated or otherwise corrupted pg_dump
archive file.  Do you get a similar failure if you just do "pg_restore
-l" on the archive file?  Is the pg_dump run reporting any signs of
distress?

            regards, tom lane

Greg Johnson <greg.johnson@interprose.com> writes:
> Interesting.. I was able to pg_restore -f to a file... and then psql -f  the
> resulting file. and it loaded just fine.. the down side to this method is I
> cannot use the parallel load function (and the extra time). but I am glad
> that I got the data loaded. Let me know if there is any other info I get
> you.

Parallel restore?  You didn't mention using parallel restore before.
Were the failed pg_restore runs using parallelism?

            regards, tom lane

pg_restore: [custom archiver] could not read from input file: end of file

Thanks for your help!

On Thu, Jul 21, 2011 at 11:44 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

> "Greg Johnson" <greg.johnson@interprose.com> writes:
> > I am running into an error loading a backup of the production database..
>
> > ERROR:  unexpected message type 0x58 during COPY from stdin
> > CONTEXT:  COPY form_big, line 9195632
>
> This looks like pg_restore is terminating unexpectedly.  What do you see
> on the client end of it?
>
>                        regards, tom lane
>



--
----------------------------------------------------------------
Greg Johnson
The InterProse Corporation
Software Developer
Phone: (360) 604-3531 x225
Fax: (360) 604-3579

Interesting.. I was able to pg_restore -f to a file... and then psql -f  the
resulting file. and it loaded just fine.. the down side to this method is I
cannot use the parallel load function (and the extra time). but I am glad
that I got the data loaded. Let me know if there is any other info I get
you.

On Thu, Jul 21, 2011 at 12:58 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

> Greg Johnson <greg.johnson@interprose.com> writes:
> > On Thu, Jul 21, 2011 at 11:44 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> >> This looks like pg_restore is terminating unexpectedly.  What do you see
> >> on the client end of it?
>
> > pg_restore: [custom archiver] could not read from input file: end of file
>
> Well, that suggests you have a truncated or otherwise corrupted pg_dump
> archive file.  Do you get a similar failure if you just do "pg_restore
> -l" on the archive file?  Is the pg_dump run reporting any signs of
> distress?
>
>                        regards, tom lane
>



--
----------------------------------------------------------------
Greg Johnson
The InterProse Corporation
Software Developer
Phone: (360) 604-3531 x225
Fax: (360) 604-3579

I tried it both ways..

On Thu, Jul 21, 2011 at 2:10 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Greg Johnson <greg.johnson@interprose.com> writes:
>> Interesting.. I was able to pg_restore -f to a file... and then psql -f =
=A0the
>> resulting file. and it loaded just fine.. the down side to this method i=
s I
>> cannot use the parallel load function (and the extra time). but I am glad
>> that I got the data loaded. Let me know if there is any other info I get
>> you.
>
> Parallel restore? =A0You didn't mention using parallel restore before.
> Were the failed pg_restore runs using parallelism?
>
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0regards, tom lane
>



--=20
----------------------------------------------------------------
Greg Johnson
The InterProse Corporation
Software Developer
Phone: (360) 604-3531 x225
Fax: (360) 604-3579

Just a follow up on this bug. After further checking.. some of the data did
not load, but it was able to continue restoring. (looks like it skipped the
bad records?)

The interesting thing.. after I discovered the missing data. I dumped just
those three tables(form_config, form_field_config, form_big)  using -t  flag
and they loaded in just fine...

Here is what I found in the log file:
LOG:  statement: BEGIN
LOG:  statement:
    TRUNCATE TABLE ONLY form_config;
LOG:  statement: COPY form_field_config (form_field_config_id,
form_config_id, identifier, label, field_type, field_group, required,
display_on_summary, new_line, col_span, field_order, searchable,
fk_form_config_id, fk_label, fk_on_delete_action, primary_key,
form_big_column) FROM stdin;
LOG:  statement: COPY form_field_config_select (form_field_config_select_id,
form_field_config_id, label, value, "position") FROM stdin;
LOG:  statement: COPY form_config (form_config_id, customer_id, identifier,
form_config_type, label, description, icon, location, allow_multiple,
created_by, create_date, last_updated_by, last_updated, view_on_update,
view_on_insert, "position", record_label, converted, text_count,
bigint_count, timestamp_count, real_count, boolean_count) FROM stdin;
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_field_config, line 1
STATEMENT:  COPY form_field_config (form_field_config_id, form_config_id,
identifier, label, field_type, field_group, required, display_on_summary,
new_line, col_span, field_order, searchable, fk_form_config_id, fk_label,
fk_on_delete_action, primary_key, form_big_column) FROM stdin;
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_field_config_select, line 1
STATEMENT:  COPY form_field_config_select (form_field_config_select_id,
form_field_config_id, label, value, "position") FROM stdin;
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_config, line 1
STATEMENT:  COPY form_config (form_config_id, customer_id, identifier,
form_config_type, label, description, icon, location, allow_multiple,
created_by, create_date, last_updated_by, last_updated, view_on_update,
view_on_insert, "position", record_label, converted, text_count,
bigint_count, timestamp_count, real_count, boolean_count) FROM stdin;
LOG:  could not send data to client: Broken pipe
STATEMENT:  COPY form_field_config_select (form_field_config_select_id,
form_field_config_id, label, value, "position") FROM stdin;
LOG:  could not send data to client: Broken pipe
STATEMENT:  COPY form_field_config (form_field_config_id, form_config_id,
identifier, label, field_type, field_group, required, display_on_summary,
new_line, col_span, field_order, searchable, fk_form_config_id, fk_label,
fk_on_delete_action, primary_key, form_big_column) FROM stdin;
LOG:  could not send data to client: Broken pipe
STATEMENT:  COPY form_config (form_config_id, customer_id, identifier,
form_config_type, label, description, icon, location, allow_multiple,
created_by, create_date, last_updated_by, last_updated, view_on_update,
view_on_insert, "position", record_label, converted, text_count,
bigint_count, timestamp_count, real_count, boolean_count) FROM stdin;
LOG:  unexpected EOF on client connection
LOG:  unexpected EOF on client connection
LOG:  unexpected EOF on client connection
LOG:  checkpoint starting: time
LOG:  checkpoint complete: wrote 208 buffers (0.1%); 0 transaction log
file(s) added, 0 removed, 0 recycled; write=41.602 s, sync=0.542 s,
total=42.273 s
ERROR:  unexpected message type 0x58 during COPY from stdin
CONTEXT:  COPY form_big, line 11102095
STATEMENT:  COPY form_big (form_big_id, customer_id, client_id, debt_id,
debt_trans_id, created_by, create_date, last_update, last_updated_by,
text0000, text0001, text0002, text0003, text0004, text0005, text0006,
text0007, text0008, text0009, text0010, text0011, text0012, text0013,
text0014, text0015, text0016, text0017, text0018, text0019, text0020,
text0021, text0022, text0023, text0024, text0025, text0026, text0027,
text0028, text0029, text0030, text0031, text0032, text0033, text0034,
text0035, text0036, text0037, text0038, text0039, text0040, text0041,
text0042, text0043, text0044, text0045, text0046, text0047, text0048,
text0049, text0050, text0051, text0052, text0053, text0054, text0055,
text0056, text0057, text0058, text0059, text0060, text0061, text0062,
text0063, text0064, text0065, text0066, text0067, text0068, text0069,
text0070, text0071, text0072, text0073, text0074, text0075, text0076,
text0077, text0078, text0079, text0080, text0081, text0082, text0083,
text0084, text0085, text0086, text0087, text0088, text0089, text0090,
text0091, text0092, text0093, text0094, text0095, text0096, text0097,
text0098, text0099, text0100, text0101, text0102, text0103, text0104,
text0105, text0106, text0107, text0108, text0109, text0110, text0111,
text0112, text0113, text0114, text0115, text0116, text0117, text0118,
text0119, text0120, text0121, text0122, text0123, text0124, text0125,
text0126, text0127, bigint0000, bigint0001, bigint0002, bigint0003,
bigint0004, bigint0005, bigint0006, bigint0007, bigint0008, bigint0009,
bigint0010, bigint0011, bigint0012, bigint0013, bigint0014, bigint0015,
bigint0016, bigint0017, bigint0018, bigint0019, bigint0020, bigint0021,
bigint0022, bigint0023, bigint0024, bigint0025, bigint0026, bigint0027,
bigint0028, bigint0029, bigint0030, bigint0031, bigint0032, bigint0033,
bigint0034, bigint0035, bigint0036, bigint0037, bigint0038, bigint0039,
bigint0040, bigint0041, bigint0042, bigint0043, bigint0044, bigint0045,
bigint0046, bigint0047, bigint0048, bigint0049, bigint0050, bigint0051,
bigint0052, bigint0053, bigint0054, bigint0055, bigint0056, bigint0057,
bigint0058, bigint0059, bigint0060, bigint0061, bigint0062, bigint0063,
bigint0064, bigint0065, bigint0066, bigint0067, bigint0068, bigint0069,
bigint0070, bigint0071, bigint0072, bigint0073, bigint0074, bigint0075,
bigint0076, bigint0077, bigint0078, bigint0079, bigint0080, bigint0081,
bigint0082, bigint0083, bigint0084, bigint0085, bigint0086, bigint0087,
bigint0088, bigint0089, bigint0090, bigint0091, bigint0092, bigint0093,
bigint0094, bigint0095, bigint0096, bigint0097, bigint0098, bigint0099,
bigint0100, bigint0101, bigint0102, bigint0103, bigint0104, bigint0105,
bigint0106, bigint0107, bigint0108, bigint0109, bigint0110, bigint0111,
bigint0112, bigint0113, bigint0114, bigint0115, bigint0116, bigint0117,
bigint0118, bigint0119, bigint0120, bigint0121, bigint0122, bigint0123,
bigint0124, bigint0125, bigint0126, bigint0127, timestamp0000,
timestamp0001, timestamp0002, timestamp0003, timestamp0004, timestamp0005,
timestamp0006, timestamp0007, timestamp0008, timestamp0009, timestamp0010,
timestamp0011, timestamp0012, timestamp0013, timestamp0014, timestamp0015,
timestamp0016, timestamp0017, timestamp0018, timestamp0019, timestamp0020,
timestamp0021, timestamp0022, timestamp0023, timestamp0024, timestamp0025,
timestamp0026, timestamp0027, timestamp0028, timestamp0029, timestamp0030,
timestamp0031, timestamp0032, timestamp0033, timestamp0034, timestamp0035,
timestamp0036, timestamp0037, timestamp0038, timestamp0039, timestamp0040,
timestamp0041, timestamp0042, timestamp0043, timestamp0044, timestamp0045,
timestamp0046, timestamp0047, timestamp0048, timestamp0049, timestamp0050,
timestamp0051, timestamp0052, timestamp0053, timestamp0054, timestamp0055,
timestamp0056, timestamp0057, timestamp0058, timestamp0059, timestamp0060,
timestamp0061, timestamp0062, timestamp0063, timestamp0064, timestamp0065,
timestamp0066, timestamp0067, timestamp0068, timestamp0069, timestamp0070,
timestamp0071, timestamp0072, timestamp0073, timestamp0074, timestamp0075,
timestamp0076, timestamp0077, timestamp0078, timestamp0079, timestamp0080,
timestamp0081, timestamp0082, timestamp0083, timestamp0084, timestamp0085,
timestamp0086, timestamp0087, timestamp0088, timestamp0089, timestamp0090,
timestamp0091, timestamp0092, timestamp0093, timestamp0094, timestamp0095,
timestamp0096, timestamp0097, timestamp0098, timestamp0099, timestamp0100,
timestamp0101, timestamp0102, timestamp0103, timestamp0104, timestamp0105,
timestamp0106, timestamp0107, timestamp0108, timestamp0109, timestamp0110,
timestamp0111, timestamp0112, timestamp0113, timestamp0114, timestamp0115,
timestamp0116, timestamp0117, timestamp0118, timestamp0119, timestamp0120,
timestamp0121, timestamp0122, timestamp0123, timestamp0124, timestamp0125,
timestamp0126, timestamp0127, real0000, real0001, real0002, real0003,
real0004, real0005, real0006, real0007, real0008, real0009, real0010,
real0011, real0012, real0013, real0014, real0015, real0016, real0017,
real0018, real0019, real0020, real0021, real0022, real0023, real0024,
real0025, real0026, real0027, real0028, real0029, real0030, real0031,
real0032, real0033, real0034, real0035, real0036, real0037, real0038,
real0039, real0040, real0041, real0042, real0043, real0044, real0045,
real0046, real0047, real0048, real0049, real0050, real0051, real0052,
real0053, real0054, real0055, real0056, real0057, real0058, real0059,
real0060, real0061, real0062, real0063, real0064, real0065, real0066,
real0067, real0068, real0069, real0070, real0071, real0072, real0073,
real0074, real0075, real0076, real0077, real0078, real0079, real0080,
real0081, real0082, real0083, real0084, real0085, real0086, real0087,
real0088, real0089, real0090, real0091, real0092, real0093, real0094,
real0095, real0096, real0097, real0098, real0099, real0100, real0101,
real0102, real0103, real0104, real0105, real0106, real0107, real0108,
real0109, real0110, real0111, real0112, real0113, real0114, real0115,
real0116, real0117, real0118, real0119, real0120, real0121, real0122,
real0123, real0124, real0125, real0126, real0127, boolean0000, boolean0001,
boolean0002, boolean0003, boolean0004, boolean0005, boolean0006,
boolean0007, boolean0008, boolean0009, boolean0010, boolean0011,
boolean0012, boolean0013, boolean0014, boolean0015, boolean0016,
boolean0017, boolean0018, boolean0019, boolean0020, boolean0021,
boolean0022, boolean0023, boolean0024, boolean0025, boolean0026,
boolean0027, boolean0028, boolean0029, boolean0030, boolean0031,
boolean0032, boolean0033, boolean0034, boolean0035, boolean0036,
boolean0037, boolean0038, boolean0039, boolean0040, boolean0041,
boolean0042, boolean0043, boolean0044, boolean0045, boolean0046,
boolean0047, boolean0048, boolean0049, boolean0050, boolean0051,
boolean0052, boolean0053, boolean0054, boolean0055, boolean0056,
boolean0057, boolean0058, boolean0059, boolean0060, boolean0061,
boolean0062, boolean0063, boolean0064, boolean0065, boolean0066,
boolean0067, boolean0068, boolean0069, boolean0070, boolean0071,
boolean0072, boolean0073, boolean0074, boolean0075, boolean0076,
boolean0077, boolean0078, boolean0079, boolean0080, boolean0081,
boolean0082, boolean0083, boolean0084, boolean0085, boolean0086,
boolean0087, boolean0088, boolean0089, boolean0090, boolean0091,
boolean0092, boolean0093, boolean0094, boolean0095, boolean0096,
boolean0097, boolean0098, boolean0099, boolean0100, boolean0101,
boolean0102, boolean0103, boolean0104, boolean0105, boolean0106,
boolean0107, boolean0108, boolean0109, boolean0110, boolean0111,
boolean0112, boolean0113, boolean0114, boolean0115, boolean0116,
boolean0117, boolean0118, boolean0119, boolean0120, boolean0121,
boolean0122, boolean0123, boolean0124, boolean0125, boolean0126,
boolean0127, form_config_id) FROM stdin;


On Thu, Jul 21, 2011 at 2:10 PM, Greg Johnson
<greg.johnson@interprose.com>wrote:

> I tried it both ways..
>
> On Thu, Jul 21, 2011 at 2:10 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> > Greg Johnson <greg.johnson@interprose.com> writes:
> >> Interesting.. I was able to pg_restore -f to a file... and then psql -f
>  the
> >> resulting file. and it loaded just fine.. the down side to this method
> is I
> >> cannot use the parallel load function (and the extra time). but I am
> glad
> >> that I got the data loaded. Let me know if there is any other info I get
> >> you.
> >
> > Parallel restore?  You didn't mention using parallel restore before.
> > Were the failed pg_restore runs using parallelism?
> >
> >                        regards, tom lane
> >
>
>
>
> --
> ----------------------------------------------------------------
> Greg Johnson
> The InterProse Corporation
> Software Developer
> Phone: (360) 604-3531 x225
> Fax: (360) 604-3579
>



--
----------------------------------------------------------------
Greg Johnson
The InterProse Corporation
Software Developer
Phone: (360) 604-3531 x225
Fax: (360) 604-3579