Обсуждение: CPU load
Hello,
postmaster heavily loads processor. The database is accessed from java
aplication (with several threads), C applications and from PHP scripts.
It seems that one php script, called periodicaly, rises the load but the
script is very simple, something like this:
$var__base = new baza($dbhost,$dbport,$dbname,$dbuser,$dbpasswd);
$pok_baza = new upit($var__base->veza);
$upit_datum="SELECT * FROM system_alarm WHERE date= '$danas' AND
time>=(LOCALTIME - interval '$vrijeme_razmak hours') ORDER BY date DESC,
time DESC";
The statment is executed in approximately 0.6 sec.
The number of open connections is constantly 107.
The operating system is Debian GNU/Linux kernel 2.6.18-4-686.
Database version is PostgreSQL 8.2.4.
Thank you very much for any help.
Maja Stula
_________________________________________________________________________
The result of the top command:
top - 20:44:58 up 5:36, 1 user, load average: 1.31, 1.39, 1.24
Tasks: 277 total, 2 running, 275 sleeping, 0 stopped, 0 zombie
Cpu(s): 11.5%us, 2.2%sy, 0.0%ni, 86.3%id, 0.0%wa, 0.0%hi, 0.0%si,
0.0%st
Mem: 3370808k total, 1070324k used, 2300484k free, 49484k buffers
Swap: 1951888k total, 0k used, 1951888k free, 485396k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4990 postgres 25 0 41160 19m 18m R 100 0.6 1:36.74 postmaster
15278 test 24 0 1000m 40m 5668 S 9 1.2 1:42.37 java
18892 root 15 0 2468 1284 884 R 0 0.0 0:00.05 top
1 root 15 0 2044 696 596 S 0 0.0 0:02.51 init
2 root RT 0 0 0 0 S 0 0.0 0:00.00 migration/0
3 root 34 19 0 0 0 S 0 0.0 0:00.12 ksoftirqd/0
4 root RT 0 0 0 0 S 0 0.0 0:00.00 migration/1
5 root 34 19 0 0 0 S 0 0.0 0:00.00 ksoftirqd/1
6 root RT 0 0 0 0 S 0 0.0 0:00.00 migration/2
7 root 34 19 0 0 0 S 0 0.0 0:00.00 ksoftirqd/2
__________________________________________________________________________
The result of vmstat command:
kamis03:/etc# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
2 0 0 2271356 49868 505252 0 0 2 32 40 83 6 1
93 0
2 0 0 2271232 49868 505304 0 0 0 2348 459 1118 14 2
84 0
3 0 0 2271232 49868 505304 0 0 0 16 305 1197 11 2
87 0
3 0 0 2270984 49868 505432 0 0 0 8 407 1821 15 3
82 0
2 0 0 2270984 49868 505432 0 0 0 0 271 1328 11 2
87 0
1 0 0 2270984 49868 505440 0 0 0 24 375 1530 5 1
94 0
2 0 0 2270488 49868 505440 0 0 0 1216 401 1541 12 2
86 0
__________________________________________________________________________
The cpu configuration is:
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 0
siblings : 4
core id : 0
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3194.46
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 0
siblings : 4
core id : 1
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3191.94
processor : 2
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 0
siblings : 4
core id : 2
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3192.01
processor : 3
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 0
siblings : 4
core id : 3
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3192.01
processor : 4
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 1
siblings : 4
core id : 0
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3191.98
processor : 5
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 1
siblings : 4
core id : 1
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3191.98
processor : 6
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 1
siblings : 4
core id : 2
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3191.97
processor : 7
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU E5310 @ 1.60GHz
stepping : 7
cpu MHz : 1596.076
cache size : 4096 KB
physical id : 1
siblings : 4
core id : 3
cpu cores : 4
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm
constant_tsc pni monitor ds_cpl vmx tm2 cx16 xtpr lahf_lm
bogomips : 3191.97
__________________________________________________________________________
Postgresql.conf file:
# -----------------------------
# 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_addresses, 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 = '/etc/postgresql/8.1/main/pg_hba.conf' # host-based
authentication file
ident_file = '/etc/postgresql/8.1/main/pg_ident.conf' # IDENT
configuration file
# If external_pid_file is not explicitly set, no extra pid file is written.
external_pid_file = '/var/run/postgresql/8.1-main.pid' # write an extra
pid file
#---------------------------------------------------------------------------
# CONNECTIONS AND AUTHENTICATION
#---------------------------------------------------------------------------
# - Connection Settings -
#listen_addresses = 'localhost' # what IP address(es) to listen on;
# comma-separated list of addresses;
# defaults to 'localhost', '*' = all
port = 5432
# Maksimalni broj konekcija je podignut na 1000
# Maja 15.6
max_connections = 1000
#max_connections = 100
# note: increasing max_connections costs ~400 bytes of shared memory per
# connection slot, plus lock space (see max_locks_per_transaction). You
# might also need to raise shared_buffers to support more connections.
#superuser_reserved_connections = 2
unix_socket_directory = '/var/run/postgresql'
#unix_socket_group = ''
#unix_socket_permissions = 0777 # octal
#bonjour_name = '' # defaults to the computer name
# - Security & Authentication -
#authentication_timeout = 60 # 1-600, in seconds
ssl = false
#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_interval = 0 # TCP_KEEPINTVL, in seconds;
# 0 selects the system default
#tcp_keepalives_count = 0 # TCP_KEEPCNT;
# 0 selects the system default
#---------------------------------------------------------------------------
# RESOURCE USAGE (except WAL)
#---------------------------------------------------------------------------
# - Memory -
#shared_buffers = 1000 # min 16 or max_connections*2, 8KB each
# broj buffera mora biti dva puta veci od max. broj konekcija
shared_buffers = 2000
#temp_buffers = 1000 # min 100, 8KB each
#max_prepared_transactions = 5 # can be 0 or more
# note: increasing max_prepared_transactions costs ~600 bytes of shared
memory
# per transaction slot, plus lock space (see max_locks_per_transaction).
#work_mem = 1024 # min 64, size in KB
#maintenance_work_mem = 16384 # min 1024, size in KB
#max_stack_depth = 2048 # min 100, size in KB
# - Free Space Map -
#max_fsm_pages = 20000 # min max_fsm_relations*16, 6 bytes each
#max_fsm_relations = 1000 # min 100, ~70 bytes each
# - Kernel Resource Usage -
#max_files_per_process = 1000 # min 25
#preload_libraries = ''
# - Cost-Based Vacuum Delay -
#vacuum_cost_delay = 0 # 0-1000 milliseconds
#vacuum_cost_page_hit = 1 # 0-10000 credits
#vacuum_cost_page_miss = 10 # 0-10000 credits
#vacuum_cost_page_dirty = 20 # 0-10000 credits
#vacuum_cost_limit = 200 # 0-10000 credits
# - Background writer -
#bgwriter_delay = 200 # 10-10000 milliseconds between rounds
#bgwriter_lru_percent = 1.0 # 0-100% of LRU buffers scanned/round
#bgwriter_lru_maxpages = 5 # 0-1000 buffers max written/round
#bgwriter_all_percent = 0.333 # 0-100% of all buffers scanned/round
#bgwriter_all_maxpages = 5 # 0-1000 buffers max written/round
#---------------------------------------------------------------------------
# WRITE AHEAD LOG
#---------------------------------------------------------------------------
# - Settings -
#fsync = on # 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 = on # recover from partial page writes
#wal_buffers = 8 # min 4, 8KB each
#commit_delay = 0 # range 0-100000, in microseconds
#commit_siblings = 5 # range 1-1000
# - Checkpoints -
#checkpoint_segments = 3 # 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_size = 1000 # typically 8KB each
#random_page_cost = 4 # units are one sequential page fetch
# cost
#cpu_tuple_cost = 0.01 # (same)
#cpu_index_tuple_cost = 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_exclusion = 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 = off # 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_rotation = off # 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 = 10240 # 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_statement = panic # Values in order of increasing severity:
# debug5
# debug4
# debug3
# debug2
# debug1
# info
# notice
# warning
# error
# panic(off)
#log_min_duration_statement = -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_rewritten = off
#debug_print_plan = off
#debug_pretty_print = off
#log_connections = off
#log_disconnections = off
#log_duration = off
log_line_prefix = '%t ' # 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_collector = on
#stats_command_string = off
#stats_block_level = off
stats_row_level = on
#stats_reset_on_server_start = off
#---------------------------------------------------------------------------
# AUTOVACUUM PARAMETERS
#---------------------------------------------------------------------------
autovacuum = on # enable autovacuum subprocess?
#autovacuum_naptime = 60 # time between autovacuum runs, in secs
#autovacuum_vacuum_threshold = 1000 # min # of tuple updates before
# vacuum
#autovacuum_analyze_threshold = 500 # min # of tuple updates before
# analyze
#autovacuum_vacuum_scale_factor = 0.4 # fraction of rel size before
# vacuum
#autovacuum_analyze_scale_factor = 0.2 # fraction of rel size before
# analyze
#autovacuum_vacuum_cost_delay = -1 # default vacuum cost delay for
# autovac, -1 means use
# vacuum_cost_delay
#autovacuum_vacuum_cost_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_bodies = 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_timezones = 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_print = on
#dynamic_library_path = '$libdir'
#---------------------------------------------------------------------------
# LOCK MANAGEMENT
#---------------------------------------------------------------------------
#deadlock_timeout = 1000 # in milliseconds
#max_locks_per_transaction = 64 # min 10
# note: each lock table slot uses ~220 bytes of shared memory, and there are
# max_locks_per_transaction * (max_connections + max_prepared_transactions)
# lock table slots.
#---------------------------------------------------------------------------
# VERSION/PLATFORM COMPATIBILITY
#---------------------------------------------------------------------------
# - Previous Postgres Versions -
#add_missing_from = off
#backslash_quote = safe_encoding # on, off, or safe_encoding
#default_with_oids = off
#escape_string_warning = off
#regex_flavor = advanced # advanced, extended, or basic
#sql_inheritance = on
# - Other Platforms & Clients -
#transform_null_equals = off
#---------------------------------------------------------------------------
# CUSTOMIZED OPTIONS
#---------------------------------------------------------------------------
#custom_variable_classes = '' # list of custom variable class names
2008/9/25 <kiki@fesb.hr>: > The result of the top command: > > top - 20:44:58 up 5:36, 1 user, load average: 1.31, 1.39, 1.24 > Tasks: 277 total, 2 running, 275 sleeping, 0 stopped, 0 zombie > Cpu(s): 11.5%us, 2.2%sy, 0.0%ni, 86.3%id, 0.0%wa, 0.0%hi, 0.0%si, > 0.0%st > Mem: 3370808k total, 1070324k used, 2300484k free, 49484k buffers > Swap: 1951888k total, 0k used, 1951888k free, 485396k cached SNIP > The result of vmstat command: > > kamis03:/etc# vmstat 1 > procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu---- > r b swpd free buff cache si so bi bo in cs us sy id wa > 2 0 0 2271356 49868 505252 0 0 2 32 40 83 6 1 > 93 0 > 2 0 0 2271232 49868 505304 0 0 0 2348 459 1118 14 2 > 84 0 > 3 0 0 2271232 49868 505304 0 0 0 16 305 1197 11 2 > 87 0 > 3 0 0 2270984 49868 505432 0 0 0 8 407 1821 15 3 If that's what it looks like your server is running just fine. Load of 1.31, 85+% idle, no wait time. Or is that top and vmstat output from when the server is running fine?
> If that's what it looks like your server is running just fine. Load > of 1.31, 85+% idle, no wait time. Or is that top and vmstat output > from when the server is running fine? Don't forget that there are 8 CPUs, and the backend will only run on one of them. But I concur that this seems ok. How many rows are returned? Is 0.6 seconds an unacceptable time for that? If there is a lot of sorting going on and the pages are residing in the buffer, I would expect high CPU load. Normally, I am quite happy if my database is CPU bound. I start worrying if I/O wait grows too high. Yours, Laurenz Albe
Thank's for your response. The situation is that the top result is when the server is already exhibiting problems. The number of rows returned by the query varies, right now is: 49 row(s) Total runtime: 3,965.718 ms The table currently has 971582 rows. But the problem is that when database server is restarted everything works fine and fast. No heavy loads of the processor and as time passes situation with the processor is worsen. I forget to mention that php scrip is executed as a web application (Apache web server 2.2.3, php installed as a Server API Apache 2.0 Handler) called periodically each 8 seconds. After the restart of the postgres server everything works fine for several hours, the web application has a fast response when opening a web page. But after some time postmaster process (sometimes two postmaster process both owned by postgres user) rises and response time of the web application becomes slow, i.e. opening a php page with postgres access last for 8-10 seconds or even more. The php configuration for the postgres is default PostgreSQL Support enabled PostgreSQL(libpq) Version 8.1.8 Multibyte character support enabled SSL support enabled Active Persistent Links 1 Active Links 1 Directive Local Value Master Value pgsql.allow_persistent On On pgsql.auto_reset_persistent Off Off pgsql.ignore_notice Off Off pgsql.log_notice Off Off pgsql.max_links Unlimited Unlimited pgsql.max_persistent Unlimited Unlimited >> If that's what it looks like your server is running just fine. Load >> of 1.31, 85+% idle, no wait time. Or is that top and vmstat output >> from when the server is running fine? > > Don't forget that there are 8 CPUs, and the backend will only run on one > of them. > > But I concur that this seems ok. > How many rows are returned? Is 0.6 seconds an unacceptable time for that? > > If there is a lot of sorting going on and the pages are residing in the > buffer, I would expect high CPU load. > > Normally, I am quite happy if my database is CPU bound. I start worrying > if I/O wait grows too high. > > Yours, > Laurenz Albe >
kiki wrote: > The number of rows returned by the query varies, right now is: > > 49 row(s) > Total runtime: 3,965.718 ms > The table currently has 971582 rows. > > But the problem is that when database server is restarted everything works > fine and fast. No heavy loads of the processor and as time passes > situation with the processor is worsen. It would be interesting to know the result of EXPLAIN ANALYZE for the query, both when it performs well and when it doesn't. One thing I see right away when I look at your postgresql.conf is that you have set shared_buffers to an awfully small value of 2000, when you have enough memory on the machine (vmstat reports 2GB free memory, right?). Does the situation improve if you set it to a higher value? Yours, Laurenz Albe
It would be useful to confirm that this is a backend process.
With top, hit the 'c' key to show the full path / description of the process.
Backend postgres processes should then have more useful descriptions of what they are doing and identifying themselves.
You can also confirm what query is causing that by lining up the process id from top with the one returned by:
select current_query, procpid from pg_stat_activity where current_query not like '<IDLE%';
Or by simply using the process id for the where clause (where procpid = ).
How often is the table being queried modified? Between the startup when the query is fast, and when it slows down, is there a lot of modification to its rows?
With top, hit the 'c' key to show the full path / description of the process.
Backend postgres processes should then have more useful descriptions of what they are doing and identifying themselves.
You can also confirm what query is causing that by lining up the process id from top with the one returned by:
select current_query, procpid from pg_stat_activity where current_query not like '<IDLE%';
Or by simply using the process id for the where clause (where procpid = ).
How often is the table being queried modified? Between the startup when the query is fast, and when it slows down, is there a lot of modification to its rows?
On Fri, Sep 26, 2008 at 5:52 AM, Albe Laurenz <laurenz.albe@wien.gv.at> wrote:
kiki wrote:It would be interesting to know the result of EXPLAIN ANALYZE for the
> The number of rows returned by the query varies, right now is:
>
> 49 row(s)
> Total runtime: 3,965.718 ms
> The table currently has 971582 rows.
>
> But the problem is that when database server is restarted everything works
> fine and fast. No heavy loads of the processor and as time passes
> situation with the processor is worsen.
query, both when it performs well and when it doesn't.
One thing I see right away when I look at your postgresql.conf is that
you have set shared_buffers to an awfully small value of 2000, when you have
enough memory on the machine (vmstat reports 2GB free memory, right?).
Does the situation improve if you set it to a higher value?
Yours,
Laurenz Albe
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Thanks for the instructions for detecting the problem. It helped a lot. First I have increased shared_buffers from 2000 to 8000. Since the postgresql is on Debian I had to increase SHMMAX kernel value. Everything is working much faster now. There is still heavy load of postmaster process (up to 100%) for a simple query EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC LIMIT 1; (the table is indexed by id_camera, has around 1 milion rows, and this query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in around 4800 ms, and this table is queried a lot although not so often queried modified) but I don't think that is strange behavior of the postgresql. And it is exhibited all the time; the postgresql reset does not influence it at all. Once again thanks a lot, I learned a lot. Regards, Maja > It would be useful to confirm that this is a backend process. > With top, hit the 'c' key to show the full path / description of the > process. > Backend postgres processes should then have more useful descriptions of > what > they are doing and identifying themselves. > You can also confirm what query is causing that by lining up the process > id > from top with the one returned by: > > select current_query, procpid from pg_stat_activity where current_query > not > like '<IDLE%'; > > Or by simply using the process id for the where clause (where procpid = ). > > How often is the table being queried modified? Between the startup when > the > query is fast, and when it slows down, is there a lot of modification to > its > rows? > > > On Fri, Sep 26, 2008 at 5:52 AM, Albe Laurenz > <laurenz.albe@wien.gv.at>wrote: > >> kiki wrote: >> > The number of rows returned by the query varies, right now is: >> > >> > 49 row(s) >> > Total runtime: 3,965.718 ms >> > The table currently has 971582 rows. >> > >> > But the problem is that when database server is restarted everything >> works >> > fine and fast. No heavy loads of the processor and as time passes >> > situation with the processor is worsen. >> >> It would be interesting to know the result of EXPLAIN ANALYZE for the >> query, both when it performs well and when it doesn't. >> >> One thing I see right away when I look at your postgresql.conf is that >> you have set shared_buffers to an awfully small value of 2000, when you >> have >> enough memory on the machine (vmstat reports 2GB free memory, right?). >> >> Does the situation improve if you set it to a higher value? >> >> Yours, >> Laurenz Albe >> >> -- >> Sent via pgsql-performance mailing list >> (pgsql-performance@postgresql.org) >> To make changes to your subscription: >> http://www.postgresql.org/mailpref/pgsql-performance >> >
Hello Maja, > EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND > confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC > LIMIT 1; > > (the table is indexed by id_camera, has around 1 milion rows, and this > query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in > around 4800 ms, and this table is queried a lot although not so often > queried modified) 700.000 of 1.000.000 rows is around 70% ... that are nearly all rows. As much as I read you, this table is not often modified. What reason is there for quering all that data again and again instead of keeping it in memory (should it be really needed) ? Harald -- GHUM Harald Massa persuadere et programmare Harald Armin Massa Spielberger Straße 49 70435 Stuttgart 0173/9409607 no fx, no carrier pigeon - EuroPython 2009 will take place in Birmingham - Stay tuned!
kiki wrote: > First I have increased shared_buffers from 2000 to 8000. Since the > postgresql is on Debian I had to increase SHMMAX kernel value. > Everything is working much faster now. Good to hear that the problem is gone. > There is still heavy load of postmaster process (up to 100%) for a simple > query > > EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND > confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC > LIMIT 1; > > (the table is indexed by id_camera, has around 1 milion rows, and this > query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in > around 4800 ms, and this table is queried a lot although not so often > queried modified) > > but I don't think that is strange behavior of the postgresql. > And it is exhibited all the time; the postgresql reset does not influence > it at all. I'd expect a sequential scan for a query that returns 70% of the table. But I cannot believe that this query returns more than one row since it has a "LIMIT 1". Can you enlighten me? In the above query (with LIMIT 1), maybe an index on "date" could help. Yours, Laurenz Albe
Sorry, without LIMIT returns around 700000 rows. Tried to index date column and time column but the performance is pretty much the same. Everything is OK, I just dont understand way is this query burdening the processor so much. Regards, Maja > kiki wrote: >> First I have increased shared_buffers from 2000 to 8000. Since the >> postgresql is on Debian I had to increase SHMMAX kernel value. >> Everything is working much faster now. > > Good to hear that the problem is gone. > >> There is still heavy load of postmaster process (up to 100%) for a >> simple >> query >> >> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND >> confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC >> LIMIT 1; >> >> (the table is indexed by id_camera, has around 1 milion rows, and this >> query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in >> around 4800 ms, and this table is queried a lot although not so often >> queried modified) >> >> but I don't think that is strange behavior of the postgresql. >> And it is exhibited all the time; the postgresql reset does not >> influence >> it at all. > > I'd expect a sequential scan for a query that returns 70% of the table. > > But I cannot believe that this query returns more than one row since > it has a "LIMIT 1". Can you enlighten me? > > In the above query (with LIMIT 1), maybe an index on "date" could help. > > Yours, > Laurenz Albe > > > -- > Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-performance >
Hello Herald, the queried table is used for communication between server application and web user interface. When application detects an event it writes it down in table. The web client checks every 10 second if something new is written in the table. Usually nothing new is written but the client has to check it. I don't fetch all rows, usually just the last one written. The speed of the query is not a problem but the strange thing is the processor load with postmaster when the query is executed. I dont now how to reduce processor load. Should I change some other settings beside shared_buffers like work_mem? Or maybe such processor load is OK? Regards, Maja > Hello Maja, > >> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND >> confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC >> LIMIT 1; >> >> (the table is indexed by id_camera, has around 1 milion rows, and this >> query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in >> around 4800 ms, and this table is queried a lot although not so often >> queried modified) > > 700.000 of 1.000.000 rows is around 70% ... that are nearly all rows. > As much as I read you, this table is not often modified. What reason > is there for quering all that data again and again instead of keeping > it in memory (should it be really needed) ? > > > Harald > > -- > GHUM Harald Massa > persuadere et programmare > Harald Armin Massa > Spielberger Straße 49 > 70435 Stuttgart > 0173/9409607 > no fx, no carrier pigeon > - > EuroPython 2009 will take place in Birmingham - Stay tuned! > > -- > Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-performance >
On Mon, Sep 29, 2008 at 10:29:45AM +0200, kiki@fesb.hr wrote: > >> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND > >> confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC > >> LIMIT 1; > Sorry, without LIMIT returns around 700000 rows. > Tried to index date column and time column but the performance is pretty > much the same. > Everything is OK, I just dont understand way is this query burdening the > processor so much. 1. please do not top-post. 2. for this query, you can use this index: create index xxx on system_alarm (id_camera, date, time) where confirmed = 'false' and dismissed = 'false'; or you can make it without where: create index xxx on system_alarm (id_camera, confirmed, dismissed, date, time); but if you usually have the criteria "confirmed = 'false' and dismissed = 'false'" then the first index should be faster. Best regards, depesz -- Linkedin: http://www.linkedin.com/in/depesz / blog: http://www.depesz.com/ jid/gtalk: depesz@depesz.com / aim:depeszhdl / skype:depesz_hdl / gg:6749007
Please try to avoid top-posting where inappropriate. kiki wrote: >>> There is still heavy load of postmaster process (up to 100%) for a simple >>> query >>> >>> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE id_camera='3' AND >>> confirmed='false' AND dismissed='false' ORDER BY date DESC, time DESC >>> LIMIT 1; >>> >>> (the table is indexed by id_camera, has around 1 milion rows, and this >>> query returns around 700000 rows and is executed (EXPLAIN ANALYSE) in >>> around 4800 ms, and this table is queried a lot although not so often >>> queried modified) >>> >>> but I don't think that is strange behavior of the postgresql. >>> And it is exhibited all the time; the postgresql reset does not >>> influence it at all. >> >> I'd expect a sequential scan for a query that returns 70% of the table. >> >> But I cannot believe that this query returns more than one row since >> it has a "LIMIT 1". Can you enlighten me? >> >> In the above query (with LIMIT 1), maybe an index on "date" could help. > > Sorry, without LIMIT returns around 700000 rows. > Tried to index date column and time column but the performance is pretty > much the same. > Everything is OK, I just don't understand way is this query burdening the > processor so much. Yes, for the query without the LIMIT clause I wouldn't expect any gain from indexing. Probably the CPU load is caused by the sorting. Does it look different if you omit ORDER BY? Maybe the sort will perform better if you increase work_mem in postgresql.conf, you could experiment with that. Yours, Laurenz Albe
kiki wrote: > The speed of the query is not a problem but the strange thing is the > processor load with postmaster when the query is executed. > I dont now how to reduce processor load. Did you try without the ORDER BY? Where are the execution plans? Yours, Laurenz Albe
> kiki wrote:
>> The speed of the query is not a problem but the strange thing is the
>> processor load with postmaster when the query is executed.
>> I dont now how to reduce processor load.
>
> Did you try without the ORDER BY?
> Where are the execution plans?
>
> Yours,
> Laurenz Albe
>
I expanded work_mem to 256 Mb and created index on table
create index xxx on system_alarm (id_camera, date, time) where confirmed =
'false' and dismissed = 'false';
the processor load now executing the query is max. 70%
the query execution with and without order is:
istra_system=> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE
id_camera='3' AND confirmed='false' AND dismissed='false' ;
Seq Scan on system_alarm (cost=0.00..24468.33 rows=735284 width=47)
(actual time=90.792..1021.967 rows=724846 loops=1)
Filter: ((id_camera = 3) AND (NOT confirmed) AND (NOT dismissed))
Total runtime: 1259.426 ms
(3 rows)
istra_system=> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE
id_camera='3' AND confirmed='false' AND dismissed='false' ORDER BY date
DESC, time ;
Sort (cost=96114.18..97952.39 rows=735284 width=47) (actual
time=2303.547..2602.116 rows=724846 loops=1)
Sort Key: date, "time"
-> Seq Scan on system_alarm (cost=0.00..24468.33 rows=735284
width=47) (actual time=100.322..1115.837 rows=724846 loops=1)
Filter: ((id_camera = 3) AND (NOT confirmed) AND (NOT dismissed))
Total runtime: 2916.557 ms
(5 rows)
I think this is OK.
Thanx
kiki wrote: > I expanded work_mem to 256 Mb and created index on table > > create index xxx on system_alarm (id_camera, date, time) where confirmed = > 'false' and dismissed = 'false'; That index is not used for the query (as could be expected). You better remove it. > the processor load now executing the query is max. 70% > > the query execution with and without order is: > > istra_system=> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE > id_camera='3' AND confirmed='false' AND dismissed='false' ; > > Seq Scan on system_alarm (cost=0.00..24468.33 rows=735284 width=47) (actual time=90.792..1021.967 rows=724846 loops=1) > Filter: ((id_camera = 3) AND (NOT confirmed) AND (NOT dismissed)) > Total runtime: 1259.426 ms > (3 rows) > > istra_system=> EXPLAIN ANALYSE SELECT * FROM system_alarm WHERE > id_camera='3' AND confirmed='false' AND dismissed='false' ORDER BY date > DESC, time ; > > Sort (cost=96114.18..97952.39 rows=735284 width=47) (actual time=2303.547..2602.116 rows=724846 loops=1) > Sort Key: date, "time" > -> Seq Scan on system_alarm (cost=0.00..24468.33 rows=735284 width=47) (actual time=100.322..1115.837 rows=724846loops=1) > Filter: ((id_camera = 3) AND (NOT confirmed) AND (NOT dismissed)) > Total runtime: 2916.557 ms > (5 rows) > > I think this is OK. I think so too. I would say it is OK for the query to use much CPU during sort as long as this does not last for too long. Yours, Laurenz Albe