linux-kernel - Re: Pin-pointing the root of unusual application latencies

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <46A8BAC8.9000306@free.fr>
Date:	Thu, 26 Jul 2007 17:16:24 +0200
From:	John Sigler <linux.kernel@...e.fr>
To:	linux-rt-users@...r.kernel.org
CC:	Ingo Molnar <mingo@...e.hu>, linux-kernel@...r.kernel.org,
	linux-net@...r.kernel.org
Subject: Re: Pin-pointing the root of unusual application latencies

[ Adding linux-net to the mix ]

John Sigler wrote:

> ( 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)

Could someone explain why the kernel is "spinning" in rt_run_flush.
http://lxr.linux.no/source/net/ipv4/route.c#L692
What is the kernel trying to do?

Is the kernel in the following loop?

701         for (i = rt_hash_mask; i >= 0; i--) {
702                 spin_lock_bh(rt_hash_lock_addr(i));
703                 rth = rt_hash_table[i].chain;
704                 if (rth)
705                         rt_hash_table[i].chain = NULL;
706                 spin_unlock_bh(rt_hash_lock_addr(i));

Line 702 would be __lock_text_start (rt_run_flush)
Line 706 would be rt_spin_unlock
Is that correct?

And this would be done 2000 times because rt_hash_mask=2000?

Regards.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/