<screen>

Testing timing overhead for 3 seconds.

Per loop time including overhead: 35.96nsec

Per loop time including overhead: 35.96ns

Histogram of timing durations:

< usec % of total count

< us % of total count

1 96.40465 80435604

2 3.59518 2999652

4 0.00015 126

<para>

Note that different units are used for the per loop time than the

histogram. The loop can have resolution within a few nanoseconds (nsec),

histogram. The loop can have resolution within a few nanoseconds (ns),

while the individual timing calls can only resolve down to one microsecond

(usec).

(us).

</para>

</refsect2>

tsc hpet acpi_pm

# echo acpi_pm > /sys/devices/system/clocksource/clocksource0/current_clocksource

# pg_test_timing

Per loop time including overhead: 722.92nsec

Per loop time including overhead: 722.92ns

Histogram of timing durations:

< usec % of total count

< us % of total count

1 27.84870 1155682

2 72.05956 2990371

4 0.07810 3241

<para>

In this configuration, the sample <command>EXPLAIN ANALYZE</command> above

takes 115.9 ms. That's 1061nsec of timing overhead, again a small multiple

takes 115.9 ms. That's 1061ns of timing overhead, again a small multiple

of what's measured directly by this utility. That much timing overhead

means the actual query itself is only taking a tiny fraction of the

accounted for time, most of it is being consumed in overhead instead. In

Testing timing overhead for 3 seconds.

Per timing duration including loop overhead: 97.75 ns

Histogram of timing durations:

< usec % of total count

< us % of total count

1 90.23734 27694571

2 9.75277 2993204

4 0.00981 3010

CATALOG_NAME = pg_test_timing

AVAIL_LANGUAGES =

GETTEXT_FILES = pg_test_timing.c

{

uint64loop_count;

set_pglocale_pgservice(argv[0],PG_TEXTDOMAIN("pg_test_timing"));

progname=get_progname(argv[0]);

handle_args(argc,argv);

{

if (strcmp(argv[1],"--help")==0||strcmp(argv[1],"-?")==0)

{

printf("Usage: %s [-d DURATION]\n",progname);

printf(_("Usage: %s [-d DURATION]\n"),progname);

exit(0);

}

if (strcmp(argv[1],"--version")==0||strcmp(argv[1],"-V")==0)

break;

default:

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

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

progname);

exit(1);

break;

if (argc>optind)

{

fprintf(stderr,

"%s: too many command-line arguments (first is \"%s\")\n",

_("%s: too many command-line arguments (first is \"%s\")\n"),

progname,argv[optind]);

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

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

progname);

exit(1);

}

if (test_duration>0)

{

printf("Testing timing overhead for %d seconds.\n",test_duration);

printf(ngettext("Testing timing overhead for %d second.\n",

"Testing timing overhead for %d seconds.\n",

test_duration),

test_duration);

}

{

fprintf(stderr,

"%s: duration must be a positive integer (duration is \"%d\")\n",

_("%s: duration must be a positive integer (duration is \"%d\")\n"),

progname,test_duration);

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

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

progname);

exit(1);

}

if (diff<0)

{

printf("Detected clock going backwards in time.\n");

printf("Time warp: %dmicroseconds\n",diff);

fprintf(stderr,_("Detected clock going backwards in time.\n"));

fprintf(stderr,_("Time warp: %dms\n"),diff);

exit(1);

}

INSTR_TIME_SUBTRACT(end_time,start_time);

printf("Per loop time including overhead: %0.2fnsec\n",

printf(_("Per loop time including overhead: %0.2fns\n"),

INSTR_TIME_GET_DOUBLE(end_time)*1e9 /loop_count);

returnloop_count;

while (max_bit>0&&histogram[max_bit]==0)

max_bit--;

printf("Histogram of timing durations:\n");

printf("%6s %10s %10s\n","<usec","% of total","count");

printf(_("Histogram of timing durations:\n"));

printf("%6s %10s %10s\n",_("<us"),_("% of total"),_("count"));

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

{