1. 15 Feb, 2011 1 commit
  2. 12 Feb, 2011 1 commit
    • Peter Zijlstra's avatar
      x86: Fix text_poke_smp_batch() deadlock · d91309f6
      Peter Zijlstra authored
      Fix this deadlock - we are already holding the mutex:
      
      =======================================================
      [ INFO: possible circular locking dependency detected ] 2.6.38-rc4-test+ #1
      -------------------------------------------------------
      bash/1850 is trying to acquire lock:
       (text_mutex){+.+.+.}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
      
      but task is already holding lock:
       (smp_alt){+.+...}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
      
      which lock already depends on the new lock.
      
      the existing dependency chain (in reverse order) is:
      
      -> #2 (smp_alt){+.+...}:
             [<ffffffff81082d02>] lock_acquire+0xcd/0xf8
             [<ffffffff8192e119>] __mutex_lock_common+0x4c/0x339
             [<ffffffff8192e4ca>] mutex_lock_nested+0x3e/0x43
             [<ffffffff8101050f>] alternatives_smp_switch+0x77/0x1d8
             [<ffffffff81926a6f>] do_boot_cpu+0xd7/0x762
             [<ffffffff819277dd>] native_cpu_up+0xe6/0x16a
             [<ffffffff81928e28>] _cpu_up+0x9d/0xee
             [<ffffffff81928f4c>] cpu_up+0xd3/0xe7
             [<ffffffff82268d4b>] kernel_init+0xe8/0x20a
             [<ffffffff8100ba24>] kernel_thread_helper+0x4/0x10
      
      -> #1 (cpu_hotplug.lock){+.+.+.}:
             [<ffffffff81082d02>] lock_acquire+0xcd/0xf8
             [<ffffffff8192e119>] __mutex_lock_common+0x4c/0x339
             [<ffffffff8192e4ca>] mutex_lock_nested+0x3e/0x43
             [<ffffffff810568cc>] get_online_cpus+0x41/0x55
             [<ffffffff810a1348>] stop_machine+0x1e/0x3e
             [<ffffffff819314c1>] text_poke_smp_batch+0x3a/0x3c
             [<ffffffff81932b6c>] arch_optimize_kprobes+0x10d/0x11c
             [<ffffffff81933a51>] kprobe_optimizer+0x152/0x222
             [<ffffffff8106bb71>] process_one_work+0x1d3/0x335
             [<ffffffff8106cfae>] worker_thread+0x104/0x1a4
             [<ffffffff810707c4>] kthread+0x9d/0xa5
             [<ffffffff8100ba24>] kernel_thread_helper+0x4/0x10
      
      -> #0 (text_mutex){+.+.+.}:
      
      other info that might help us debug this:
      
      6 locks held by bash/1850:
       #0:  (&buffer->mutex){+.+.+.}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
       #1:  (s_active#75){.+.+.+}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
       #2:  (x86_cpu_hotplug_driver_mutex){+.+.+.}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
       #3:  (cpu_add_remove_lock){+.+.+.}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
       #4:  (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
       #5:  (smp_alt){+.+...}, at: [<ffffffff8100a9c1>] return_to_handler+0x0/0x2f
      
      stack backtrace:
      Pid: 1850, comm: bash Not tainted 2.6.38-rc4-test+ #1
      Call Trace:
      
       [<ffffffff81080eb2>] print_circular_bug+0xa8/0xb7
       [<ffffffff8192e4ca>] mutex_lock_nested+0x3e/0x43
       [<ffffffff81010302>] alternatives_smp_unlock+0x3d/0x93
       [<ffffffff81010630>] alternatives_smp_switch+0x198/0x1d8
       [<ffffffff8102568a>] native_cpu_die+0x65/0x95
       [<ffffffff818cc4ec>] _cpu_down+0x13e/0x202
       [<ffffffff8117a619>] sysfs_write_file+0x108/0x144
       [<ffffffff8111f5a2>] vfs_write+0xac/0xff
       [<ffffffff8111f7a9>] sys_write+0x4a/0x6e
      Reported-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Tested-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: mathieu.desnoyers@efficios.com
      Cc: rusty@rustcorp.com.au
      Cc: ananth@in.ibm.com
      Cc: masami.hiramatsu.pt@hitachi.com
      Cc: fweisbec@gmail.com
      Cc: jbeulich@novell.com
      Cc: jbaron@redhat.com
      Cc: mhiramat@redhat.com
      LKML-Reference: <1297458466.5226.93.camel@laptop>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      d91309f6
  3. 10 Feb, 2011 2 commits
    • Arnaldo Carvalho de Melo's avatar
      perf tools: Fix thread_map event synthesizing in top and record · 401b8e13
      Arnaldo Carvalho de Melo authored
      Jeff Moyer reported these messages:
      
        Warning:  ... trying to fall back to cpu-clock-ticks
      
      couldn't open /proc/-1/status
      couldn't open /proc/-1/maps
      [ls output]
      [ perf record: Woken up 1 times to write data ]
      [ perf record: Captured and wrote 0.008 MB perf.data (~363 samples) ]
      
      That lead me and David Ahern to see that something was fishy on the thread
      synthesizing routines, at least for the case where the workload is started
      from 'perf record', as -1 is the default for target_tid in 'perf record --tid'
      parameter, so somehow we were trying to synthesize the PERF_RECORD_MMAP and
      PERF_RECORD_COMM events for the thread -1, a bug.
      
      So I investigated this and noticed that when we introduced support for
      recording a process and its threads using --pid some bugs were introduced and
      that the way to fix it was to instead of passing the target_tid to the event
      synthesizing routines we should better pass the thread_map that has the list of
      threads for a --pid or just the single thread for a --tid.
      
      Checked in the following ways:
      
      On a 8-way machine run cyclictest:
      
      [root@emilia ~]# perf record cyclictest -a -t -n -p99 -i100 -d50
      policy: fifo: loadavg: 0.00 0.13 0.31 2/139 28798
      
      T: 0 (28791) P:99 I:100 C:  25072 Min:      4 Act:    5 Avg:    6 Max:     122
      T: 1 (28792) P:98 I:150 C:  16715 Min:      4 Act:    6 Avg:    5 Max:      27
      T: 2 (28793) P:97 I:200 C:  12534 Min:      4 Act:    5 Avg:    4 Max:       8
      T: 3 (28794) P:96 I:250 C:  10028 Min:      4 Act:    5 Avg:    5 Max:      96
      T: 4 (28795) P:95 I:300 C:   8357 Min:      5 Act:    6 Avg:    5 Max:      12
      T: 5 (28796) P:94 I:350 C:   7163 Min:      5 Act:    6 Avg:    5 Max:      12
      T: 6 (28797) P:93 I:400 C:   6267 Min:      4 Act:    5 Avg:    5 Max:       9
      T: 7 (28798) P:92 I:450 C:   5571 Min:      4 Act:    5 Avg:    5 Max:       9
      ^C[ perf record: Woken up 1 times to write data ]
      [ perf record: Captured and wrote 0.108 MB perf.data (~4719 samples) ]
      
      [root@emilia ~]#
      
      This will create one extra thread per CPU:
      
      [root@emilia ~]# tuna -t cyclictest -CP
                            thread       ctxt_switches
          pid SCHED_ rtpri affinity voluntary nonvoluntary             cmd
       28825   OTHER     0     0xff      2169          671      cyclictest
        28832   FIFO    93        6     52338            1      cyclictest
        28833   FIFO    92        7     46524            1      cyclictest
        28826   FIFO    99        0    209360            1      cyclictest
        28827   FIFO    98        1    139577            1      cyclictest
        28828   FIFO    97        2    104686            0      cyclictest
        28829   FIFO    96        3     83751            1      cyclictest
        28830   FIFO    95        4     69794            1      cyclictest
        28831   FIFO    94        5     59825            1      cyclictest
      [root@emilia ~]#
      
      So we should expect only samples for the above 9 threads when using the
      --dump-raw-trace|-D perf report switch to look at the column with the tid:
      
      [root@emilia ~]# perf report -D | grep RECORD_SAMPLE | cut -d/ -f2 | cut -d: -f1 | sort | uniq -c
          629 28825
          110 28826
          491 28827
          308 28828
          198 28829
          621 28830
          225 28831
          203 28832
           89 28833
      [root@emilia ~]#
      
      So for workloads started by 'perf record' seems to work, now for existing workloads,
      just run cyclictest first, without 'perf record':
      
      [root@emilia ~]# tuna -t cyclictest -CP
                            thread       ctxt_switches
          pid SCHED_ rtpri affinity voluntary nonvoluntary             cmd
       28859   OTHER     0     0xff       594          200      cyclictest
        28864   FIFO    95        4     16587            1      cyclictest
        28865   FIFO    94        5     14219            1      cyclictest
        28866   FIFO    93        6     12443            0      cyclictest
        28867   FIFO    92        7     11062            1      cyclictest
        28860   FIFO    99        0     49779            1      cyclictest
        28861   FIFO    98        1     33190            1      cyclictest
        28862   FIFO    97        2     24895            1      cyclictest
        28863   FIFO    96        3     19918            1      cyclictest
      [root@emilia ~]#
      
      and then later did:
      
      [root@emilia ~]# perf record --pid 28859 sleep 3
      [ perf record: Woken up 1 times to write data ]
      [ perf record: Captured and wrote 0.027 MB perf.data (~1195 samples) ]
      [root@emilia ~]#
      
      To collect 3 seconds worth of samples for pid 28859 and its children:
      
      [root@emilia ~]# perf report -D | grep RECORD_SAMPLE | cut -d/ -f2 | cut -d: -f1 | sort | uniq -c
           15 28859
           33 28860
           19 28861
           13 28862
           13 28863
           10 28864
           11 28865
            9 28866
          255 28867
      [root@emilia ~]#
      
      Works, last thing is to check if looking at just one of those threads also works:
      
      [root@emilia ~]# perf record --tid 28866 sleep 3
      [ perf record: Woken up 1 times to write data ]
      [ perf record: Captured and wrote 0.006 MB perf.data (~242 samples) ]
      [root@emilia ~]# perf report -D | grep RECORD_SAMPLE | cut -d/ -f2 | cut -d: -f1 | sort | uniq -c
            3 28866
      [root@emilia ~]#
      
      Works too.
      Reported-by: default avatarJeff Moyer <jmoyer@redhat.com>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Ingo Molnar <mingo@elte.hu>
      Cc: Jeff Moyer <jmoyer@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Cc: Tom Zanussi <tzanussi@gmail.com>
      LKML-Reference: <new-submission>
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      401b8e13
    • Don Zickus's avatar
      watchdog, nmi: Lower the severity of error messages · 5651f7f4
      Don Zickus authored
      During boot if the hardlockup detector fails to initialize, it
      complains very loudly.  Some failures should be expected under
      certain situations, ie no lapics, or resource in-use.  Tone
      those error messages down a bit.  Keep the rest at a high level.
      Reported-by: default avatarPaul Bolle <pebolle@tiscali.nl>
      Tested-by: default avatarPaul Bolle <pebolle@tiscali.nl>
      Signed-off-by: default avatarDon Zickus <dzickus@redhat.com>
      Cc: Peter Zijlstra <peterz@infradead.org>
      LKML-Reference: <1297278153-21111-1-git-send-email-dzickus@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      5651f7f4
  4. 08 Feb, 2011 1 commit
  5. 07 Feb, 2011 28 commits
  6. 06 Feb, 2011 7 commits