Skip to content
Snippets Groups Projects
  1. May 23, 2008
    • Steven Rostedt's avatar
      ftrace: trace irq disabled critical timings · 81d68a96
      Steven Rostedt authored
      
      This patch adds latency tracing for critical timings
      (how long interrupts are disabled for).
      
       "irqsoff" is added to /debugfs/tracing/available_tracers
      
      Note:
        tracing_max_latency
          also holds the max latency for irqsoff (in usecs).
         (default to large number so one must start latency tracing)
      
        tracing_thresh
          threshold (in usecs) to always print out if irqs off
          is detected to be longer than stated here.
          If irq_thresh is non-zero, then max_irq_latency
          is ignored.
      
      Here's an example of a trace with ftrace_enabled = 0
      
      =======
      preemption latency trace v1.1.5 on 2.6.24-rc7
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      --------------------------------------------------------------------
       latency: 100 us, #3/3, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
          -----------------
          | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
          -----------------
       => started at: _spin_lock_irqsave+0x2a/0xb7
       => ended at:   _spin_unlock_irqrestore+0x32/0x5f
      
                       _------=> CPU#
                      / _-----=> irqs-off
                     | / _----=> need-resched
                     || / _---=> hardirq/softirq
                     ||| / _--=> preempt-depth
                     |||| /
                     |||||     delay
         cmd     pid ||||| time  |   caller
            \   /    |||||   \   |   /
       swapper-0     1d.s3    0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
       swapper-0     1d.s3  100us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1d.s3  100us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
      
      vim:ft=help
      =======
      
      And this is a trace with ftrace_enabled == 1
      
      =======
      preemption latency trace v1.1.5 on 2.6.24-rc7
      --------------------------------------------------------------------
       latency: 102 us, #12/12, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
          -----------------
          | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
          -----------------
       => started at: _spin_lock_irqsave+0x2a/0xb7
       => ended at:   _spin_unlock_irqrestore+0x32/0x5f
      
                       _------=> CPU#
                      / _-----=> irqs-off
                     | / _----=> need-resched
                     || / _---=> hardirq/softirq
                     ||| / _--=> preempt-depth
                     |||| /
                     |||||     delay
         cmd     pid ||||| time  |   caller
            \   /    |||||   \   |   /
       swapper-0     1dNs3    0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
       swapper-0     1dNs3   46us : e1000_read_phy_reg+0x16/0x225 [e1000] (e1000_update_stats+0x5e2/0x64c [e1000])
       swapper-0     1dNs3   46us : e1000_swfw_sync_acquire+0x10/0x99 [e1000] (e1000_read_phy_reg+0x49/0x225 [e1000])
       swapper-0     1dNs3   46us : e1000_get_hw_eeprom_semaphore+0x12/0xa6 [e1000] (e1000_swfw_sync_acquire+0x36/0x99 [e1000])
       swapper-0     1dNs3   47us : __const_udelay+0x9/0x47 (e1000_read_phy_reg+0x116/0x225 [e1000])
       swapper-0     1dNs3   47us+: __delay+0x9/0x50 (__const_udelay+0x45/0x47)
       swapper-0     1dNs3   97us : preempt_schedule+0xc/0x84 (__delay+0x4e/0x50)
       swapper-0     1dNs3   98us : e1000_swfw_sync_release+0xc/0x55 [e1000] (e1000_read_phy_reg+0x211/0x225 [e1000])
       swapper-0     1dNs3   99us+: e1000_put_hw_eeprom_semaphore+0x9/0x35 [e1000] (e1000_swfw_sync_release+0x50/0x55 [e1000])
       swapper-0     1dNs3  101us : _spin_unlock_irqrestore+0xe/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1dNs3  102us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
       swapper-0     1dNs3  102us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
      
      vim:ft=help
      =======
      
      Signed-off-by: default avatarSteven Rostedt <srostedt@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarThomas Gleixner <tglx@linutronix.de>
      81d68a96
  2. Feb 25, 2008
  3. Jan 25, 2008
    • Ingo Molnar's avatar
      softlockup: automatically detect hung TASK_UNINTERRUPTIBLE tasks · 82a1fcb9
      Ingo Molnar authored
      
      this patch extends the soft-lockup detector to automatically
      detect hung TASK_UNINTERRUPTIBLE tasks. Such hung tasks are
      printed the following way:
      
       ------------------>
       INFO: task prctl:3042 blocked for more than 120 seconds.
       "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message
       prctl         D fd5e3793     0  3042   2997
              f6050f38 00000046 00000001 fd5e3793 00000009 c06d8264 c06dae80 00000286
              f6050f40 f6050f00 f7d34d90 f7d34fc8 c1e1be80 00000001 f6050000 00000000
              f7e92d00 00000286 f6050f18 c0489d1a f6050f40 00006605 00000000 c0133a5b
       Call Trace:
        [<c04883a5>] schedule_timeout+0x6d/0x8b
        [<c04883d8>] schedule_timeout_uninterruptible+0x15/0x17
        [<c0133a76>] msleep+0x10/0x16
        [<c0138974>] sys_prctl+0x30/0x1e2
        [<c0104c52>] sysenter_past_esp+0x5f/0xa5
        =======================
       2 locks held by prctl/3042:
       #0:  (&sb->s_type->i_mutex_key#5){--..}, at: [<c0197d11>] do_fsync+0x38/0x7a
       #1:  (jbd_handle){--..}, at: [<c01ca3d2>] journal_start+0xc7/0xe9
       <------------------
      
      the current default timeout is 120 seconds. Such messages are printed
      up to 10 times per bootup. If the system has crashed already then the
      messages are not printed.
      
      if lockdep is enabled then all held locks are printed as well.
      
      this feature is a natural extension to the softlockup-detector (kernel
      locked up without scheduling) and to the NMI watchdog (kernel locked up
      with IRQs disabled).
      
      [ Gautham R Shenoy <ego@in.ibm.com>: CPU hotplug fixes. ]
      [ Andrew Morton <akpm@linux-foundation.org>: build warning fix. ]
      
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarArjan van de Ven <arjan@linux.intel.com>
      82a1fcb9
  4. Jan 24, 2008
  5. Jan 16, 2008
  6. Dec 07, 2007
  7. Dec 05, 2007
    • Oleg Nesterov's avatar
      lockdep: in_range() fix · 54561783
      Oleg Nesterov authored
      
      Torsten Kaiser wrote:
      
      | static inline int in_range(const void *start, const void *addr, const void *end)
      | {
      |         return addr >= start && addr <= end;
      | }
      | This  will return true, if addr is in the range of start (including)
      | to end (including).
      |
      | But debug_check_no_locks_freed() seems does:
      | const void *mem_to = mem_from + mem_len
      | -> mem_to is the last byte of the freed range, that fits in_range
      | lock_from = (void *)hlock->instance;
      | -> first byte of the lock
      | lock_to = (void *)(hlock->instance + 1);
      | -> first byte of the next lock, not last byte of the lock that is being checked!
      |
      | The test is:
      | if (!in_range(mem_from, lock_from, mem_to) &&
      |                                         !in_range(mem_from, lock_to, mem_to))
      |                         continue;
      | So it tests, if the first byte of the lock is in the range that is freed ->OK
      | And if the first byte of the *next* lock is in the range that is freed
      | -> Not OK.
      
      We can also simplify in_range checks, we need only 2 comparisons, not 4.
      If the lock is not in memory range, it should be either at the left of range
      or at the right.
      
      Signed-off-by: default avatarOleg Nesterov <oleg@tv-sign.ru>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      54561783
    • Ingo Molnar's avatar
      lockdep: fix debug_show_all_locks() · 85684873
      Ingo Molnar authored
      fix the oops that can be seen in:
      
         http://bugzilla.kernel.org/attachment.cgi?id=13828&action=view
      
      
      
      it is not safe to print the locks of running tasks.
      
      (even with this fix we have a small race - but this is a debug
       function after all.)
      
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      85684873
  8. Oct 28, 2007
  9. Oct 19, 2007
  10. Oct 11, 2007
  11. Jul 19, 2007
    • Johannes Berg's avatar
      lockdep debugging: give stacktrace for init_error · c71063c9
      Johannes Berg authored
      
      When I started adding support for lockdep to 64-bit powerpc, I got a
      lockdep_init_error and with this patch was able to pinpoint why and where
      to put lockdep_init().  Let's support this generally for others adding
      lockdep support to their architecture.
      
      Signed-off-by: default avatarJohannes Berg <johannes@sipsolutions.net>
      Cc: Ingo Molnar <mingo@elte.hu>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Arjan van de Ven <arjan@infradead.org>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      c71063c9
    • Peter Zijlstra's avatar
      lockstat: measure lock bouncing · 96645678
      Peter Zijlstra authored
      
          __acquire
              |
             lock _____
              |        \
              |    __contended
              |         |
              |        wait
              | _______/
              |/
              |
         __acquired
              |
         __release
              |
           unlock
      
      We measure acquisition and contention bouncing.
      
      This is done by recording a cpu stamp in each lock instance.
      
      Contention bouncing requires the cpu stamp to be set on acquisition. Hence we
      move __acquired into the generic path.
      
      __acquired is then used to measure acquisition bouncing by comparing the
      current cpu with the old stamp before replacing it.
      
      __contended is used to measure contention bouncing (only useful for preemptable
      locks)
      
      [akpm@linux-foundation.org: cleanups]
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      96645678
    • Peter Zijlstra's avatar
      lockdep: various fixes · 4b32d0a4
      Peter Zijlstra authored
      
       - update the copyright notices
       - use the default hash function
       - fix a thinko in a BUILD_BUG_ON
       - add a WARN_ON to spot inconsitent naming
       - fix a termination issue in /proc/lock_stat
      
      [akpm@linux-foundation.org: cleanups]
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      4b32d0a4
    • Peter Zijlstra's avatar
      lockstat: human readability tweaks · c46261de
      Peter Zijlstra authored
      
      Present all this fancy new lock statistics information:
      
      *warning, _wide_ output ahead*
      
      (output edited for purpose of brevity)
      
       # cat /proc/lock_stat
      lock_stat version 0.1
      -----------------------------------------------------------------------------------------------------------------------------------------------------------------
                                    class name    contentions   waittime-min   waittime-max waittime-total   acquisitions   holdtime-min   holdtime-max holdtime-total
      -----------------------------------------------------------------------------------------------------------------------------------------------------------------
      
                               &inode->i_mutex:         14458           6.57      398832.75     2469412.23        6768876           0.34    11398383.65   339410830.89
                               ---------------
                               &inode->i_mutex           4486          [<ffffffff802a08f9>] pipe_wait+0x86/0x8d
                               &inode->i_mutex              0          [<ffffffff802a01e8>] pipe_write_fasync+0x29/0x5d
                               &inode->i_mutex              0          [<ffffffff802a0e18>] pipe_read+0x74/0x3a5
                               &inode->i_mutex              0          [<ffffffff802a1a6a>] do_lookup+0x81/0x1ae
      
      .................................................................................................................................................................
      
                    &inode->i_data.tree_lock-W:           491           0.27          62.47         493.89        2477833           0.39         468.89     1146584.25
                    &inode->i_data.tree_lock-R:            65           0.44           4.27          48.78       26288792           0.36         184.62    10197458.24
                    --------------------------
                      &inode->i_data.tree_lock             46          [<ffffffff80277095>] __do_page_cache_readahead+0x69/0x24f
                      &inode->i_data.tree_lock             31          [<ffffffff8026f9fb>] add_to_page_cache+0x31/0xba
                      &inode->i_data.tree_lock              0          [<ffffffff802770ee>] __do_page_cache_readahead+0xc2/0x24f
                      &inode->i_data.tree_lock              0          [<ffffffff8026f6e4>] find_get_page+0x1a/0x58
      
      .................................................................................................................................................................
      
                            proc_inum_idr.lock:             0           0.00           0.00           0.00             36           0.00          65.60         148.26
                              proc_subdir_lock:             0           0.00           0.00           0.00        3049859           0.00         106.81     1563212.42
                              shrinker_rwsem-W:             0           0.00           0.00           0.00              5           0.00           1.73           3.68
                              shrinker_rwsem-R:             0           0.00           0.00           0.00            633           2.57         246.57       10909.76
      
      'contentions' and 'acquisitions' are the number of such events measured (since
      the last reset). The waittime- and holdtime- (min, max, total) numbers are
      presented in microseconds.
      
      If there are any contention points, the lock class is presented in the block
      format (as i_mutex and tree_lock above), otherwise a single line of output is
      presented.
      
      The output is sorted on absolute number of contentions (read + write), this
      should get the worst offenders presented first, so that:
      
       # grep : /proc/lock_stat | head
      
      will quickly show who's bad.
      
      The stats can be reset using:
      
       # echo 0 > /proc/lock_stat
      
      [bunk@stusta.de: make 2 functions static]
      [akpm@linux-foundation.org: fix printk warning]
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Acked-by: default avatarJason Baron <jbaron@redhat.com>
      Signed-off-by: default avatarAdrian Bunk <bunk@stusta.de>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      c46261de
    • Peter Zijlstra's avatar
      lockstat: core infrastructure · f20786ff
      Peter Zijlstra authored
      
      Introduce the core lock statistics code.
      
      Lock statistics provides lock wait-time and hold-time (as well as the count
      of corresponding contention and acquisitions events). Also, the first few
      call-sites that encounter contention are tracked.
      
      Lock wait-time is the time spent waiting on the lock. This provides insight
      into the locking scheme, that is, a heavily contended lock is indicative of
      a too coarse locking scheme.
      
      Lock hold-time is the duration the lock was held, this provides a reference for
      the wait-time numbers, so they can be put into perspective.
      
        1)
          lock
        2)
          ... do stuff ..
          unlock
        3)
      
      The time between 1 and 2 is the wait-time. The time between 2 and 3 is the
      hold-time.
      
      The lockdep held-lock tracking code is reused, because it already collects locks
      into meaningful groups (classes), and because it is an existing infrastructure
      for lock instrumentation.
      
      Currently lockdep tracks lock acquisition with two hooks:
      
        lock()
          lock_acquire()
          _lock()
      
       ... code protected by lock ...
      
        unlock()
          lock_release()
          _unlock()
      
      We need to extend this with two more hooks, in order to measure contention.
      
        lock_contended() - used to measure contention events
        lock_acquired()  - completion of the contention
      
      These are then placed the following way:
      
        lock()
          lock_acquire()
          if (!_try_lock())
            lock_contended()
            _lock()
            lock_acquired()
      
       ... do locked stuff ...
      
        unlock()
          lock_release()
          _unlock()
      
      (Note: the try_lock() 'trick' is used to avoid instrumenting all platform
             dependent lock primitive implementations.)
      
      It is also possible to toggle the two lockdep features at runtime using:
      
        /proc/sys/kernel/prove_locking
        /proc/sys/kernel/lock_stat
      
      (esp. turning off the O(n^2) prove_locking functionaliy can help)
      
      [akpm@linux-foundation.org: build fixes]
      [akpm@linux-foundation.org: nuke unneeded ifdefs]
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Acked-by: default avatarJason Baron <jbaron@redhat.com>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      f20786ff
    • Peter Zijlstra's avatar
      lockdep: reduce the ifdeffery · 8e18257d
      Peter Zijlstra authored
      
      Move code around to get fewer but larger #ifdef sections.  Break some
      in-function #ifdefs out into their own functions.
      
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      8e18257d
    • Peter Zijlstra's avatar
      lockdep: sanitise CONFIG_PROVE_LOCKING · ca58abcb
      Peter Zijlstra authored
      
      Ensure that all of the lock dependency tracking code is under
      CONFIG_PROVE_LOCKING.  This allows us to use the held lock tracking code for
      other purposes.
      
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Acked-by: default avatarJason Baron <jbaron@redhat.com>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      ca58abcb
  12. Jul 17, 2007
    • Tejun Heo's avatar
      kallsyms: make KSYM_NAME_LEN include space for trailing '\0' · 9281acea
      Tejun Heo authored
      
      KSYM_NAME_LEN is peculiar in that it does not include the space for the
      trailing '\0', forcing all users to use KSYM_NAME_LEN + 1 when allocating
      buffer.  This is nonsense and error-prone.  Moreover, when the caller
      forgets that it's very likely to subtly bite back by corrupting the stack
      because the last position of the buffer is always cleared to zero.
      
      This patch increments KSYM_NAME_LEN by one and updates code accordingly.
      
      * off-by-one bug in asm-powerpc/kprobes.h::kprobe_lookup_name() macro
        is fixed.
      
      * Where MODULE_NAME_LEN and KSYM_NAME_LEN were used together,
        MODULE_NAME_LEN was treated as if it didn't include space for the
        trailing '\0'.  Fix it.
      
      Signed-off-by: default avatarTejun Heo <htejun@gmail.com>
      Acked-by: default avatarPaulo Marques <pmarques@grupopie.com>
      Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
      Cc: Paul Mackerras <paulus@samba.org>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      9281acea
  13. May 08, 2007
  14. Mar 22, 2007
  15. Mar 01, 2007
    • Sam Ravnborg's avatar
      [PATCH] fix section mismatch warning in lockdep · 1499993c
      Sam Ravnborg authored
      
      lockdep_init() is marked __init but used in several places
      outside __init code. This causes following warnings:
      $ scripts/mod/modpost kernel/lockdep.o
      WARNING: kernel/built-in.o - Section mismatch: reference to .init.text:lockdep_init from .text.lockdep_init_map after 'lockdep_init_map' (at offset 0x105)
      WARNING: kernel/built-in.o - Section mismatch: reference to .init.text:lockdep_init from .text.lockdep_reset_lock after 'lockdep_reset_lock' (at offset 0x35)
      WARNING: kernel/built-in.o - Section mismatch: reference to .init.text:lockdep_init from .text.__lock_acquire after '__lock_acquire' (at offset 0xb2)
      
      The warnings are less obviously due to heavy inlining by gcc - this is not
      altered.
      
      Fix the section mismatch warnings by removing the __init marking, which
      seems obviously wrong.
      
      Signed-off-by: default avatarSam Ravnborg <sam@ravnborg.org>
      Acked-by: default avatarIngo Molnar <mingo@elte.hu>
      Cc: <stable@kernel.org>
      Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
      1499993c
  16. Feb 20, 2007
  17. Feb 11, 2007
  18. Dec 30, 2006
  19. Dec 13, 2006
  20. Dec 07, 2006
Loading