PostgreSQL Bugs - BUG #2104: pg_xlog/ trace files not reclaimed by server

Author

BUG #2104: pg_xlog/ trace files not reclaimed by server

Reuben Pasquini

2005-12-09, 11:24 am

The following bug has been logged online:

Bug reference: 2104
Logged by: Reuben Pasquini
Email address: pasquini@imageworks.com
PostgreSQL version: 8.1
Operating system: linux redhat-4.1
Description: pg_xlog/ trace files not reclaimed by server
Details:

Hello!

It appears that when my 8.1 database is forced
to generate more than
2*checkpoint_segment
s + 1
trace files under pg_xlog/, that the database
becomes confused and stops recycling the trace files.
Unfortunately - I haven't been able to catch this condition
until after it filled up the disk (hundreds of trace files)
and things crashed. I did not have this problem running
postgres-7.4, but performance was not nearly so good as 8.1.

I'm running a high-transaction postgres-8.1 database
on a 2-proc linux box - looks like 4 procs due to hyperthreading:

Main memory size: 3931 Mbytes
4 GenuineIntel Intel(R) Xeon(TM) CPU 2.80GHz processors

Attached below is the postgresql.conf file
I was running with at the time of the last crash.
I've had a few crashes like this, but only diagnosed
the problem recently.
I increased the checkpoint-segments to 30 after the
last crash early thismorning to see if that works
around the problem.

Thanks for the help!
Reuben

---------------
# -----------------------------
# PostgreSQL configuration file
# -----------------------------
#
# This file consists of lines of the form:
#
# name = value
#
# (The '=' is optional.) White space may be used. Comments are introduced
# with '#' anywhere on a line. The complete list of option names and
# allowed values can be found in the PostgreSQL documentation. The
# commented-out settings shown in this file represent the default values.
#
# Please note that re-commenting a setting is NOT sufficient to revert it
# to the default value, unless you restart the postmaster.
#
# Any option can also be given as a command line switch to the
# postmaster, e.g. 'postmaster -c log_connections=on'. Some options
# can be changed at run-time with the 'SET' SQL command.
#
# This file is read on postmaster startup and when the postmaster
# receives a SIGHUP. If you edit the file on a running system, you have
# to SIGHUP the postmaster for the changes to take effect, or use
# "pg_ctl reload". Some settings, such as listen_address, require
# a postmaster shutdown and restart to take effect.

#---------------------------------------------------------------------------

# FILE LOCATIONS
#---------------------------------------------------------------------------

# The default values of these variables are driven from the -D command line
# switch or PGDATA environment variable, represented here as ConfigDir.

#data_directory = 'ConfigDir' # use data in another directory
#hba_file = 'ConfigDir/pg_hba.conf' # host-based authentication file
#ident_file = 'ConfigDir/pg_ident.conf # IDENT configuration file

# If external_pid_file is not explicitly set, no extra pid file is written.
#external_pid_file = '(none)' # write an extra pid file

#---------------------------------------------------------------------------

# CONNECTIONS AND AUTHENTICATION
#---------------------------------------------------------------------------

# - Connection Settings -

listen_addresses = '*' # what IP address(es) to listen on;
# comma-separated list of
addresses;
# defaults to 'localhost', '*' =
all
#port = 5432
max_connections = 100
# note: increasing max_connections costs ~400 bytes of shared memory per
# connection slot, plus lock space (see max_locks_per_transa
ction). You
# might also need to raise shared_buffers to support more connections.
#superuser_reserved_
connections = 2
#unix_socket_directo
ry = ''
#unix_socket_group = ''
#unix_socket_permiss
ions = 0777 # octal
#bonjour_name = '' # defaults to the computer name

# - Security & Authentication -

#authentication_time
out = 60 # 1-600, in seconds
#ssl = off
#password_encryption
= on
#db_user_namespace = off

# Kerberos
#krb_server_keyfile = ''
#krb_srvname = 'postgres'
#krb_server_hostname
= '' # empty string matches any keytab
entry
#krb_caseins_users = off

# - TCP Keepalives -
# see 'man 7 tcp' for details

#tcp_keepalives_idle
= 0 # TCP_KEEPIDLE, in seconds;
# 0 selects the system default
#tcp_keepalives_inte
rval = 0 # TCP_KEEPINTVL, in seconds;
# 0 selects the system default
#tcp_keepalives_coun
t = 0 # TCP_KEEPCNT;
# 0 selects the system default

#---------------------------------------------------------------------------

# RESOURCE USAGE (except WAL)
#---------------------------------------------------------------------------

# - Memory -

shared_buffers = 220000 # min 16 or max_connections*2, 8KB
each
temp_buffers = 244000 # min 100, 8KB each
max_prepared_transac
tions = 100 # can be 0 or more
# note: increasing max_prepared_transac
tions costs ~600 bytes of shared
memory
# per transaction slot, plus lock space (see max_locks_per_transa
ction).
work_mem = 204800 # min 64, size in KB
maintenance_work_mem
= 323840 # min 1024, size in KB
#max_stack_depth = 2048 # min 100, size in KB

# - Free Space Map -

max_fsm_pages = 8000000 # min max_fsm_relations*16
, 6 bytes
each
max_fsm_relations = 10000 # min 100, ~70 bytes each

# - Kernel Resource Usage -

#max_files_per_proce
ss = 1000 # min 25
#preload_libraries = ''

# - Cost-Based Vacuum Delay -

#vacuum_cost_delay = 0 # 0-1000 milliseconds
#vacuum_cost_page_hi
t = 1 # 0-10000 credits
#vacuum_cost_page_mi
ss = 10 # 0-10000 credits
#vacuum_cost_page_di
rty = 20 # 0-10000 credits
#vacuum_cost_limit = 200 # 0-10000 credits

# - Background writer -

#bgwriter_delay = 200 # 10-10000 milliseconds between
rounds
#bgwriter_lru_percen
t = 1.0 # 0-100% of LRU buffers
scanned/round
bgwriter_lru_maxpage
s = 100 # 0-1000 buffers max written/round
#bgwriter_all_percen
t = 0.333 # 0-100% of all buffers
scanned/round
bgwriter_all_maxpage
s = 100 # 0-1000 buffers max written/round

#---------------------------------------------------------------------------

# WRITE AHEAD LOG
#---------------------------------------------------------------------------

# - Settings -

fsync = off # turns forced synchronization on or
off
#wal_sync_method = fsync # the default is the first option
# supported by the operating
system:
# open_datasync
# fdatasync
# fsync
# fsync_writethrough
# open_sync
full_page_writes = off # recover from partial page writes
wal_buffers = 200 # min 4, 8KB each
#commit_delay = 0 # range 0-100000, in microseconds
#commit_siblings = 5 # range 1-1000

# - Checkpoints -

checkpoint_segments = 30 # in logfile segments, min 1, 16MB
each
#checkpoint_timeout = 300 # range 30-3600, in seconds
#checkpoint_warning = 30 # in seconds, 0 is off

# - Archiving -

#archive_command = '' # command to use to archive a
logfile
# segment

#---------------------------------------------------------------------------

# QUERY TUNING
#---------------------------------------------------------------------------

# - Planner Method Configuration -

#enable_bitmapscan = on
#enable_hashagg = on
#enable_hashjoin = on
#enable_indexscan = on
#enable_mergejoin = on
#enable_nestloop = on
#enable_seqscan = on
#enable_sort = on
#enable_tidscan = on

# - Planner Cost Constants -

#effective_cache_siz
e = 1000 # typically 8KB each
#random_page_cost = 4 # units are one sequential page
fetch
# cost
#cpu_tuple_cost = 0.01 # (same)
#cpu_index_tuple_cos
t = 0.001 # (same)
#cpu_operator_cost = 0.0025 # (same)

# - Genetic Query Optimizer -

#geqo = on
#geqo_threshold = 12
#geqo_effort = 5 # range 1-10
#geqo_pool_size = 0 # selects default based on effort
#geqo_generations = 0 # selects default based on effort
#geqo_selection_bias
= 2.0 # range 1.5-2.0

# - Other Planner Options -

#default_statistics_
target = 10 # range 1-1000
#constraint_exclusio
n = off
#from_collapse_limit
= 8
#join_collapse_limit
= 8 # 1 disables collapsing of explicit

# JOINs

#---------------------------------------------------------------------------

# ERROR REPORTING AND LOGGING
#---------------------------------------------------------------------------

# - Where to Log -

#log_destination = 'stderr' # Valid values are combinations of
# stderr, syslog and eventlog,
# depending on platform.

# This is used when logging to stderr:
redirect_stderr = on # Enable capturing of stderr into
log
# files

# These are only used if redirect_stderr is on:
log_directory = 'pg_log' # Directory where log files are
written
# Can be absolute or relative to
PGDATA
#log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # Log file name pattern.
# Can include strftime() escapes
log_truncate_on_rota
tion = on # If on, any existing log file of
the same
# name as the new log file will be
# truncated rather than appended to.
But
# such truncation only occurs on
# time-driven rotation, not on
restarts
# or size-driven rotation. Default
is
# off, meaning append to existing
files
# in all cases.
log_rotation_age = 1440 # Automatic rotation of logfiles
will
# happen after so many minutes. 0
to
# disable.
log_rotation_size = 0 # Automatic rotation of logfiles
will
# happen after so many kilobytes of
log
# output. 0 to disable.

# These are relevant when logging to syslog:
#syslog_facility = 'LOCAL0'
#syslog_ident = 'postgres'

# - When to Log -

#client_min_messages
= notice # Values, in order of decreasing
detail:
# debug5
# debug4
# debug3
# debug2
# debug1
# log
# notice
# warning
# error

#log_min_messages = notice # Values, in order of decreasing
detail:
# debug5
# debug4
# debug3
# debug2
# debug1
# info
# notice
# warning
# error
# log
# fatal
# panic

#log_error_verbosity
= default # terse, default, or verbose
messages

#log_min_error_state
ment = panic # Values in order of increasing
severity:
# debug5
# debug4
# debug3
# debug2
# debug1
# info
# notice
# warning
# error
# panic(off)

#log_min_duration_st
atement = -1 # -1 is disabled, 0 logs all
statements
# and their durations, in
milliseconds.

#silent_mode = off # DO NOT USE without syslog or
# redirect_stderr

# - What to Log -

#debug_print_parse = off
#debug_print_rewritt
en = off
#debug_print_plan = off
#debug_pretty_print = off
#log_connections = off
#log_disconnections = off
#log_duration = off
#log_line_prefix = '' # Special values:
# %u = user name
# %d = database name
# %r = remote host and port
# %h = remote host
# %p = PID
# %t = timestamp (no
milliseconds)
# %m = timestamp with
milliseconds
# %i = command tag
# %c = session id
# %l = session line number
# %s = session start timestamp
# %x = transaction id
# %q = stop here in non-session
# processes
# %% = '%'
# e.g. '<%u%%%d> '
#log_statement = 'none' # none, mod, ddl, all
#log_hostname = off

#---------------------------------------------------------------------------

# RUNTIME STATISTICS
#---------------------------------------------------------------------------

# - Statistics Monitoring -

#log_parser_stats = off
#log_planner_stats = off
#log_executor_stats = off
#log_statement_stats
= off

# - Query/Index Statistics Collector -

#stats_start_collect
or = on
#stats_command_strin
g = off
#stats_block_level = off
#stats_row_level = off
#stats_reset_on_serv
er_start = off

#---------------------------------------------------------------------------

# AUTOVACUUM PARAMETERS
#---------------------------------------------------------------------------

#autovacuum = off # enable autovacuum subprocess?
#autovacuum_naptime = 60 # time between autovacuum runs, in
secs
#autovacuum_vacuum_t
hreshold = 1000 # min # of tuple updates before
# vacuum
#autovacuum_analyze_
threshold = 500 # min # of tuple updates before
# analyze
#autovacuum_vacuum_s
cale_factor = 0.4 # fraction of rel size before
# vacuum
#autovacuum_analyze_
scale_factor = 0.2 # fraction of rel size before
# analyze
#autovacuum_vacuum_c
ost_delay = -1 # default vacuum cost delay for
# autovac, -1 means use
# vacuum_cost_delay
#autovacuum_vacuum_c
ost_limit = -1 # default vacuum cost limit for
# autovac, -1 means use
# vacuum_cost_limit

#---------------------------------------------------------------------------

# CLIENT CONNECTION DEFAULTS
#---------------------------------------------------------------------------

# - Statement Behavior -

#search_path = '$user,public' # schema names
#default_tablespace = '' # a tablespace name, '' uses
# the default
#check_function_bodi
es = on
#default_transaction
_isolation = 'read committed'
#default_transaction
_read_only = off
#statement_timeout = 0 # 0 is disabled, in milliseconds

# - Locale and Formatting -

#datestyle = 'iso, mdy'
#timezone = unknown # actually, defaults to TZ
# environment setting
#australian_timezone
s = off
#extra_float_digits = 0 # min -15, max 2
#client_encoding = sql_ascii # actually, defaults to database
# encoding

# These settings are initialized by initdb -- they might be changed
lc_messages = 'en_US.UTF-8' # locale for system error
message
# strings
lc_monetary = 'en_US.UTF-8' # locale for monetary
formatting
lc_numeric = 'en_US.UTF-8' # locale for number
formatting
lc_time = 'en_US.UTF-8' # locale for time
formatting

# - Other Defaults -

#explain_pretty_prin
t = on
#dynamic_library_pat
h = '$libdir'

#---------------------------------------------------------------------------

# LOCK MANAGEMENT
#---------------------------------------------------------------------------

#deadlock_timeout = 1000 # in milliseconds
#max_locks_per_trans
action = 64 # min 10
# note: each lock table slot uses ~220 bytes of shared memory, and there
are
# max_locks_per_transa
ction * (max_connections + max_prepared_transac
tions)
# lock table slots.

#---------------------------------------------------------------------------

# VERSION/PLATFORM COMPATIBILITY
#---------------------------------------------------------------------------

# - Previous Postgres Versions -

#add_missing_from = off
#regex_flavor = advanced # advanced, extended, or basic
#sql_inheritance = on
#default_with_oids = off
#escape_string_warni
ng = off

# - Other Platforms & Clients -

#transform_null_equa
ls = off

#---------------------------------------------------------------------------

# CUSTOMIZED OPTIONS
#---------------------------------------------------------------------------

#custom_variable_cla
sses = '' # list of custom variable class
names

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

Tom Lane

2005-12-09, 11:24 am

"Reuben Pasquini" <pasquini@imageworks.com> writes:
> It appears that when my 8.1 database is forced
> to generate more than
> 2*checkpoint_segment
s + 1
> trace files under pg_xlog/, that the database
> becomes confused and stops recycling the trace files.

That's fairly hard to believe, especially since you haven't presented
any actual evidence of it.

What might have happened is that checkpoints were failing for some
reason and so recycling of WAL segments couldn't be performed. Was
there anything in the postmaster log about write failures?

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

Reuben Pasquini

2005-12-10, 1:24 pm

Hi Tom,

Unfortunately, I had to rebuild the database pretty quickly
to get the app it supports back up,
and I wiped out the log files.
The postmaster would dump core on startup - so I
just wiped the database, and recreated the schema
(my app can rebuild its state).
I didn't save the core file either - but it wasn't
not very informative - something like:

abort ();
failedToStartupChild
Processes ();
....

I'll save the logs and core if this happens again.
I may have misdiagnosed the cause of the problem,
but the pg_xlog/ directory does fill up with files until
the disk is full - 8 GB worth - when it enters this unstable
state. I thought it might be related to exceeding
2*checkpoint_segment
s + 1
because of what I read here:

http://www.postgresql.org/docs/8.1/...figuration.html

-------------

There will be at least one WAL segment file, and will normally not be
more than 2 * checkpoint_segments + 1 files. Each segment file is
normally 16 MB (though this size can be altered when building the
server). You can use this to estimate space requirements for WAL.
Ordinarily, when old log segment files are no longer needed, they are
recycled (renamed to become the next segments in the numbered sequence).
If, due to a short-term peak of log output rate, there are more than 2 *
checkpoint_segments + 1 segment files, the unneeded segment files will
be deleted instead of recycled until the system gets back under this limit.

-------------

The database ran fine for the last 10 days - seemed to recycle the
trace files under pg_xlog/ fine. I was monitoring the
pg_xlog/ directory, because I knew that was what grew out of control
the last crash. I noticed at the end of the day yesterday that
we had grown up to 25 trace files, and I knew my checkpoint-segment
was set to '12'.

Anyway - I could be completely off here.
I uped my checkpoint_segment setting to 30 (still have a 5 minute timeout),
and trace files are recycling ok:

$ ls -lrt pg_xlog/
total 278872
drwx------ 2 monitor user 4096 Dec 9 04:59 archive_status
-rw------- 1 monitor user 16777216 Dec 9 11:00 00000001000000010000
00C9
-rw------- 1 monitor user 16777216 Dec 9 11:00 00000001000000010000
00C8
-rw------- 1 monitor user 16777216 Dec 9 11:02 00000001000000010000
00C7
-rw------- 1 monitor user 16777216 Dec 9 11:05 00000001000000010000
00B9
-rw------- 1 monitor user 16777216 Dec 9 11:05 00000001000000010000
00BA
-rw------- 1 monitor user 16777216 Dec 9 11:06 00000001000000010000
00BB
-rw------- 1 monitor user 16777216 Dec 9 11:07 00000001000000010000
00BC
-rw------- 1 monitor user 16777216 Dec 9 11:07 00000001000000010000
00BD
-rw------- 1 monitor user 16777216 Dec 9 11:08 00000001000000010000
00BE
-rw------- 1 monitor user 16777216 Dec 9 11:09 00000001000000010000
00BF
-rw------- 1 monitor user 16777216 Dec 9 11:09 00000001000000010000
00C0
-rw------- 1 monitor user 16777216 Dec 9 11:10 00000001000000010000
00C1
-rw------- 1 monitor user 16777216 Dec 9 11:11 00000001000000010000
00C2
-rw------- 1 monitor user 16777216 Dec 9 11:11 00000001000000010000
00C3
-rw------- 1 monitor user 16777216 Dec 9 11:12 00000001000000010000
00C4
-rw------- 1 monitor user 16777216 Dec 9 11:13 00000001000000010000
00C5
-rw------- 1 monitor user 16777216 Dec 9 11:13 00000001000000010000
00C6

We'll see how that goes. I'll let you know if I get another crash.

Cheers,
Reuben

Tom Lane wrote:

>"Reuben Pasquini" <pasquini@imageworks.com> writes:
>
>
>
>That's fairly hard to believe, especially since you haven't presented
>any actual evidence of it.
>
>What might have happened is that checkpoints were failing for some
>reason and so recycling of WAL segments couldn't be performed. Was
>there anything in the postmaster log about write failures?
>
> regards, tom lane
>
>
>

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

Sponsored Links