timing.diff
text/x-diff
Filename: timing.diff
Type: text/x-diff
Part: 0
Patch
Same data as JSON:
GET /api/v1/attachments/:id/patch
the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes.
API reference →
Format: unified
| File | + | − |
|---|---|---|
| contrib/pg_test_timing/pg_test_timing.c | 0 | 0 |
| doc/src/sgml/pgtesttiming.sgml | 0 | 0 |
diff --git a/contrib/pg_test_timing/pg_test_timing.c b/contrib/pg_test_timing/pg_test_timing.c
new file mode 100644
index b3f98ab..8d79c7b
*** a/contrib/pg_test_timing/pg_test_timing.c
--- b/contrib/pg_test_timing/pg_test_timing.c
*************** static const char *progname;
*** 14,29 ****
static int32 test_duration = 3;
static void handle_args(int argc, char *argv[]);
! static void test_timing(int32);
int
main(int argc, char *argv[])
{
progname = get_progname(argv[0]);
handle_args(argc, argv);
! test_timing(test_duration);
return 0;
}
--- 14,37 ----
static int32 test_duration = 3;
static void handle_args(int argc, char *argv[]);
! static uint64 test_timing(int32);
! static void output(uint64 loop_count);
!
! /* record duration in powers of 2 microseconds */
! int64 histogram[32];
int
main(int argc, char *argv[])
{
+ uint64 loop_count;
+
progname = get_progname(argv[0]);
handle_args(argc, argv);
! loop_count = test_timing(test_duration);
!
! output(loop_count);
return 0;
}
*************** handle_args(int argc, char *argv[])
*** 95,119 ****
}
}
! static void
test_timing(int32 duration)
{
uint64 total_time;
int64 time_elapsed = 0;
uint64 loop_count = 0;
! uint64 prev,
! cur;
! int32 diff,
! i,
! bits,
! found;
!
! instr_time start_time,
! end_time,
! temp;
!
! static int64 histogram[32];
! char buf[100];
total_time = duration > 0 ? duration * 1000000 : 0;
--- 103,116 ----
}
}
! static uint64
test_timing(int32 duration)
{
uint64 total_time;
int64 time_elapsed = 0;
uint64 loop_count = 0;
! uint64 prev, cur;
! instr_time start_time, end_time, temp;
total_time = duration > 0 ? duration * 1000000 : 0;
*************** test_timing(int32 duration)
*** 122,132 ****
--- 119,132 ----
while (time_elapsed < total_time)
{
+ int32 diff, bits = 0;
+
prev = cur;
INSTR_TIME_SET_CURRENT(temp);
cur = INSTR_TIME_GET_MICROSEC(temp);
diff = cur - prev;
+ /* Did time go backwards? */
if (diff < 0)
{
printf("Detected clock going backwards in time.\n");
*************** test_timing(int32 duration)
*** 134,145 ****
exit(1);
}
! bits = 0;
while (diff)
{
diff >>= 1;
bits++;
}
histogram[bits]++;
loop_count++;
--- 134,147 ----
exit(1);
}
! /* What is the highest bit in the time diff? */
while (diff)
{
diff >>= 1;
bits++;
}
+
+ /* Update appropriate duration bucket */
histogram[bits]++;
loop_count++;
*************** test_timing(int32 duration)
*** 153,171 ****
printf("Per loop time including overhead: %0.2f nsec\n",
INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
printf("Histogram of timing durations:\n");
! printf("%9s: %10s %9s\n", "< usec", "count", "percent");
! found = 0;
! for (i = 31; i >= 0; i--)
{
! if (found || histogram[i])
! {
! found = 1;
! /* lame hack to work around INT64_FORMAT deficiencies */
! snprintf(buf, sizeof(buf), INT64_FORMAT, histogram[i]);
! printf("%9ld: %10s %8.5f%%\n", 1l << i, buf,
! (double) histogram[i] * 100 / loop_count);
! }
}
}
--- 155,183 ----
printf("Per loop time including overhead: %0.2f nsec\n",
INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
+
+ return loop_count;
+ }
+
+ static void
+ output(uint64 loop_count)
+ {
+ int64 max_bit = 31, i;
+
+ /* find highest bit value */
+ 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");
! for (i = 0; i <= max_bit; i++)
{
! char buf[100];
!
! /* lame hack to work around INT64_FORMAT deficiencies */
! snprintf(buf, sizeof(buf), INT64_FORMAT, histogram[i]);
! printf("%6ld %9.5f %10s\n", 1l << i,
! (double) histogram[i] * 100 / loop_count, buf);
}
}
diff --git a/doc/src/sgml/pgtesttiming.sgml b/doc/src/sgml/pgtesttiming.sgml
new file mode 100644
index f74d63e..45ee80c
*** a/doc/src/sgml/pgtesttiming.sgml
--- b/doc/src/sgml/pgtesttiming.sgml
***************
*** 98,109 ****
Testing timing overhead for 3 seconds.
Per loop time including overhead: 35.96 nsec
Histogram of timing durations:
! < usec: count percent
! 16: 2 0.00000%
! 8: 13 0.00002%
! 4: 126 0.00015%
! 2: 2999652 3.59518%
! 1: 80435604 96.40465%
</screen>
</para>
--- 98,109 ----
Testing timing overhead for 3 seconds.
Per loop time including overhead: 35.96 nsec
Histogram of timing durations:
! < usec % of total count
! 1 96.40465 80435604
! 2 3.59518 2999652
! 4 0.00015 126
! 8 0.00002 13
! 16 0.00000 2
</screen>
</para>
*************** tsc hpet acpi_pm
*** 159,170 ****
# pg_test_timing
Per loop time including overhead: 722.92 nsec
Histogram of timing durations:
! < usec: count percent
! 16: 3 0.00007%
! 8: 563 0.01357%
! 4: 3241 0.07810%
! 2: 2990371 72.05956%
! 1: 1155682 27.84870%
</screen>
</para>
--- 159,170 ----
# pg_test_timing
Per loop time including overhead: 722.92 nsec
Histogram of timing durations:
! < usec % of total count
! 1 27.84870 1155682
! 2 72.05956 2990371
! 4 0.07810 3241
! 8 0.01357 563
! 16 0.00007 3
</screen>
</para>
*************** $ pg_test_timing
*** 206,218 ****
Testing timing overhead for 3 seconds.
Per timing duration including loop overhead: 97.75 ns
Histogram of timing durations:
! < usec: count percent
! 32: 1 0.00000%
! 16: 1 0.00000%
! 8: 22 0.00007%
! 4: 3010 0.00981%
! 2: 2993204 9.75277%
! 1: 27694571 90.23734%
</screen></para>
</refsect2>
--- 206,218 ----
Testing timing overhead for 3 seconds.
Per timing duration including loop overhead: 97.75 ns
Histogram of timing durations:
! < usec % of total count
! 1 90.23734 27694571
! 2 9.75277 2993204
! 4 0.00981 3010
! 8 0.00007 22
! 16 0.00000 1
! 32 0.00000 1
</screen></para>
</refsect2>