Re: BUG #4996: postgres.exe memory consumption keeps going up

The following bug has been logged online:

Bug reference: 4996
Logged by: Shivesh Wangrungvichaisri
Email address: sbw(at)appsig(dot)com
PostgreSQL version: 8.3.7
Operating system: Windows XP x64 / Windows 7 x64
Description: postgres.exe memory consumption keeps going up
Details:

Application: C++
Connector: libpq that came with 8.3.7
Problem: postgres.exe memory consumption keeps going up. (Working set and
Sharable as viewed from Windows Task Manager)
Steps to reproduce problem:
1) Create a test table
2) Using a C++ program, create 2 threads.
3) First thread will keep doing an INSERT of anything.
4) Second thread will keep doing a SELECT of anything.
5) Do NOT call PQfinish on PGconn. Rather, keep the connection opened after
each query is finished.
6) PGresult, of course, should be PQClear after every query.
7) Look in Windows Task manager. Since there were 2 threads that opened the
connection, there will be 2 postgres.exe whose memory consumption keeps
going up slowly.
8) In our real application, since we INSERT a large amount of data per
query, as well as SELECT a large amount of data per query, the memory leak
is much worse, and postgres.exe crashes after its memory consumption has
reached about 1.8GB.

Reference:
- What our command line looks like:

http://picasaweb.google.com/shivesh/PostgresqlCommandLine#537169872221980512
2
- Example code that should demonstrate the problem:
http://stackoverflow.com/questions/1280513/posgressql-memory-leaque (note we
use Intel TBB to launch threads..you can use whatever thread library you
want.)

On 19/08/2009 11:50 PM, Shivesh Wangrungvichaisri wrote:

> Logged by: Shivesh Wangrungvichaisri
> Email address: sbw(at)appsig(dot)com
> PostgreSQL version: 8.3.7
> Operating system: Windows XP x64 / Windows 7 x64
> Description: postgres.exe memory consumption keeps going up

> - Example code that should demonstrate the problem:
> http://stackoverflow.com/questions/1280513/posgressql-memory-leaque (note we
> use Intel TBB to launch threads..you can use whatever thread library you
> want.)

I went to build your example for testing, but found that the threading
library you use isn't freely available. Any chance you can post a
version using the standard win32 threading calls and test that version
to make sure it still exhibits the problem?

(I do a little bit of programming on Windows, but all of it is
cross-platform code that sticks to POSIX APIs or uses the Qt library, so
I never have to touch the actual win32 bits and know very little about
things like win32's threading. As such, if I try converting it myself I
won't be confident I'm really accurately testing the same thing you are).

--
Craig Ringer

On 23/08/2009 10:37 AM, Craig Ringer wrote:
> On 19/08/2009 11:50 PM, Shivesh Wangrungvichaisri wrote:
>
>> Logged by: Shivesh Wangrungvichaisri
>> Email address: sbw(at)appsig(dot)com
>> PostgreSQL version: 8.3.7
>> Operating system: Windows XP x64 / Windows 7 x64
>> Description: postgres.exe memory consumption keeps going up
>
>
>> - Example code that should demonstrate the problem:
>> http://stackoverflow.com/questions/1280513/posgressql-memory-leaque
>> (note we
>> use Intel TBB to launch threads..you can use whatever thread library you
>> want.)
>
> I went to build your example for testing, but found that the threading
> library you use isn't freely available.

... so of course, as soon as I post this I find out I located the
commercial licensing page for a dual proprietary-and-GPL library. Sigh.

Building the test with VC++EE '08 now.

--
Craig Ringer

On Wed, Aug 19, 2009 at 4:50 PM, Shivesh
Wangrungvichaisri<sbw(at)appsig(dot)com> wrote:
> 8) In our real application, since we INSERT a large amount of data per
> query, as well as SELECT a large amount of data per query, the memory leak
> is much worse, and postgres.exe crashes after its memory consumption has
> reached about 1.8GB.

And what does it print in the logs when that happens? It should print
a memory dump which would show precisely where the memory leak is.

--
greg
http://mit.edu/~gsstark/resume.pdf

On 19/08/2009 11:50 PM, Shivesh Wangrungvichaisri wrote:
>
> The following bug has been logged online:
>
> Bug reference: 4996
> Logged by: Shivesh Wangrungvichaisri
> Email address: sbw(at)appsig(dot)com
> PostgreSQL version: 8.3.7

I ran your test program on 8.4.0 (not 8.3.7 as you used), and didn't
find any sign of a leak in the backends (postgres.exe).

Interestingly, though, the test program does appear to be leaking - at
least, the peak working set slowly climbs. It's all private working set.
Not sure why yet since the memory use looks like it _should_ be constant.

Re the backends, the shared working set on each postgres.exe backend
goes up until each backend has touched all the shm it'll ever touch, at
which point the backends' usage stabilizes. I see no sign of a leak.

Have you perhaps tried to configure WAY too much shared memory? How much
RAM does your test machine have? Can you post all uncommented lines from
your postgresql.conf ?

For the next thing you need to check you'll need Process Explorer.
Install it and the rest of the sysinternals suite if you don't have it
yet, it's a VITAL windows admin tool:

http://technet.microsoft.com/en-gb/sysinternals/bb842062.aspx

Please launch Process Explorer and then your test program. Double-click
on the postgres.exe backends to open info windows for them and do the
same for the test program. Take a screenshot (windows-prtscrn) and save
it. Let the test run a while and do the same thing occasionally to keep
a record. If/when a backend crashes save the windows event log and the
postgresql log. Upload the lot as a zip file somewhere accessible and
post a report on what happened.

I'll try to figure out why your test program appears to be leaking (or
just using more memory with time). libpq and friends were built with
MSVC7 and I'm using MSVC9 for the test program so there are two
different runtimes linked to the program, but there aren't any FILE
pointers being passed around, no memory is allocated in one module and
freed in another, etc, so I'm not sure where it's going yet. Valgrind
doesn't support Windows and all the Windows leak-checking tools cost
$LOTS so I can't just hook it up to a heap analyzer / leak checker. Sigh.

--
Craig Ringer

> Please launch Process Explorer and then your test program. Double-click
> on the postgres.exe backends to open info windows for them and do the
> same for the test program. Take a screenshot (windows-prtscrn) and save
> it. Let the test run a while and do the same thing occasionally to keep
> a record.

Auto Screen Recorder from:

http://wisdom-soft.com/products/screenhunter_free.htm

might be handy for that, by the way.

--
Craig Ringer

On Sun, Aug 23, 2009 at 4:48 AM, Craig
Ringer<craig(at)postnewspapers(dot)com(dot)au> wrote:
> Interestingly, though, the test program does appear to be leaking - at
> least, the peak working set slowly climbs. It's all private working set. Not
> sure why yet since the memory use looks like it _should_ be constant.

How does the return value of str() get cleaned up here?

PGresult* res=PQexec(conn,insert.str().c_str());

--
greg
http://mit.edu/~gsstark/resume.pdf

On 23/08/2009 12:42 PM, Greg Stark wrote:
> On Sun, Aug 23, 2009 at 4:48 AM, Craig
> Ringer<craig(at)postnewspapers(dot)com(dot)au> wrote:
>> Interestingly, though, the test program does appear to be leaking - at
>> least, the peak working set slowly climbs. It's all private working set. Not
>> sure why yet since the memory use looks like it _should_ be constant.
>
> How does the return value of str() get cleaned up here?
>
> PGresult* res=PQexec(conn,insert.str().c_str());

str() returns a std::string instance by value. It's not returning a
pointer to a heap allocated object. The returned std::string is cleaned
up when it leaves scope - in this case, at end-of-statement.

c_str() is called on the temporary std::string . This returns a const
char * to a block of memory owned by the std::string . It must *NOT* be
freed by the caller or modified by the caller. It's usually just the
internal buffer maintained by the std::string. See:

http://www.cplusplus.com/reference/string/string/c_str/

So, no, there's no leak there.

--
Craig Ringer

Hi,

I have uploaded everything that you should need here:

http://www.filefactory.com/file/ah334c6/n/Pgsql_Leak_zip

The zip file contains a readme.txt file that will explain everything.

Please note that if you want to see that the test program itself is not leaking, then change every occurrence of #if 1 that you find (there are 2 of them) to #if 0, and re-run the program. The memory consumption of the test program will stay constant.

My hypothesis is that we are doing the queries too fast for the OS to free up the memory, but that's just my hypothesis.

Please let me know what you find.

Thanks,

S.

-----Original Message-----
From: Craig Ringer [mailto:craig(at)postnewspapers(dot)com(dot)au]
Sent: Saturday, August 22, 2009 8:58 PM
To: WANGRUNGVICHAISRI, SHIVESH
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: [BUGS] BUG #4996: postgres.exe memory consumption keeps going up

> Please launch Process Explorer and then your test program. Double-click
> on the postgres.exe backends to open info windows for them and do the
> same for the test program. Take a screenshot (windows-prtscrn) and save
> it. Let the test run a while and do the same thing occasionally to keep
> a record.

Auto Screen Recorder from:

http://wisdom-soft.com/products/screenhunter_free.htm

might be handy for that, by the way.

--
Craig Ringer

On 26/08/2009 9:25 AM, WANGRUNGVICHAISRI, SHIVESH wrote:
> Hi,
>
> I have uploaded everything that you should need here:
>
> http://www.filefactory.com/file/ah334c6/n/Pgsql_Leak_zip

I notice that you used the Windows Task Manager to monitor memory usage,
rather than Process Explorer. There's a reason I suggested that you
monitor with Process Explorer: it provides more detail about the
process's memory usage. In particular, it lets you tell how much of the
memory usage is shared memory and how much is private.

The Task Manager does not. Because PostgreSQL makes heavy use of shared
memory this information is important.

That said, the "VM size" looks like the private size, making the rest
shared. The growth you're observing is in shared memory, suggesting it's
not in fact a leak at all, but the backend touching more and more of
shared_buffers .

I don't see any sign of a leak in postgres.exe . Given your
configuration, I'd expect to see postgres.exe's memory use grow up to
between 256 and say 290-ish MB (given that you have shared_buffers =
256MB) and none of your screenshots show it exceeding that. It all looks
quite normal to me from what you've posted.

You need to understand that PostgreSQL uses shared memory. The
postmaster allocates this memory *once*. All postgres.exe backends
attach to this shared memory block, which is already allocated. The way
Windows accounts for memory use means that they don't immediately show
up as using that memory, but it does get added to their reported memory
usage as they read from and write to the shared memory block. Despite it
being shown as part of each backend's memory use, the memory is actually
ONLY USED ONCE - by the postmaster.

You haven't let the test run long enough for the crash you've reported
to take place or even for postgres.exe to grow beyond normal size (if it
does). You also haven't provided the contents of postgresql's log file
after the crash you described. As a result so I can't tell what happens
when growth hits the ~2GB limit you mentioned in your initial post.

I can't reproduce the crash myself since shared usage on my postgres.exe
process(es) stabilizes and ceases growing after a while, as it should.

I'm running your test program on my sandbox machine now to see if I can
reproduce the issue, but so far everything looks quite normal. Both
active backends have stabilized at 37,965K of shared memory - one has a
total working set of 41,697K and the other 41,620K (so each is using
about 3.6MB of real system RAM). I'll come back tomorrow and see if
there are any signs of anything odd going on, but right now it looks
sensible.

SandBox.exe is growing in the same way my locally built test program is.
Weird. I think I'm going to have to recompile PostgreSQL's libpq using
VC++8 in memory debugging mode. Sigh.

--
Craig Ringer

On Wed, 2009-08-26 at 07:09 -0700, WANGRUNGVICHAISRI, SHIVESH wrote:

> I also did use the Process Explorer as you suggested; I'm sorry I
> didnt mention that in the post. As I mentioned before in the zip file,
> the working set kept growing.

Yes, but does the *private* working set? The screen shots of the Task
Manager you supplied suggest it does not. Please provide screen
recordings, screenshots, or other details from Process Explorer that
show the growing private working set. You're just not providing the
details needed to understand this, which are AT LEAST timed snapshots
of:

* For both active postgres.exe backends and SandboxTest.exe:
** Total working set size
** Private working set size
** Shared memory size
** Sharable memory size

Process Explorer can tell you all these.

If it is in fact postgres.exe that crashes at some point, it'd also
*REALLY* help to have a backtrace of the crash. Please see this wiki
article on how to collect a backtrace of a crashing process:

http://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQL_backend_on_Windows

This is REALLY important to help identify where the memory being
allocated is. Note that you will need to set up your debug environment
as per the instructions and make sure the stack trace is a useful one.

> I will keep the program running today until it crashes.

I've now been able to get your test program to crash (but not
postgres.exe - only SandboxTest.exe). The postgres.exe backends are fine
and do not have any problems. I'm running your test program again with a
debugger attached.

> Which one is the postgresql log file that you would be interested in
> looking at?

The most recent log in the pg_log directory inside the postgresql data
directory.

Please confirm the crash USING SANDBOXTEST.EXE not the real application.
You need to be using the same test program as I am for it to be much
use.

If you cannot cause the postgres.exe crash with sandboxtest.exe but you
can with your real application, then the test case isn't actually
demonstrating the problem and we'll need different debugging tactics
instead.

--
Craig Ringer

On Wed, Aug 26, 2009 at 4:38 PM, Craig
Ringer<craig(at)postnewspapers(dot)com(dot)au> wrote:
> If it is in fact postgres.exe that crashes at some point, it'd also
> *REALLY* help to have a backtrace of the crash.

If Postgres crashes due to running out of memory it prints a memory
dump to its log which would (hopefully) make it clear where the memory
leak is. I don't know where to find Postgres logs on Windows but it
shouldn't be hard to find.

--
greg
http://mit.edu/~gsstark/resume.pdf

Greg Stark wrote:
> I don't know where to find Postgres logs on Windows but it
> shouldn't be hard to find.
>

$(INSTALLDIR)/data/pg_log

D:\postgres\8.3\data\pg_log on mine here.

Craig,

I looked into this problem extensively today, and here's what I found.

It's not PostgreSQL that is leaking memory; it's the fact that our
application is also using PostGIS 1.3.6.

We have modified the test program such that it clearly shows memory leak
when PostGIS is used.

Below is the email that we sent to PostGIS group along with the download
link of the new test program.

"We have an example program that should demonstrate a memory leak in
postgres.exe caused by PostGIS when used in a multi-threaded situation.

The link to the entire zip file is here:

http://www.2shared.com/file/7399978/56887b86/Postgis_Leak.html

OS: Windows XP 32-bit
PostgreSQL: 8.3.7
PostGIS: 1.3.6"

So my claim that PostgreSQL was leaking memory was not true, and I do
apologize.

However, I still insist that potentially the PostgreSQL community might
want to look into why making use of libpq causes the client program's
memory consumption to keep growing. This can be easily observed using
the earlier test program uploaded to here:

http://www.filefactory.com/file/ah334c6/n/Pgsql_Leak_zip

(Note to Craig: you have already have downloaded this file)

Thanks for all the help,

S.

On Wed, 2009-08-26 at 16:51 -0700, WANGRUNGVICHAISRI, SHIVESH wrote:

>
> So my claim that PostgreSQL was leaking memory was not true, and I do
> apologize.
>

No problem. That's why it's important to look into these things - so we
find out.

> However, I still insist that potentially the PostgreSQL community might
> want to look into why making use of libpq causes the client program's
> memory consumption to keep growing. This can be easily observed using
> the earlier test program uploaded to here:

I agree. I can reproduce the growth with your test program when I built
it from sources against 8.4.0's libpq and run it against an 8.4.0
server.

The source of the growth (leak?) isn't clear at the moment. It doesn't
seem to be the test code its self, nor is it clear how it could be. To
learn more I'm going to have to build PostgreSQL (or at least libpq)
from sources using VC++8 in debug mode with memory tracing enabled.

I'll also try building it on a Linux machine to see if it's a
Windows-specific issue.

Thanks for your persistence on this. I'll follow up in a bit when I've
learned more about what's going on with libpq.

--
Craig Ringer

On Wed, 2009-08-26 at 16:51 -0700, WANGRUNGVICHAISRI, SHIVESH wrote:

> However, I still insist that potentially the PostgreSQL community might
> want to look into why making use of libpq causes the client program's
> memory consumption to keep growing. This can be easily observed using
> the earlier test program uploaded to here:

I've looked into it ... and concluded I'm an idiot.

Your query is:

SELECT * FROM tmp WHERE id>615;

(where "615" could be any value < 1000)

For some reason I'd been thinking all along that the query was grabbing
*no* *more* *than* *1000* *rows* ... but of course it's not, it's
grabbing all but some lower fraction of the rows. So the result set gets
bigger and bigger over time until the program doesn't have enough RAM to
hold the result set and it crashes.

The attached (adjusted) test program no longer has any issues with
growth or runtime. There's no libpq issue here, only a
my-brain-is-only-semifunctional issue.

So, it seems we've eliminated any issue with leakage in the PostgreSQL
server backend, you've isolated your problem to PostGIS, and we've found
that the growth of the test program was libpq working as designed.

It looks like we're done here.

--
Craig Ringer

Now why did this message get delayed by 4 hours before maia-1
delivered it to me? That was long enough in this to completely lose
the thread of conversation.

Received: from postgresql.org (mail.postgresql.org [200.46.204.86])
by maia-1.hub.org (Postfix) with ESMTP id 2909CAFD073;
Thu, 27 Aug 2009 03:21:19 +0000 (UTC)
Received: from localhost (unknown [200.46.208.211])
by mail.postgresql.org (Postfix) with ESMTP id 0AC3463486D
for <pgsql-bugs-postgresql(dot)org(at)mail(dot)postgresql(dot)org>; Wed, 26 Aug 2009
20:52:17 -0300 (ADT)

--
greg
http://mit.edu/~gsstark/resume.pdf

Greg Stark wrote:
> Now why did this message get delayed by 4 hours before maia-1
> delivered it to me? That was long enough in this to completely lose
> the thread of conversation.
>
> Received: from postgresql.org (mail.postgresql.org [200.46.204.86])
> by maia-1.hub.org (Postfix) with ESMTP id 2909CAFD073;
> Thu, 27 Aug 2009 03:21:19 +0000 (UTC)
> Received: from localhost (unknown [200.46.208.211])
> by mail.postgresql.org (Postfix) with ESMTP id 0AC3463486D
> for <pgsql-bugs-postgresql(dot)org(at)mail(dot)postgresql(dot)org>; Wed, 26 Aug 2009
> 20:52:17 -0300 (ADT)

Moderator delay? I note that the message jumped to me from mx2.hub.org
instead of maia-1, but at exactly the same time (down to seconds) -- but
at a different time zone.

--
Alvaro Herrera http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Hi Craig,

Firstly, I would like to say I'm sorry for the stupid kind of query that I had in the test program. It did indeed make the test program appeared to be "leaking" and I obviously misinterpreted the result.

Secondly, thank you for taking the time to look into this issue. Your assessment was absolutely correct.

Lastly, I will respond to this thread one more time when I get an answer back from PostGIS regarding the leak that I see in the test I sent to them.

Thanks again.

Sincerely,

S.

-----Original Message-----
From: Craig Ringer [mailto:craig(at)postnewspapers(dot)com(dot)au]
Sent: Wednesday, August 26, 2009 7:37 PM
To: WANGRUNGVICHAISRI, SHIVESH
Cc: pgsql-bugs
Subject: RE: [BUGS] BUG #4996: postgres.exe memory consumption keeps going up

On Wed, 2009-08-26 at 16:51 -0700, WANGRUNGVICHAISRI, SHIVESH wrote:

> However, I still insist that potentially the PostgreSQL community
> might want to look into why making use of libpq causes the client
> program's memory consumption to keep growing. This can be easily
> observed using the earlier test program uploaded to here:

I've looked into it ... and concluded I'm an idiot.

Your query is:

SELECT * FROM tmp WHERE id>615;

(where "615" could be any value < 1000)

For some reason I'd been thinking all along that the query was grabbing
*no* *more* *than* *1000* *rows* ... but of course it's not, it's grabbing all but some lower fraction of the rows. So the result set gets bigger and bigger over time until the program doesn't have enough RAM to hold the result set and it crashes.

The attached (adjusted) test program no longer has any issues with growth or runtime. There's no libpq issue here, only a my-brain-is-only-semifunctional issue.

So, it seems we've eliminated any issue with leakage in the PostgreSQL server backend, you've isolated your problem to PostGIS, and we've found that the growth of the test program was libpq working as designed.

It looks like we're done here.

--
Craig Ringer

2009/8/27 Alvaro Herrera <alvherre(at)commandprompt(dot)com>:
> Greg Stark wrote:
>> Now why did this message get delayed by 4 hours before maia-1
>> delivered it to me? That was long enough in this to completely lose
>> the thread of conversation.
>>
>> Received: from postgresql.org (mail.postgresql.org [200.46.204.86])
>>       by maia-1.hub.org (Postfix) with ESMTP id 2909CAFD073;
>>       Thu, 27 Aug 2009 03:21:19 +0000 (UTC)
>> Received: from localhost (unknown [200.46.208.211])
>>       by mail.postgresql.org (Postfix) with ESMTP id 0AC3463486D
>>       for <pgsql-bugs-postgresql(dot)org(at)mail(dot)postgresql(dot)org>; Wed, 26 Aug 2009
>> 20:52:17 -0300 (ADT)
>
> Moderator delay?  I note that the message jumped to me from mx2.hub.org
> instead of maia-1, but at exactly the same time (down to seconds) -- but
> at a different time zone.

Quite likely. It's often not possible to see the difference between
moderation delay and mailsystem breakage delay, without looking at the
logfiles.

It'd be kind of neat of majordomo could insert a "held for moderation
at <time>" and "released from moderation at <time>" headers or
something. Anybody know if that's possible to do?

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander wrote:

> It'd be kind of neat of majordomo could insert a "held for moderation
> at <time>" and "released from moderation at <time>" headers or
> something. Anybody know if that's possible to do?

You'd need to get Marc to patch the Majordomo2 source code ...
I proposed a patch months ago to have message-ids expanded in the
message footer, but no luck.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

2009/8/27 Alvaro Herrera <alvherre(at)commandprompt(dot)com>:
> Magnus Hagander wrote:
>
>> It'd be kind of neat of majordomo could insert a "held for moderation
>> at <time>" and "released from moderation at <time>" headers or
>> something. Anybody know if that's possible to do?
>
> You'd need to get Marc to patch the Majordomo2 source code ...
> I proposed a patch months ago to have message-ids expanded in the
> message footer, but no luck.

Did you cook up an actual patch? The majordomo server actually is
something that the community has access to... (it's not properly
documented, of course, but it's there)

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander wrote:
> 2009/8/27 Alvaro Herrera <alvherre(at)commandprompt(dot)com>:
> > Magnus Hagander wrote:
> >
> >> It'd be kind of neat of majordomo could insert a "held for moderation
> >> at <time>" and "released from moderation at <time>" headers or
> >> something. Anybody know if that's possible to do?
> >
> > You'd need to get Marc to patch the Majordomo2 source code ...
> > I proposed a patch months ago to have message-ids expanded in the
> > message footer, but no luck.
>
> Did you cook up an actual patch? The majordomo server actually is
> something that the community has access to... (it's not properly
> documented, of course, but it's there)

Of course; attached.

I have not tried a patch for the feature you propose. It'd be good to
have those (and also an indication of which moderator approved the
message).

--
Alvaro Herrera http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.