受支持版本: 当前版本 (18) / 17 / 16 / 15 / 14
开发版本: 19 / devel
此文档适用于不受支持的 PostgreSQL 版本。
您可能需要查看当前版本的相同页面,或上面列出的其他受支持版本。

pg_test_timing

pg_test_timing — 测量计时开销

Synopsis

pg_test_timing [option...]

描述

pg_test_timing 是一个用于测量系统上的计时开销并确认 系统时间不会倒退的工具。它会在指定时长内以尽可能快的速度反复读取受支持的时钟源, 然后打印相邻时钟读数之间观测到的差异统计,以及将使用哪个时钟源。

更小(但不为零)的差异更好,因为这意味着时钟硬件更精确,收集一次时钟读数的开销 也更小。收集计时数据较慢的系统,可能会给出不够精确的 EXPLAIN ANALYZE结果。

该工具还有助于判断 track_io_timing 配置参数是否可能产生有用结果, 以及 TSC 时钟源(参见 timing_clock_source) 是否可用并会默认使用。

选项

pg_test_timing接受下列命令行选项:

-d duration
--duration=duration #

指定测试持续时间,以秒为单位。持续时间越长,精度会略有提高,也更可能发现 系统时钟倒退的问题。默认测试持续时间为 3 秒。

-c cutoff
--cutoff=cutoff #

指定精确观测计时持续时间列表的 cutoff 百分比(也就是系统时钟值从一次读数到下一次读数的变化)。 当累计百分比达到或超过该值时,列表就会结束,不过始终会打印观测到的最大持续时间。 默认 cutoff 为 99.99。

-V
--version #

打印pg_test_timing版本并退出。

-?
--help #

显示有关pg_test_timing命令行参数的帮助信息并退出。

用法

结果解读

第一块输出有四列,其中的各行展示了按位移一位的 log2(ns) 计时持续时间直方图 (也就是连续时钟读数之间的差值)。这不是传统的 log2(n+1) 直方图,因为它会 单独统计零值,然后从值 1 开始切换到 log2(ns)。

各列含义如下:

  • 大于等于该桶持续时间的纳秒值
  • 该桶内持续时间所占百分比
  • 该桶及之前各桶持续时间的累计百分比
  • 该桶内持续时间的计数

第二块输出会给出更详细的信息,显示观测到的精确计时差异。为简洁起见, 当累计百分比超过用户可选的 cutoff 值时,这个列表就会截断。不过,始终会显示 观测到的最大差异。

在支持 TSC 时钟源的平台上,还会显示额外的输出部分, 分别对应 RDTSCP 指令(用于一般计时需求,例如 track_io_timing)和 RDTSC 指令 (用于 EXPLAIN ANALYZE)。在输出末尾,还会显示 TSC 频率,它可能直接来自 CPU 信息,也可能来自替代校准机制, 以及 TSC 时钟源是否会默认使用。

下面的示例结果显示,系统时钟计时中有 99.99% 的循环耗时介于 16 到 63 纳秒之间。 在第二块中,可以看到典型循环时间为 40 纳秒,读数看起来具有完整的纳秒精度。 在系统时钟结果之后,以同样方式显示了 TSC 时钟源结果。 RDTSCP 指令显示大多数循环在 20-30 纳秒内完成,而 RDTSC 指令最快,平均循环时间为 20 纳秒。在这个示例中, TSC 时钟源会默认使用,但可以通过将 timing_clock_source 设为 system 来禁用。

System clock source: clock_gettime (CLOCK_MONOTONIC)
Testing timing overhead for 3 seconds.
Average loop time including overhead: 44.67 ns
Histogram of timing durations:
   <= ns   % of total  running %      count
       0       0.0000     0.0000          0
       1       0.0000     0.0000          0
       3       0.0000     0.0000          0
       7       0.0000     0.0000          0
      15       0.0000     0.0000          0
      31      24.0606    24.0606    5385707
      63      75.8342    99.8948   16974658
     127       0.0900    99.9848      20143
     255       0.0069    99.9917       1542
     511       0.0014    99.9932        322
    1023       0.0003    99.9935         68
    2047       0.0001    99.9936         23
    4095       0.0036    99.9972        813
    8191       0.0018    99.9990        402
   16383       0.0005    99.9995        120
   32767       0.0001    99.9997         32
   65535       0.0001    99.9998         24

Observed timing durations up to 99.9900%:
      ns   % of total  running %      count
      29       3.6921     3.6921     826442
      30      16.6755    20.3676    3732628
      31       3.6930    24.0606     826637
      40      75.7761    99.8368   16961658
      41       0.0019    99.8387        431
...
     190       0.0003    99.9901         65
...
29657159       0.0000   100.0000          1

Clock source: RDTSCP
Average loop time including overhead: 37.32 ns
Histogram of timing durations:
   <= ns   % of total  running %      count
       0       0.0000     0.0000          0
       1       0.0000     0.0000          0
       3       0.0000     0.0000          0
       7       0.0000     0.0000          0
      15       0.0000     0.0000          0
      31      99.9499    99.9499   26782299
      63       0.0381    99.9880      10220
     127       0.0008    99.9889        224
     255       0.0052    99.9941       1403
     511       0.0013    99.9954        340
    1023       0.0001    99.9954         17
    2047       0.0000    99.9955          7
    4095       0.0021    99.9976        569
    8191       0.0013    99.9989        357
   16383       0.0005    99.9994        128
   32767       0.0003    99.9996         70
   65535       0.0001    99.9997         19

Observed timing durations up to 99.9900%:
      ns   % of total  running %      count
      20      16.9064    16.9064    4530201
      29      41.5214    58.4279   11125972
      30      41.5220    99.9499   11126126
      40       0.0089    99.9587       2374
...
     130       0.0007    99.9902        181
...
18501572       0.0000   100.0000          1

Fast clock source: RDTSC
Average loop time including overhead: 27.12 ns
Histogram of timing durations:
   <= ns   % of total  running %      count
       0       0.0000     0.0000          0
       1       0.0000     0.0000          0
       3       0.0000     0.0000          0
       7       0.0000     0.0000          0
      15       1.2247     1.2247     456231
      31      98.7566    99.9813   36789785
      63       0.0109    99.9921       4049
     127       0.0029    99.9951       1087
     255       0.0008    99.9959        305
     511       0.0007    99.9966        279
    1023       0.0000    99.9966          7
    2047       0.0001    99.9967         22
    4095       0.0018    99.9985        673
    8191       0.0010    99.9995        383
   16383       0.0003    99.9998         94
   32767       0.0001    99.9999         38
   65535       0.0000    99.9999          9

Observed timing durations up to 99.9900%:
      ns   % of total  running %      count
       9       0.6316     0.6316     235290
      10       0.5931     1.2247     220941
      20      91.4328    92.6574   34061442
      29       3.6427    96.3001    1357007
      30       3.6811    99.9813    1371336
      40       0.0089    99.9902       3325
...
61594291       0.0000   100.0000          1

TSC frequency in use: 2449228 kHz
TSC frequency from calibration: 2448603 kHz
TSC clock source will be used by default, unless timing_clock_source is set to 'system'.