One source of constant annoyance identified

Markus Wollny wrote:

Are there any known issues concerning persistant connections apart from
the pgpconnect-thingy with PHP? Is anyone running the same combination
of *nix/Postgres+IIS/ColdFusion?

PostgreSQL 7.1 on i386-unknown-openbsd2.9, compiled by GCC 2.95.3
ColdFusion 4.5.1 SP2 on Windows NT 4 SP6a, ODBC 7.01.00.06

But it is all super light load, all the queries return 1 row or they are
cached on the ColdFusion side. Only issue I ever had was that I needed
to explicitly cast text columns to varchar or else the query would
return an error (which I have been unable to reproduce with later ODBC
drivers).

If you are running CF MX, try the JDBC driver. I haven't finished
testing it, but so far it is looking good.

Jochem

--
Jochem van Dieten
Team Macromedia Volunteer for ColdFusion
http://www.macromedia.com/support/forums/team_macromedia/

"Markus Wollny" <Markus.Wollny@computec.de> writes:

[ turned off persistent connections ]

Now there's still the odd 250MB backend lingering around for some time,
but it's not four or five of them any more, wich is a big gain when
there's 250MB swap around more often than not.

So you haven't really solved the problem --- somewhere there is a query
being issued that ramps the backend up to a lot of memory. All you've
done is ensured that the backend won't hang around very long. The
persistent connection isn't really at fault, except in that it causes
backends to keep being used after their memory usage has become bloated.

Although this might be enough to eliminate your immediate performance
problem, you should keep looking. Starting lots more backends than you
need to is a performance hit, so turning off persistent connections is
really only a stopgap not a desirable answer. And I'm still wondering
whether you've exposed a fixable memory leak bug. We need to identify
exactly what query is causing the backends to eat memory.

regards, tom lane

Hi!

I see - so the beast is still roaming, but the current settings sort of
keep it at bay for a while...

I'd surely like to find the specific query/queries which cause this
behaviour; all I could find out as yet was the database for the query.
If I switch on query_stats and query-output in the logfile, I get about
300-500MB log per hour - even during low-load times. Scanning through
these logs is like searching for a needle in a haystack. I can indeed
identify those queries with exceptionally high execution times, but
there's no mentioning of memory-usage anywhere - so I'm still left in
the dark. I can get the PIDs from top-output and scan through the log,
taking down execution times, but then there's nothing much out of the
ordinary - mostly below 0.05 seconds or much, much less. Again I cannot
guess about any correlation between execution time and memory usage. As
one backend processes lots of queries in sequence, I cannot find it hard
to imagine that each and every one of these queries isn't in any way
extraordinary, but there might be some issue with freeing up memory that
belonged to the predecessor, when the backend begins with a new query,
thus grabbing more and more memory during its lifetime.

With the current tools I know of, I shall have a hard time finding the
error - if I ever do. I cannot claim however to really know a lot :) How
would you, being "real DBAs" and knowing the intestines of this
particular DB probably much better than your very own, go about with
this task of tracking down the memory-eater?

Regards,

Markus

On Thu, 27 Jun 2002, Tom Lane wrote:

So you haven't really solved the problem --- somewhere there is a query
being issued that ramps the backend up to a lot of memory. All you've
done is ensured that the backend won't hang around very long. The
persistent connection isn't really at fault, except in that it causes
backends to keep being used after their memory usage has become bloated.

Yeah, but if the queries after that are not using all of the mapped
memory, that should be swapped out fairly quickly because the
machine is short on memory.

Same for memory leaks; if you're losing a lot of memory, you'd
think there would be a fair number of pages you never touch that
could then be swapped out.

The bloated processes, at least from the top fragment I saw, appear
to have a working set of 200-250 MB; basically the entire data
space is resident. So what's touching all of those pages often
enough that they don't get swapped?

cjs
--
Curt Sampson <cjs@cynic.net> +81 90 7737 2974 http://www.netbsd.org
Don't you know, in this new Dark Age, we're all light. --XTC

Hi!

It seems I found one of the queries which suck up memory as if there
were terabytes available.

If a user starts a search for e.g. "Ich brauche Mitleid" on one of our
websites (site-ID is 43 in this example), we construct our select like
this:

select MESSAGE.BOARD_ID
, MESSAGE.THREAD_ID
, MESSAGE.MESSAGE_ID
, MESSAGE.TITLE
, MESSAGE.USER_ID
, USERS.LOGIN
, USERS.STATUS
, USERS.RIGHTS
, to_char(MESSAGE.CREATED,'DD.MM.YY
hh24:mi') as DATUM
, MESSAGE.COUNT_REPLY

, (select count(*) from
CT_COM_USER_THREAD_FOLLOW where USER_ID= '484387' and
thread_id=MESSAGE.THREAD_ID) as TFUID

from CT_COM_BOARD_MESSAGE MESSAGE
, CT_COM_USER
USERS
, CT_COM_BOARD_RULES READRULE
, CT_COM_SITE_BOARDS SITE
where SITE.SITE_ID = '43'

and
(
lower(MESSAGE.TEXT) like '%ich%'
or lower(MESSAGE.TEXT) like 'ich%'
or lower(MESSAGE.TEXT) like '%ich'

or lower(MESSAGE.TITLE) like '%ich%'
or lower(MESSAGE.TITLE) like 'ich%'
or lower(MESSAGE.TITLE) like '%ich'

)

and
(
lower(MESSAGE.TEXT) like '%brauche%'
or lower(MESSAGE.TEXT) like 'brauche%'
or lower(MESSAGE.TEXT) like '%brauche'

or lower(MESSAGE.TITLE) like '%brauche%'
or lower(MESSAGE.TITLE) like 'brauche%'
or lower(MESSAGE.TITLE) like '%brauche'

)

and
(
lower(MESSAGE.TEXT) like '%mitleid%'
or lower(MESSAGE.TEXT) like 'mitleid%'
or lower(MESSAGE.TEXT) like '%mitleid'

or lower(MESSAGE.TITLE) like '%mitleid%'
or lower(MESSAGE.TITLE) like 'mitleid%'
or lower(MESSAGE.TITLE) like '%mitleid'

)

and MESSAGE.STATE_ID = 0
and MESSAGE.USER_ID =
USERS.USER_ID
and USERS.STATUS > 0
and SITE.BOARD_ID =
MESSAGE.BOARD_ID
and READRULE.BOARD_ID =
MESSAGE.BOARD_ID
and READRULE.RULE_ID = 1
and READRULE.VALUE <= '5'
order by MESSAGE.LAST_REPLY desc

Now I think it's the bit with the LIKEs that kills us, especially as the
database refuses to create an index on MESSAGE.TEXT for it being to big
or whatever - search me, but it just wouldn't do it (the field is of
type varchar with a maximum length of 10,000 characters). This query is
a true killer, taking over 2 minutes to complete while eating up more
than a quarter of a gig of memory. Oracle wasn't too bothered about this
one, but now PostgreSQL seems to act very differently...

Now as far as I searched through the docs and the archives, there's this
fulltext-search method provided in CONTRIB
(http://developer.postgresql.org/cvsweb.cgi/pgsql/contrib/fulltextindex/
?only_with_tag=REL7_2_STABLE); is this an equivalent of the
conText-cartridge provided by Oracle? This lack for a full-text-search
might be the main issue in our attempts to migrate from Oracle to
PostgreSQL, so to me it looks like it might just be the saving straw.
Please feel free to correct me if I'm wrong...

I never had much experience with this CVS-system and as yet left it to
those ambitous enough to tinker with the innards of their projects, but
right now it seems like I am forced to risk a try... Unfortunately from
my point of view this thing lacks a bit in terms of documentation - do I
need to recompile the whole of PostgreSQL or just this bit? How would I
go about installing it up to the point of actually running and making
use of it on two columns (TITLE and TEXT in the MESSAGE-table)?

Or am I completely misled concerning this fulltext-search-option - and
there's some cheaper way out to speed things up without reducing
functionality?

Regards,

Markus

LIKE '%dfjdsklfdfjdklfjds' is what is killing you.

LIKE 'sdfdklf%' can be indexed, but the leading wildcard
forces an index search.

Markus Wollny wrote:

Hi!

It seems I found one of the queries which suck up memory as if there
were terabytes available.

--
P. J. "Josh" Rovero Sonalysts, Inc.
Email: rovero@sonalysts.com www.sonalysts.com 215 Parkway North
Work: (860)326-3671 or 442-4355 Waterford CT 06385
***********************************************************************

Should have said:

"leading % forces a sequential scan". Sorry

P.J. \"Josh\" Rovero wrote:

LIKE '%dfjdsklfdfjdklfjds' is what is killing you.

LIKE 'sdfdklf%' can be indexed, but the leading wildcard
forces an index search.

--
P. J. "Josh" Rovero Sonalysts, Inc.
Email: rovero@sonalysts.com www.sonalysts.com 215 Parkway North
Work: (860)326-3671 or 442-4355 Waterford CT 06385
***********************************************************************

Curt Sampson <cjs@cynic.net> writes:

On Thu, 27 Jun 2002, Tom Lane wrote:

So you haven't really solved the problem --- somewhere there is a query
being issued that ramps the backend up to a lot of memory. All you've
done is ensured that the backend won't hang around very long. The
persistent connection isn't really at fault, except in that it causes
backends to keep being used after their memory usage has become bloated.

Yeah, but if the queries after that are not using all of the mapped
memory, that should be swapped out fairly quickly because the
machine is short on memory.

And the swapping activity is exactly the problem, isn't it?

In any case, we can't make much progress until we identify the query
that is making the backend's address space grow.

(Markus, you don't happen to have SORT_MEM set to a large value,
do you?)

regards, tom lane

And the swapping activity is exactly the problem, isn't it?

Yupp, I guess so; once swapping is reduced, there should be not only
much more fast memory available to the queries but also more processing
time.

In any case, we can't make much progress until we identify the query
that is making the backend's address space grow.

This here is one of them (see full text in mail from 13:25):

-----Ursprüngliche Nachricht-----
Von: Markus Wollny
Gesendet: Freitag, 28. Juni 2002 13:25
An: pgsql-general@postgresql.org
Betreff: Re: [GENERAL] One source of constant annoyance identified

Hi!

It seems I found one of the queries which suck up memory as if there
were terabytes available.

If a user starts a search for e.g. "Ich brauche Mitleid" on one of our
websites (site-ID is 43 in this example), we construct our select like
this:

select MESSAGE.BOARD_ID
, MESSAGE.THREAD_ID
, MESSAGE.MESSAGE_ID
, MESSAGE.TITLE
, MESSAGE.USER_ID
, USERS.LOGIN
, USERS.STATUS
, USERS.RIGHTS
, to_char(MESSAGE.CREATED,'DD.MM.YY
hh24:mi') as DATUM
, MESSAGE.COUNT_REPLY

, (select count(*) from
CT_COM_USER_THREAD_FOLLOW where USER_ID= '484387' and
thread_id=MESSAGE.THREAD_ID) as TFUID

from CT_COM_BOARD_MESSAGE MESSAGE
, CT_COM_USER
USERS
, CT_COM_BOARD_RULES READRULE
, CT_COM_SITE_BOARDS SITE
where SITE.SITE_ID = '43'

and
(
lower(MESSAGE.TEXT) like '%ich%'
or lower(MESSAGE.TEXT) like 'ich%'
or lower(MESSAGE.TEXT) like '%ich'

or lower(MESSAGE.TITLE) like '%ich%'
or lower(MESSAGE.TITLE) like 'ich%'
or lower(MESSAGE.TITLE) like '%ich'

)

and
(
lower(MESSAGE.TEXT) like '%brauche%'
or lower(MESSAGE.TEXT) like 'brauche%'
or lower(MESSAGE.TEXT) like '%brauche'

or lower(MESSAGE.TITLE) like '%brauche%'
or lower(MESSAGE.TITLE) like 'brauche%'
or lower(MESSAGE.TITLE) like '%brauche'

)

and
(
lower(MESSAGE.TEXT) like '%mitleid%'
or lower(MESSAGE.TEXT) like 'mitleid%'
or lower(MESSAGE.TEXT) like '%mitleid'

or lower(MESSAGE.TITLE) like '%mitleid%'
or lower(MESSAGE.TITLE) like 'mitleid%'
or lower(MESSAGE.TITLE) like '%mitleid'

)

and MESSAGE.STATE_ID = 0
and MESSAGE.USER_ID =
USERS.USER_ID
and USERS.STATUS > 0
and SITE.BOARD_ID =
MESSAGE.BOARD_ID
and READRULE.BOARD_ID =
MESSAGE.BOARD_ID
and READRULE.RULE_ID = 1
and READRULE.VALUE <= '5'
order by MESSAGE.LAST_REPLY desc

[snip]

(Markus, you don't happen to have SORT_MEM set to a large value,
do you?)

Not at all - recommendations are 2-4% of available RAM AFAIK. On a 1GB
machine this would be 21000 to 42000KBs. Nevertheless I reduced it from
these values to a meagre sort_mem = 8192, that's 8MB, but to no avail.
Reducing this value any further doesn't really make too much sense, does
it.

Anyway, I think that one of our main problems is the lack of options for
fulltext-indexing. I'm currently trying to find out how to get FTI (from
CVS/Contrib) up and running, because I hope that this will solve 90% of
my problems if not more :)

Regards,

Markus

On Fri, Jun 28, 2002 at 07:40:46AM -0400, P.J. Josh Rovero wrote:

LIKE '%dfjdsklfdfjdklfjds' is what is killing you.

LIKE 'sdfdklf%' can be indexed, but the leading wildcard
forces an index search.

You mean it forces a sequential scan, of course.

Cheers,

Neil

--
Neil Conway <neilconway@rogers.com>
PGP Key ID: DB3C29FC

"Markus Wollny" <Markus.Wollny@computec.de> writes:

lower(MESSAGE.TEXT) like '%ich%'
or lower(MESSAGE.TEXT) like 'ich%'
or lower(MESSAGE.TEXT) like '%ich'

Is whoever wrote this under the misimpression that % can't match zero
characters? You could reduce the number of LIKE tests by a factor of 3,
because the foo% and %foo tests are completely redundant.

But, back to the problem at hand --- it seems like a fair bet that
we must have a memory leak in lower() or LIKE or both. Did you build
with locale or multibyte (or both) enabled? If so, what locale and
what database encoding are you using, respectively?

regards, tom lane

Hi!

-----Ursprüngliche Nachricht-----
Von: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Gesendet: Freitag, 28. Juni 2002 17:03
An: Markus Wollny
Cc: pgsql-general@postgresql.org
Betreff: Re: [GENERAL] One source of constant annoyance identified

"Markus Wollny" <Markus.Wollny@computec.de> writes:

lower(MESSAGE.TEXT) like '%ich%'
or lower(MESSAGE.TEXT) like 'ich%'
or lower(MESSAGE.TEXT) like '%ich'

Is whoever wrote this under the misimpression that % can't match zero
characters? You could reduce the number of LIKE tests by a
factor of 3,
because the foo% and %foo tests are completely redundant.

Wasn't me :) I think there might be the odd generous wastage of
processing time still in the code just because we could afford it under
Oracle. We intend to implement this very bit using regular expressions,
as we hope that this will improve performance a bit. So we might get
away without using LIKE at all in this particular case. We cannot
however remove LIKE completely from every bit of code.

But, back to the problem at hand --- it seems like a fair bet that
we must have a memory leak in lower() or LIKE or both. Did you build
with locale or multibyte (or both) enabled? If so, what locale and
what database encoding are you using, respectively?

Compilation-options were:

--enable-locale
--enable-recode
--enable-multibyte
--with-perl
--enable-odbc
--enable-syslog

Environment-variables RC_LANG/LC_CTYPE are set to de_DE@euro, encoding
for the databases is SQL_ASCII. As we are hosting german websites and
communities, we need to sort data containing characters ÄÖÜäöüß in the
correct context (AÄ,OÖ,UÜ,sß), so I figured we'd need locale support.

Would it be worth a try recompiling without multibyte enabled? Can I
dump/reimport the current DB afterwards?

Regards,

Markus

Hi,

On Fri, Jun 28, 2002 at 05:30:58PM +0200, Markus Wollny wrote:

Compilation-options were:

--enable-locale
--enable-recode
--enable-multibyte
--with-perl
--enable-odbc
--enable-syslog

Environment-variables RC_LANG/LC_CTYPE are set to de_DE@euro, encoding
for the databases is SQL_ASCII. As we are hosting german websites and
communities, we need to sort data containing characters ������� in the
correct context (A�,O�,U�,s�), so I figured we'd need locale support.

AFAIK the compiling options are ok, but did You the initdb command with
the proper LC_ALL env set? It shoul be de_DE or de_DE@euro.

BTW: I've found on my linux distribution (SlackWare 7.x) a wrong i18n
source file. After fixing this and compiling the new locale evering
worked fine. It's corrected in the newer SlackWare.

-tb
--
Thomas Beutin tb@laokoon.IN-Berlin.DE
Beam me up, Scotty. There is no intelligent live down in Redmond.

Hi!

-----Ursprüngliche Nachricht-----
Von: Thomas Beutin
Gesendet: Fr 28.06.2002 19:43
An: pgsql-general@postgresql.org
Cc:
Betreff: Re: [GENERAL] One source of constant annoyance
identified

Environment-variables RC_LANG/LC_CTYPE are set to de_DE@euro,

encoding

for the databases is SQL_ASCII. As we are hosting german

websites and

communities, we need to sort data containing characters

ÄÖÜäöüß in the

correct context (AÄ,OÖ,UÜ,sß), so I figured we'd need locale

support.

AFAIK the compiling options are ok, but did You the initdb
command with
the proper LC_ALL env set? It shoul be de_DE or de_DE@euro.

For initdb-option "--locale=" I found in the documentation "If this
option is not specified, the locale is inherited from the environment
that initdb runs in." So I presume that if I didn't explicitly set it to
anything other than my current environment, which I didn't, it should be
okay.

BTW: I've found on my linux distribution (SlackWare 7.x)
a wrong i18n
source file. After fixing this and compiling the new
locale evering
worked fine. It's corrected in the newer SlackWare.

I use SuSE 7.3, a german distro, so I cannot imagine that some serious
problem with german localization would have gone unnoticed. Of course I
did not use the PostgreSQL-Version provided with the distro - I got the
latest stable release 7.2.1 and compiled. So I guess that's not the
source of the problem.

Regards,

Markus

"Markus Wollny" <Markus.Wollny@computec.de> writes:

For initdb-option "--locale=" I found in the documentation "If this
option is not specified, the locale is inherited from the environment
that initdb runs in." So I presume that if I didn't explicitly set it to
anything other than my current environment, which I didn't, it should be
okay.

If you're not certain about this, compile contrib/pg_controldata and see
what it says the locale values in your pg_control file are.

regards, tom lane

On Fri, 28 Jun 2002, Tom Lane wrote:

Yeah, but if the queries after that are not using all of the mapped
memory, that should be swapped out fairly quickly because the
machine is short on memory.

And the swapping activity is exactly the problem, isn't it?

That particular swapping activity would not be a problem. Memory
that's not used gets paged out and that's the end of it. The problem
is that something is *using* that memory, so it's not being paged
out, or if it does get paged out, it gets paged back in again.

cjs
--
Curt Sampson <cjs@cynic.net> +81 90 7737 2974 http://www.netbsd.org
Don't you know, in this new Dark Age, we're all light. --XTC

Curt Sampson <cjs@cynic.net> writes:

On Fri, 28 Jun 2002, Tom Lane wrote:

And the swapping activity is exactly the problem, isn't it?

That particular swapping activity would not be a problem. Memory
that's not used gets paged out and that's the end of it. The problem
is that something is *using* that memory, so it's not being paged
out, or if it does get paged out, it gets paged back in again.

Yeah --- but typical implementations of malloc are very pager-
unfriendly; they tend to traverse data structures that consist
of a word or two at the head of each randomly-sized chunk of
data or former-now-freed data.

PG adds its own layer of not-very-paging-friendly allocation
logic on top of whatever sins your local malloc may commit.

Bottom line is that a PG backend that's swollen to a couple
hundred MB is trouble. Don't assume it'll play nice with the
swapper; it won't.

regards, tom lane

Hi!

I did as you suggested - and locale is indeed not set correctly, it
seems. Here's the output:

pg_control version number: 71
[...]
LC_COLLATE: C
LC_CTYPE: de_DE@euro

So LC_COLLATE wasn't set correctly; I dumped all databases, recompiled
(without multibyte- and recode-support this time, just to reduce
possible sources of failure), did initdb again and reimported the
dumpfile.

pg_control-output is now:
pg_control version number: 71
[...]
LC_COLLATE: de_DE@euro
LC_CTYPE: de_DE@euro

Configure-options were ./configure --prefix=/opt/pgsql/ --with-perl
--enable-odbc --enable-locale --enable-syslog

So that's most definitely fixed. It didn't do anything for me, though -
there are still several giant backends, as you can see by top-output

12:29pm up 1 day, 21:04, 3 users, load average: 1.44, 1.13, 1.18
85 processes: 81 sleeping, 4 running, 0 zombie, 0 stopped
CPU0 states: 87.3% user, 9.2% system, 0.0% nice, 3.1% idle
CPU1 states: 34.0% user, 6.0% system, 0.0% nice, 59.5% idle
CPU2 states: 47.3% user, 1.4% system, 0.0% nice, 50.5% idle
CPU3 states: 44.6% user, 7.3% system, 0.0% nice, 47.3% idle
Mem: 1029400K av, 1002272K used, 27128K free, 0K shrd, 5352K
buff
Swap: 2097136K av, 13160K used, 2083976K free 842792K
cached
PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
9269 postgres 10 0 257M 257M 256M S 96.2 25.5 0:54 postmaster
9264 postgres 9 0 250M 250M 249M S 1.9 24.9 0:42 postmaster
9375 postgres 9 0 127M 127M 126M S 1.2 12.6 0:05 postmaster
9372 postgres 9 0 106M 106M 105M S 3.9 10.5 0:26 postmaster
9312 postgres 9 0 68900 67M 67616 S 1.8 6.6 0:02 postmaster
9379 postgres 9 0 41144 40M 39880 S 2.8 3.9 0:04 postmaster
9377 postgres 9 0 39276 38M 38104 S 0.0 3.8 0:14 postmaster
9380 postgres 9 0 34548 33M 33388 S 0.0 3.3 1:14 postmaster
9381 postgres 9 0 32140 31M 30760 S 0.0 3.1 0:26 postmaster
9373 postgres 9 0 24068 23M 23064 S 0.0 2.3 0:01 postmaster
9353 postgres 9 0 22224 21M 20332 S 7.8 2.1 0:37 postmaster
9371 postgres 9 0 22036 21M 21032 S 0.0 2.1 0:01 postmaster
9382 postgres 9 0 17840 17M 16652 S 0.0 1.7 0:01 postmaster
9268 postgres 12 0 16104 15M 15036 R 0.7 1.5 0:16 postmaster
9352 postgres 9 0 15584 15M 14076 S 0.0 1.5 0:19 postmaster
9351 postgres 19 0 14644 14M 13080 R 36.9 1.4 0:16 postmaster
9313 postgres 9 0 14068 13M 13036 S 5.1 1.3 0:14 postmaster
9374 postgres 9 0 13996 13M 12976 S 3.1 1.3 0:14 postmaster
9354 postgres 9 0 13116 12M 12088 S 1.3 1.2 0:03 postmaster
9376 postgres 9 0 12744 12M 11732 S 0.9 1.2 0:02 postmaster
9452 postgres 9 0 12356 12M 11208 S 0.0 1.1 0:10 postmaster
9370 postgres 9 0 12300 12M 11332 S 1.8 1.1 0:02 postmaster
9355 postgres 9 0 11768 11M 10756 S 0.0 1.1 0:00 postmaster
9524 postgres 9 0 10744 10M 9740 S 3.6 1.0 0:00 postmaster
9476 postgres 9 0 10020 9.8M 9044 S 1.9 0.9 0:00 postmaster
9602 postgres 18 0 9472 9468 8356 R 58.0 0.9 0:03 postmaster
9535 postgres 9 0 9368 9364 8216 S 0.7 0.9 0:00 postmaster

Any more ideas?

Regards,

Markus

"Markus Wollny" <Markus.Wollny@computec.de> writes:

Now I think it's the bit with the LIKEs that kills us,

That's what I thought too, but I've tried and failed to reproduce any
memory leak with lower/LIKE and the same configuration options that you
used. It might be that some other part of the query is the problem, or
maybe I'm not duplicating the setup correctly. Could I trouble you for
the exact schemas of the tables used by the problem query? (The output
of pg_dump -s would be the best thing to send.)

regards, tom lane