Обсуждение: Backends dying due to memory exhaustion--I'm stonkered

I have a 7.0.3 installation, compiled from source, on a (pretty much)
stock RedHat 6.2 system with security patches.  There are about 8
databases, none of which are very active.  I'm running a web
application (OpenACS 3.2.4) that runs under AOLServer and uses the
databases.

The problem I'm having is that the backends will crash randomly, after
the database has been up for a few days, with:

FATAL 1:  Memory exhausted in AllocSetAlloc()

Sometimes this happens while the nightly vacuum is running, sometimes
at random times when the web app makes a query.  Here's an example of
the full error from the vacuum script:

Vacuuming template1
VACUUM
Vacuuming nsaweb
VACUUM
Vacuuming wb
VACUUM
Vacuuming eq
VACUUM
Vacuuming penntex
FATAL 1:  Memory exhausted in AllocSetAlloc()
pqReadData() -- backend closed the channel unexpectedly.
        This probably means the backend terminated abnormally
        before or while processing the request.
connection to server was lost

I have core dumps enabled (ulimit -c unlimited) and there are no core
files in the $PGDATA tree.  This makes sense, as I looked at the
source, and this message is only generated when malloc() fails, on
which the backend terminates--there's no signal generated.

I've check all other ulimit settings and can't see any limits that PG
would be hitting.  I'm running the postmaster as follows:

/usr/local/pgsql/bin/postmaster -N 64 -B 2000 -o "-S 2000" -D $PGDATA

The system has plenty of memory and swap, and under normal
circumstances the backends take up 10-15 megabytes.  If it's a
runaway situation of some kind, it happens very fast, as I've even
taken snapshots of the process table at 1 minute intervals, and they
show no abnormality right up to the time of the crash.

Any ideas on what might be the problem?  It seems odd that I'm the
only person seeing this level of instability...

-Doug

Doug McNaught <doug@wireboard.com> writes:
> The problem I'm having is that the backends will crash randomly, after
> the database has been up for a few days, with:
> FATAL 1:  Memory exhausted in AllocSetAlloc()

> The system has plenty of memory and swap, and under normal
> circumstances the backends take up 10-15 megabytes.  If it's a
> runaway situation of some kind, it happens very fast, as I've even
> taken snapshots of the process table at 1 minute intervals, and they
> show no abnormality right up to the time of the crash.

Hmm.  That puts a damper on the idea that it's a memory leak --- doesn't
eliminate the theory entirely, however.  The other likely theory is that
you've got a variable-size column value someplace whose size word has
been corrupted, so that it claims to be umpteen megabytes long.  Any
attempt to copy such a value out of the tuple it's in will result in
an instant "out of memory" complaint.

Is there any consistency about which table is being touched when the
failure occurs?  It's not hard to isolate and delete a damaged tuple
once you know which table it's in, but if you've got a lot of tables
the initial search can be tedious.

One way to get more info is to tweak the code to abort() just before
it would normally report the out-of-memory error.  Then you will get
a coredump and can learn something from the backtrace (don't forget
to compile with -g).

            regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> writes:

> Doug McNaught <doug@wireboard.com> writes:
> > The problem I'm having is that the backends will crash randomly, after
> > the database has been up for a few days, with:
> > FATAL 1:  Memory exhausted in AllocSetAlloc()
>
> > The system has plenty of memory and swap, and under normal
> > circumstances the backends take up 10-15 megabytes.  If it's a
> > runaway situation of some kind, it happens very fast, as I've even
> > taken snapshots of the process table at 1 minute intervals, and they
> > show no abnormality right up to the time of the crash.
>
> Hmm.  That puts a damper on the idea that it's a memory leak --- doesn't
> eliminate the theory entirely, however.  The other likely theory is that
> you've got a variable-size column value someplace whose size word has
> been corrupted, so that it claims to be umpteen megabytes long.  Any
> attempt to copy such a value out of the tuple it's in will result in
> an instant "out of memory" complaint.

Hmm, very interesting.  Does VARCHAR count as a variable-size column?
One funny thing is that the nightly VACUUM doesn't always fail--the
system will run smoothly for one to three days on average before a
crash.

> Is there any consistency about which table is being touched when the
> failure occurs?  It's not hard to isolate and delete a damaged tuple
> once you know which table it's in, but if you've got a lot of tables
> the initial search can be tedious.

I'll check into this.  Having just looked over my error logs, I see
some suspects but nothing jumps out at me.  Unfortunately, OpenACS has
a boatload of tables, and there are 8 different instances, each with
its own database.

> One way to get more info is to tweak the code to abort() just before
> it would normally report the out-of-memory error.  Then you will get
> a coredump and can learn something from the backtrace (don't forget
> to compile with -g).

That's a thought, and I will try it.  I'm currently (as of yesterday's
crash) running with -d 2 and output sent to a logfile.  Is this
debuglevel high enough to tell me which table contains the bad tuple,
if that's indeed the problem?

If I can't nail it down that way, how hard would it be to write a C
program to scan all the tuples in a database looking for bogus size
fields?

-Doug

Doug McNaught <doug@wireboard.com> writes:
> Hmm, very interesting.  Does VARCHAR count as a variable-size column?

Yes.  (So does char(n) btw...)

> One funny thing is that the nightly VACUUM doesn't always fail--the
> system will run smoothly for one to three days on average before a
> crash.

That does seem to contradict the corrupt-data theory.  Do you run a
VACUUM ANALYZE or just a plain VACUUM?  If there were a persisting
corrupted tuple, I'd expect VACUUM ANALYZE to crash always, VACUUM
never (VACUUM doesn't inquire into the actual contents of tuples).

> That's a thought, and I will try it.  I'm currently (as of yesterday's
> crash) running with -d 2 and output sent to a logfile.  Is this
> debuglevel high enough to tell me which table contains the bad tuple,
> if that's indeed the problem?

That would tell you what query is running.  It's not enough to tell you
where VACUUM is unless you do VACUUM VERBOSE.

> If I can't nail it down that way, how hard would it be to write a C
> program to scan all the tuples in a database looking for bogus size
> fields?

Fairly hard.  I'd suggest instead that you just do
    psql -c "copy FOO to stdout" dbname >/dev/null
and try that on each table in turn to see if you get any crashes...

            regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> writes:

> Doug McNaught <doug@wireboard.com> writes:
> > One funny thing is that the nightly VACUUM doesn't always fail--the
> > system will run smoothly for one to three days on average before a
> > crash.
>
> That does seem to contradict the corrupt-data theory.  Do you run a
> VACUUM ANALYZE or just a plain VACUUM?  If there were a persisting
> corrupted tuple, I'd expect VACUUM ANALYZE to crash always, VACUUM
> never (VACUUM doesn't inquire into the actual contents of tuples).

I'm running VACUUM, then VACUUM ANALYZE (the docs seem to suggest that
you need both).  Basically my script is:

$ vacuumdb -a
$ vacuumdb -z -a

The example I sent was a crash during VACUUM.

> > That's a thought, and I will try it.  I'm currently (as of yesterday's
> > crash) running with -d 2 and output sent to a logfile.  Is this
> > debuglevel high enough to tell me which table contains the bad tuple,
> > if that's indeed the problem?
>
> That would tell you what query is running.  It's not enough to tell you
> where VACUUM is unless you do VACUUM VERBOSE.

Which will no doubt generate reams and reams of data...

> > If I can't nail it down that way, how hard would it be to write a C
> > program to scan all the tuples in a database looking for bogus size
> > fields?
>
> Fairly hard.  I'd suggest instead that you just do
>     psql -c "copy FOO to stdout" dbname >/dev/null
> and try that on each table in turn to see if you get any crashes...

OK, I'll keep that in reserve.

Another thing that springs to mind--once the crash happens, the
database doesn't respond (or gives fatal errors) to new connections
and to queries on existing connections.  Killing the postmaster does
nothing--I have to send SIGTERM to all backends and the postmaster in
order to get it to exit.  I don't know if this helps...

-Doug

Doug McNaught <doug@wireboard.com> writes:
> I'm running VACUUM, then VACUUM ANALYZE (the docs seem to suggest that
> you need both).  Basically my script is:

VACUUM ANALYZE is a superset of VACUUM; you do not need both.

> The example I sent was a crash during VACUUM.

Hm.  Another perfectly good theory shot to heck ;-).  It seems unlikely
that VACUUM would fail because of corrupted data inside a tuple ...
although corrupted tuple headers could kill it.  Again, though, one
would think such a crash would be repeatable.

> Another thing that springs to mind--once the crash happens, the
> database doesn't respond (or gives fatal errors) to new connections
> and to queries on existing connections.  Killing the postmaster does
> nothing--I have to send SIGTERM to all backends and the postmaster in
> order to get it to exit.  I don't know if this helps...

Now *this* is interesting.  Normally the system recovers quite nicely
from an elog(FATAL), or even from a backend coredump.  I now suspect
something must be getting corrupted in shared memory.  The next time
it happens, would you proceed as follows:
    1. kill -INT the postmaster.
    2. The backends *should* exit in response to the SIGTERM the
       postmaster will have sent them.  Any backend that survives
       more than a fraction of a second is stuck somehow.  For each
       stuck backend, in turn:
    3. kill -ABORT the backend, to create a corefile, and collect
       a gdb backtrace from the corefile.  Be careful to get the
       right corefile, if you are dealing with more than one
       database.

That should give us some idea of what's stuck (especially if you compile
with -g).

BTW, which version did you say you were running?  If it's less than
7.0.3 I'd recommend an update before we pursue this much further ...

            regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> writes:

> Doug McNaught <doug@wireboard.com> writes:
> > I'm running VACUUM, then VACUUM ANALYZE (the docs seem to suggest that
> > you need both).  Basically my script is:
>
> VACUUM ANALYZE is a superset of VACUUM; you do not need both.

Good to know.

> > The example I sent was a crash during VACUUM.
>
> Hm.  Another perfectly good theory shot to heck ;-).  It seems unlikely
> that VACUUM would fail because of corrupted data inside a tuple ...
> although corrupted tuple headers could kill it.  Again, though, one
> would think such a crash would be repeatable.

Agreed, given what you've said.

> > Another thing that springs to mind--once the crash happens, the
> > database doesn't respond (or gives fatal errors) to new connections
> > and to queries on existing connections.  Killing the postmaster does
> > nothing--I have to send SIGTERM to all backends and the postmaster in
> > order to get it to exit.  I don't know if this helps...
>
> Now *this* is interesting.  Normally the system recovers quite nicely
> from an elog(FATAL), or even from a backend coredump.  I now suspect
> something must be getting corrupted in shared memory.  The next time
> it happens, would you proceed as follows:
>     1. kill -INT the postmaster.
>     2. The backends *should* exit in response to the SIGTERM the
>        postmaster will have sent them.  Any backend that survives
>        more than a fraction of a second is stuck somehow.  For each
>        stuck backend, in turn:
>     3. kill -ABORT the backend, to create a corefile, and collect
>        a gdb backtrace from the corefile.  Be careful to get the
>        right corefile, if you are dealing with more than one
>        database.
>
> That should give us some idea of what's stuck (especially if you compile
> with -g).

I don't remember if I did or not, and (like a moron) I blew away the
source tree.  I'll see what gdb tells me about the presence of
symbols.

From what I've seen so far, all the backends (other than the one that
actually crashes) seem to survive the SIGTERM I send to the
postmaster.  How do I tell which one is which?  The command line?

> BTW, which version did you say you were running?  If it's less than
> 7.0.3 I'd recommend an update before we pursue this much further ...

Just double-checked and it is indeed 7.0.3.

I'll be back with more info once I get another crash...

-Doug

Doug McNaught <doug@wireboard.com> writes:
> From what I've seen so far, all the backends (other than the one that
> actually crashes) seem to survive the SIGTERM I send to the
> postmaster.  How do I tell which one is which?  The command line?

SIGTERM to the postmaster commands polite shutdown, ie, don't accept
new connections but allow existing clients to finish out their sessions.
So unless your clients are short-lived I wouldn't expect SIGTERM'ing
the postmaster to do much.

If you want to force things to happen then you should send SIGINT to
the postmaster, which in turn will SIGTERM its backends, which in
theory will abort their transactions and shut down.  (No, this isn't
real consistent, but we wanted the right things to happen when a
system-wide shutdown sends SIGTERM to all the processes.  Usually
you shouldn't be manually killing individual backends anyway, so the
lack of consistency in signal meaning shouldn't mean much...)

As far as telling which is which, I doubt it much matters for this.
If you've compiled with -g then the backtraces should show the queries
that each one was executing, and that's as much info as we're likely
to need.

            regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> writes:

> Doug McNaught <doug@wireboard.com> writes:
> > From what I've seen so far, all the backends (other than the one that
> > actually crashes) seem to survive the SIGTERM I send to the
> > postmaster.  How do I tell which one is which?  The command line?
>
> SIGTERM to the postmaster commands polite shutdown, ie, don't accept
> new connections but allow existing clients to finish out their sessions.
> So unless your clients are short-lived I wouldn't expect SIGTERM'ing
> the postmaster to do much.
>
> If you want to force things to happen then you should send SIGINT to
> the postmaster, which in turn will SIGTERM its backends, which in
> theory will abort their transactions and shut down.

OK, this makes sense.  I must have missed it in the manual.  SIGINT it
is.

Waiting for the next crash with anticipation...

-Doug

>
>Waiting for the next crash with anticipation...

Since you said you are running ACS is here you may as well want to
set the param Verbose to True in your db pool which will log all queries to
the db in the access log.  Then when it crashes during
normal execution you can simple determine the offending query.  Of
course this may create a copius log file on an heavily accessed site and you
may wish to roll the log more freqently. Also wont may not
be related or help the vacuum situation.

Best Regards,
Carl Garland
_________________________________________________________________
Get your FREE download of MSN Explorer at http://explorer.msn.com

Tom Lane <tgl@sss.pgh.pa.us> writes:

> If you want to force things to happen then you should send SIGINT to
> the postmaster, which in turn will SIGTERM its backends, which in
> theory will abort their transactions and shut down.  (No, this isn't
> real consistent, but we wanted the right things to happen when a
> system-wide shutdown sends SIGTERM to all the processes.  Usually
> you shouldn't be manually killing individual backends anyway, so the
> lack of consistency in signal meaning shouldn't mean much...)

OK, finally got another crash.  There is no core file, and all the
backends exited cleanly when I sent SIGINT to the postmaster.

I realized something very interesting that I hadn't twigged to before:
OpenACS was running a scheduled notification (that involves least one
update) at the exact same time that VACUUM was running on the
database.  This time, I got a different memory-related error in the
VACUUM:

basename: error in loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate
memory
/usr/local/pgsql/bin/vacuumdb: /usr/local/pgsql/bin/vacuumdbpsql: No such file or directory
Vacuuming template1
VACUUM
[...]

This is *very* interesting, as it indicates that the system as a whole
is running out of memory right as the VACUUM and OpenACS notification
thread kick off.

What may be happening is that the update that ACS wants to do is
blocked by the VACUUM, and something in there is going nuts and eating
memory like crazy.

The only fly in this ointment is that the above log fragment seems to
indicate that the system ran out of memory before VACUUM even started
(the 'basename' command in 'vacuumdb' is what crapped out AFAICS).

So maybe the AOLServer/ACS combo is the culprit here.

I've moved the VACUUM to a time that doesn't coincide with the ACS
notification stuff; I'll see if we continue to get crashes, and when.

Anyhow, thanks for listening to my ramblings; looks like PG may be
off the hook, which would make me very happy, as I think it's a great
product.

-Doug