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@poindessous.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.