All the mail mirrored from lore.kernel.org
 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 Linux 2.6.32-rc1 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
  -- strict thread matches above, loose matches on Subject: below --
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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.