[ADMIN] out of memory error

Discussion:

(too old to reply)

Vincent Dautremont

2012-05-22 16:44:41 UTC

H,
after a few days, i'm seeing the following logs in a database (postgresql
8.3.15 on Windows)
running with rubyrep 1.2.0 for syncing a few table small that have frequent
update / insert/ delete.

I don't understand it and I'd like to know what happens and why. How to get
rid of it.
I've seen in the same time from Windows Task Manager that the memory of a
postregres.exe process goes constantly up (I've seen it up to 1.4 GB) then
I suppose the process must crash since I can't see it anymore.

log :
---------------------
TopMemoryContext: 197681816 total in 24131 blocks; 394104 free (24179
chunks); 197287712 used
TopTransactionContext: 8192 total in 1 blocks; 7792 free (0 chunks); 400
used
PL/PgSQL function context: 8192 total in 1 blocks; 2912 free (3 chunks);
5280 used
PL/PgSQL function context: 8192 total in 1 blocks; 2912 free (3 chunks);
5280 used
PL/PgSQL function context: 8192 total in 1 blocks; 3168 free (4 chunks);
5024 used
PL/PgSQL function context: 8192 total in 1 blocks; 3168 free (4 chunks);
5024 used
PL/PgSQL function context: 8192 total in 1 blocks; 3184 free (4 chunks);
5008 used
PL/PgSQL function context: 8192 total in 1 blocks; 3184 free (4 chunks);
5008 used
RI compare cache: 8192 total in 1 blocks; 1800 free (0 chunks); 6392 used
RI query cache: 24576 total in 2 blocks; 14136 free (5 chunks); 10440 used
CFuncHash: 8192 total in 1 blocks; 4936 free (0 chunks); 3256 used
Rendezvous variable hash: 8192 total in 1 blocks; 3848 free (0 chunks);
4344 used
PLpgSQL function cache: 24328 total in 2 blocks; 5904 free (0 chunks);
18424 used
Type information cache: 8192 total in 1 blocks; 1800 free (0 chunks);
6392 used
Record information cache: 8192 total in 1 blocks; 1800 free (0 chunks);
6392 used
Prepared Queries: 8192 total in 1 blocks; 1800 free (0 chunks); 6392 used
Operator class cache: 8192 total in 1 blocks; 3848 free (0 chunks); 4344
used
Operator lookup cache: 24576 total in 2 blocks; 14072 free (6 chunks);
10504 used
MessageContext: 8192 total in 1 blocks; 7144 free (1 chunks); 1048 used
smgr relation table: 8192 total in 1 blocks; 1776 free (0 chunks); 6416
used
TransactionAbortContext: 32768 total in 1 blocks; 32752 free (0 chunks);
16 used
Portal hash: 8192 total in 1 blocks; 3912 free (0 chunks); 4280 used
PortalMemory: 8192 total in 1 blocks; 8040 free (0 chunks); 152 used
PortalHeapMemory: 4096 total in 1 blocks; 1888 free (0 chunks); 2208
used
ExecutorState: 122880 total in 4 blocks; 46296 free (5 chunks); 76584
used
TupleSort: 24600 total in 2 blocks; 7512 free (0 chunks); 17088 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
Relcache by OID: 8192 total in 1 blocks; 2856 free (0 chunks); 5336 used
CacheMemoryContext: 8531792 total in 24 blocks; 282000 free (617 chunks);
8249792 used
unnamed prepared statement: 253952 total in 5 blocks; 10664 free (7
chunks); 243288 used
unnamed prepared statement: 253952 total in 5 blocks; 86232 free (1
chunks); 167720 used
CachedPlan: 1024 total in 1 blocks; 576 free (0 chunks); 448 used
CachedPlanSource: 1024 total in 1 blocks; 344 free (0 chunks); 680 used
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used
CachedPlan: 1024 total in 1 blocks; 576 free (0 chunks); 448 used
CachedPlanSource: 1024 total in 1 blocks; 344 free (0 chunks); 680 used
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used

.
.
. there it goes for about 80MB of log then it ends
.
.
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used
CachedPlan: 1024 total in 1 blocks; 576 free (0 chunks); 448 used
CachedPlanSource: 1024 total in 1 blocks; 344 free (0 chunks); 680 used
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used
CachedPlan: 1024 total in 1 blocks; 904 free (0 chunks); 120 used
CachedPlanSource: 1024 total in 1 blocks; 840 free (0 chunks); 184 used
CachedPlan: 3072 total in 2 blocks; 392 free (0 chunks); 2680 used
CachedPlanSource: 3072 total in 2 blocks; 1904 free (1 chunks); 1168
used
CachedPlan: 7168 total in 3 blocks; 4080 free (1 chunks); 3088 used
CachedPlanSource: 3072 total in 2 blocks; 1384 free (0 chunks); 1688
used
pg_opclass_oid_index: 1024 total in 1 blocks; 304 free (0 chunks); 720
used
pg_amop_fam_strat_index: 1024 total in 1 blocks; 88 free (0 chunks);
936 used
pg_trigger_tgrelid_tgname_index: 1024 total in 1 blocks; 240 free (0
chunks); 784 used
pg_attribute_relid_attnum_index: 1024 total in 1 blocks; 240 free (0
chunks); 784 used
pg_class_oid_index: 1024 total in 1 blocks; 304 free (0 chunks); 720
used
pg_amproc_fam_proc_index: 1024 total in 1 blocks; 88 free (0 chunks);
936 used
pg_index_indexrelid_index: 1024 total in 1 blocks; 304 free (0 chunks);
720 used
pg_rewrite_rel_rulename_index: 1024 total in 1 blocks; 240 free (0
chunks); 784 used
pg_operator_oid_index: 1024 total in 1 blocks; 304 free (0 chunks); 720
used
MdSmgr: 8192 total in 1 blocks; 7288 free (6 chunks); 904 used
LOCALLOCK hash: 8192 total in 1 blocks; 1856 free (0 chunks); 6336 used
Timezones: 49432 total in 2 blocks; 5968 free (0 chunks); 43464 used
ErrorContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
2012-05-02 08:01:10 WET ERROR: out of memory
2012-05-02 08:01:10 WET DETAIL: Failed on request of size 8.
2012-05-02 08:01:10 WET STATEMENT: SELECT
n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull,a.atttypmod,a.attlen,a.attnum,pg_catalog.pg_get_expr(def.adbin,
def.adrelid) AS adsrc,dsc.description,t.typbasetype,t.typtype FROM
pg_catalog.pg_namespace n JOIN pg_catalog.pg_class c ON (c.relnamespace =
n.oid) JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid) JOIN
pg_catalog.pg_type t ON (a.atttypid = t.oid) LEFT JOIN
pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum =
def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid
AND a.attnum = dsc.objsubid) LEFT JOIN pg_catalog.pg_class dc ON
(dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN
pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND
dn.nspname='pg_catalog') WHERE a.attnum > 0 AND NOT a.attisdropped AND
n.nspname LIKE 'public' AND c.relname LIKE 'rr_pending_changes' ORDER BY
nspname,c.relname,attnum
2012-05-02 08:01:10 WET LOG: could not send data to client: No connection
could be made because the target machine actively refused it.

2012-05-02 08:01:10 WET STATEMENT: SELECT
n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull,a.atttypmod,a.attlen,a.attnum,pg_catalog.pg_get_expr(def.adbin,
def.adrelid) AS adsrc,dsc.description,t.typbasetype,t.typtype FROM
pg_catalog.pg_namespace n JOIN pg_catalog.pg_class c ON (c.relnamespace =
n.oid) JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid) JOIN
pg_catalog.pg_type t ON (a.atttypid = t.oid) LEFT JOIN
pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum =
def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid
AND a.attnum = dsc.objsubid) LEFT JOIN pg_catalog.pg_class dc ON
(dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN
pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND
dn.nspname='pg_catalog') WHERE a.attnum > 0 AND NOT a.attisdropped AND
n.nspname LIKE 'public' AND c.relname LIKE 'rr_pending_changes' ORDER BY
nspname,c.relname,attnum
2012-05-02 08:01:10 WET LOG: could not receive data from client: No
connection could be made because the target machine actively refused it.
---------------------

Thank you for hints about that.
Vincent.

Tom Lane

2012-05-22 17:33:43 UTC

Permalink

Post by Vincent Dautremont
after a few days, i'm seeing the following logs in a database (postgresql
8.3.15 on Windows)
running with rubyrep 1.2.0 for syncing a few table small that have frequent
update / insert/ delete.
I don't understand it and I'd like to know what happens and why. How to get
rid of it.
TopMemoryContext: 197681816 total in 24131 blocks; 394104 free (24179
chunks); 197287712 used

It's not normal to have so much stuff in TopMemoryContext. That could
represent a leak, but it's also possible that that's just management

Post by Vincent Dautremont
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used
.
.
. there it goes for about 80MB of log then it ends
.
.
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928 used

That's a *heck* of a lot of SPI plans. You haven't provided any
information that would let anybody diagnose why you have so many,
though. Tell us about your usage patterns, especially of PL-language
functions.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-***@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

Vincent Dautremont

2012-05-22 18:04:39 UTC

Permalink

Well,
I think that i'm using the database for pretty basic stuffs.
It's mostly used with stored procedures to update/ insert / select a row of
each table.
On 3 tables (less than 10 rows each), clients does updates/select at 2Hz to
have pseudo real-time data up to date.
I've got a total of 6 clients to the DB, they all access DB using stored
procedures
I would say that this is a light usage of the DB.

Then I have rubyrep 1.2.0 running to sync a backup of the DB.
it syncs 8 tables : 7 of them doesn't really change often and 1 is one of
the pseudo real-time data one.

So everything works fine, but I see postgres process memory usage growing,
it can go about 1GB to 1.5GB in about 5to 6 days, then I suppose it crashes.

I don't know a lot about PostgreSQL, what does the TopMemoryContext means.
I haven't been able to find much information about it.
Is it like a global memory stack for the DB ?

I've tried using the default postgres.conf file I usually run this modified
one with these values.
------------------------
"version";"PostgreSQL 8.3.15, compiled by Visual C++ build 1400"
"autovacuum";"on"
"autovacuum_analyze_threshold";"50"
"autovacuum_max_workers";"3"
"autovacuum_naptime";"1min"
"autovacuum_vacuum_threshold";"50"
"client_encoding";"UNICODE"
"deadlock_timeout";"5s"
"effective_cache_size";"2GB"
"lc_collate";"English_United States.1252"
"lc_ctype";"English_United States.1252"
"listen_addresses";"*"
"log_destination";"stderr"
"log_filename";"postgresql-%Y-%m-%d.log"
"log_line_prefix";"%t "
"log_rotation_age";"1d"
"log_truncate_on_rotation";"on"
"logging_collector";"on"
"max_connections";"100"
"max_fsm_pages";"204800"
"max_stack_depth";"2MB"
"port";"5432"
"server_encoding";"UTF8"
"shared_buffers";"512MB"
"shared_preload_libraries";"$libdir/plugins/plugin_debugger.dll"
"TimeZone";"Africa/Casablanca"
"track_counts";"on"
------------------------
Thanks,
Vincent

Post by Vincent Dautremont

Post by Vincent Dautremont
after a few days, i'm seeing the following logs in a database

(postgresql

Post by Vincent Dautremont
8.3.15 on Windows)
running with rubyrep 1.2.0 for syncing a few table small that have

frequent

Post by Vincent Dautremont
update / insert/ delete.
I don't understand it and I'd like to know what happens and why. How to

get

Post by Vincent Dautremont
rid of it.
TopMemoryContext: 197681816 total in 24131 blocks; 394104 free (24179
chunks); 197287712 used

It's not normal to have so much stuff in TopMemoryContext. That could
represent a leak, but it's also possible that that's just management

used

Post by Vincent Dautremont
SPI Plan: 1024 total in 1 blocks; 928 free (0 chunks); 96 used
.
.
. there it goes for about 80MB of log then it ends
.
.
SPI Plan: 1024 total in 1 blocks; 912 free (0 chunks); 112 used
CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used
CachedPlanSource: 1024 total in 1 blocks; 96 free (0 chunks); 928

used
That's a *heck* of a lot of SPI plans. You haven't provided any
information that would let anybody diagnose why you have so many,
though. Tell us about your usage patterns, especially of PL-language
functions.
regards, tom lane

Tom Lane

2012-05-22 18:30:03 UTC

Permalink

Post by Vincent Dautremont
I think that i'm using the database for pretty basic stuffs.
It's mostly used with stored procedures to update/ insert / select a row of
each table.
On 3 tables (less than 10 rows each), clients does updates/select at 2Hz to
have pseudo real-time data up to date.
I've got a total of 6 clients to the DB, they all access DB using stored
procedures
I would say that this is a light usage of the DB.
Then I have rubyrep 1.2.0 running to sync a backup of the DB.
it syncs 8 tables : 7 of them doesn't really change often and 1 is one of
the pseudo real-time data one.

This is not much information. What I suspect is happening is that
you're using plpgsql functions (or some other PL) in such a way that the
system is leaking cached plans for the functions' queries; but there is
far from enough evidence here to prove or disprove that, let alone debug
the problem if that is a correct guess. An entirely blue-sky guess as
to what your code might be doing to trigger such a problem is if you
were constantly replacing the same function's definition via CREATE OR
REPLACE FUNCTION. But that could be totally wrong, too.

Can you put together a self-contained test case that triggers similar
growth in the server process size?

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-***@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

Vincent Dautremont

2012-05-22 19:46:41 UTC

Permalink

Thanks Tom,
when you say,

Post by Tom Lane
An entirely blue-sky guess as
to what your code might be doing to trigger such a problem is if you
were constantly replacing the same function's definition via CREATE OR
REPLACE FUNCTION.

Do you mean that what would happen is that when we call the plpgsql
function, it executes each time a create or replace, then execute the
function ?
because my functions are all written like that :

-- Function: spzoneinsert(integer, integer)

Post by Tom Lane
CREATE OR REPLACE FUNCTION spzoneinsert(i_zoneid integer, i_output_port
integer)
RETURNS void AS
$BODY$
BEGIN
Begin
INSERT INTO zone
(zone_Id,
output_port)
VALUES
(i_zoneID,
i_Output_Port);
End;
END;
$BODY$
LANGUAGE 'plpgsql' VOLATILE
COST 100;
ALTER FUNCTION spzoneinsert(integer, integer) OWNER TO db_casd_admin_role;
GRANT EXECUTE ON FUNCTION spzoneinsert(integer, integer) TO
db_casd_admin_role;

Which is suppose is the normal way to write a function. I assume only the
partr between the $BODY$ are executed.
then this is called via ADODB in our C++ softwares.

I will try to run a DB without its client softwares, just both DBs with
rubyrep and a BAT script doing updates using one of my functions call at a
quicker rate than 2Hz. and'll monitor the memory usage and PG logs

Vincent.

Post by Tom Lane

Post by Vincent Dautremont
I think that i'm using the database for pretty basic stuffs.
It's mostly used with stored procedures to update/ insert / select a row

Post by Vincent Dautremont
each table.
On 3 tables (less than 10 rows each), clients does updates/select at 2Hz

Post by Vincent Dautremont
have pseudo real-time data up to date.
I've got a total of 6 clients to the DB, they all access DB using stored
procedures
I would say that this is a light usage of the DB.
Then I have rubyrep 1.2.0 running to sync a backup of the DB.
it syncs 8 tables : 7 of them doesn't really change often and 1 is one of
the pseudo real-time data one.

This is not much information. What I suspect is happening is that
you're using plpgsql functions (or some other PL) in such a way that the
system is leaking cached plans for the functions' queries; but there is
far from enough evidence here to prove or disprove that, let alone debug
the problem if that is a correct guess. An entirely blue-sky guess as
to what your code might be doing to trigger such a problem is if you
were constantly replacing the same function's definition via CREATE OR
REPLACE FUNCTION. But that could be totally wrong, too.
Can you put together a self-contained test case that triggers similar
growth in the server process size?
regards, tom lane

Tom Lane

2012-05-22 20:04:55 UTC

Permalink

Post by Vincent Dautremont

Do you mean that what would happen is that when we call the plpgsql
function, it executes each time a create or replace, then execute the
function ?
-- Function: spzoneinsert(integer, integer)

Post by Tom Lane
CREATE OR REPLACE FUNCTION spzoneinsert(i_zoneid integer, i_output_port
integer)
RETURNS void AS

Well, yeah, that is the common way to define a function. The question
was about whether you are constantly re-executing this same SQL
thousands of times over the course of a session. I think it would take
actually using the function in between such redefinitions to provoke a
plan leak, but if you were doing that it might explain the problem.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-***@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

Vincent Dautremont

2012-05-23 14:06:00 UTC

Permalink

Thanks,
So I've been able to find what's causing my postgres process memory amount
to grow, but I don't know why it happens.

So, my software is updating 6 rows/second on my main database.
Rubyrep is running on my server with thebackup database doing a "replicate"
The huge TopMemoryContext problem and memory size of the postgres process
are happening on my backup database.

I've found out that when my software does these updates the memory of the
postgres process grows constantly at 24 MB/hour. when I stop my software to
update these rows, the memory of the process stops to grow.

also I've noticed that when I stop rubyrep, this postgres process disappear.

I'm running rubyrep 1.2.0 and here is my rubyrep config file :

RR::Initializer::run do |config|

config.left = { # main database
:adapter => 'xxx',
:database => 'yyy',
:username => 'zzz',
:password => 'ttt',
:host => '10.97.14.102'
}
config.right = { # backup database
:adapter => 'xxx',
:database => 'yyy',
:username => 'zzz',
:password => 'ttt',
:host => '10.97.14.101'
}
config.options[:sync_conflict_handling] = :right_wins
config.options[:replication_conflict_handling] = :right_wins
config.include_tables 'archiver'
config.include_tables 'camera'
config.include_tables 'cda'
config.include_tables 'component_restart'
config.include_tables 'operation_mode'
config.include_tables 'ptz_lock'
config.include_tables 'standby_table'
config.include_tables 'video_output'
end

I don't know what other information I could add to that.

Vincent.

Post by Vincent Dautremont

Do you mean that what would happen is that when we call the plpgsql
function, it executes each time a create or replace, then execute the
function ?
-- Function: spzoneinsert(integer, integer)

Post by Tom Lane
CREATE OR REPLACE FUNCTION spzoneinsert(i_zoneid integer, i_output_port
integer)
RETURNS void AS

Tom Lane

2012-05-23 15:26:42 UTC

Permalink

Post by Vincent Dautremont
I've found out that when my software does these updates the memory of the
postgres process grows constantly at 24 MB/hour. when I stop my software to
update these rows, the memory of the process stops to grow.
also I've noticed that when I stop rubyrep, this postgres process disappear.

Hmm. I wondered whether rubyrep might be triggering this somehow;
I don't know anything about that software. I went so far as to download
rubyrep and look at the Postgres-specific source code yesterday. It
doesn't look like it's doing anything strange, but I could easily have
missed something.

One thing you could try doing is to turn on query logging (set
log_statement = all) and look to see if rubyrep, or some other part of
your system, is indeed issuing repeated CREATE OR REPLACE FUNCTION
commands.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-***@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

Vincent Dautremont

2012-05-23 21:22:07 UTC

Permalink

Hi,
you were right,
I do see those CREATE OR REPLACE FUNCTION a bit more than 1 per second
(approx. 12 times for 10 seconds)

2012-05-23 21:15:45 WET LOG: execute <unnamed>: CREATE OR

REPLACE FUNCTION "rr_ptz_lock"() RETURNS TRIGGER AS $change_trigger$
BEGIN
PERFORM ACTIVE FROM
"public".rr_running_flags;
IF FOUND THEN
RETURN NULL;
END IF;
IF (TG_OP = 'DELETE') THEN
INSERT INTO "public".rr_pending_changes(change_table,
change_key, change_type, change_time)
SELECT 'ptz_lock', 'workstation_id|' ||
OLD."workstation_id" || '|' || 'camera_id|' || OLD."camera_id", 'D', now();
ELSIF (TG_OP = 'UPDATE') THEN
INSERT INTO "public".rr_pending_changes(change_table,
change_key, change_new_key, change_type, change_time)
SELECT 'ptz_lock', 'workstation_id|' ||
OLD."workstation_id" || '|' || 'camera_id|' || OLD."camera_id",
'workstation_id|' || NEW."workstation_id" || '|' || 'camera_id|' ||
NEW."camera_id", 'U', now();
ELSIF (TG_OP = 'INSERT') THEN
INSERT INTO "public".rr_pending_changes(change_table,
change_key, change_type, change_time)
SELECT 'ptz_lock', 'workstation_id|' ||
NEW."workstation_id" || '|' || 'camera_id|' || NEW."camera_id", 'I', now();
END IF;
RETURN NULL; -- result is ignored since this is an AFTER
trigger
END;
$change_trigger$ LANGUAGE plpgsql

I don't know a lot about the internal of rubyrep, but do you think this is
not a normal behaviour from a postgresql server point of view ?

Vincent.

Post by Vincent Dautremont
I've found out that when my software does these updates the memory of the
postgres process grows constantly at 24 MB/hour. when I stop my software

Post by Vincent Dautremont
update these rows, the memory of the process stops to grow.
also I've noticed that when I stop rubyrep, this postgres process

disappear.
Hmm. I wondered whether rubyrep might be triggering this somehow;
I don't know anything about that software. I went so far as to download
rubyrep and look at the Postgres-specific source code yesterday. It
doesn't look like it's doing anything strange, but I could easily have
missed something.
One thing you could try doing is to turn on query logging (set
log_statement = all) and look to see if rubyrep, or some other part of
your system, is indeed issuing repeated CREATE OR REPLACE FUNCTION
commands.
regards, tom lane

Tom Lane

2012-05-23 21:33:29 UTC

Permalink

Post by Vincent Dautremont
you were right,
I do see those CREATE OR REPLACE FUNCTION a bit more than 1 per second
(approx. 12 times for 10 seconds)

Hah. Complain to the rubyrep people. It's most likely just a thinko
about where they should issue that command. If they actually are
changing the function text from one issuance to the next, they would be
well advised to think of a better way to deal with whatever they're
doing that for; it's going to be quite inefficient even without
considering the effects of this leak.

Post by Vincent Dautremont
I don't know a lot about the internal of rubyrep, but do you think this is
not a normal behaviour from a postgresql server point of view ?

It's not. We have plugged that leak, I think, as of 9.1; but the fact
that it took us this long to notice the leak shows that constant
replacement of a function is not a common usage. All the server's
internal caching related to functions is designed around the assumption
that functions aren't redefined too often.

If you can't get the rubyrep people to fix their code, updating to PG
9.1 is a possible workaround.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-***@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

Vincent Dautremont

2012-05-23 21:46:30 UTC

Permalink

Well,
Thank you very much for your help, it's greatly appreciated.
At least I can now pinpoint the problem and search for a solution or
another reason to upgrade to 9.1 !

Regards,
Vincent.

Post by Tom Lane

Post by Vincent Dautremont
you were right,
I do see those CREATE OR REPLACE FUNCTION a bit more than 1 per second
(approx. 12 times for 10 seconds)

Post by Vincent Dautremont
I don't know a lot about the internal of rubyrep, but do you think this

Post by Vincent Dautremont
not a normal behaviour from a postgresql server point of view ?

It's not. We have plugged that leak, I think, as of 9.1; but the fact
that it took us this long to notice the leak shows that constant
replacement of a function is not a common usage. All the server's
internal caching related to functions is designed around the assumption
that functions aren't redefined too often.
If you can't get the rubyrep people to fix their code, updating to PG
9.1 is a possible workaround.
regards, tom lane