Skip to content
Snippets Groups Projects
  1. Apr 14, 2009
    • Steven Rostedt's avatar
      tracing: create automated trace defines · a8d154b0
      Steven Rostedt authored
      
      This patch lowers the number of places a developer must modify to add
      new tracepoints. The current method to add a new tracepoint
      into an existing system is to write the trace point macro in the
      trace header with one of the macros TRACE_EVENT, TRACE_FORMAT or
      DECLARE_TRACE, then they must add the same named item into the C file
      with the macro DEFINE_TRACE(name) and then add the trace point.
      
      This change cuts out the needing to add the DEFINE_TRACE(name).
      Every file that uses the tracepoint must still include the trace/<type>.h
      file, but the one C file must also add a define before the including
      of that file.
      
       #define CREATE_TRACE_POINTS
       #include <trace/mytrace.h>
      
      This will cause the trace/mytrace.h file to also produce the C code
      necessary to implement the trace point.
      
      Note, if more than one trace/<type>.h is used to create the C code
      it is best to list them all together.
      
       #define CREATE_TRACE_POINTS
       #include <trace/foo.h>
       #include <trace/bar.h>
       #include <trace/fido.h>
      
      Thanks to Mathieu Desnoyers and Christoph Hellwig for coming up with
      the cleaner solution of the define above the includes over my first
      design to have the C code include a "special" header.
      
      This patch converts sched, irq and lockdep and skb to use this new
      method.
      
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Cc: Neil Horman <nhorman@tuxdriver.com>
      Cc: Zhao Lei <zhaolei@cn.fujitsu.com>
      Cc: Eduard - Gabriel Munteanu <eduard.munteanu@linux360.ro>
      Cc: Pekka Enberg <penberg@cs.helsinki.fi>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      a8d154b0
  2. Apr 10, 2009
    • Frederic Weisbecker's avatar
      tracing/lockdep: report the time waited for a lock · 2062501a
      Frederic Weisbecker authored
      
      While trying to optimize the new lock on reiserfs to replace
      the bkl, I find the lock tracing very useful though it lacks
      something important for performance (and latency) instrumentation:
      the time a task waits for a lock.
      
      That's what this patch implements:
      
        bash-4816  [000]   202.652815: lock_contended: lock_contended: &sb->s_type->i_mutex_key
        bash-4816  [000]   202.652819: lock_acquired: &rq->lock (0.000 us)
       <...>-4787  [000]   202.652825: lock_acquired: &rq->lock (0.000 us)
       <...>-4787  [000]   202.652829: lock_acquired: &rq->lock (0.000 us)
        bash-4816  [000]   202.652833: lock_acquired: &sb->s_type->i_mutex_key (16.005 us)
      
      As shown above, the "lock acquired" field is followed by the time
      it has been waiting for the lock. Usually, a lock contended entry
      is followed by a near lock_acquired entry with a non-zero time waited.
      
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Acked-by: default avatarPeter Zijlstra <peterz@infradead.org>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      LKML-Reference: <1238975373-15739-1-git-send-email-fweisbec@gmail.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      2062501a
  3. Mar 31, 2009
  4. Mar 30, 2009
  5. Mar 05, 2009
  6. Mar 04, 2009
    • Peter Zijlstra's avatar
      tracing: add lockdep tracepoints for lock acquire/release · efed792d
      Peter Zijlstra authored
      
      Augment the traces with lock names when lockdep is available:
      
       1)               |  down_read_trylock() {
       1)               |    _spin_lock_irqsave() {
       1)               |      /* lock_acquire: &sem->wait_lock */
       1)   4.201 us    |    }
       1)               |    _spin_unlock_irqrestore() {
       1)               |      /* lock_release: &sem->wait_lock */
       1)   3.523 us    |    }
       1)               |  /* lock_acquire: try read &mm->mmap_sem */
       1) + 13.386 us   |  }
       1)   1.635 us    |  find_vma();
       1)               |  handle_mm_fault() {
       1)               |    __do_fault() {
       1)               |      filemap_fault() {
       1)               |        find_lock_page() {
       1)               |          find_get_page() {
       1)               |            /* lock_acquire: read rcu_read_lock */
       1)               |            /* lock_release: rcu_read_lock */
       1)   5.697 us    |          }
       1)   8.158 us    |        }
       1) + 11.079 us   |      }
       1)               |      _spin_lock() {
       1)               |        /* lock_acquire: __pte_lockptr(page) */
       1)   3.949 us    |      }
       1)   1.460 us    |      page_add_file_rmap();
       1)               |      _spin_unlock() {
       1)               |        /* lock_release: __pte_lockptr(page) */
       1)   3.115 us    |      }
       1)               |      unlock_page() {
       1)   1.421 us    |        page_waitqueue();
       1)   1.220 us    |        __wake_up_bit();
       1)   6.519 us    |      }
       1) + 34.328 us   |    }
       1) + 37.452 us   |  }
       1)               |  up_read() {
       1)               |  /* lock_release: &mm->mmap_sem */
       1)               |    _spin_lock_irqsave() {
       1)               |      /* lock_acquire: &sem->wait_lock */
       1)   3.865 us    |    }
       1)               |    _spin_unlock_irqrestore() {
       1)               |      /* lock_release: &sem->wait_lock */
       1)   8.562 us    |    }
       1) + 17.370 us   |  }
      
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Steven Rostedt <rostedt@goodmis.org>
      Cc: =?ISO-8859-1?Q?T=F6r=F6k?= Edwin <edwintorok@gmail.com>
      Cc: Jason Baron <jbaron@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      LKML-Reference: <1236166375.5330.7209.camel@laptop>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      efed792d
    • Peter Zijlstra's avatar
      lockdep: remove extra "irq" string · 26575e28
      Peter Zijlstra authored
      
      Impact: clarify lockdep printk text
      
      print_irq_inversion_bug() gets handed state strings of the form
      
        "HARDIRQ", "SOFTIRQ", "RECLAIM_FS"
      
      and appends "-irq-{un,}safe" to them, which is either redudant for *IRQ or
      confusing in the RECLAIM_FS case.
      
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      LKML-Reference: <1236175192.5330.7585.camel@laptop>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      26575e28
    • Peter Zijlstra's avatar
      lockdep: fix incorrect state name · 1c21f14e
      Peter Zijlstra authored
      
      In the recent mark_lock_irq() rework a bug snuck in that would report the
      state of write locks causing irq inversion under a read lock as a read
      lock.
      
      Fix this by masking the read bit of the state when validating write
      dependencies.
      
      Reported-by: default avatarAndrew Morton <akpm@linux-foundation.org>
      Signed-off-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      LKML-Reference: <1236172646.5330.7450.camel@laptop>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      1c21f14e
  7. Feb 14, 2009
  8. Dec 04, 2008
  9. Dec 03, 2008
  10. Nov 25, 2008
    • Ingo Molnar's avatar
      lockdep: fix unused function warning in kernel/lockdep.c · 7807fafa
      Ingo Molnar authored
      
      Impact: fix build warning
      
      this warning:
      
        kernel/lockdep.c:584: warning: ‘print_lock_dependencies’ defined but not used
      
      triggers because print_lock_dependencies() is only used if both
      CONFIG_TRACE_IRQFLAGS and CONFIG_PROVE_LOCKING are enabled.
      
      But adding #ifdefs is not an option here - it would spread out to 4-5
      other helper functions and uglify the file. So mark this function
      as __used - it's static and the compiler can eliminate it just fine.
      
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      7807fafa
  11. Nov 21, 2008
  12. Oct 28, 2008
  13. Oct 20, 2008
  14. Aug 27, 2008
    • Zhu Yi's avatar
      lockdep: fix invalid list_del_rcu in zap_class · 74870172
      Zhu Yi authored
      
      The problem is found during iwlagn driver testing on
      v2.6.27-rc4-176-gb8e6c91 kernel, but it turns out to be a lockdep bug.
      In our testing, we frequently load and unload the iwlagn driver
      (>50 times). Then the MAX_STACK_TRACE_ENTRIES is reached (expected
      behaviour?). The error message with the call trace is as below.
      
      BUG: MAX_STACK_TRACE_ENTRIES too low!
      turning off the locking correctness validator.
      Pid: 4895, comm: iwlagn Not tainted 2.6.27-rc4 #13
      
      Call Trace:
       [<ffffffff81014aa1>] save_stack_trace+0x22/0x3e
       [<ffffffff8105390a>] save_trace+0x8b/0x91
       [<ffffffff81054e60>] mark_lock+0x1b0/0x8fa
       [<ffffffff81056f71>] __lock_acquire+0x5b9/0x716
       [<ffffffffa00d818a>] ieee80211_sta_work+0x0/0x6ea [mac80211]
       [<ffffffff81057120>] lock_acquire+0x52/0x6b
       [<ffffffff81045f0e>] run_workqueue+0x97/0x1ed
       [<ffffffff81045f5e>] run_workqueue+0xe7/0x1ed
       [<ffffffff81045f0e>] run_workqueue+0x97/0x1ed
       [<ffffffff81046ae4>] worker_thread+0xd8/0xe3
       [<ffffffff81049503>] autoremove_wake_function+0x0/0x2e
       [<ffffffff81046a0c>] worker_thread+0x0/0xe3
       [<ffffffff810493ec>] kthread+0x47/0x73
       [<ffffffff8128e3ab>] trace_hardirqs_on_thunk+0x3a/0x3f
       [<ffffffff8100cea9>] child_rip+0xa/0x11
       [<ffffffff8100c4df>] restore_args+0x0/0x30
       [<ffffffff810316e1>] finish_task_switch+0x0/0xcc
       [<ffffffff810493a5>] kthread+0x0/0x73
       [<ffffffff8100ce9f>] child_rip+0x0/0x11
      
      Although the above is harmless, when the ilwagn module is removed
      later lockdep will trigger a kernel oops as below.
      
      BUG: unable to handle kernel NULL pointer dereference at
      0000000000000008
      IP: [<ffffffff810531e1>] zap_class+0x24/0x82
      PGD 73128067 PUD 7448c067 PMD 0
      Oops: 0002 [1] SMP
      CPU 0
      Modules linked in: rfcomm l2cap bluetooth autofs4 sunrpc
      nf_conntrack_ipv6 xt_state nf_conntrack xt_tcpudp ip6t_ipv6header
      ip6t_REJECT ip6table_filter ip6_tables x_tables ipv6 cpufreq_ondemand
      acpi_cpufreq dm_mirror dm_log dm_multipath dm_mod snd_hda_intel sr_mod
      snd_seq_dummy snd_seq_oss snd_seq_midi_event battery snd_seq
      snd_seq_device cdrom button snd_pcm_oss snd_mixer_oss snd_pcm
      snd_timer snd_page_alloc e1000e snd_hwdep sg iTCO_wdt
      iTCO_vendor_support ac pcspkr i2c_i801 i2c_core snd soundcore video
      output ata_piix ata_generic libata sd_mod scsi_mod ext3 jbd mbcache
      uhci_hcd ohci_hcd ehci_hcd [last unloaded: mac80211]
      Pid: 4941, comm: modprobe Not tainted 2.6.27-rc4 #10
      RIP: 0010:[<ffffffff810531e1>]  [<ffffffff810531e1>]
      zap_class+0x24/0x82
      RSP: 0000:ffff88007bcb3eb0  EFLAGS: 00010046
      RAX: 0000000000068ee8 RBX: ffffffff8192a0a0 RCX: 0000000000000000
      RDX: 0000000000000000 RSI: 0000000000001dfb RDI: ffffffff816e70b0
      RBP: ffffffffa00cd000 R08: ffffffff816818f8 R09: ffff88007c923558
      R10: ffffe20002ad2408 R11: ffffffff811028ec R12: ffffffff8192a0a0
      R13: 000000000002bd90 R14: 0000000000000000 R15: 0000000000000296
      FS:  00007f9d1cee56f0(0000) GS:ffffffff814a58c0(0000)
      knlGS:0000000000000000
      CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
      CR2: 0000000000000008 CR3: 0000000073047000 CR4: 00000000000006e0
      DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
      DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
      Process modprobe (pid: 4941, threadinfo ffff88007bcb2000, task
      ffff8800758d1fc0)
      Stack:  ffffffff81057376 0000000000000000 ffffffffa00f7b00
      0000000000000000
       0000000000000080 0000000000618278 00007fff24f16720 0000000000000000
       ffffffff8105d37a ffffffffa00f7b00 ffffffff8105d591 313132303863616d
      Call Trace:
       [<ffffffff81057376>] ? lockdep_free_key_range+0x61/0xf5
       [<ffffffff8105d37a>] ? free_module+0xd4/0xe4
       [<ffffffff8105d591>] ? sys_delete_module+0x1de/0x1f9
       [<ffffffff8106dbfa>] ? audit_syscall_entry+0x12d/0x160
       [<ffffffff8100be2b>] ? system_call_fastpath+0x16/0x1b
      
      Code: b2 00 01 00 00 00 c3 31 f6 49 c7 c0 10 8a 61 81 eb 32 49 39 38
      75 26 48 98 48 6b c0 38 48 8b 90 08 8a 61 81 48 8b 88 00 8a 61 81 <48>
      89 51 08 48 89 0a 48 c7 80 08 8a 61 81 00 02 20 00 48 ff c6
      RIP  [<ffffffff810531e1>] zap_class+0x24/0x82
       RSP <ffff88007bcb3eb0>
      CR2: 0000000000000008
      ---[ end trace a1297e0c4abb0f2e ]---
      
      The root cause for this oops is in add_lock_to_list() when
      save_trace() fails due to MAX_STACK_TRACE_ENTRIES is reached,
      entry->class is assigned but entry is never added into any lock list.
      This makes the list_del_rcu() in zap_class() oops later when the
      module is unloaded. This patch fixes the problem by assigning
      entry->class after save_trace() returns success.
      
      Signed-off-by: default avatarZhu Yi <yi.zhu@intel.com>
      Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
      74870172
  15. Aug 26, 2008
  16. Aug 18, 2008
  17. Aug 13, 2008
  18. Aug 11, 2008
Loading