One of the most effective ways to know what your postgreSQL has done is to analyze the logs of what queries it executed. Here is the steps for logging setup, considering log analyze later.

Step 1, enable logging to file

In postgresql.conf, here are main parameters for logging enable.

logging_collector = on
log_destination = 'stderr'
log_directory = 'pg_log' 
log_filename = 'postgresql-%a.log'

Logging Collector tells Postgres to capture stderr and csvlog into log files, while in this case, we sset log_destination to 'stderr'. While log_directory defines the log directory, it's a relative path to postgres data path.

log_filename can include strftime() escapes, so you can also specify it as

log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log'

In this example, '%a' was used, it is the abbreviated name of the day of the week.

Step 2, log file rotation

Must not forget this section, here are 3 parameters for log rotation to play with

log_truncate_on_rotation = on 
log_rotation_age = 1d
log_rotation_size = 0

truncate on means an existing log file with the same name as the new log file will be truncated. rotation age tells postgres after that time, automatic rotation of logfiles will happen, rotation size 0 means disable.

Together with log file setting,

log_filename = 'postgresql-%a.log

The postgres log will have 7 log files for each day of the week, therefore, the log file will be overwriten the same day next week, so archive log files if need, otherwise, you will only see 7 days log.

Step 3, How log get written -- log content format

It's managed by log_line_prefix, here is my example. Also, you an also make it for yourself.

log_line_prefix = '%t|%d|%u|%x|%e|%c|'  

Below is the list of special values

#log_line_prefix = ''               # special values:
                                    #   %a = application name
                                    #   %u = user name
                                    #   %d = database name
                                    #   %r = remote host and port
                                    #   %h = remote host
                                    #   %p = process ID
                                    #   %t = timestamp without milliseconds
                                    #   %m = timestamp with milliseconds
                                    #   %i = command tag
                                    #   %e = SQL state
                                    #   %c = session ID
                                    #   %l = session line number
                                    #   %s = session start timestamp
                                    #   %v = virtual transaction ID
                                    #   %x = transaction ID (0 if none)
                                    #   %q = stop here in non-session
                                    #        processes
                                    #   %% = '%'
                                    # e.g. '<%u%%%d> '

To be noted is that there are three basic formats of line prefix that will match the standard of sorts introduced by the requirements of pgFouine, a popular log parsing utility. So, if you'd like to use the tool, the following three are available for you in below.

log_line_prefix = '%t [%p]: [%l-1] '
log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d'
log_line_prefix = '%t [%p]: [%l-1]  user=%u,db=%d,remote=%r'

The first line logs basic information, The second upgrades that to also include the user and database information for the connection, the final line also adds the remote host the connection came from.

Note1: if you use CSV format logs, the timestamp and process information will be inserted for you automatically, you don't need to include it into the prefix of the PostgreSQL log output.

Note2: you need to be careful with multi-line queries, which mostly happens in psql. So other types of logging can be alternate logging formats. Syslog or CSV logging. They are easier to be enabled.

Step 4, Filtering log

Moveing a bit ahead, logging every query is a heavy burden on server, so most of time, you may only want to log complex,long running queries on your server.

Here are related settings.

log_min_duration_statement = 10000      # -1 is disabled, 0 logs all statements
log_duration = on
log_statement = 'all'                 # none, ddl, mod, all

The first line tells server to log every query that takes over 1000ms(one second), the second default is 'off' and the third is none by default.

Step 5, Capature deadlocks

There is lock waits option, let you capature deadlock queiries.

log_lock_waits = on                     # log lock waits >= deadlock_timeout
By default, 1s is the deadlock timeout setting.
#deadlock_timeout = 1s

Step 6, auto explain

After PostgreSQL 8.4, there is a feature auto_explain, it's a contrib module, you need to install it , after installatin, add the following three lines into postgres.conf.

shared_preload_libraries ='auto_explain'
custom_variable_classes ='auto_explain'

This tells system that, any query takes longer than 1s will be logged with a full explain plan for the output.


Comments powered by CComment