( check_dektec_in-1095 |#0): new 271 us user-latency.
( check_dektec_in-1095 |#0): new 275 us user-latency.
( check_dektec_in-1095 |#0): new 290 us user-latency.
( check_dektec_in-1095 |#0): new 297 us user-latency.
( check_dektec_in-1095 |#0): new 345 us user-latency.
( check_dektec_in-1095 |#0): new 358 us user-latency.
( check_dektec_in-1095 |#0): new 384 us user-latency.
( check_dektec_in-1095 |#0): new 392 us user-latency.
( check_dektec_in-1095 |#0): new 395 us user-latency.
( check_dektec_in-1095 |#0): new 396 us user-latency.
( check_dektec_in-1095 |#0): new 1031 us user-latency.
( check_dektec_in-1095 |#0): new 1100 us user-latency.
( check_dektec_in-1095 |#0): new 1105 us user-latency.
( check_dektec_in-1095 |#0): new 1106 us user-latency.
Here's the function trace for the 1106-µs latency:
http://linux.kernel.free.fr/latency/1106-us-trace.txt
These two lines repeat ~2000 times for ~800 µs:
softirq--4 0.... 272us : __lock_text_start (rt_run_flush)
softirq--4 0.... 272us : rt_spin_unlock (rt_run_flush)
With a pair of the following in the middle:
softirq--4 0.... 670us : call_rcu (rt_run_flush)
softirq--4 0D..1 670us : __rcu_advance_callbacks (call_rcu)