lkml.org 
[lkml]   [2007]   [Mar]   [20]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    SubjectRe: 2.6.21-rc4-mm1
    From
    Andrew Morton napisał(a):
    > Temporarily at
    >
    > http://userweb.kernel.org/~akpm/2.6.21-rc4-mm1/
    >

    Some new details about
    http://www.ussg.iu.edu/hypermail/linux/kernel/0703.2/1367.html

    I can reproduce it by running this on AutoTest

    for profiler in ('oprofile', ):
    try:
    print "Testing profiler %s ..." % profiler
    job.profilers.add(profiler)
    job.run_test('aiostress',)
    job.profilers.delete(profiler)
    except:
    print "Test of profiler %s failed" % profiler
    raise

    I guess that oprofile triggers it.

    BUG: using smp_processor_id() in preemptible [00000001] code: mount/4934
    caller is avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<c0105256>] show_trace_log_lvl+0x1a/0x2f
    [<c010597b>] show_trace+0x12/0x14
    [<c0105a3d>] dump_stack+0x16/0x18
    [<c0212f43>] debug_smp_processor_id+0xb3/0xc8
    [<c0116a26>] avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<fdc829b9>] nmi_create_files+0x2a/0x10e [oprofile]
    [<fdc81f52>] oprofile_create_files+0xe6/0xec [oprofile]
    [<fdc82157>] oprofilefs_fill_super+0x78/0x7e [oprofile]
    [<c018296e>] get_sb_single+0x59/0x9f
    [<fdc8208f>] oprofilefs_get_sb+0x1c/0x1e [oprofile]
    [<c01823d2>] vfs_kern_mount+0x81/0xf1
    [<c0182492>] do_kern_mount+0x38/0xde
    [<c01962b1>] do_mount+0x605/0x693
    [<c01963bf>] sys_mount+0x80/0xb5
    [<c0104270>] syscall_call+0x7/0xb
    =======================

    l *avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    0xc01169fb is in avail_to_resrv_perfctr_nmi_bit (/mnt/md0/devel/linux-mm/arch/i386/kernel/nmi.c:124).
    119 return 0;
    120 }
    121
    122 /* checks for a bit availability (hack for oprofile) */
    123 int avail_to_resrv_perfctr_nmi_bit(unsigned int counter)
    124 {
    125 BUG_ON(counter > NMI_MAX_COUNTER_BITS);
    126
    127 return (!test_bit(counter, &__get_cpu_var(perfctr_nmi_owner)));
    128 }


    BUG: using smp_processor_id() in preemptible [00000001] code: mount/4934
    caller is avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<c0105256>] show_trace_log_lvl+0x1a/0x2f
    [<c010597b>] show_trace+0x12/0x14
    [<c0105a3d>] dump_stack+0x16/0x18
    [<c0212f43>] debug_smp_processor_id+0xb3/0xc8
    [<c0116a26>] avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<fdc829b9>] nmi_create_files+0x2a/0x10e [oprofile]
    [<fdc81f52>] oprofile_create_files+0xe6/0xec [oprofile]
    [<fdc82157>] oprofilefs_fill_super+0x78/0x7e [oprofile]
    [<c018296e>] get_sb_single+0x59/0x9f
    [<fdc8208f>] oprofilefs_get_sb+0x1c/0x1e [oprofile]
    [<c01823d2>] vfs_kern_mount+0x81/0xf1
    [<c0182492>] do_kern_mount+0x38/0xde
    [<c01962b1>] do_mount+0x605/0x693
    [<c01963bf>] sys_mount+0x80/0xb5
    [<c0104270>] syscall_call+0x7/0xb
    =======================
    BUG: using smp_processor_id() in preemptible [00000001] code: mount/4934
    caller is avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<c0105256>] show_trace_log_lvl+0x1a/0x2f
    [<c010597b>] show_trace+0x12/0x14
    [<c0105a3d>] dump_stack+0x16/0x18
    [<c0212f43>] debug_smp_processor_id+0xb3/0xc8
    [<c0116a26>] avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<fdc829b9>] nmi_create_files+0x2a/0x10e [oprofile]
    [<fdc81f52>] oprofile_create_files+0xe6/0xec [oprofile]
    [<fdc82157>] oprofilefs_fill_super+0x78/0x7e [oprofile]
    [<c018296e>] get_sb_single+0x59/0x9f
    [<fdc8208f>] oprofilefs_get_sb+0x1c/0x1e [oprofile]
    [<c01823d2>] vfs_kern_mount+0x81/0xf1
    [<c0182492>] do_kern_mount+0x38/0xde
    [<c01962b1>] do_mount+0x605/0x693
    [<c01963bf>] sys_mount+0x80/0xb5
    [<c0104270>] syscall_call+0x7/0xb
    =======================
    BUG: using smp_processor_id() in preemptible [00000001] code: mount/4934
    caller is avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<c0105256>] show_trace_log_lvl+0x1a/0x2f
    [<c010597b>] show_trace+0x12/0x14
    [<c0105a3d>] dump_stack+0x16/0x18
    [<c0212f43>] debug_smp_processor_id+0xb3/0xc8
    [<c0116a26>] avail_to_resrv_perfctr_nmi_bit+0x2b/0x43
    [<fdc829b9>] nmi_create_files+0x2a/0x10e [oprofile]
    [<fdc81f52>] oprofile_create_files+0xe6/0xec [oprofile]
    [<fdc82157>] oprofilefs_fill_super+0x78/0x7e [oprofile]
    [<c018296e>] get_sb_single+0x59/0x9f
    [<fdc8208f>] oprofilefs_get_sb+0x1c/0x1e [oprofile]
    [<c01823d2>] vfs_kern_mount+0x81/0xf1
    [<c0182492>] do_kern_mount+0x38/0xde
    [<c01962b1>] do_mount+0x605/0x693
    [<c01963bf>] sys_mount+0x80/0xb5
    [<c0104270>] syscall_call+0x7/0xb
    =======================
    SELinux: initialized (dev oprofilefs, type oprofilefs), uses genfs_contexts

    =================================
    [ INFO: inconsistent lock state ]
    2.6.21-rc4-mm1 #5
    ---------------------------------
    inconsistent {hardirq-on-W} -> {in-hardirq-W} usage.
    init/1 [HC1[1]:SC0[0]:HE0:SE1] takes:
    (oprofilefs_lock){+-..}, at: [<fdc82b6e>] nmi_cpu_setup+0x15/0x4f [oprofile]
    {hardirq-on-W} state was registered at:
    [<c0140c15>] __lock_acquire+0x4e8/0xceb
    [<c0141491>] lock_acquire+0x79/0x93
    [<c033eb3f>] _spin_lock+0x35/0x42
    [<fdc82347>] oprofilefs_ulong_from_user+0x4e/0x74 [oprofile]
    [<fdc81fc7>] depth_write+0x27/0x43 [oprofile]
    [<c0180afa>] vfs_write+0xd1/0x15a
    [<c018112a>] sys_write+0x3d/0x72
    [<c0104270>] syscall_call+0x7/0xb
    [<ffffffff>] 0xffffffff
    irq event stamp: 1022800
    hardirqs last enabled at (1022799): [<c01042b8>] restore_nocheck+0x12/0x15
    hardirqs last disabled at (1022800): [<c0104cf1>] call_function_interrupt+0x29/0x38
    softirqs last enabled at (1022784): [<c0128eb4>] __do_softirq+0xe4/0xea
    softirqs last disabled at (1022779): [<c0128ef3>] do_softirq+0x39/0x55

    l *0xc01042b8
    0xc01042b8 is at include2/asm/bitops.h:246.
    241 static int test_bit(int nr, const volatile void * addr);
    242 #endif
    243
    244 static __always_inline int constant_test_bit(int nr, const volatile unsigned long *addr)
    245 {
    246 return ((1UL << (nr & 31)) & (addr[nr >> 5])) != 0;
    247 }
    248
    249 static inline int variable_test_bit(int nr, const volatile unsigned long * addr)
    250 {

    l *0xc0104cf1
    0xc0104cf1 is at include2/asm/bitops.h:246.
    241 static int test_bit(int nr, const volatile void * addr);
    242 #endif
    243
    244 static __always_inline int constant_test_bit(int nr, const volatile unsigned long *addr)
    245 {
    246 return ((1UL << (nr & 31)) & (addr[nr >> 5])) != 0;
    247 }
    248
    249 static inline int variable_test_bit(int nr, const volatile unsigned long * addr)
    250 {

    l *0xc0128eb4
    0xc0128eb4 is in __do_softirq (/mnt/md0/devel/linux-mm/kernel/softirq.c:252).
    247
    248 trace_softirq_exit();
    249
    250 account_system_vtime(current);
    251 _local_bh_enable();
    252 }
    253
    254 #ifndef __ARCH_HAS_DO_SOFTIRQ
    255
    256 asmlinkage void do_softirq(void)

    l *0xc0128ef3
    0xc0128ef3 is in do_softirq (/mnt/md0/devel/linux-mm/kernel/softirq.c:271).
    266 pending = local_softirq_pending();
    267
    268 if (pending)
    269 __do_softirq();
    270
    271 local_irq_restore(flags);
    272 }
    273
    274 EXPORT_SYMBOL(do_softirq);
    275


    other info that might help us debug this:
    2 locks held by init/1:
    #0: (tasklist_lock){..??}, at: [<c01261b6>] do_wait+0x54/0xba4
    #1: (policy_rwlock){..??}, at: [<c01ef326>] security_compute_av+0x4f/0xbf

    l *0xc01261b6
    0xc01261b6 is in do_wait (include2/asm/current.h:11).
    6
    7 struct task_struct;
    8
    9 static __always_inline struct task_struct *get_current(void)
    10 {
    11 return read_pda(pcurrent);
    12 }
    13
    14 #define current get_current()
    15

    l *0xc01ef326
    0xc01ef326 is in security_compute_av (/mnt/md0/devel/linux-mm/security/selinux/ss/services.c:527).
    522 return 0;
    523 }
    524
    525 POLICY_RDLOCK;
    526
    527 scontext = sidtab_search(&sidtab, ssid);
    528 if (!scontext) {
    529 printk(KERN_ERR "security_compute_av: unrecognized SID %d\n",
    530 ssid);
    531 rc = -EINVAL;


    stack backtrace:
    [<c0105256>] show_trace_log_lvl+0x1a/0x2f
    [<c010597b>] show_trace+0x12/0x14
    [<c0105a3d>] dump_stack+0x16/0x18
    [<c013f327>] print_usage_bug+0x140/0x14a
    [<c013fbbf>] mark_lock+0xc9/0x510
    [<c0140b86>] __lock_acquire+0x459/0xceb
    [<c0141491>] lock_acquire+0x79/0x93
    [<c033eb3f>] _spin_lock+0x35/0x42
    [<fdc82b6e>] nmi_cpu_setup+0x15/0x4f [oprofile]
    [<c0113b63>] smp_call_function_interrupt+0x3a/0x56
    [<c0104cfb>] call_function_interrupt+0x33/0x38
    [<c01ef380>] security_compute_av+0xa9/0xbf
    [<c01e2649>] avc_has_perm_noaudit+0x1cf/0x490
    [<c01e34da>] avc_has_perm+0x28/0x58
    [<c01e3cd7>] task_has_perm+0x2d/0x2f
    [<c01e6e74>] selinux_task_wait+0x2f/0x31
    [<c0126295>] do_wait+0x133/0xba4
    [<c0126d36>] sys_wait4+0x30/0x32
    [<c0126d5f>] sys_waitpid+0x27/0x29
    [<c01041e6>] sysenter_past_esp+0x5f/0x99
    =======================

    http://www.stardust.webpages.pl/files/tbf/bitis-gabonica/2.6.21-rc4-mm1/mm-dmesg
    http://www.stardust.webpages.pl/files/tbf/bitis-gabonica/2.6.21-rc4-mm1/mm-config

    Regards,
    Michal

    --
    Michal K. K. Piotrowski
    LTG - Linux Testers Group (PL)
    (http://www.stardust.webpages.pl/ltg/)
    LTG - Linux Testers Group (EN)
    (http://www.stardust.webpages.pl/linux_testers_group_en/)
    -
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

    \
     
     \ /
      Last update: 2007-03-20 08:59    [W:4.328 / U:0.500 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site