1PG_TEST_TIMING(1) PostgreSQL 9.2.24 Documentation PG_TEST_TIMING(1)
2
6 pg_test_timing - measure timing overhead
7
9 pg_test_timing [option...]
10
12 pg_test_timing is a tool to measure the timing overhead on your system
13 and confirm that the system time never moves backwards. Systems that
14 are slow to collect timing data can give less accurate EXPLAIN ANALYZE
15 results.
16
18 pg_test_timing accepts the following command-line options:
19 -d duration, --duration=duration
21 Specifies the test duration, in seconds. Longer durations give
22 slightly better accuracy, and are more likely to discover problems
23 with the system clock moving backwards. The default test duration
24 is 3 seconds.
25 -V, --version
27 Print the pg_test_timing version and exit.
28 -?, --help
30 Show help about pg_test_timing command line arguments, and exit.
31
33 Interpreting results
34 Good results will show most (>90%) individual timing calls take less
35 than one microsecond. Average per loop overhead will be even lower,
36 below 100 nanoseconds. This example from an Intel i7-860 system using a
37 TSC clock source shows excellent performance:
38 Testing timing overhead for 3 seconds.
40 Per loop time including overhead: 35.96 nsec
41 Histogram of timing durations:
42 < usec: count percent
43 16: 2 0.00000%
44 8: 13 0.00002%
45 4: 126 0.00015%
46 2: 2999652 3.59518%
47 1: 80435604 96.40465%
48 Note that different units are used for the per loop time than the
50 histogram. The loop can have resolution within a few nanoseconds
51 (nsec), while the individual timing calls can only resolve down to one
52 microsecond (usec).
53 Measuring executor timing overhead
55 When the query executor is running a statement using EXPLAIN ANALYZE,
56 individual operations are timed as well as showing a summary. The
57 overhead of your system can be checked by counting rows with the psql
58 program:
59 CREATE TABLE t AS SELECT * FROM generate_series(1,100000);
61 \timing
62 SELECT COUNT(*) FROM t;
63 EXPLAIN ANALYZE SELECT COUNT(*) FROM t;
64 The i7-860 system measured runs the count query in 9.8 ms while the
66 EXPLAIN ANALYZE version takes 16.6 ms, each processing just over
67 100,000 rows. That 6.8 ms difference means the timing overhead per row
68 is 68 ns, about twice what pg_test_timing estimated it would be. Even
69 that relatively small amount of overhead is making the fully timed
70 count statement take almost 70% longer. On more substantial queries,
71 the timing overhead would be less problematic.
72 Changing time sources
74 On some newer Linux systems, it's possible to change the clock source
75 used to collect timing data at any time. A second example shows the
76 slowdown possible from switching to the slower acpi_pm time source, on
77 the same system used for the fast results above:
78 # cat /sys/devices/system/clocksource/clocksource0/available_clocksource
80 tsc hpet acpi_pm
81 # echo acpi_pm > /sys/devices/system/clocksource/clocksource0/current_clocksource
82 # pg_test_timing
83 Per loop time including overhead: 722.92 nsec
84 Histogram of timing durations:
85 < usec: count percent
86 16: 3 0.00007%
87 8: 563 0.01357%
88 4: 3241 0.07810%
89 2: 2990371 72.05956%
90 1: 1155682 27.84870%
91 In this configuration, the sample EXPLAIN ANALYZE above takes 115.9 ms.
93 That's 1061 nsec of timing overhead, again a small multiple of what's
94 measured directly by this utility. That much timing overhead means the
95 actual query itself is only taking a tiny fraction of the accounted for
96 time, most of it is being consumed in overhead instead. In this
97 configuration, any EXPLAIN ANALYZE totals involving many timed
98 operations would be inflated significantly by timing overhead.
99 FreeBSD also allows changing the time source on the fly, and it logs
101 information about the timer selected during boot:
102 dmesg | grep "Timecounter"
104 sysctl kern.timecounter.hardware=TSC
105 Other systems may only allow setting the time source on boot. On older
107 Linux systems the "clock" kernel setting is the only way to make this
108 sort of change. And even on some more recent ones, the only option
109 you'll see for a clock source is "jiffies". Jiffies are the older Linux
110 software clock implementation, which can have good resolution when it's
111 backed by fast enough timing hardware, as in this example:
112 $ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
114 jiffies
115 $ dmesg | grep time.c
116 time.c: Using 3.579545 MHz WALL PM GTOD PIT/TSC timer.
117 time.c: Detected 2400.153 MHz processor.
118 $ pg_test_timing
119 Testing timing overhead for 3 seconds.
120 Per timing duration including loop overhead: 97.75 ns
121 Histogram of timing durations:
122 < usec: count percent
123 32: 1 0.00000%
124 16: 1 0.00000%
125 8: 22 0.00007%
126 4: 3010 0.00981%
127 2: 2993204 9.75277%
128 1: 27694571 90.23734%
129 Clock hardware and timing accuracy
131 Collecting accurate timing information is normally done on computers
132 using hardware clocks with various levels of accuracy. With some
133 hardware the operating systems can pass the system clock time almost
134 directly to programs. A system clock can also be derived from a chip
135 that simply provides timing interrupts, periodic ticks at some known
136 time interval. In either case, operating system kernels provide a clock
137 source that hides these details. But the accuracy of that clock source
138 and how quickly it can return results varies based on the underlying
139 hardware.
140 Inaccurate time keeping can result in system instability. Test any
142 change to the clock source very carefully. Operating system defaults
143 are sometimes made to favor reliability over best accuracy. And if you
144 are using a virtual machine, look into the recommended time sources
145 compatible with it. Virtual hardware faces additional difficulties when
146 emulating timers, and there are often per operating system settings
147 suggested by vendors.
148 The Time Stamp Counter (TSC) clock source is the most accurate one
150 available on current generation CPUs. It's the preferred way to track
151 the system time when it's supported by the operating system and the TSC
152 clock is reliable. There are several ways that TSC can fail to provide
153 an accurate timing source, making it unreliable. Older systems can have
154 a TSC clock that varies based on the CPU temperature, making it
155 unusable for timing. Trying to use TSC on some older multicore CPUs can
156 give a reported time that's inconsistent among multiple cores. This can
157 result in the time going backwards, a problem this program checks for.
158 And even the newest systems can fail to provide accurate TSC timing
159 with very aggressive power saving configurations.
160 Newer operating systems may check for the known TSC problems and switch
162 to a slower, more stable clock source when they are seen. If your
163 system supports TSC time but doesn't default to that, it may be
164 disabled for a good reason. And some operating systems may not detect
165 all the possible problems correctly, or will allow using TSC even in
166 situations where it's known to be inaccurate.
167 The High Precision Event Timer (HPET) is the preferred timer on systems
169 where it's available and TSC is not accurate. The timer chip itself is
170 programmable to allow up to 100 nanosecond resolution, but you may not
171 see that much accuracy in your system clock.
172 Advanced Configuration and Power Interface (ACPI) provides a Power
174 Management (PM) Timer, which Linux refers to as the acpi_pm. The clock
175 derived from acpi_pm will at best provide 300 nanosecond resolution.
176 Timers used on older PC hardware including the 8254 Programmable
178 Interval Timer (PIT), the real-time clock (RTC), the Advanced
179 Programmable Interrupt Controller (APIC) timer, and the Cyclone timer.
180 These timers aim for millisecond resolution.
181
183 Ants Aasma <ants.aasma@eesti.ee>
184
186 EXPLAIN(7)
187PostgreSQL 9.2.24 2017-11-06 PG_TEST_TIMING(1)