booluse_log;/* log transaction latencies to a file */

booluse_quiet;/* quiet logging onto stderr */

intagg_interval;/* log aggregates instead of individual transactions */

boolis_connect;/* establish connection for each transaction */

boolis_latencies;/* report per-command latencies */

intmain_pid;/* main process id used in log filename */

char*argv[MAX_ARGS];/* command word list */

}Command;

{

longstart_time;/* when does the interval start */

intcnt;/* number of transactions */

doublemin_duration;/* min/max durations */

doublemax_duration;

doublesum;/* sum(duration), sum(duration^2) - for estimates */

doublesum2;

}AggVals;

staticCommand**sql_files[MAX_FILES];/* SQL script files */

staticintnum_files;/* number of script files */

staticintnum_commands=0;/* total number of Command structs */

return false;/* always false */

}

voidagg_vals_init(AggVals*aggs,instr_timestart)

{

aggs->cnt=0;/* number of transactions */

aggs->sum=0;/* SUM(duration) */

aggs->sum2=0;/* SUM(duration*duration) */

aggs->min_duration=0;

aggs->max_duration=0;

aggs->start_time=INSTR_TIME_GET_DOUBLE(start);

}

doCustom(TState*thread,CState*st,instr_time*conn_time,FILE*logfile)

doCustom(TState*thread,CState*st,instr_time*conn_time,FILE*logfile,AggVals*agg)

{

PGresult*res;

Command**commands;

if (sample_rate==0.0||

pg_erand48(thread->random_state) <=sample_rate)

{

INSTR_TIME_SET_CURRENT(now);

diff=now;

INSTR_TIME_SUBTRACT(diff,st->txn_begin);

usec= (double)INSTR_TIME_GET_MICROSEC(diff);

if (agg_interval>0)

{

if (agg->start_time+agg_interval >=INSTR_TIME_GET_DOUBLE(now))

{

agg->cnt+=1;

agg->sum+=usec;

agg->sum2+=usec*usec;

if ((agg->cnt==1)|| (usec<agg->min_duration))

agg->min_duration=usec;

if ((agg->cnt==1)|| (usec>agg->max_duration))

agg->max_duration=usec;

}

{

while (agg->start_time+agg_interval<INSTR_TIME_GET_DOUBLE(now))

{

fprintf(logfile,"%ld %d %.0f %.0f %.0f %.0f\n",

agg->start_time,agg->cnt,agg->sum,agg->sum2,

agg->min_duration,agg->max_duration);

agg->start_time=agg->start_time+agg_interval;

agg->cnt=0;

agg->min_duration=0;

agg->max_duration=0;

agg->sum=0;

agg->sum2=0;

}

agg->cnt=1;

agg->min_duration=usec;

agg->max_duration=usec;

agg->sum=usec;

agg->sum2=usec*usec;

}

}

{

fprintf(logfile,"%d %d %.0f %d %ld %ld\n",

st->id,st->cnt,usec,st->use_file,

(long)now.tv_sec, (long)now.tv_usec);

fprintf(logfile,"%d %d %.0f %d %ld %ld\n",

st->id,st->cnt,usec,st->use_file,

(long)now.tv_sec, (long)now.tv_usec);

fprintf(logfile,"%d %d %.0f %d 0 0\n",

st->id,st->cnt,usec,st->use_file);

fprintf(logfile,"%d %d %.0f %d 0 0\n",

st->id,st->cnt,usec,st->use_file);

}

}

}

{"tablespace",required_argument,NULL,2},

{"unlogged-tables",no_argument,&unlogged_tables,1},

{"sampling-rate",required_argument,NULL,4},

{"aggregate-interval",required_argument,NULL,5},

{NULL,0,NULL,0}

};

exit(1);

}

break;

case5:

fprintf(stderr,"--aggregate-interval is not currently supported on Windows");

exit(1);

agg_interval=atoi(optarg);

if (agg_interval <=0)

{

fprintf(stderr,"invalid number of seconds for aggregation: %d\n",agg_interval);

exit(1);

}

break;

default:

fprintf(stderr,_("Try \"%s --help\" for more information.\n"),progname);

exit(1);

exit(1);

}

if (sample_rate>0.0&&agg_interval>0)

{

fprintf(stderr,"log sampling (--sampling-rate) and aggregation (--aggregate-interval) can't be used at the same time\n");

exit(1);

}

if (agg_interval>0&& (!use_log)) {

fprintf(stderr,"log aggregation is allowed only when actually logging transactions\n");

exit(1);

}

if ((duration>0)&& (agg_interval>duration)) {

fprintf(stderr,"number of seconds for aggregation (%d) must not be higher that test duration (%d)\n",agg_interval,duration);

exit(1);

}

if ((duration>0)&& (agg_interval>0)&& (duration %agg_interval!=0)) {

fprintf(stderr,"duration (%d) must be a multiple of aggregation interval (%d)\n",duration,agg_interval);

exit(1);

}

intremains=nstate;/* number of remaining clients */

inti;

AggValsaggs;

result=pg_malloc(sizeof(TResult));

INSTR_TIME_SET_ZERO(result->conn_time);

INSTR_TIME_SET_CURRENT(result->conn_time);

INSTR_TIME_SUBTRACT(result->conn_time,thread->start_time);

agg_vals_init(&aggs,thread->start_time);

for (i=0;i<nstate;i++)

{

intprev_ecnt=st->ecnt;

st->use_file=getrand(thread,0,num_files-1);

if (!doCustom(thread,st,&result->conn_time,logfile))

if (!doCustom(thread,st,&result->conn_time,logfile,&aggs))

remains--;/* I've aborted */

if (st->ecnt>prev_ecnt&&commands[st->state]->type==META_COMMAND)

if (st->con&& (FD_ISSET(PQsocket(st->con),&input_mask)

||commands[st->state]->type==META_COMMAND))

{

if (!doCustom(thread,st,&result->conn_time,logfile))

if (!doCustom(thread,st,&result->conn_time,logfile,&aggs))

remains--;/* I've aborted */

}

returnresult;

}

</listitem>

</varlistentry>

<varlistentry>

<term><option>--aggregate-interval</option> <replaceable>seconds</></term>

<listitem>

<para>

Length of aggregation interval (in seconds). May be used only together

with <application>-l</application> - with this option, the log contains

per-interval summary (number of transactions, min/max latency and two

additional fields useful for variance estimation).

</para>

<para>

This option is not currently supported on Windows.

</para>

</listitem>

</varlistentry>

<varlistentry>

<term><option>-M</option> <replaceable>querymode</></term>

<listitem>

<title>Per-Transaction Logging</title>

<para>

With the <option>-l</> option, <application>pgbench</> writes the time

taken by each transaction to a log file. The log file will be named

With the <option>-l</> option but without the <option>--aggregate-interval</option>,

<application>pgbench</> writes the time taken by each transaction

to a log file. The log file will be named

<filename>pgbench_log.<replaceable>nnn</></filename>, where

<replaceable>nnn</> is the PID of the pgbench process.

If the <option>-j</> option is 2 or higher, creating multiple worker

</para>

</refsect2>

<refsect2>

<title>Aggregated Logging</title>

<para>

With the <option>--aggregate-interval</option> option, the logs use a bit different format:

<synopsis>

<replaceable>interval_start</> <replaceable>num_of_transactions</> <replaceable>latency_sum</> <replaceable>latency_2_sum</> <replaceable>min_latency</> <replaceable>max_latency</>

</synopsis>

where <replaceable>interval_start</> is the start of the interval (UNIX epoch

format timestamp), <replaceable>num_of_transactions</> is the number of transactions

within the interval, <replaceable>latency_sum</replaceable> is a sum of latencies

(so you can compute average latency easily). The following two fields are useful

for variance estimation - <replaceable>latency_sum</> is a sum of latencies and

<replaceable>latency_2_sum</> is a sum of 2nd powers of latencies. The last two

fields are <replaceable>min_latency</> - a minimum latency within the interval, and

<replaceable>max_latency</> - maximum latency within the interval. A transaction is

counted into the interval when it was committed.

</para>

<para>

Here is example outputs:

<screen>

1345828501 5601 1542744 483552416 61 2573

1345828503 7884 1979812 565806736 60 1479

1345828505 7208 1979422 567277552 59 1391

1345828507 7685 1980268 569784714 60 1398

1345828509 7073 1979779 573489941 236 1411

</screen></para>

<para>

Notice that while the plain (unaggregated) log file contains index

of the custom script files, the aggregated log does not. Therefore if

you need per script data, you need to aggregate the data on your own.

</para>

</refsect2>

<refsect2>

<title>Per-Statement Latencies</title>