OLS 2007 - Real-Time Linux Latency Comparisons

Kernels and System Information

	2.6.16-ols1-LOADED	2.6.18-ols01-LOADED	2.6.18-rt7-ols02-LOADED	2.6.20-ols02-LOADED	2.6.20-rt8-ols02-LOADED
System Information	2.6.16-ols1-LOADED-config 2.6.16-ols1-LOADED-cpuinfo 2.6.16-ols1-LOADED-dmesg 2.6.16-ols1-LOADED-meminfo	2.6.18-ols01-LOADED-available_clocksource 2.6.18-ols01-LOADED-config 2.6.18-ols01-LOADED-cpuinfo 2.6.18-ols01-LOADED-current_clocksource 2.6.18-ols01-LOADED-dmesg 2.6.18-ols01-LOADED-meminfo	2.6.18-rt7-ols02-LOADED-available_clocksource 2.6.18-rt7-ols02-LOADED-config 2.6.18-rt7-ols02-LOADED-cpuinfo 2.6.18-rt7-ols02-LOADED-current_clocksource 2.6.18-rt7-ols02-LOADED-dmesg 2.6.18-rt7-ols02-LOADED-meminfo	2.6.20-ols02-LOADED-available_clocksource 2.6.20-ols02-LOADED-config 2.6.20-ols02-LOADED-cpuinfo 2.6.20-ols02-LOADED-current_clocksource 2.6.20-ols02-LOADED-dmesg 2.6.20-ols02-LOADED-meminfo	2.6.20-rt8-ols02-LOADED-available_clocksource 2.6.20-rt8-ols02-LOADED-config 2.6.20-rt8-ols02-LOADED-cpuinfo 2.6.20-rt8-ols02-LOADED-current_clocksource 2.6.20-rt8-ols02-LOADED-dmesg 2.6.20-rt8-ols02-LOADED-meminfo

Tests

The following selection of tests from the IBM real-time test package were run on the kernels listed above. While test results varied from run to run, I ran each test multiple times and presented the worst case scenario (which tended to be farily representative) with the exception of sched_latency where the first run almost invariably fails with a missed period.

gtod_latency

/*
 * Simple program to measure the time between several pairs of calls to 
 * gettimeofday().  If the average delta is greater than just a few 
 * microseconds on an unloaded system, then something is probably wrong.
 *
 * It is quite similar to the programs in the directory, but provides the
 * additional capability to produce graphical output as a histogram or a
 * scatter graph.
 */

	2.6.18-ols01-LOADED	2.6.18-rt7-ols02-LOADED
Test Logs	---------------------- Gettimeofday() Latency ---------------------- Iterations: 10000000 Minimum: 1 us Maximum: 208 us Average: 1.238646 us Standard Deviation: 0.479071us	---------------------- Gettimeofday() Latency ---------------------- Iterations: 10000000 Minimum: 1 us Maximum: 17 us Average: 1.223345 us Standard Deviation: 0.438119us
Scatter Plots
Histograms
Data Files	gtod_latency-2.6.18-ols01-LOADED-hist.dat gtod_latency-2.6.18-ols01-LOADED-hist.plt gtod_latency-2.6.18-ols01-LOADED-hist.plt.png gtod_latency-2.6.18-ols01-LOADED-samples.plt.png gtod_latency-2.6.18-ols01-LOADED-scatter.dat gtod_latency-2.6.18-ols01-LOADED-scatter.plt gtod_latency-2.6.18-ols01-LOADED.log	gtod_latency-2.6.18-rt7-ols02-LOADED-hist.dat gtod_latency-2.6.18-rt7-ols02-LOADED-hist.plt gtod_latency-2.6.18-rt7-ols02-LOADED-hist.plt.png gtod_latency-2.6.18-rt7-ols02-LOADED-samples.plt.png gtod_latency-2.6.18-rt7-ols02-LOADED-scatter.dat gtod_latency-2.6.18-rt7-ols02-LOADED-scatter.plt gtod_latency-2.6.18-rt7-ols02-LOADED.log

sched_latency

/*
 * Measure the latency involved with periodic scheduling.
 * Steps:
 * - A thread is created at a priority of 89.
 * - It periodically sleeps for a specified duration(PERIOD).
 * - The delay is measured as
 *
 *        delay = (now - start - i*PERIOD) converted to microseconds
 *
 * where, now = CLOCK_MONOTONIC gettime in ns, start = CLOCK_MONOTONIC gettime
 * at the start of the test, i = iteration number, PERIOD = the period chosen
 */

	2.6.16-ols1-LOADED	2.6.20-rt8-ols02-LOADED
Test Log	------------------------------- Scheduling Latency ------------------------------- Running 10000 iterations with a period of 5 ms Expected running time: 50 s jvmsim disabled Start Latency: 79 us: PASS Min Latency: 12 us: PASS Avg Latency: 1975 us: FAIL Max Latency: 4032 us: FAIL Standard Deviation: 1158.221813 Failed Iterations: 9748 Criteria: latencies < 100 us Result: FAIL	------------------------------- Scheduling Latency ------------------------------- Running 10000 iterations with a period of 5 ms Expected running time: 50 s jvmsim disabled Start Latency: 77 us: PASS Min Latency: 8 us: PASS Avg Latency: 13 us: PASS Max Latency: 24 us: PASS Standard Deviation: 2.865707 Failed Iterations: 0 Criteria: latencies < 100 us Result: PASS
Scatter Plots
Histograms
Data Files	sched_latency-2.6.16-ols1-LOADED-hist.dat sched_latency-2.6.16-ols1-LOADED-hist.plt sched_latency-2.6.16-ols1-LOADED-hist.plt.png sched_latency-2.6.16-ols1-LOADED-samples.dat sched_latency-2.6.16-ols1-LOADED-samples.plt sched_latency-2.6.16-ols1-LOADED-samples.plt.png sched_latency-2.6.16-ols1-LOADED.log	sched_latency-2.6.20-rt8-ols02-LOADED-hist.dat sched_latency-2.6.20-rt8-ols02-LOADED-hist.plt sched_latency-2.6.20-rt8-ols02-LOADED-hist.plt.png sched_latency-2.6.20-rt8-ols02-LOADED-samples.dat sched_latency-2.6.20-rt8-ols02-LOADED-samples.plt sched_latency-2.6.20-rt8-ols02-LOADED-samples.plt.png sched_latency-2.6.20-rt8-ols02-LOADED.log

async_handler

/*
 * Measure the latency involved with asynchronous event handlers. Specifically
 * it measures the latency of the pthread_cond_signal call until the signalled
 * thread is scheduled.
 */

	2.6.20-ols02-LOADED	2.6.20-rt8-ols02-LOADED
Test Log	----------------------------------- Asynchronous Event Handling Latency ----------------------------------- jvmsim disabled Running 5000 iterations recording statistics... handler thread exiting Minimum: 3 Maximum: 38 Average: 13.337000 Standard Deviation: 3.692564 signal thread exiting Criteria: latencies < 100 Result: PASS	----------------------------------- Asynchronous Event Handling Latency ----------------------------------- jvmsim disabled Running 5000 iterations recording statistics... handler thread exiting Minimum: 4 Maximum: 36 Average: 5.583800 Standard Deviation: 1.159904 signal thread exiting Criteria: latencies < 100 Result: PASS
Scatter Plots
Histograms
Data Files	async_handler-2.6.20-ols02-LOADED-hist.dat async_handler-2.6.20-ols02-LOADED-hist.plt async_handler-2.6.20-ols02-LOADED-hist.plt.png async_handler-2.6.20-ols02-LOADED-samples.dat async_handler-2.6.20-ols02-LOADED-samples.plt async_handler-2.6.20-ols02-LOADED-samples.plt.png async_handler-2.6.20-ols02-LOADED.log	async_handler-2.6.20-rt8-ols02-LOADED-hist.dat async_handler-2.6.20-rt8-ols02-LOADED-hist.plt async_handler-2.6.20-rt8-ols02-LOADED-hist.plt.png async_handler-2.6.20-rt8-ols02-LOADED-samples.dat async_handler-2.6.20-rt8-ols02-LOADED-samples.plt async_handler-2.6.20-rt8-ols02-LOADED-samples.plt.png async_handler-2.6.20-rt8-ols02-LOADED.log