BUG #5196: Excessive memory consumption when using csvlog

The following bug has been logged online:

Bug reference: 5196
Logged by: Poindessous Thomas
Email address: thomas(at)poindessous(dot)com
PostgreSQL version: 8.3.8
Operating system: Linux redhat 5.3 x86_64
Description: Excessive memory consumption when using csvlog
Details:

Hi

we have a weird bug. When using csvlog instead of stderr, the postgres
logger process uses a lot of memory. We even had an OOM error with kernel.

For example, after 30 minutes of high use of the DB (apache benchmark),
logger process uses more than 1 Go of RAM :

begin of postgres :
ps fauxw :
pg83 14397 15.0 0.5 1148168 29472 ? Ss 22:08 0:00
/usr/bin/postgres
pg83 14439 0.0 0.0 61076 800 ? Ss 22:08 0:00 \_
postgres: logger process
pg83 14443 0.0 0.0 1148632 1096 ? Ss 22:08 0:00 \_
postgres: writer process
pg83 14444 0.0 0.0 1148632 936 ? Ss 22:08 0:00 \_
postgres: wal writer process
pg83 14445 0.0 0.0 1148820 1216 ? Ss 22:08 0:00 \_
postgres: autovacuum launcher process
pg83 14446 0.0 0.0 61360 980 ? Ss 22:08 0:00 \_
postgres: stats collector process

end of bench :
pg83 14397 2.8 0.5 1148168 29488 ? Ss 22:08 0:33
/usr/bin/postgres
pg83 14439 2.6 21.6 1200360 1132696 ? Ss 22:08 0:31 \_
postgres: logger process
pg83 14443 0.0 2.6 1148632 141380 ? Ss 22:08 0:00 \_
postgres: writer process
pg83 14444 0.0 0.0 1148632 1044 ? Ss 22:08 0:00 \_
postgres: wal writer process
pg83 14445 0.0 0.0 1148820 1256 ? Ss 22:08 0:00 \_
postgres: autovacuum launcher process
pg83 14446 0.2 0.0 61360 980 ? Ss 22:08 0:02 \_
postgres: stats collector process

If we change log_destination to stderr and we relaunch postgres and the
benchmark :

begin of postgres :
pg83 29567 1.3 0.5 1148168 29476 ? Ss 22:37 0:00
/usr/bin/postgres
pg83 29572 0.0 0.0 61072 736 ? Ss 22:37 0:00 \_
postgres: logger process
pg83 29574 0.0 0.0 1148632 3312 ? Ss 22:37 0:00 \_
postgres: writer process
pg83 29575 0.0 0.0 1148632 936 ? Ss 22:37 0:00 \_
postgres: wal writer process
pg83 29576 0.0 0.0 1148820 1244 ? Ss 22:37 0:00 \_
postgres: autovacuum launcher process
pg83 29577 0.0 0.0 61360 980 ? Ss 22:37 0:00 \_
postgres: stats collector process

end of bench :
pg83 29567 2.8 0.5 1148168 29484 ? Ss 22:37 0:30
/usr/bin/postgres
pg83 29572 2.3 0.0 61072 804 ? Ss 22:37 0:25 \_
postgres: logger process
pg83 29574 0.0 2.4 1148632 129872 ? Ss 22:37 0:00 \_
postgres: writer process
pg83 29575 0.0 0.0 1148632 1052 ? Ss 22:37 0:00 \_
postgres: wal writer process
pg83 29576 0.0 0.0 1148820 1244 ? Ss 22:37 0:00 \_
postgres: autovacuum launcher process
pg83 29577 0.1 0.0 61360 980 ? Ss 22:37 0:02 \_
postgres: stats collector process

Here are our param :
datestyle = 'iso, mdy'
default_text_search_config = 'pg_catalog.english'
effective_cache_size = 1536MB
lc_messages = 'C'
lc_monetary = 'C'
lc_numeric = 'C'
lc_time = 'C'
listen_addresses = '*'
log_checkpoints = on
log_connections = on
log_destination = 'stderr'
log_directory = 'pg_log'
log_disconnections = on
log_filename = 'postgresql-%Y-%m-%d.log'
log_hostname = on
log_line_prefix = '%m %u:%d : '
log_lock_waits = on
log_min_duration_statement = 0
logging_collector = on
maintenance_work_mem = 256MB
max_connections = 500
max_fsm_pages = 204800
shared_buffers = 1024MB
silent_mode = on
work_mem = 8MB

and we have 5 Go of physical RAM.

Thanks.