mirror of https://lore.kernel.org/lkml/
 help / color / mirror / Atom feed
From: Eric Dumazet <eric.dumazet@gmail.com>
To: Martin Schwidefsky <schwidefsky@de.ibm.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>,
	Thomas Gleixner <tglx@linutronix.de>,
	John Stultz <johnstul@us.ibm.com>,
	Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
	Peter Zijlstra <a.p.zijlstra@chello.nl>,
	Ingo Molnar <mingo@elte.hu>,
	Arjan van de Ven <arjan@infradead.org>
Subject: Re: Linux 2.6.32-rc1
Date: Mon, 28 Sep 2009 20:41:41 +0200	[thread overview]
Message-ID: <4AC10365.7090802@gmail.com> (raw)
In-Reply-To: <20090928191506.40b61793@mschwide.boeblingen.de.ibm.com>

[-- Attachment #1: Type: text/plain, Size: 9045 bytes --]

Martin Schwidefsky a écrit :
> On Mon, 28 Sep 2009 08:39:31 -0700 (PDT)
> Linus Torvalds <torvalds@linux-foundation.org> wrote:
> 
>> On Mon, 28 Sep 2009, Eric Dumazet wrote:
>>> Linus Torvalds a écrit :
>>>> Go wild, test it out, and let us know about any regressions you find,
>>> Something seems wrong with process time accounting.
>>>
>>> Following program should consume 10*8 seconds of cpu on a 8 cpu machine, but
>>> with 2.6.32-rc1 numbers are crazy.
>> Ok, so the top-level process time looks sane _while_ the thing is running 
>> (sum of all threads), but the per-thread times look broken (as if they had 
>> randomly had the times of the other threads added into them - looks to me 
>> like they on average had half the other threads' time accounted into 
>> them).
>>
>> And then at the end, it looks like the time of the threads (which was 
>> over-accounted) get re-accounted back into the main process, so the final 
>> time is indeed wildly inflated.
>>
>> IOW, looks like we're adding thread times multiple times to other threads 
>> (and then finally to the parent).
>>
>> I'm adding the usual suspects to the cc, and leaving your results and 
>> test-program quoted here for them.. Thomas, Martin, John - if you're not 
>> the people I should blame for this, let me know.
> 
> Uh-oh.. usual suspects, eh?
> 
> For starters I run the test program on an s390 with
> VIRT_CPU_ACCOUNTING=y:
> 
> time ./burn-cpu 
>   PID TTY      STAT   TIME COMMAND 
>  2979 pts/0    -      0:08 ./burn-cpu
>     - -        Sl+    0:00 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>     - -        Rl+    0:01 -         
>   PID TTY      STAT   TIME COMMAND   
>  2979 pts/0    -      0:16 ./burn-cpu
>     - -        Sl+    0:00 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>     - -        Rl+    0:02 -         
>   PID TTY      STAT   TIME COMMAND   
>  2979 pts/0    -      0:25 ./burn-cpu
>     - -        Sl+    0:00 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>     - -        Rl+    0:03 -         
>   PID TTY      STAT   TIME COMMAND   
>  2979 pts/0    -      0:33 ./burn-cpu
>     - -        Sl+    0:00 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>     - -        Rl+    0:04 -         
>   PID TTY      STAT   TIME COMMAND   
>  2979 pts/0    -      0:41 ./burn-cpu
>     - -        Sl+    0:00 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>     - -        Rl+    0:05 -         
>   PID TTY      STAT   TIME COMMAND   
>  2979 pts/0    -      0:50 ./burn-cpu
>     - -        Sl+    0:00 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>     - -        Rl+    0:06 -
>   PID TTY      STAT   TIME COMMAND
>  2979 pts/0    -      0:58 ./burn-cpu
>     - -        Sl+    0:00 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>     - -        Rl+    0:07 -
>   PID TTY      STAT   TIME COMMAND
>  2979 pts/0    -      1:07 ./burn-cpu
>     - -        Sl+    0:00 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>     - -        Rl+    0:08 -
>   PID TTY      STAT   TIME COMMAND
>  2979 pts/0    -      1:15 ./burn-cpu
>     - -        Sl+    0:00 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>     - -        Rl+    0:09 -
>   PID TTY      STAT   TIME COMMAND
>  2979 pts/0    -      1:25 ./burn-cpu
>     - -        S+     1:25 -
> 
> real    0m10.708s
> user    1m25.051s
> sys     0m0.174s
> 
> looks better, gives an average of 10.63 seconds per thread and the per
> thread numbers are fine. I'll see what happens with the test case on my
> pc@home.
> 


I did a bisection and found commit def0a9b2573e00ab0b486cb5382625203ab4c4a6
was the origin of the problem on my x86_32 machine.

def0a9b2573e00ab0b486cb5382625203ab4c4a6 is first bad commit
commit def0a9b2573e00ab0b486cb5382625203ab4c4a6
Author: Peter Zijlstra <a.p.zijlstra@chello.nl>
Date:   Fri Sep 18 20:14:01 2009 +0200

    sched_clock: Make it NMI safe

    Arjan complained about the suckyness of TSC on modern machines, and
    asked if we could do something about that for PERF_SAMPLE_TIME.

    Make cpu_clock() NMI safe by removing the spinlock and using
    cmpxchg. This also makes it smaller and more robust.

    Affects architectures that use HAVE_UNSTABLE_SCHED_CLOCK, i.e. IA64
    and x86.

    Signed-off-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
    LKML-Reference: <new-submission>
    Signed-off-by: Ingo Molnar <mingo@elte.hu>

git bisect start
# bad: [17d857be649a21ca90008c6dc425d849fa83db5c] Linux 2.6.32-rc1
git bisect bad 17d857be649a21ca90008c6dc425d849fa83db5c
# good: [74fca6a42863ffacaf7ba6f1936a9f228950f657] Linux 2.6.31
git bisect good 74fca6a42863ffacaf7ba6f1936a9f228950f657
# good: [74fca6a42863ffacaf7ba6f1936a9f228950f657] Linux 2.6.31
git bisect good 74fca6a42863ffacaf7ba6f1936a9f228950f657
# good: [5d1fe0c98f2aef99fb57aaf6dd25e793c186cea3] Staging: vt6656: Integrate vt6656 into build system.
git bisect good 5d1fe0c98f2aef99fb57aaf6dd25e793c186cea3
# good: [5d1fe0c98f2aef99fb57aaf6dd25e793c186cea3] Staging: vt6656: Integrate vt6656 into build system.
git bisect good 5d1fe0c98f2aef99fb57aaf6dd25e793c186cea3
# bad: [c720f5655df159a630fa0290a0bd67c93e92b0bf] Merge branch 'for_linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-2.6
git bisect bad c720f5655df159a630fa0290a0bd67c93e92b0bf
# good: [a03fdb7612874834d6847107198712d18b5242c7] Merge branch 'timers-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect good a03fdb7612874834d6847107198712d18b5242c7
# good: [3530c1886291df061e3972c55590777ef1cb67f8] Merge branch 'for_linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tytso/ext4
git bisect good 3530c1886291df061e3972c55590777ef1cb67f8
# good: [84d6ae431f315e8973aac3c3fe1d550fc9240ef3] V4L/DVB (13033): pt1: Don't use a deprecated DMA_BIT_MASK macro
git bisect good 84d6ae431f315e8973aac3c3fe1d550fc9240ef3
# bad: [ebc79c4f8da0f92efa968e0328f32334a2ce80cf] Merge git://git.kernel.org/pub/scm/linux/kernel/git/jaswinder/linux-2.6
git bisect bad ebc79c4f8da0f92efa968e0328f32334a2ce80cf
# good: [7bd032dc2793afcbaf4a350056768da84cdbd89b] USB serial: update the console driver
git bisect good 7bd032dc2793afcbaf4a350056768da84cdbd89b
# good: [1281a49b7aa865a1f0d60e2b28410e6234fc686b] perf trace: Sample timestamp and cpu when using record flag
git bisect good 1281a49b7aa865a1f0d60e2b28410e6234fc686b
# bad: [e11c675ede0d42a405ae595528bf0b29ce1ae56f] Merge git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty-2.6
git bisect bad e11c675ede0d42a405ae595528bf0b29ce1ae56f
# bad: [6161352142d5fed4cd753b32e5ccde66e705b14e] tracing, perf: Convert the power tracer into an event tracer
git bisect bad 6161352142d5fed4cd753b32e5ccde66e705b14e
# bad: [929bf0d0156562ce631728b6fa53d68004d456d2] Merge branch 'linus' into perfcounters/core
git bisect bad 929bf0d0156562ce631728b6fa53d68004d456d2
# good: [5622f295b53fb60dbf9bed3e2c89d182490a8b7f] x86, perf_counter, bts: Optimize BTS overflow handling
git bisect good 5622f295b53fb60dbf9bed3e2c89d182490a8b7f
# bad: [def0a9b2573e00ab0b486cb5382625203ab4c4a6] sched_clock: Make it NMI safe
git bisect bad def0a9b2573e00ab0b486cb5382625203ab4c4a6


My .config file is attached to this mail


[-- Attachment #2: .config --]
[-- Type: application/xml, Size: 58848 bytes --]

  reply	other threads:[~2009-09-28 18:42 UTC|newest]

Thread overview: 80+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2009-09-27 22:34 Linus Torvalds
2009-09-27 23:44 ` Stephen Rothwell
2009-09-27 23:48   ` Diego Calleja
2009-09-27 23:52   ` Linus Torvalds
2009-09-28  0:17     ` Stephen Rothwell
2009-09-28  7:07 ` Eric Dumazet
2009-09-28 15:39   ` Linus Torvalds
2009-09-28 17:15     ` Martin Schwidefsky
2009-09-28 18:41       ` Eric Dumazet [this message]
2009-09-28 20:56         ` Martin Schwidefsky
2009-09-29 20:42         ` Eric Dumazet
2009-09-29 21:17           ` Linus Torvalds
2009-09-29 21:22             ` Arjan van de Ven
2009-09-29 21:56               ` Linus Torvalds
2009-09-30 15:07                 ` Arjan van de Ven
2009-09-30 15:27                   ` Eric Dumazet
2009-09-30 15:31                     ` Arjan van de Ven
2009-10-01  0:42                       ` Yuhong Bao
2009-09-30 15:57                   ` Eric Dumazet
2009-09-30 16:13                     ` Arjan van de Ven
2009-09-30 16:14                     ` Linus Torvalds
2009-09-30 18:53                       ` Ingo Molnar
2009-09-30 22:03                         ` [GIT PULL] scheduler fixes Ingo Molnar
2009-10-01  0:42                           ` Linus Torvalds
2009-10-01  0:57                             ` Linus Torvalds
2009-10-01  5:30                               ` Eric Dumazet
2009-10-01  6:11                                 ` Ingo Molnar
2009-10-01  6:18                                   ` Eric Dumazet
2009-10-01  6:42                                     ` Ingo Molnar
2009-10-01  6:59                                       ` Eric Dumazet
2009-10-01  7:28                                       ` Sam Ravnborg
2009-10-01  6:49                                 ` [tip:x86/urgent] x86: Don't generate cmpxchg8b_emu if CONFIG_X86_CMPXCHG64=y tip-bot for Eric Dumazet
2009-10-01  6:40                               ` [tip:x86/urgent] x86: Optimize cmpxchg64() at build-time some more tip-bot for Linus Torvalds
2009-10-02 16:40                               ` [GIT PULL] scheduler fixes Yuhong Bao
2009-10-01  6:05                             ` Ingo Molnar
2009-09-30 16:14                     ` Linux 2.6.32-rc1 Cyrill Gorcunov
2009-09-30 16:55                   ` Stefan Richter
2009-09-30 17:08                     ` Linus Torvalds
2009-09-30 17:40                       ` Stefan Richter
2009-09-30 19:32                   ` Ingo Molnar
2009-09-30 19:35                     ` Ingo Molnar
2009-09-30 20:16                     ` Eric Dumazet
2009-09-30 20:20                       ` Linus Torvalds
2009-09-30 20:22                         ` Ingo Molnar
2009-09-30 20:38                           ` Ingo Molnar
2009-10-01  7:18                             ` Arjan van de Ven
2009-09-30 19:37                   ` [tip:sched/urgent] x86: Provide an alternative() based cmpxchg64() tip-bot for Arjan van de Ven
2009-09-30 19:37                   ` [tip:sched/urgent] sched_clock: Fix atomicity/continuity bug by using cmpxchg64() tip-bot for Arjan van de Ven
2009-09-30 19:39                     ` Ingo Molnar
2009-09-30 19:39                   ` tip-bot for Eric Dumazet
2009-09-30 20:19                   ` Linux 2.6.32-rc1 Linus Torvalds
2009-09-30 20:24                     ` Eric Dumazet
2009-09-30 20:41                       ` Linus Torvalds
2009-09-30 20:49                         ` Ingo Molnar
2009-09-30 20:53                           ` Eric Dumazet
2009-09-30 21:00                             ` Ingo Molnar
2009-09-30 20:54                         ` Linus Torvalds
2009-09-30 21:53                         ` David Miller
2009-10-01 12:48                         ` Christoph Hellwig
2009-10-01 16:08                           ` Valdis.Kletnieks
2009-10-05 14:39                             ` Peter Zijlstra
2009-09-30 20:40                   ` [tip:sched/urgent] x86: Provide an alternative() based cmpxchg64() tip-bot for Arjan van de Ven
2009-09-30 20:58                     ` Ingo Molnar
2009-09-30 20:40                   ` [tip:sched/urgent] sched_clock: Fix atomicity/continuity bug by using cmpxchg64() tip-bot for Eric Dumazet
2009-09-30 20:55                   ` [tip:sched/urgent] x86: Provide an alternative() based cmpxchg64() tip-bot for Arjan van de Ven
2009-09-30 20:55                   ` [tip:sched/urgent] sched_clock: Fix atomicity/continuity bug by using cmpxchg64() tip-bot for Eric Dumazet
2009-09-30 21:00                   ` [tip:sched/urgent] x86: Provide an alternative() based cmpxchg64() tip-bot for Arjan van de Ven
2009-09-30 21:01                   ` [tip:sched/urgent] sched_clock: Fix atomicity/continuity bug by using cmpxchg64() tip-bot for Eric Dumazet
2009-10-05 16:00             ` [PATCH] x86: Generate cmpxchg build failures Peter Zijlstra
2009-10-05 18:51               ` Maciej Żenczykowski
2009-10-05 19:16               ` Linus Torvalds
2009-10-05 19:33                 ` Peter Zijlstra
2009-10-05 20:54                   ` Linus Torvalds
2009-10-09 14:23                   ` [tip:x86/asm] " tip-bot for Peter Zijlstra
2009-09-28 14:34 ` Linux 2.6.32-rc1 compile error Wolfgang Erig
2009-09-28 15:10   ` Jaswinder Singh Rajput
2009-09-28 15:32     ` Wolfgang Erig
2009-09-28 16:25 ` [PATCH] isdn: fix netjet/isdnhdlc build errors Randy Dunlap
2009-09-28 19:47   ` David Miller
2009-09-28 22:10 Linux 2.6.32-rc1 devzero

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=4AC10365.7090802@gmail.com \
    --to=eric.dumazet@gmail.com \
    --cc=a.p.zijlstra@chello.nl \
    --cc=arjan@infradead.org \
    --cc=johnstul@us.ibm.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@elte.hu \
    --cc=schwidefsky@de.ibm.com \
    --cc=tglx@linutronix.de \
    --cc=torvalds@linux-foundation.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox

Powered by JetHome