Thread: pqReadData() -- backend closed the channel unexpectedly.

I am running PostgreSQL 7.1.2 on FreeBSD 4.3
This is an old 486 with only 12MB memory.

I am able to create databases and insert and retrieve data,
but when I try to query on the structure of the database
I am getting this error:

signin=# \d person_personid_seq
pqReadData() -- backend closed the channel unexpectedly.
        This probably means the backend terminated abnormally
        before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!# \q


I have never seen that prompt before (!#)

I turned up debugging and here is (some) of the output:

<snip>
DEBUG:  database system is in production state
DEBUG:  proc_exit(0)
DEBUG:  shmem_exit(0)
DEBUG:  exit(0)
postmaster: reaping dead processes...
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
<snip>
postmaster: ServerLoop:         handling writing 4
postmaster: BackendStartup: pid 635 user lee db lee socket 4
postmaster child[635]: starting with (postgres -d5 -d 5 -v131072 -p lee )
FindExec: searching PATH ...
FindExec: found "/usr/local/bin/postgres" using PATH
DEBUG:  connection: host=[local] user=lee database=lee
DEBUG:  InitPostgres
DEBUG:  StartTransactionCommand
DEBUG:  query: SELECT usesuper FROM pg_user WHERE usename = 'lee'
<snip>
DEBUG:  ProcessQuery
DEBUG:  CommitTransactionCommand
DEBUG:  proc_exit(0)
DEBUG:  shmem_exit(0)
DEBUG:  exit(0)
postmaster: reaping dead processes...
postmaster: CleanupProc: pid 635 exited with status 0
postmaster: ServerLoop:         handling reading 4
<snip>
postmaster: ServerLoop:         handling writing 4
postmaster: BackendStartup: pid 642 user lee db signin socket 4
postmaster child[642]: starting with (postgres -d5 -d 5 -v131072 -p signin )
FindExec: searching PATH ...
FindExec: found "/usr/local/bin/postgres" using PATH
DEBUG:  connection: host=[local] user=lee database=signin
DEBUG:  InitPostgres
DEBUG:  proc_exit(0)
DEBUG:  shmem_exit(0)
DEBUG:  exit(0)
postmaster: reaping dead processes...
postmaster: CleanupProc: pid 639 exited with status 0
<snip>
postmaster: reaping dead processes...
postmaster: CleanupProc: pid 642 exited with status 132
Server process (pid 642) exited with status 132 at Mon Jul 23 09:46:26 2001
Terminating any active server processes...
Server processes were terminated at Mon Jul 23 09:46:26 2001
Reinitializing shared memory and semaphores
invoking IpcMemoryCreate(size=1236992)
DEBUG:  database system was interrupted at 2001-07-23 09:44:48 EDT
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
The Data Base System is starting up
postmaster: ServerLoop:         handling writing 4
DEBUG:  CheckPoint record at (0, 3580356)
DEBUG:  Redo record at (0, 3580356); Undo record at (0, 0); Shutdown TRUE
DEBUG:  NextTransactionId: 1362; NextOid: 101105
DEBUG:  database system was not properly shut down; automatic recovery in progre
ss...
DEBUG:  ReadRecord: record with zero len at (0, 3580420)
DEBUG:  redo is not required
DEBUG:  database system is in production state
DEBUG:  proc_exit(0)
DEBUG:  shmem_exit(0)
DEBUG:  exit(0)
postmaster: reaping dead processes...
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
<snip>
DEBUG:  StartTransactionCommand
DEBUG:  query: SELECT relhasindex, relkind, relchecks, reltriggers, relhasrules
FROM pg_class WHERE relname='person_personid_seq'
DEBUG:  parse tree: { QUERY :command 1  :utility <> :resultRelation 0 :into <> :
<snip>
<> :sortClause ({ SORTCLAUSE :tleSortGroupRef 1 :sortop 95 }) :limitOffset <> :l
imitCount <> :setOperations <> :resultRelations ()}
postmaster: reaping dead processes...
postmaster: CleanupProc: pid 654 exited with status 132
Server process (pid 654) exited with status 132 at Mon Jul 23 09:47:37 2001
Terminating any active server processes...
Server processes were terminated at Mon Jul 23 09:47:37 2001
Reinitializing shared memory and semaphores
invoking IpcMemoryCreate(size=1236992)
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
postmaster: ServerLoop:         handling reading 4
The Data Base System is starting up
postmaster: ServerLoop:         handling writing 4
DEBUG:  database system was interrupted at 2001-07-23 09:46:29 EDT
DEBUG:  CheckPoint record at (0, 3580420)
DEBUG:  Redo record at (0, 3580420); Undo record at (0, 0); Shutdown TRUE
DEBUG:  NextTransactionId: 1362; NextOid: 101105
DEBUG:  database system was not properly shut down; automatic recovery in progre
ss...
DEBUG:  ReadRecord: record with zero len at (0, 3580484)
DEBUG:  redo is not required
DEBUG:  database system is in production state
DEBUG:  proc_exit(0)
DEBUG:  shmem_exit(0)
DEBUG:  exit(0)
postmaster: reaping dead processes...

Ouch, 12 megs of RAM with FreeBSD *might* lead to troubles itself.

From
http://www.freebsd.org/doc/en_US.ISO8859-1/books/handbook/install-hw.html :

"In order to run FreeBSD, a recommended minimum of eight megabytes of RAM is
suggested. Sixteen megabytes is the preferred amount of RAM as you may have
some trouble with anything less than sixteen depending on your hardware.."

I can't decipher anything from the log but hopefully someone else can to
tell you if it's a memory problem or not for sure (if it is, I'd think PG
would exit a bit more gracefully)...

Good luck!

-Mitch

----- Original Message -----
From: "Lee Harr" <lee@troll.east.rochester.k12.ny.us>
To: <pgsql-general@postgresql.org>
Sent: Monday, July 23, 2001 10:19 AM
Subject: [GENERAL] pqReadData() -- backend closed the channel unexpectedly.


> I am running PostgreSQL 7.1.2 on FreeBSD 4.3
> This is an old 486 with only 12MB memory.
>
> I am able to create databases and insert and retrieve data,
> but when I try to query on the structure of the database
> I am getting this error:
>
> signin=# \d person_personid_seq
> pqReadData() -- backend closed the channel unexpectedly.
>         This probably means the backend terminated abnormally
>         before or while processing the request.
> The connection to the server was lost. Attempting reset: Failed.
> !# \q
>
>
> I have never seen that prompt before (!#)
>
> I turned up debugging and here is (some) of the output:
>
> <snip>
> DEBUG:  database system is in production state
> DEBUG:  proc_exit(0)
> DEBUG:  shmem_exit(0)
> DEBUG:  exit(0)
> postmaster: reaping dead processes...
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> <snip>
> postmaster: ServerLoop:         handling writing 4
> postmaster: BackendStartup: pid 635 user lee db lee socket 4
> postmaster child[635]: starting with (postgres -d5 -d 5 -v131072 -p lee )
> FindExec: searching PATH ...
> FindExec: found "/usr/local/bin/postgres" using PATH
> DEBUG:  connection: host=[local] user=lee database=lee
> DEBUG:  InitPostgres
> DEBUG:  StartTransactionCommand
> DEBUG:  query: SELECT usesuper FROM pg_user WHERE usename = 'lee'
> <snip>
> DEBUG:  ProcessQuery
> DEBUG:  CommitTransactionCommand
> DEBUG:  proc_exit(0)
> DEBUG:  shmem_exit(0)
> DEBUG:  exit(0)
> postmaster: reaping dead processes...
> postmaster: CleanupProc: pid 635 exited with status 0
> postmaster: ServerLoop:         handling reading 4
> <snip>
> postmaster: ServerLoop:         handling writing 4
> postmaster: BackendStartup: pid 642 user lee db signin socket 4
> postmaster child[642]: starting with (postgres -d5 -d 5 -v131072 -p
signin )
> FindExec: searching PATH ...
> FindExec: found "/usr/local/bin/postgres" using PATH
> DEBUG:  connection: host=[local] user=lee database=signin
> DEBUG:  InitPostgres
> DEBUG:  proc_exit(0)
> DEBUG:  shmem_exit(0)
> DEBUG:  exit(0)
> postmaster: reaping dead processes...
> postmaster: CleanupProc: pid 639 exited with status 0
> <snip>
> postmaster: reaping dead processes...
> postmaster: CleanupProc: pid 642 exited with status 132
> Server process (pid 642) exited with status 132 at Mon Jul 23 09:46:26
2001
> Terminating any active server processes...
> Server processes were terminated at Mon Jul 23 09:46:26 2001
> Reinitializing shared memory and semaphores
> invoking IpcMemoryCreate(size=1236992)
> DEBUG:  database system was interrupted at 2001-07-23 09:44:48 EDT
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> The Data Base System is starting up
> postmaster: ServerLoop:         handling writing 4
> DEBUG:  CheckPoint record at (0, 3580356)
> DEBUG:  Redo record at (0, 3580356); Undo record at (0, 0); Shutdown TRUE
> DEBUG:  NextTransactionId: 1362; NextOid: 101105
> DEBUG:  database system was not properly shut down; automatic recovery in
progre
> ss...
> DEBUG:  ReadRecord: record with zero len at (0, 3580420)
> DEBUG:  redo is not required
> DEBUG:  database system is in production state
> DEBUG:  proc_exit(0)
> DEBUG:  shmem_exit(0)
> DEBUG:  exit(0)
> postmaster: reaping dead processes...
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> <snip>
> DEBUG:  StartTransactionCommand
> DEBUG:  query: SELECT relhasindex, relkind, relchecks, reltriggers,
relhasrules
> FROM pg_class WHERE relname='person_personid_seq'
> DEBUG:  parse tree: { QUERY :command 1  :utility <> :resultRelation 0
:into <> :
> <snip>
> <> :sortClause ({ SORTCLAUSE :tleSortGroupRef 1 :sortop 95 }) :limitOffset
<> :l
> imitCount <> :setOperations <> :resultRelations ()}
> postmaster: reaping dead processes...
> postmaster: CleanupProc: pid 654 exited with status 132
> Server process (pid 654) exited with status 132 at Mon Jul 23 09:47:37
2001
> Terminating any active server processes...
> Server processes were terminated at Mon Jul 23 09:47:37 2001
> Reinitializing shared memory and semaphores
> invoking IpcMemoryCreate(size=1236992)
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> postmaster: ServerLoop:         handling reading 4
> The Data Base System is starting up
> postmaster: ServerLoop:         handling writing 4
> DEBUG:  database system was interrupted at 2001-07-23 09:46:29 EDT
> DEBUG:  CheckPoint record at (0, 3580420)
> DEBUG:  Redo record at (0, 3580420); Undo record at (0, 0); Shutdown TRUE
> DEBUG:  NextTransactionId: 1362; NextOid: 101105
> DEBUG:  database system was not properly shut down; automatic recovery in
progre
> ss...
> DEBUG:  ReadRecord: record with zero len at (0, 3580484)
> DEBUG:  redo is not required
> DEBUG:  database system is in production state
> DEBUG:  proc_exit(0)
> DEBUG:  shmem_exit(0)
> DEBUG:  exit(0)
> postmaster: reaping dead processes...
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Don't 'kill -9' the postmaster
>

I got an email saying that my message did not make it to the list, so I
am posting again. Hopefully it will go through this time.

 I am running PostgreSQL 7.1.2 on FreeBSD 4.3
 This is an old 486 with only 12MB memory.

 I am able to create databases and insert and retrieve data,
 but when I try to query on the structure of the database
 I am getting this error:

 signin=# \d person_personid_seq
 pqReadData() -- backend closed the channel unexpectedly.
         This probably means the backend terminated abnormally
         before or while processing the request.
 The connection to the server was lost. Attempting reset: Failed.
 !# \q


 I have never seen that prompt before (!#)

 I turned up debugging and here is (some) of the output:

<snip>
 DEBUG:  database system is in production state
 DEBUG:  proc_exit(0)
 DEBUG:  shmem_exit(0)
 DEBUG:  exit(0)
 postmaster: reaping dead processes...
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
<snip>
 postmaster: ServerLoop:         handling writing 4
 postmaster: BackendStartup: pid 635 user lee db lee socket 4
 postmaster child[635]: starting with (postgres -d5 -d 5 -v131072 -p lee )
 FindExec: searching PATH ...
 FindExec: found "/usr/local/bin/postgres" using PATH
 DEBUG:  connection: host=[local] user=lee database=lee
 DEBUG:  InitPostgres
 DEBUG:  StartTransactionCommand
 DEBUG:  query: SELECT usesuper FROM pg_user WHERE usename = 'lee'
<snip>
 DEBUG:  ProcessQuery
 DEBUG:  CommitTransactionCommand
 DEBUG:  proc_exit(0)
 DEBUG:  shmem_exit(0)
 DEBUG:  exit(0)
 postmaster: reaping dead processes...
 postmaster: CleanupProc: pid 635 exited with status 0
 postmaster: ServerLoop:         handling reading 4
<snip>
 postmaster: ServerLoop:         handling writing 4
 postmaster: BackendStartup: pid 642 user lee db signin socket 4
 postmaster child[642]: starting with (postgres -d5 -d 5 -v131072 -p signin )
 FindExec: searching PATH ...
 FindExec: found "/usr/local/bin/postgres" using PATH
 DEBUG:  connection: host=[local] user=lee database=signin
 DEBUG:  InitPostgres
 DEBUG:  proc_exit(0)
 DEBUG:  shmem_exit(0)
 DEBUG:  exit(0)
 postmaster: reaping dead processes...
 postmaster: CleanupProc: pid 639 exited with status 0
<snip>
 postmaster: reaping dead processes...
 postmaster: CleanupProc: pid 642 exited with status 132
 Server process (pid 642) exited with status 132 at Mon Jul 23 09:46:26 2001
 Terminating any active server processes...
 Server processes were terminated at Mon Jul 23 09:46:26 2001
 Reinitializing shared memory and semaphores
 invoking IpcMemoryCreate(size=1236992)
 DEBUG:  database system was interrupted at 2001-07-23 09:44:48 EDT
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 The Data Base System is starting up
 postmaster: ServerLoop:         handling writing 4
 DEBUG:  CheckPoint record at (0, 3580356)
 DEBUG:  Redo record at (0, 3580356); Undo record at (0, 0); Shutdown TRUE
 DEBUG:  NextTransactionId: 1362; NextOid: 101105
 DEBUG:  database system was not properly shut down; automatic recovery in progr
 DEBUG:  ReadRecord: record with zero len at (0, 3580420)
 DEBUG:  redo is not required
 DEBUG:  database system is in production state
 DEBUG:  proc_exit(0)
 DEBUG:  shmem_exit(0)
 DEBUG:  exit(0)
 postmaster: reaping dead processes...
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
<snip>
 DEBUG:  StartTransactionCommand
 DEBUG:  query: SELECT relhasindex, relkind, relchecks, reltriggers, relhasrules
 FROM pg_class WHERE relname='person_personid_seq'
 DEBUG:  parse tree: { QUERY :command 1  :utility <> :resultRelation 0 :into <>
<snip>
<> :sortClause ({ SORTCLAUSE :tleSortGroupRef 1 :sortop 95 }) :limitOffset <> :l
 imitCount <> :setOperations <> :resultRelations ()}
 postmaster: reaping dead processes...
 postmaster: CleanupProc: pid 654 exited with status 132
 Server process (pid 654) exited with status 132 at Mon Jul 23 09:47:37 2001
 Terminating any active server processes...
 Server processes were terminated at Mon Jul 23 09:47:37 2001
 Reinitializing shared memory and semaphores
 invoking IpcMemoryCreate(size=1236992)
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 postmaster: ServerLoop:         handling reading 4
 The Data Base System is starting up
 postmaster: ServerLoop:         handling writing 4
 DEBUG:  database system was interrupted at 2001-07-23 09:46:29 EDT
 DEBUG:  CheckPoint record at (0, 3580420)
 DEBUG:  Redo record at (0, 3580420); Undo record at (0, 0); Shutdown TRUE
 DEBUG:  NextTransactionId: 1362; NextOid: 101105
 DEBUG:  database system was not properly shut down; automatic recovery in progr
 DEBUG:  ReadRecord: record with zero len at (0, 3580484)
 DEBUG:  redo is not required
 DEBUG:  database system is in production state
 DEBUG:  proc_exit(0)
 DEBUG:  shmem_exit(0)
 DEBUG:  exit(0)
 postmaster: reaping dead processes...



Could running out of memory cause the backend to die like that? I have the
exact same schema and data loaded on another 486 (with 64M RAM) and it
runs without any hitches.

If it is a memory problem, any hints on tuning the system so that it
can run without crashing?

BTW, I bumped the RAM in this machine up to 40M just now to see if
it could be a memory problem, and it still acts the same way.

Could still be running out of resources, but like I said I had this
same setup on another 486 running without any trouble.

On Tue, 24 Jul 2001 19:26:07 +0000 (UTC), Lee Harr <missive@frontiernet.net>:


I have tried twice to post some output from psql and from the postmaster
error log, but I get an email saying:


Rejected:

Inews returned Operation not permitted for this message
even after escaping quoted content.

Message has not been posted to the discussion group.


Is there something in a log file that might cause this? The Inews
error message does not say what I should be removing from my post
in order for it to go through.

Aargh!

Ok, I was able to copy my data out in to a text file. I thought
maybe the database file was corrupted somehow, so I wiped out the
data directory, initdb and recreated the database from the backup.

Still when I run some queries I get the error message from the subject:

pqReadData() -- backend closed channel unexpectedly


Could this be a shared memory problem?
ie, running out of shared memory?

I recompiled with debugging enabled, but it does not seem to have helped
much with this backtrace output. Any suggestions?



jc12# gdb -c postgres.core
GNU gdb 4.18
Copyright 1998 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-unknown-freebsd".
Core was generated by `postgres'.
Program terminated with signal 4, Illegal instruction.
#0  0x812023a in ?? ()
(gdb) bt
#0  0x812023a in ?? ()
#1  0x81200fc in ?? ()
#2  0x811f97c in ?? ()
#3  0x813a4a8 in ?? ()
#4  0x811fae0 in ?? ()
#5  0x813ae0e in ?? ()
#6  0x80e730e in ?? ()
#7  0x80da636 in ?? ()
#8  0x80da523 in ?? ()
#9  0x80db434 in ?? ()
#10 0x80da1e1 in ?? ()
#11 0x80da19c in ?? ()
#12 0x80d9ffb in ?? ()
#13 0x80e12e4 in ?? ()
#14 0x80e11f3 in ?? ()
#15 0x80e20a4 in ?? ()
#16 0x80e1593 in ?? ()
#17 0x80e1449 in ?? ()
#18 0x80feec7 in ?? ()
#19 0x80ff0bd in ?? ()
#20 0x810018c in ?? ()
#21 0x80ea75a in ?? ()
#22 0x80ea2ce in ?? ()
#23 0x80e94d1 in ?? ()
---Type <return> to continue, or q <return> to quit---
#24 0x80e8ee7 in ?? ()
#25 0x80c9465 in ?? ()
#26 0x80645f5 in ?? ()
(gdb) q
jc12# exit
exit

Ok, I got some more information out of the debugger, but not much more.
Any wisdom is appreciated.


Script started on Fri Jul 27 10:24:29 2001
jc12# gdb -c postgres.core -s /usr/local/bin/postgres
GNU gdb 4.18
Copyright 1998 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-unknown-freebsd"...
Core was generated by `postgres'.
Program terminated with signal 4, Illegal instruction.
#0  0x812023a in convert_numeric_to_scalar (value=65529, typid=21)
    at selfuncs.c:923
923    selfuncs.c: No such file or directory.
(gdb) bt
#0  0x812023a in convert_numeric_to_scalar (value=65529, typid=21)
    at selfuncs.c:923
Cannot access memory at address 0x81201cc.
(gdb) backtrace
#0  0x812023a in convert_numeric_to_scalar (value=65529, typid=21)
    at selfuncs.c:923
Cannot access memory at address 0x81201cc.
(gdb) jc12#
jc12# exit
exit

Script done on Fri Jul 27 10:26:11 2001

missive@frontiernet.net (Lee Harr) writes:
>  I am running PostgreSQL 7.1.2 on FreeBSD 4.3
>  This is an old 486 with only 12MB memory.
>  I am able to create databases and insert and retrieve data,
>  but when I try to query on the structure of the database
>  I am getting this error:
>  signin=# \d person_personid_seq
>  pqReadData() -- backend closed the channel unexpectedly.

Hmm ... status 132 evidently means the backend died with signal 4,
which I believe is illegal instruction trap on *BSD.  Most odd.
There should be a core file left by the failed backend (in
$PGDATA/base/YOURDB/core).  Can you get a stack trace from the
core file with gdb?

            regards, tom lane

missive@frontiernet.net (Lee Harr) writes:
> Ok, I got some more information out of the debugger, but not much more.

Ah, I didn't see this message before --- apologies for my previous
waste-of-bandwidth.

> Program terminated with signal 4, Illegal instruction.
> #0  0x812023a in convert_numeric_to_scalar (value=65529, typid=21)
>     at selfuncs.c:923
> 923    selfuncs.c: No such file or directory.

That's strange --- the source line in question is

    return (double) DatumGetInt16(value);

There's no reason I can see that converting int16 to double should fail.
What compiler did you compile with, exactly?

            regards, tom lane