linux-kernel - Re: [Bug #12650] Strange load average and ksoftirqd behavior with 2.6.29-rc2-git1

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] [thread-next>] [day] [month] [year] [list]

Message-ID: <20090216093251.GK6182@elte.hu>
Date:	Mon, 16 Feb 2009 10:32:51 +0100
From:	Ingo Molnar <mingo@...e.hu>
To:	Damien Wyart <damien.wyart@...e.fr>
Cc:	Peter Zijlstra <a.p.zijlstra@...llo.nl>,
	Mike Galbraith <efault@....de>,
	Frédéric Weisbecker <fweisbec@...il.com>,
	"Rafael J. Wysocki" <rjw@...k.pl>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	Kernel Testers List <kernel-testers@...r.kernel.org>
Subject: Re: [Bug #12650] Strange load average and ksoftirqd behavior with
	2.6.29-rc2-git1


Ok, the ksoftirqd/1 stats contain a smoking gun:

ksoftirqd/1 (2280, #threads: 1)
---------------------------------------------------------
se.exec_start                      :        152642.614531
se.vruntime                        :         57051.648140
se.sum_exec_runtime                :          5741.506722
se.avg_overlap                     :             0.000000
se.avg_wakeup                      :            10.000000
se.wait_start                      :             0.000000
se.sleep_start                     :        152642.623948
se.block_start                     :             0.000000
se.sleep_max                       :         22662.455146
se.block_max                       :          4096.496408
se.exec_max                        :             0.016849
se.slice_max                       :             0.000000
se.wait_max                        :             0.053862
se.wait_sum                        :          7899.023463
se.wait_count                      :              4235574
sched_info.bkl_count               :                    0
se.nr_migrations                   :                    1
se.nr_migrations_cold              :                    0
se.nr_failed_migrations_affine     :                   32
se.nr_failed_migrations_running    :                   47
se.nr_failed_migrations_hot        :                   23
se.nr_forced_migrations            :                    0
se.nr_forced2_migrations           :                    5
se.nr_wakeups                      :              4235539
se.nr_wakeups_sync                 :                    0
se.nr_wakeups_migrate              :                   11
se.nr_wakeups_local                :              4235506
se.nr_wakeups_remote               :                   34
se.nr_wakeups_affine               :                    4
se.nr_wakeups_affine_attempts      :                   44
se.nr_wakeups_passive              :                    7
se.nr_wakeups_idle                 :                    0
avg_atom                           :             0.001355
avg_per_cpu                        :          5741.514564
nr_switches                        :              4235404
nr_voluntary_switches              :              4235389
nr_involuntary_switches            :                   18
se.load.weight                     :                 3121
policy                             :                    0
prio                               :                  115
clock-delta                        :                  295

these bits:

 se.sum_exec_runtime                :          5741.506722
 nr_switches                        :              4235404
 nr_voluntary_switches              :              4235389
 nr_involuntary_switches            :                   18

mean that ksoftirqd _really_ ran more than 4 million times since bootup 
- that is _highly_ anomalous. It means that scheduler clock is fine, and 
that your box is really running a lot of softirq workload.

Here is how it should look like normally. A 16-way testbox with almost 
an hour of uptime, running high load with a lot of networking. Its CPU#0 
ksoftirqd [the busiest one] has these stats:

 se.sum_exec_runtime                :             0.523552
 nr_switches                        :                   42
 nr_voluntary_switches              :                   42
 nr_involuntary_switches            :                    0

it ran only 42 times. That is a normal ksoftirqd pattern.

I'll check your traces as the next step.

	Ingo
--
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/