Skip to content

yokawasa/mod_log_slow

Repository files navigation

/*
 * README
 * mod_log_slow - Logging Slow Request Module for Apache1.3 and Apache2.X
 */

                     _     _                     _
 _ __ ___   ___   __| |   | | ___   __ _     ___| | _____      __
| '_ ` _ \ / _ \ / _` |   | |/ _ \ / _` |   / __| |/ _ \ \ /\ / /
| | | | | | (_) | (_| |   | | (_) | (_| |   \__ \ | (_) \ V  V /
|_| |_| |_|\___/ \__,_|___|_|\___/ \__, |___|___/_|\___/ \_/\_/
                     |_____|       |___/_____|


====================================================================
* Introduction
====================================================================

mod_log_slow is Apache module to provide measures of the time period
used for handling each request by the current process. Logging is done
after processing a request if the request takes more than certain
period of time that you specifiy.
The idea of this module comes from MySQL's slow-query-log, and its
logging logic is partially based on mod_log_forensic.


====================================================================
* Download
====================================================================

http://code.google.com/p/modlogslow/downloads/list


====================================================================
* Build and Install
====================================================================

1) extract files from an archive
tar zxf modlogslow-<VERSION>.tar.gz
cd modlogslow-<VERSION>

2) open Makefile and modify ap_basedir variable
vi Makefile
 ap_basedir=/PATH-TO-APACHE-BASE

3) make and install
make
sudo make install


====================================================================
* Configuration Directives
====================================================================

All the directives below may be specified as per-server configuration.

o LogSlowEnabled

    Description: set "On" to enable log_slow, "Off" to disable.
           Default "Off"
    Syntax: LogSlowEnabled On/Off
    Context: server config, virtual host
    Status: Extension
    Module: mod_log_slow

o LogSlowLongRequestTime

    Description: Set the limit of request handling time in millisecond.
           Default "1000". Logging is done after processing a request
           if the request takes more than LogSlowLongRequestTime.
    Syntax: LogSlowLongRequestTime number(millisecond)
    Context: server config, virtual host
    Status: Extension
    Module: mod_log_slow

o LogSlowFileName

    Description: Set the filename of the slow log. The SlowLogFileName
           directive is used to log requests info that takes more than
           the time period specified in LogSlowLongRequestTime directive.
    Syntax: LogSlowFileName filename or pipe
    Context: server config, virtual host
    Status: Extension
    Module: mod_log_slow

    [note]
    In case of using pipe("|"), followed by the path to a program to receive the log information on its standard input.

o LogSlowTimeFormat

    Description: Set the time, in the form given by format, which should
           be in strftime(3) format. The slow_log's log entries are written
           in this format. If not set, the log entries are written in
           Common Log Format(CLF) by default.
    Syntax: LogSlowTimeFormat timeformat
    Context: server config, virtual host
    Status: Extension
    Module: mod_log_slow

    [example]
    LogSlowTimeFormat  "[%Y-%m-%d %H:%M:%S]"
    ->  [2009-06-24 00:09:44]

o LogSlowBufferedLogs

    Description: set "On" to enable buffered logs flush, "Off" to disable.
           Default "Off". Of cource if buffered logs option is set "On",
           slow_log is written delayed so as to decrease disk io and thus
           to lower the load. Only apache2 module supports.
    Syntax: LogSlowBufferedLogs On/Off
    Context: server config, virtual host
    Status: Extension
    Module: mod_log_slow

====================================================================
* Logging Format
====================================================================

Slow log entry is written to the file that specified in LogSlowFileName
directive, and the logging is made only after the request processing
that takes more than the time period specified in LogSlowLongRequestTime
directive.

1) Unique ID

mod_log_slow assigns a unique ID for each log entry, and the ID is
added to the log string. If you're using mod_unique_id, its generated
ID will be used as the unique ID.

2) Slow Log Format

<Unique ID> <time> elapsed: <elapsed time> cpu: <cpu usrtime>(usr)/<cpu systime>(sys) pic: <PID> ip: <REMOTE_IP> host: <HOSTNAME> reqinfo: <REQINFO>

o <Unique ID>
    Description: the unique ID assigned for each log entry.
o <time> (CLF or User Defined Format)
    Description: the time to occur the log entry.
o <elapsed time> (sec)
    Description: the time took for the request processing.
o <cpu usrtime> (sec)
    Description: cpu user time used for the request processing.
o <cpu systime> (sec)
    Description: cpu sys time used for the request processing.
o <PID>
    Description: the process ID of apache child process.
o <REMOTE_IP>
    Description: the request's remote ip address.
o <HOSTNAME>
    Description: the request's hostname.
o <REQINFO>
    Description: the request information string.
    Format: <METHOD> <PATH> <PROTOCOL>
    ex.  reqinfo: GET /wiki/index.html?foo=val1&bar=val2 HTTP/1.0

log example)
3f2b:4a40e871:0 [23/Jun/2009:23:36:33 +0900] elapsed: 0.15 cpu: 0.05(usr)/0.00(sys) pid: 16171 ip: 127.0.0.1 host: localhost:80 reqinfo: GET /wiki/index.html?foo=val1&bar=val2 HTTP/1.0


3) Apache Note Info and CustomLog Format

mod_log_slow adds 2 records below in apache request_rec's 'notes'
table when the request processing time is slow enough for the slow
logging to be make.

o Unique ID
    Description: the unique ID assigned for each log entry.
    Name: "logslow-id"
o Elapsed time
    Description: the time took for the request processing.
    Name: "logslow-time"

Therefore, you can add the unique ID and the elapsed time info to
the "CustomLog" by adding the %{logslow-id}n, %{logslow-time}n string
to log format string of CustomLog directive.

ex.
CustomLog logs/clicklog "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" \"%{logslow-id}n\" \"%{logslow-time}n\""


====================================================================
* Sample Configuration
====================================================================

1) load module
LoadModule log_slow_module modules/mod_log_slow.so

2) add directives below
LogSlowEnabled On
LogSlowLongRequestTime 100
LogSlowFileName  /path-to-log/slow_log
LogSlowTimeFormat "[%Y-%m-%d %H:%M:%S]"
LogSlowBufferedLogs On

see also: sample.conf


====================================================================
* Authors
====================================================================
Yoichi Kawasaki <yokawasa@gmail.com>