Home · Search · Print · Help 

This page describes console output format of Polygraph clients and servers. Individual errors, warnings, and other run-time messages are explained elsewhere.

1. Overview
2. Client side
    2.1 Run-time stats
    2.2 Error message format
3. Server side

1. Overview

Polygraph sends status and error messages to the console. Console output can be redirected into a file using the --console option. The amount of information is controlled using the --verb_lvl option.

Most messages that can go to the console (they may or may not be admitted based on the current verbosity level) are also logged into a binary log.

Request and reply dumps are not send to the console but are rather printed to the standard output stream. Errors that are not caught by polygraph are dumped to the standard error stream. Standard streams are also redirected, but are not logged.

Excessive printing to the console during a production test is a bad idea as it is likely to affect performance.

There are more console messages than is described on this page. Hopefully, most messages that are left out are self-explanatory. Please let us know if some message requires further documentation.

2. Client side

Below is a copy of client-side console output with some lines snipped. A letter-link on the left points to the description of the corresponding output section. Note that a high verbosity level is required to get all the output presented here.

		pail> ./polyclt --config /tmp/my-simple.pg --verb_lvl 5 ...
A		000.00| Command: ./polyclt --config /tmp/simple.pg ... 000.00| Configuration: version: 2.1.H host_type: i386-unknown-freebsd3.1 verb_lvl: 5 prn_reqs: off ... proxy: 10.0.1.253:3128 ports: <none> ign_false_hits: on prn_false_misses: off 000.00| Phases: phase load_beg load_end goal flags dflt 1.00 1.00 <none> 000.00| FDs: 12288 out of 12288 FDs can be used; safeguard limit: 11906 000.00| run-id: 01801f37.045eced8:00000004 pid: 52952 000.00| current time: Thu, 16 Sep 1999 22:04:52 GMT 000.00| waiting for traffic
B		000.01| agent `R101' starting on 10.0.0.1 000.09| i-dflt 23 4.52 196 0.00 0 1 000.17| i-dflt 48 5.00 199 0.00 0 1 000.25| i-dflt 73 5.00 199 0.00 0 1 000.34| i-dflt 98 5.00 198 0.00 0 1 000.42| i-dflt 125 5.40 185 0.00 0 1 ... 001.92| i-dflt 649 5.60 178 0.00 0 1 002.00| i-dflt 677 5.60 178 0.00 0 1 002.09| i-dflt 704 5.40 185 0.00 0 1 002.11| Connection.cc:183: error: 1/1 (60) Operation timed out 002.17| i-dflt 730 5.20 198 0.00 1 1 002.25| i-dflt 754 4.80 200 0.00 0 1
C		^Cgot shutdown signal (2) 002.26| noticed shutdown signal (2) 002.26| got 755 xactions and 1 errors 002.26| shutdown reason: got shutdown signal

Most lines are prefixed with a timestamp (minutes since experiment start). Note that polygraph may not update its internal clock before printing a line so timestamps are approximate.

Section A

Polyclt output starts with Section A. The first section includes the repeat of the command line used to start polygraph and the dump of all option values for the current run.

If an option is explicitly given on the command line, the command line value will usually be honored and preserved. Other options will have their default values. Note that some defaults depend on other options.

The configuration dump at the beginning of a run does not define Polygraph behavior completely because most workload specs are in the configuration file. Given the same configuration file and the same options, Polygraph will produce the same kind of traffic. Note, however, that the same traffic may produce different results depending on the past history (e.g., a proxy used up all free disk space at the end of the previous run). Also, system imposed limits may affect Polygraph behavior.

After the options dump, Polygraph reports execution schedule For each schedule phase, its name, load levels, ``goal'', and special flags are printed. In our case, we had a single and very simple default phase with constant (maximum) load level and no goal or flags.

After the phases schedule, Polygraph dumps some system limits:

• first 12288 FDs: Available number of FDs as reported by the setrlimit(RLIMIT_NOFILE) system call. Polygraph attempts to set current (soft) limit to maximum (hard) limit and then reports how many file descriptors OS allowed us to use.

• second 12288 FDs: Maximum number of FDs as reported by the getrlimit(RLIMIT_NOFILE) system call. If this value is higher than available number of FDs, then OS did not allow Polygraph to raise current (soft) limit hight enough.

• safeguard limit: Approximate number of FDs that Polygraph will allow itself to use. See the --fd_limit option for details.

At the bottom of Section A, Polygraph prints run id, process id, and current time. The run id is meant to be unique across all executions of Polygraph within a few years.

Section B

Section B represents run-time statistics. Run-time stats are usually printed in a table-like form. We describe the columns of that table in a separate section below.

Section B also contains an error message. The format for error messages is described below in a separate section.

Section C

Finally, Section C contains some statistics for the entire run. The output also includes the reason for run termination.

2.1 Run-time stats

(1)    (2) (3)    (4)    (5)    (6)    (7)  (8) (9)
000.09| i-dflt     23   4.52    196   0.00   0   1
000.17| i-dflt     48   5.00    199   0.00   0   1
000.25| i-dflt     73   5.00    199   0.00   0   1
000.34| i-dflt     98   5.00    198   0.00   0   1
000.42| i-dflt    125   5.40    185   0.00   0   1

Here is a brief explanation for each column of the run-time stats output.

1. Minutes since start
2. "i-" and "p-" stand for interval and phase-based stats
3. current phase name
4. number of replies received so far (across all phases)
5. reply rate (replies per second)
6. mean response time in milliseconds. For the client, the response time timer starts when the client starts establishing the connection (or starts sending the first request byte on a previously idle persistent connection); the timer stops when the last response byte is received. For the server, the response time timer starts when the connection is accepted (or the first request byte on a previously idle persistent connection is received); the timer stops when the last response byte is written. Thus, artificial server xact_think delays, if configured, are included in this measurement.
7. hit ratio in percents (client side);
   nothing interesting on the server side yet
8. number of transaction errors during that interval or phase
   (note: not all errors are transaction errors)
9. number of open sockets, including UDP and other housekeeping sockets if any;
   this number is usually close to the number of pending transactions;
   (interval stats only!)

2.2 Error message format

Individual errors, warnings, and other run-time messages are explained elsewhere.

Polygraph counts all errors it detects. However, Poly uses an exponential back-off algorithm when reporting errors on the console. Typically, only the following error occurrences will appear on a console: 1-st, 2-nd, 3-rd, 7-th, 15-th, ...

  (1)               (2)          (3/4) (5)            (6)
002.11| Connection.cc:183: error: 1/1 (s60) Operation timed out

An explanation for each column of a typical run-time error output follows.

1. Timestamp.
2. Source code location if available.
3. Number of errors of this type so far in this phase.
4. Total number of errors so far in this phase.
5. Error code. The codes starting with letter ``s'' are ``system'' error codes that correspond to the errno value on your machine. Error codes starting with letter ``c'' are custom errors detected by Polygraph rather than by OS (e.g., ``false hit'' or ``foreign reply'').
6. Short textual description of the error as produced by the OS (for system errors) or Polygraph (for other errors).

In some cases, Polygraph may decide to print more than one line per error to provide a longer, more detailed description.

N.B. To be honest, we faked the error message for the purpose of showing at least some errors. If we put some stats in the example out of sync, please let us know.

3. Server side

Server-side console output is pretty much the same as the client output described above. With the following exceptions:

• Hit ratios are not measured and hence, not reported on the server side. The i- and p- lines have -1.00 in the hit ratio field for now.

Home · Search · Print · Help