Message-ID: <48CA78F9.5090902@novatech-llc.com>
Date: Fri, 12 Sep 2008 09:13:13 -0500
From: George McCollister <georgem@novatech-llc.com>
User-Agent: Thunderbird 1.5 (X11/20060317)
MIME-Version: 1.0
To: pgsql-performance@postgresql.org
Subject: Postgres Performance on CPU limited Platforms
Content-Type: multipart/mixed; boundary="------------070206030400020002080400"

This is a multi-part message in MIME format.
--------------070206030400020002080400
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit

I'm trying to optimize postgres performance on a headless solid state
hardware platform (no fans or disks). I have the database stored on a
USB 2.0 flash drive (hdparm benchmarks reads at 10 MB/s). Performance is
limited by the 533Mhz CPU.

Hardware:
IXP425 XScale (big endian) 533Mhz 64MB RAM
USB 2.0 Flash Drive
 
Software:
Linux 2.6.21.4
postgres 8.2.5

I created a fresh database using initdb, then added one table.

Here is the create table:
CREATE TABLE archivetbl
(
  "DateTime" timestamp without time zone,
  "StationNum" smallint,
  "DeviceDateTime" timestamp without time zone,
  "DeviceNum" smallint,
  "Tagname" character(64),
  "Value" double precision,
  "Online" boolean
)
WITH (OIDS=FALSE);
ALTER TABLE archivetbl OWNER TO novatech;

I've attached my postgresql.conf

I populated the table with 38098 rows.

I'm doing this simple query:
select * from archivetbl;
 
It takes 79 seconds to complete the query (when postgres is compiled
with -O2). I'm running the query from pgadmin3 over TCP/IP.

top shows CPU usage is at 100% with 95% being in userspace. oprofile
shows memset is using 58% of the CPU cycles!

CPU: ARM/XScale PMU2, speed 0 MHz (estimated)
Counted CPU_CYCLES events (clock cycles counter) with a unit mask of
0x00 (No unit mask) count 100000
samples  %        app name                 symbol name
288445   57.9263  libc-2.5.so              memset
33273     6.6820  vmlinux                  default_idle
27910     5.6050  vmlinux                  cpu_idle
12611     2.5326  vmlinux                  schedule
8803      1.7678  libc-2.5.so              __printf_fp
7448      1.4957  postgres                 dopr
6404      1.2861  libc-2.5.so              vfprintf
6398      1.2849  oprofiled                (no symbols)
4992      1.0025  postgres                 __udivdi3
4818      0.9676  vmlinux                  run_timer_softirq


I was having trouble getting oprofile to give a back trace for memset
(probably because my libc is optimized). So I redefined MemSet to call this:
void * gmm_memset(void *s, int c, size_t n)
{
        int i=0;
        unsigned char * p = (unsigned char *)s;
        for(i=0; i<n; i++)
        {
                p[i]=0;
        }
        return s;
}

Here are the oprofile results for the same select query.

CPU: ARM/XScale PMU2, speed 0 MHz (estimated)
Counted CPU_CYCLES events (clock cycles counter) with a unit mask of
0x00 (No unit mask) count 100000
samples  %        image name               app name                
symbol name
-------------------------------------------------------------------------------
  1        5.2e-04  postgres                 postgres                
LockAcquire
  1        5.2e-04  postgres                 postgres                
set_ps_display
  20        0.0103  postgres                 postgres                
pg_vsprintf
  116695   60.2947  postgres                 postgres                 dopr
116717   60.3061  postgres                 postgres                
gmm_memset
  116717   60.3061  postgres                 postgres                
gmm_memset [self]
-------------------------------------------------------------------------------
20304    10.4908  oprofiled                oprofiled                (no
symbols)
  20304    10.4908  oprofiled                oprofiled               
(no symbols) [self]
-------------------------------------------------------------------------------
  4587      2.3700  vmlinux                  vmlinux                 
rest_init
  6627      3.4241  vmlinux                  vmlinux                 
cpu_idle
11214     5.7941  vmlinux                  vmlinux                 
default_idle
  11214     5.7941  vmlinux                  vmlinux                 
default_idle [self]
-------------------------------------------------------------------------------
  16151     8.3450  vmlinux                  vmlinux                 
rest_init
9524      4.9209  vmlinux                  vmlinux                  cpu_idle
  9524      4.9209  vmlinux                  vmlinux                 
cpu_idle [self]
  6627      3.4241  vmlinux                  vmlinux                 
default_idle
-------------------------------------------------------------------------------
5111      2.6408  oprofile                 oprofile                 (no
symbols)
  5111      2.6408  oprofile                 oprofile                
(no symbols) [self]

oprofile shows dopr is making most of the calls to memset.

Are these results typical? If memset is indeed using over 50% of the CPU
something seems seriously wrong.

Should I be expecting more performance from this hardware than what I'm
getting in these tests?

Regards,
George McCollister


--------------070206030400020002080400
Content-Type: text/plain;
 name="postgresql.conf"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
 filename="postgresql.conf"

# -----------------------------
# 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 server.
#
# Any option can also be given as a command line switch to the server,
# e.g., 'postgres -c log_connections=on'.  Some options can be changed at
# run-time with the 'SET' SQL command.
#
# This file is read on server startup and when the server receives a
# SIGHUP.  If you edit the file on a running system, you have to SIGHUP the
# server for the changes to take effect, or use "pg_ctl reload". Some
# settings, which are marked below, require a server shutdown and restart
# to take effect.
#
# Memory units:  kB = kilobytes MB = megabytes GB = gigabytes
# Time units:    ms = milliseconds s = seconds min = minutes h = hours d = days


#---------------------------------------------------------------------------
# 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
					# (change requires restart)
#hba_file = 'ConfigDir/pg_hba.conf'	# host-based authentication file
					# (change requires restart)
#ident_file = 'ConfigDir/pg_ident.conf'	# ident configuration file
					# (change requires restart)

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


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

# - Connection Settings -

#listen_addresses = 'localhost'		# what IP address(es) to listen on; 
					# comma-separated list of addresses;
					# defaults to 'localhost', '*' = all
					# (change requires restart)
listen_addresses = '*'
#port = 5432				# (change requires restart)
max_connections = 10			# (change requires restart)
# 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 = 3	# (change requires restart)
#unix_socket_directory = ''		# (change requires restart)
unix_socket_directory = '/var/run/postgresql'
#unix_socket_group = ''			# (change requires restart)
#unix_socket_permissions = 0777		# octal
					# (change requires restart)
#bonjour_name = ''			# defaults to the computer name
					# (change requires restart)

# - Security & Authentication -

#authentication_timeout = 1min		# 1s-600s
#ssl = off				# (change requires restart)
#password_encryption = on
#db_user_namespace = off

# Kerberos
#krb_server_keyfile = ''		# (change requires restart)
#krb_srvname = 'postgres'		# (change requires restart)
#krb_server_hostname = ''		# empty string matches any keytab entry
					# (change requires restart)
#krb_caseins_users = off		# (change requires restart)

# - 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 = 1600kB			# min 128kB or max_connections*16kB
					# (change requires restart)
#temp_buffers = 8MB			# min 800kB
#max_prepared_transactions = 5		# can be 0 or more
					# (change requires restart)
# Note: increasing max_prepared_transactions costs ~600 bytes of shared memory
# per transaction slot, plus lock space (see max_locks_per_transaction).
#work_mem = 1MB				# min 64kB
#maintenance_work_mem = 16MB		# min 1MB
#max_stack_depth = 2MB			# min 100kB

# - Free Space Map -

max_fsm_pages = 20000		# min max_fsm_relations*16, 6 bytes each
					# (change requires restart)
#max_fsm_relations = 1000		# min 100, ~70 bytes each
					# (change requires restart)

# - Kernel Resource Usage -

#max_files_per_process = 1000		# min 25
					# (change requires restart)
#shared_preload_libraries = ''		# (change requires restart)

# - 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 = 200ms			# 10-10000ms 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 = 64kB			# min 32kB
					# (change requires restart)
#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 = 5min		# range 30s-1h
#checkpoint_warning = 30s		# 0 is off

# - Archiving -

#archive_command = ''		# command to use to archive a logfile segment
#archive_timeout = 0		# force a logfile segment switch after this
				# many seconds; 0 is off


#---------------------------------------------------------------------------
# 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 -

#seq_page_cost = 1.0			# measured on an arbitrary scale
#random_page_cost = 4.0			# same scale as above
#cpu_tuple_cost = 0.01			# same scale as above
#cpu_index_tuple_cost = 0.005		# same scale as above
#cpu_operator_cost = 0.0025		# same scale as above
#effective_cache_size = 128MB
random_page_cost = 1.0
cpu_tuple_cost = 0.1


# - 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.

log_destination = 'syslog'
# This is used when logging to stderr:
#redirect_stderr = off			# Enable capturing of stderr into log 
					# files
					# (change requires restart)

# 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 = 1d			# Automatic rotation of logfiles will 
					# happen after that time.  0 to 
					# disable.
#log_rotation_size = 10MB		# Automatic rotation of logfiles will 
					# happen after that much 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 = error	# Values in order of increasing severity:
				 	#   debug5
					#   debug4
					#   debug3
					#   debug2
					#   debug1
				 	#   info
					#   notice
					#   warning
					#   error
					#   fatal
					#   panic (effectively off)

#log_min_duration_statement = -1	# -1 is disabled, 0 logs all statements
					# and their durations.

#silent_mode = off			# DO NOT USE without syslog or 
					# redirect_stderr
					# (change requires restart)

# - 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 = ''			# 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, ddl, mod, all
#log_hostname = off


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

# - Query/Index Statistics Collector -

#stats_command_string = on
#update_process_title = on

#stats_start_collector = on		# needed for block or row stats
					# (change requires restart)
#stats_block_level = off
#stats_row_level = off
stats_row_level = on
#stats_reset_on_server_start = off	# (change requires restart)


# - Statistics Monitoring -

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


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

#autovacuum = off			# enable autovacuum subprocess?
					# 'on' requires stats_start_collector
					# and stats_row_level to also be on
autovacuum = on
#autovacuum_naptime = 1min		# time between autovacuum runs
#autovacuum_vacuum_threshold = 500	# min # of tuple updates before
					# vacuum
#autovacuum_analyze_threshold = 250	# min # of tuple updates before 
					# analyze
#autovacuum_vacuum_scale_factor = 0.2	# fraction of rel size before 
					# vacuum
#autovacuum_analyze_scale_factor = 0.1	# fraction of rel size before 
					# analyze
#autovacuum_freeze_max_age = 200000000	# maximum XID age before forced vacuum
					# (change requires restart)
#autovacuum_vacuum_cost_delay = -1	# default vacuum cost delay for 
					# autovacuum, -1 means use 
					# vacuum_cost_delay
#autovacuum_vacuum_cost_limit = -1	# default vacuum cost limit for 
					# autovacuum, -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
#vacuum_freeze_min_age = 100000000

# - Locale and Formatting -

datestyle = 'iso, mdy'
#timezone = unknown			# actually, defaults to TZ 
					# environment setting
#timezone_abbreviations = 'Default'     # select the set of available timezone
					# abbreviations. Currently, there are
					#   Default
					#   Australia
					#   India
					# However you can also create your own
					# file in share/timezonesets/.
#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 = 'C'			# locale for system error message 
					# strings
lc_monetary = 'C'			# locale for monetary formatting
lc_numeric = 'C'			# locale for number formatting
lc_time = 'C'				# locale for time formatting

# - Other Defaults -

#explain_pretty_print = on
#dynamic_library_path = '$libdir'
#local_preload_libraries = ''


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

#deadlock_timeout = 1s
#max_locks_per_transaction = 64		# min 10
					# (change requires restart)
# Note: each lock table slot uses ~270 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
#array_nulls = on
#backslash_quote = safe_encoding	# on, off, or safe_encoding
#default_with_oids = off
#escape_string_warning = on
#standard_conforming_strings = 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

--------------070206030400020002080400--