This is the mail archive of the systemtap@sourceware.org mailing list for the systemtap project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

[SYSTEMTAP/PATCH v3 7/9] stp: rt: replace addr_map_lock rd/wr lock with stp type raw lock


Without this change, Noticed that make installcheck freezes x86_64 box, testing
done on IvyBridge v2 12 core (HT). With crash post mortem analysis observed
that multiple threads grabs rd lock and get preempted in rt mode which
shouldn't ideally be the expected flow. rd/wr lock is preemptible which is
causing this problem for -rt mode so replace them with stp style raw lock.
However I poited out in other patches that replacement of rd/wr with rcu lock
in general better approach, we'll revisit them later(todo).

Crash log:

PID: 795    TASK: ffff8804185b5a90  CPU: 9   COMMAND: "migration/9"
 #4 [ffff8804185fdc28] _raw_spin_lock at ffffffff81608c02
 #5 [ffff8804185fdc38] try_to_wake_up at ffffffff810a4c35
 #6 [ffff8804185fdc80] wake_up_lock_sleeper at ffffffff810a4ee8
 #7 [ffff8804185fdc90] wakeup_next_waiter at ffffffff810bc6fd
 #8 [ffff8804185fdcd0] __rt_spin_lock_slowunlock at ffffffff81607b49
 #9 [ffff8804185fdce8] rt_spin_lock_slowunlock at ffffffff81607b9a
 #6 [ffff88042d803c18] __rt_spin_lock at ffffffff81608df5
 #7 [ffff88042d803c28] rt_read_lock at ffffffff816090b0
 #8 [ffff88042d803c40] rt_read_lock_irqsave at ffffffff816090ce
 #9 [ffff88042d803c50] lookup_bad_addr at ffffffffa0818dc8 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
 #10 [ffff88042d803c70] function__dwarf_cast_get_cast_8 at ffffffffa08194ab

PID: 0      TASK: ffffffff8191a460  CPU: 0   COMMAND: "swapper/0"
 #4 [ffff88042d803b78] _raw_spin_lock at ffffffff81608c02
 #5 [ffff88042d803b88] rt_spin_lock_slowlock at ffffffff81608204
 #6 [ffff88042d803c18] __rt_spin_lock at ffffffff81608df5
 #7 [ffff88042d803c28] rt_read_lock at ffffffff816090b0
 #8 [ffff88042d803c40] rt_read_lock_irqsave at ffffffff816090ce
 #9 [ffff88042d803c50] lookup_bad_addr at ffffffffa0818dc8 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]

PID: 12444  TASK: ffff880410920cf0  CPU: 10  COMMAND: "stapio"
 #11 [ffff88042d943e18] _raw_spin_lock at ffffffff81608bfb
 #12 [ffff88042d943e28] scheduler_tick at ffffffff810a2cbe
 #13 [ffff88042d943e58] update_process_times at ffffffff8107cc32
 #14 [ffff88042d943e80] tick_sched_handle at ffffffff810e1235
 #15 [ffff88042d943ea0] tick_sched_timer at ffffffff810e14b4
 #16 [ffff88042d943ec8] __run_hrtimer at ffffffff81096407
 #17 [ffff88042d943f08] hrtimer_interrupt at ffffffff81097110
 #18 [ffff88042d943f80] local_apic_timer_interrupt at ffffffff81047814
 #19 [ffff88042d943f98] smp_apic_timer_interrupt at ffffffff8161393f
 #20 [ffff88042d943fb0] apic_timer_interrupt at ffffffff816122dd

Signed-off-by: Santosh Shukla <sshukla@mvista.com>
---
Full crash analysis log:

crash> bt
PID: 795    TASK: ffff8804185b5a90  CPU: 9   COMMAND: "migration/9"
 #0 [ffff88042d926e58] crash_nmi_callback at ffffffff81043a02
 #1 [ffff88042d926e68] nmi_handle at ffffffff8160a75b
 #2 [ffff88042d926ec8] do_nmi at ffffffff8160a9e9
 #3 [ffff88042d926ef0] end_repeat_nmi at ffffffff81609ba1
    [exception RIP: _raw_spin_lock+66]
    RIP: ffffffff81608c02  RSP: ffff8804185fdc28  RFLAGS: 00000012
    RAX: 0000000000000010  RBX: 0000000000000010  RCX: 0000000000000012
    RDX: ffff8804185fdc28  RSI: 0000000000000018  RDI: 0000000000000001
    RBP: ffffffff81608c02   R8: ffffffff81608c02   R9: 0000000000000018
    R10: ffff8804185fdc28  R11: 0000000000000012  R12: ffffffffffffffff
    R13: ffff88042d956e80  R14: 000000000000c7c0  R15: 000000000000c7c0
    ORIG_RAX: 000000000000c7c0  CS: 0010  SS: 0018
--- <NMI exception stack> ---
 #4 [ffff8804185fdc28] _raw_spin_lock at ffffffff81608c02
 #5 [ffff8804185fdc38] try_to_wake_up at ffffffff810a4c35
 #6 [ffff8804185fdc80] wake_up_lock_sleeper at ffffffff810a4ee8
 #7 [ffff8804185fdc90] wakeup_next_waiter at ffffffff810bc6fd
 #8 [ffff8804185fdcd0] __rt_spin_lock_slowunlock at ffffffff81607b49
 #9 [ffff8804185fdce8] rt_spin_lock_slowunlock at ffffffff81607b9a
#10 [ffff8804185fdd00] __rt_spin_unlock at ffffffff81608d6e
#11 [ffff8804185fdd10] rt_read_unlock at ffffffff81609119
#12 [ffff8804185fdd20] lookup_bad_addr at ffffffffa0818e4c [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#13 [ffff8804185fdd40] function__tracepoint_tvar_get_next_7 at ffffffffa0819358 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#14 [ffff8804185fdd80] probe_2295 at ffffffffa081bcf6 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#15 [ffff8804185fddc8] enter_real_tracepoint_probe_1 at ffffffffa081f32e [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#16 [ffff8804185fddf8] enter_tracepoint_probe_1 at ffffffffa0817034 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#17 [ffff8804185fde08] __schedule at ffffffff81606530
#18 [ffff8804185fde60] schedule at ffffffff816068a0
#19 [ffff8804185fde78] smpboot_thread_fn at ffffffff8109a9b3
#20 [ffff8804185fded0] kthread at ffffffff81092ce4
#21 [ffff8804185fdf50] ret_from_fork at ffffffff816115bc

crash> bt
PID: 0      TASK: ffffffff8191a460  CPU: 0   COMMAND: "swapper/0"
 #0 [ffff88042d806e58] crash_nmi_callback at ffffffff81043a02
 #1 [ffff88042d806e68] nmi_handle at ffffffff8160a75b
 #2 [ffff88042d806ec8] do_nmi at ffffffff8160a958
 #3 [ffff88042d806ef0] end_repeat_nmi at ffffffff81609ba1
    [exception RIP: _raw_spin_lock+66]
    RIP: ffffffff81608c02  RSP: ffff88042d803b78  RFLAGS: 00000002
    RAX: 0000000000000010  RBX: 0000000000000010  RCX: 0000000000000002
    RDX: ffff88042d803b78  RSI: 0000000000000018  RDI: 0000000000000001
    RBP: ffffffff81608c02   R8: ffffffff81608c02   R9: 0000000000000018
    R10: ffff88042d803b78  R11: 0000000000000002  R12: ffffffffffffffff
    R13: ffffffffa08245c0  R14: 000000000000001a  R15: 000000000000001a
    ORIG_RAX: 000000000000001a  CS: 0010  SS: 0018
--- <NMI exception stack> ---
 #4 [ffff88042d803b78] _raw_spin_lock at ffffffff81608c02
 #5 [ffff88042d803b88] rt_spin_lock_slowlock at ffffffff81608204
 #6 [ffff88042d803c18] __rt_spin_lock at ffffffff81608df5
 #7 [ffff88042d803c28] rt_read_lock at ffffffff816090b0
 #8 [ffff88042d803c40] rt_read_lock_irqsave at ffffffff816090ce
 #9 [ffff88042d803c50] lookup_bad_addr at ffffffffa0818dc8 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#10 [ffff88042d803c70] function__dwarf_cast_get_cast_8 at ffffffffa08194ab [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#11 [ffff88042d803cb0] probe_2293 at ffffffffa081c6b0 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#12 [ffff88042d803cf0] enter_real_tracepoint_probe_0 at ffffffffa081f07f [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#13 [ffff88042d803d18] enter_tracepoint_probe_0 at ffffffffa0817011 [stap_674aee0a10a6c961c424f3bb2537e01f_12442]
#14 [ffff88042d803d28] ttwu_do_wakeup at ffffffff810a1a12
#15 [ffff88042d803d50] ttwu_do_activate.constprop.90 at ffffffff810a1a87
#16 [ffff88042d803d70] try_to_wake_up at ffffffff810a4d9c
#17 [ffff88042d803db8] wake_up_process at ffffffff810a4ecc
#18 [ffff88042d803dd0] rcu_wake_cond at ffffffff810d1fe8
#19 [ffff88042d803de0] invoke_rcu_core at ffffffff810d411b
#20 [ffff88042d803df8] rcu_check_callbacks at ffffffff810d5fb7
#21 [ffff88042d803e58] update_process_times at ffffffff8107cc42
#22 [ffff88042d803e80] tick_sched_handle at ffffffff810e1235
#23 [ffff88042d803ea0] tick_sched_timer at ffffffff810e14b4
#24 [ffff88042d803ec8] __run_hrtimer at ffffffff81096407
#25 [ffff88042d803f08] hrtimer_interrupt at ffffffff81097110
#26 [ffff88042d803f80] local_apic_timer_interrupt at ffffffff81047814
#27 [ffff88042d803f98] smp_apic_timer_interrupt at ffffffff8161393f
#28 [ffff88042d803fb0] apic_timer_interrupt at ffffffff816122dd
--- <IRQ stack> ---
#29 [ffffffff81905db8] apic_timer_interrupt at ffffffff816122dd


PID: 12444  TASK: ffff880410920cf0  CPU: 10  COMMAND: "stapio"
 #0 [ffff88042d946b28] machine_kexec at ffffffff81050312
 #1 [ffff88042d946b78] crash_kexec at ffffffff810f2103
 #2 [ffff88042d946c40] panic at ffffffff815fd6f0
 #3 [ffff88042d946cb8] watchdog_overflow_callback at ffffffff81118f3e
 #4 [ffff88042d946cd0] __perf_event_overflow at ffffffff8115249e
 #5 [ffff88042d946d48] perf_event_overflow at ffffffff81152f74
 #6 [ffff88042d946d58] intel_pmu_handle_irq at ffffffff810332f5
 #7 [ffff88042d946e48] perf_event_nmi_handler at ffffffff8160afdb
 #8 [ffff88042d946e68] nmi_handle at ffffffff8160a75b
 #9 [ffff88042d946ec8] do_nmi at ffffffff8160a958
#10 [ffff88042d946ef0] end_repeat_nmi at ffffffff81609ba1
    [exception RIP: _raw_spin_lock+59]
    RIP: ffffffff81608bfb  RSP: ffff88042d943e18  RFLAGS: 00000006
    RAX: 0000000000000010  RBX: 0000000000000010  RCX: 0000000000000006
    RDX: ffff88042d943e18  RSI: 0000000000000018  RDI: 0000000000000001
    RBP: ffffffff81608bfb   R8: ffffffff81608bfb   R9: 0000000000000018
    R10: ffff88042d943e18  R11: 0000000000000006  R12: ffffffffffffffff
    R13: ffff88042d956e80  R14: 000000000000c7c2  R15: 000000000000c7c2
    ORIG_RAX: 000000000000c7c2  CS: 0010  SS: 0018
--- <NMI exception stack> ---
#11 [ffff88042d943e18] _raw_spin_lock at ffffffff81608bfb
#12 [ffff88042d943e28] scheduler_tick at ffffffff810a2cbe
#13 [ffff88042d943e58] update_process_times at ffffffff8107cc32
#14 [ffff88042d943e80] tick_sched_handle at ffffffff810e1235
#15 [ffff88042d943ea0] tick_sched_timer at ffffffff810e14b4
#16 [ffff88042d943ec8] __run_hrtimer at ffffffff81096407
#17 [ffff88042d943f08] hrtimer_interrupt at ffffffff81097110
#18 [ffff88042d943f80] local_apic_timer_interrupt at ffffffff81047814
#19 [ffff88042d943f98] smp_apic_timer_interrupt at ffffffff8161393f
#20 [ffff88042d943fb0] apic_timer_interrupt at ffffffff816122dd
--- <IRQ stack> ---
bt: cannot transition from exception stack to IRQ stack to current process stack:
    exception stack pointer: ffff88042d946b28
          IRQ stack pointer: ffff880419f4bbd8
      process stack pointer: ffff880419f4bbd8


 runtime/linux/addr-map.c | 15 ++++++++-------
 1 file changed, 8 insertions(+), 7 deletions(-)

diff --git a/runtime/linux/addr-map.c b/runtime/linux/addr-map.c
index 3f5aca7..a7a5e38 100644
--- a/runtime/linux/addr-map.c
+++ b/runtime/linux/addr-map.c
@@ -28,7 +28,7 @@ struct addr_map
   struct addr_map_entry entries[0];
 };
 
-static DEFINE_RWLOCK(addr_map_lock);
+static STP_DEFINE_RWLOCK(addr_map_lock);
 static struct addr_map* blackmap;
 
 /* Find address of entry where we can insert a new one. */
@@ -111,6 +111,7 @@ lookup_bad_addr(unsigned long addr, size_t size)
   struct addr_map_entry* result = 0;
   unsigned long flags;
 
+
   /* Is this a valid memory access?  */
   if (size == 0 || ULONG_MAX - addr < size - 1)
     return 1;
@@ -127,9 +128,9 @@ lookup_bad_addr(unsigned long addr, size_t size)
 #endif
 
   /* Search for the given range in the black-listed map.  */
-  read_lock_irqsave(&addr_map_lock, flags);
+  stp_read_lock_irqsave(&addr_map_lock, flags);
   result = lookup_addr_aux(addr, size, blackmap);
-  read_unlock_irqrestore(&addr_map_lock, flags);
+  stp_read_unlock_irqrestore(&addr_map_lock, flags);
   if (result)
     return 1;
   else
@@ -154,7 +155,7 @@ add_bad_addr_entry(unsigned long min_addr, unsigned long max_addr,
   while (1)
     {
       size_t old_size = 0;
-      write_lock_irqsave(&addr_map_lock, flags);
+      stp_write_lock_irqsave(&addr_map_lock, flags);
       old_map = blackmap;
       if (old_map)
         old_size = old_map->size;
@@ -163,7 +164,7 @@ add_bad_addr_entry(unsigned long min_addr, unsigned long max_addr,
          added an entry while we were sleeping. */
       if (!new_map || (new_map && new_map->size < old_size + 1))
         {
-          write_unlock_irqrestore(&addr_map_lock, flags);
+          stp_write_unlock_irqrestore(&addr_map_lock, flags);
           if (new_map)
             {
 	      _stp_kfree(new_map);
@@ -192,7 +193,7 @@ add_bad_addr_entry(unsigned long min_addr, unsigned long max_addr,
             *existing_min = min_entry;
           if (existing_max)
             *existing_max = max_entry;
-          write_unlock_irqrestore(&addr_map_lock, flags);
+          stp_write_unlock_irqrestore(&addr_map_lock, flags);
           _stp_kfree(new_map);
           return 1;
         }
@@ -210,7 +211,7 @@ add_bad_addr_entry(unsigned long min_addr, unsigned long max_addr,
                (old_map->size - existing) * sizeof(*new_entry));
     }
   blackmap = new_map;
-  write_unlock_irqrestore(&addr_map_lock, flags);
+  stp_write_unlock_irqrestore(&addr_map_lock, flags);
   if (old_map)
     _stp_kfree(old_map);
   return 0;
-- 
1.8.3.1


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]