LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
From: Jiri Olsa <olsajiri@gmail.com>
To: Jiri Kosina <jkosina@suse.cz>
Cc: Andrew Morton <akpm@linux-foundation.org>,
	linux-kernel@vger.kernel.org,
	Nadia Derbey <Nadia.Derbey@bull.net>,
	peifferp@gmail.com
Subject: Re: [BUG] soft lockup detected with ipcs
Date: Mon, 03 Mar 2008 13:00:49 +0100	[thread overview]
Message-ID: <47CBE871.4090309@gmail.com> (raw)
In-Reply-To: <Pine.LNX.4.64.0803022223360.15209@jikos.suse.cz>

[-- Attachment #1: Type: text/plain, Size: 1136 bytes --]

Jiri Kosina wrote:
> On Sun, 2 Mar 2008, Jiri Kosina wrote:
> 
>> Could you please try what is the output with the attached patch below, so 
>> that we know which spinlock buggers?
> 
> Uhm, and hereby I attach the patch.
> 
> diff --git a/ipc/shm.c b/ipc/shm.c
> index c47e872..2abfb70 100644
> --- a/ipc/shm.c
> +++ b/ipc/shm.c
> @@ -615,6 +615,7 @@ static void shm_get_stat(struct ipc_namespace *ns, unsigned long *rss,
>  			*rss += (HPAGE_SIZE/PAGE_SIZE)*mapping->nrpages;
>  		} else {
>  			struct shmem_inode_info *info = SHMEM_I(inode);
> +			printk(KERN_DEBUG "info: %p\n", info);
>  			spin_lock(&info->lock);
>  			*rss += inode->i_mapping->nrpages;
>  			*swp += info->swapped;
> diff --git a/ipc/util.c b/ipc/util.c
> index fd1b50d..5a0d4d2 100644
> --- a/ipc/util.c
> +++ b/ipc/util.c
> @@ -662,6 +662,7 @@ struct kern_ipc_perm *ipc_lock(struct ipc_ids *ids, int id)
>  
>  	up_read(&ids->rw_mutex);
>  
> +	printk(KERN_DEBUG "out: %p\n", out);
>  	spin_lock(&out->lock);
>  	
>  	/* ipc_rmid() may have already freed the ID while ipc_lock

I'll try the patch, so far I attached the ipcs strace and adjacent kernel logs.

[-- Attachment #2: ipcs.strace.out --]
[-- Type: text/plain, Size: 1838 bytes --]

execve("/usr/bin/ipcs", ["ipcs"], [/* 37 vars */]) = 0
brk(0)                                  = 0x804e000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=60196, ...}) = 0
mmap2(NULL, 60196, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f2c000
close(3)                                = 0
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@e\1\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1261852, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f2b000
mmap2(NULL, 1267248, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7df5000
mmap2(0xb7f25000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x130) = 0xb7f25000
mmap2(0xb7f28000, 9776, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f28000
close(3)                                = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7df4000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7df46c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
mprotect(0xb7f25000, 8192, PROT_READ)   = 0
mprotect(0x804c000, 4096, PROT_READ)    = 0
mprotect(0xb7f56000, 4096, PROT_READ)   = 0
munmap(0xb7f2c000, 60196)               = 0
brk(0)                                  = 0x804e000
brk(0x806f000)                          = 0x806f000
fstat64(1, {st_mode=S_IFCHR|0622, st_rdev=makedev(136, 0), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f3a000
write(1, "\n", 1)                       = 1
shmctl(0, IPC_64|SHM_INFO, 0xbfd9e9e0 <unfinished ...>
+++ killed by SIGSEGV +++

[-- Attachment #3: ipcs.kernel.out.1 --]
[-- Type: text/plain, Size: 2100 bytes --]

[   85.868123] BUG: unable to handle kernel NULL pointer dereference at virtual address 000000bf
[   85.868149] printing eip: c0133034 *pde = 00000000 
[   85.868171] Oops: 0002 [#1] 
[   85.868184] Modules linked in: netconsole i915 drm configfs snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm snd_timer snd snd_page_alloc ipw2200 e1000
[   85.868282] 
[   85.868290] Pid: 4973, comm: ipcs Not tainted (2.6.24.3test-dirty #19)
[   85.868302] EIP: 0060:[<c0133034>] EFLAGS: 00010086 CPU: 0
[   85.868315] EIP is at __lock_acquire+0x319/0xc20
[   85.868323] EAX: 00000002 EBX: 00000246 ECX: def4e4d4 EDX: 00000002
[   85.868331] ESI: ffffffff EDI: 00000000 EBP: d8fcfe7c ESP: d8fcfe20
[   85.868339]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[   85.868347] Process ipcs (pid: 4973, ti=d8fce000 task=dd96d0d0 task.ti=d8fce000)
[   85.868354] Stack: c01338f4 d8fcfe88 c01338f4 d8fcfe4c 00000347 00000000 00000002 00000000 
[   85.868421]        00000000 def4e4d4 00000000 dd96d0d0 00000001 dd96d728 d8fcfebc c01338f4 
[   85.868491]        00000000 dd96d728 00000347 00000000 00000246 00000000 00000000 d8fcfea4 
[   85.868553] Call Trace:
[   85.868565]  [<c0103e9f>] show_trace_log_lvl+0x1a/0x2f
[   85.868582]  [<c0103f51>] show_stack_log_lvl+0x9d/0xa5
[   85.868606]  [<c0104006>] show_registers+0xad/0x17c
[   85.868620]  [<c01041cc>] die+0xf7/0x1c8
[   85.868633]  [<c0110e31>] do_page_fault+0x464/0x54b
[   85.868648]  [<c036259a>] error_code+0x6a/0x70
[   85.868667]  [<c01339b3>] lock_acquire+0x78/0x91
[   85.868680]  [<c0361f65>] _spin_lock+0x2e/0x58
[   85.868693]  [<c01dc5a6>] sys_shmctl+0x6f8/0x776
[   85.868713]  [<c0106d33>] sys_ipc+0x19f/0x1b5
[   85.868727]  [<c0102fa6>] syscall_call+0x7/0xb
[   85.868740]  =======================
[   85.868747] Code: 00 85 c0 0f 84 1d 09 00 00 83 3d 20 b4 78 c0 00 0f 85 10 09 00 00 c7 44 24 0c c8 ad 36 c0 c7 44 24 08 26 03 00 00 e9 8b 07 00 00 <ff> 86 c0 00 00 00 8b 45 d0 8b 80 54 06 00 00 83 f8 1d 89 45 cc 
[   85.869152] EIP: [<c0133034>] __lock_acquire+0x319/0xc20 SS:ESP 0068:d8fcfe20
[   85.869179] ---[ end trace 807f13dee3166302 ]---

[-- Attachment #4: ipcs.kernel.out.2 --]
[-- Type: text/plain, Size: 7075 bytes --]

[  111.659866] BUG: soft lockup - CPU#0 stuck for 11s! [ipcs:4979]
[  111.659881] 
[  111.659889] Pid: 4979, comm: ipcs Tainted: G      D (2.6.24.3test-dirty #19)
[  111.659898] EIP: 0060:[<c01f2672>] EFLAGS: 00000246 CPU: 0
[  111.659911] EIP is at delay_tsc+0xe/0x17
[  111.659919] EAX: 98b6bb8f EBX: 00000001 ECX: 98b6bb5c EDX: 00000029
[  111.659927] ESI: 093ca0bf EDI: 00000001 EBP: d8f63e70 ESP: d8f63e6c
[  111.659935]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  111.659943] CR0: 8005003b CR2: 08053c30 CR3: 1e86c000 CR4: 000006d0
[  111.659951] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  111.659959] DR6: ffff0ff0 DR7: 00000400
[  111.659967]  [<c0103e9f>] show_trace_log_lvl+0x1a/0x2f
[  111.659985]  [<c0104784>] show_trace+0x12/0x14
[  111.659998]  [<c010163e>] show_regs+0x1c/0x1f
[  111.660011]  [<c013b9f8>] softlockup_tick+0xce/0xe7
[  111.660026]  [<c01202a7>] run_local_timers+0x12/0x14
[  111.660042]  [<c01204b6>] update_process_times+0x1b/0x3f
[  111.660056]  [<c012f3a3>] tick_periodic+0x65/0x71
[  111.660072]  [<c012f3c1>] tick_handle_periodic+0x12/0x61
[  111.660088]  [<c0105d27>] timer_interrupt+0x37/0x3e
[  111.660103]  [<c013bcae>] handle_IRQ_event+0x1a/0x46
[  111.660118]  [<c013d0e3>] handle_level_irq+0x6f/0xb8
[  111.660132]  [<c010517a>] do_IRQ+0x78/0x8f
[  111.660145]  [<c01039b6>] common_interrupt+0x2e/0x34
[  111.660159]  [<c01f2649>] __delay+0x9/0xb
[  111.660173]  [<c01ffe19>] _raw_spin_lock+0x7f/0xd8
[  111.660190]  [<c0361f81>] _spin_lock+0x4a/0x58
[  111.660207]  [<c01dc5a6>] sys_shmctl+0x6f8/0x776
[  111.660223]  [<c0106d33>] sys_ipc+0x19f/0x1b5
[  111.660237]  [<c0102fa6>] syscall_call+0x7/0xb
[  111.660253]  =======================
[  114.335266] ipw2200: Firmware error detected.  Restarting.
[  114.814862] ipw2200: Firmware error detected.  Restarting.
[  123.462514] BUG: soft lockup - CPU#0 stuck for 11s! [ipcs:4979]
[  123.462522] 
[  123.462529] Pid: 4979, comm: ipcs Tainted: G      D (2.6.24.3test-dirty #19)
[  123.462537] EIP: 0060:[<c01f266e>] EFLAGS: 00000246 CPU: 0
[  123.462545] EIP is at delay_tsc+0xa/0x17
[  123.462553] EAX: fe4d63d4 EBX: 00000001 ECX: fe4d63d4 EDX: 0000002d
[  123.462561] ESI: 1316f741 EDI: 00000001 EBP: d8f63e70 ESP: d8f63e6c
[  123.462569]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  123.462576] CR0: 8005003b CR2: 08053c30 CR3: 1e86c000 CR4: 000006d0
[  123.462584] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  123.462591] DR6: ffff0ff0 DR7: 00000400
[  123.462598]  [<c0103e9f>] show_trace_log_lvl+0x1a/0x2f
[  123.462612]  [<c0104784>] show_trace+0x12/0x14
[  123.462626]  [<c010163e>] show_regs+0x1c/0x1f
[  123.462639]  [<c013b9f8>] softlockup_tick+0xce/0xe7
[  123.462653]  [<c01202a7>] run_local_timers+0x12/0x14
[  123.462667]  [<c01204b6>] update_process_times+0x1b/0x3f
[  123.462681]  [<c012f3a3>] tick_periodic+0x65/0x71
[  123.462696]  [<c012f3c1>] tick_handle_periodic+0x12/0x61
[  123.462710]  [<c0105d27>] timer_interrupt+0x37/0x3e
[  123.462724]  [<c013bcae>] handle_IRQ_event+0x1a/0x46
[  123.462738]  [<c013d0e3>] handle_level_irq+0x6f/0xb8
[  123.462751]  [<c010517a>] do_IRQ+0x78/0x8f
[  123.462765]  [<c01039b6>] common_interrupt+0x2e/0x34
[  123.462779]  [<c01f2649>] __delay+0x9/0xb
[  123.462792]  [<c01ffe19>] _raw_spin_lock+0x7f/0xd8
[  123.462806]  [<c0361f81>] _spin_lock+0x4a/0x58
[  123.462819]  [<c01dc5a6>] sys_shmctl+0x6f8/0x776
[  123.462833]  [<c0106d33>] sys_ipc+0x19f/0x1b5
[  123.462846]  [<c0102fa6>] syscall_call+0x7/0xb
[  123.462859]  =======================
[  147.063819] BUG: soft lockup - CPU#0 stuck for 11s! [ipcs:4979]
[  147.063827]
[  147.063834] Pid: 4979, comm: ipcs Tainted: G      D (2.6.24.3test-dirty #19)
[  147.063842] EIP: 0060:[<c01f266c>] EFLAGS: 00000246 CPU: 0
[  147.063850] EIP is at delay_tsc+0x8/0x17
[  147.063858] EAX: c9192061 EBX: 00000001 ECX: c9191fef EDX: 00000036
[  147.063866] ESI: 26cb024e EDI: 00000001 EBP: d8f63e70 ESP: d8f63e6c
[  147.063873]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  147.063881] CR0: 8005003b CR2: 08053c30 CR3: 1e86c000 CR4: 000006d0
[  147.063889] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  147.063896] DR6: ffff0ff0 DR7: 00000400
[  147.063903]  [<c0103e9f>] show_trace_log_lvl+0x1a/0x2f
[  147.063917]  [<c0104784>] show_trace+0x12/0x14
[  147.063930]  [<c010163e>] show_regs+0x1c/0x1f
[  147.063944]  [<c013b9f8>] softlockup_tick+0xce/0xe7
[  147.063958]  [<c01202a7>] run_local_timers+0x12/0x14
[  147.063972]  [<c01204b6>] update_process_times+0x1b/0x3f
[  147.063986]  [<c012f3a3>] tick_periodic+0x65/0x71
[  147.064000]  [<c012f3c1>] tick_handle_periodic+0x12/0x61
[  147.064014]  [<c0105d27>] timer_interrupt+0x37/0x3e
[  147.064027]  [<c013bcae>] handle_IRQ_event+0x1a/0x46
[  147.064041]  [<c013d0e3>] handle_level_irq+0x6f/0xb8
[  147.064055]  [<c010517a>] do_IRQ+0x78/0x8f
[  147.064068]  [<c01039b6>] common_interrupt+0x2e/0x34
[  147.064081]  [<c01f2649>] __delay+0x9/0xb
[  147.064095]  [<c01ffe19>] _raw_spin_lock+0x7f/0xd8
[  147.064109]  [<c0361f81>] _spin_lock+0x4a/0x58
[  147.064122]  [<c01dc5a6>] sys_shmctl+0x6f8/0x776
[  147.064135]  [<c0106d33>] sys_ipc+0x19f/0x1b5
[  147.064148]  [<c0102fa6>] syscall_call+0x7/0xb
[  147.064162]  =======================
[  158.862473] BUG: soft lockup - CPU#0 stuck for 11s! [ipcs:4979]
[  158.862481]
[  158.862488] Pid: 4979, comm: ipcs Tainted: G      D (2.6.24.3test-dirty #19)
[  158.862496] EIP: 0060:[<c01f2674>] EFLAGS: 00000206 CPU: 0
[  158.862504] EIP is at delay_tsc+0x10/0x17
[  158.862511] EAX: 00000033 EBX: 00000001 ECX: 2e4e3416 EDX: 0000003b
[  158.862519] ESI: 30a4aa86 EDI: 00000001 EBP: d8f63e70 ESP: d8f63e6c
[  158.862527]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  158.862535] CR0: 8005003b CR2: 08053c30 CR3: 1e86c000 CR4: 000006d0
[  158.862542] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  158.862550] DR6: ffff0ff0 DR7: 00000400
[  158.862556]  [<c0103e9f>] show_trace_log_lvl+0x1a/0x2f
[  158.862570]  [<c0104784>] show_trace+0x12/0x14
[  158.862584]  [<c010163e>] show_regs+0x1c/0x1f
[  158.862598]  [<c013b9f8>] softlockup_tick+0xce/0xe7
[  158.862611]  [<c01202a7>] run_local_timers+0x12/0x14
[  158.862625]  [<c01204b6>] update_process_times+0x1b/0x3f
[  158.862640]  [<c012f3a3>] tick_periodic+0x65/0x71
[  158.862654]  [<c012f3c1>] tick_handle_periodic+0x12/0x61
[  158.862667]  [<c0105d27>] timer_interrupt+0x37/0x3e
[  158.862681]  [<c013bcae>] handle_IRQ_event+0x1a/0x46
[  158.862694]  [<c013d0e3>] handle_level_irq+0x6f/0xb8
[  158.862708]  [<c010517a>] do_IRQ+0x78/0x8f
[  158.862722]  [<c01039b6>] common_interrupt+0x2e/0x34
[  158.862735]  [<c01f2649>] __delay+0x9/0xb
[  158.862749]  [<c01ffe19>] _raw_spin_lock+0x7f/0xd8
[  158.862763]  [<c0361f81>] _spin_lock+0x4a/0x58
[  158.862776]  [<c01dc5a6>] sys_shmctl+0x6f8/0x776
[  158.862789]  [<c0106d33>] sys_ipc+0x19f/0x1b5
[  158.862802]  [<c0102fa6>] syscall_call+0x7/0xb
[  158.862817]  =======================

  reply	other threads:[~2008-03-03 12:01 UTC|newest]

Thread overview: 19+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2008-02-29 10:46 Jiri Olsa
2008-02-29 10:57 ` Andrew Morton
2008-02-29 11:01   ` Jiri Olsa
2008-02-29 11:29     ` Andrew Morton
2008-02-29 11:35       ` Jiri Olsa
2008-02-29 11:43 ` Jiri Kosina
2008-03-02 17:45   ` Jiri Olsa
2008-03-02 20:02     ` Andrew Morton
2008-03-02 21:23       ` Jiri Kosina
2008-03-02 21:26         ` Jiri Kosina
2008-03-03 12:00           ` Jiri Olsa [this message]
2008-03-03 12:06             ` Jiri Kosina
2008-03-03 12:19               ` Jiri Olsa
2008-03-03 12:28                 ` Jiri Kosina
2008-03-03 12:38                   ` Jiri Olsa
2008-03-03 14:04                     ` Jiri Olsa
2008-03-03 14:45                       ` Jiri Kosina
2008-03-04  9:56                         ` Jiri Olsa
2008-03-04 12:57                           ` Jiri Olsa

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=47CBE871.4090309@gmail.com \
    --to=olsajiri@gmail.com \
    --cc=Nadia.Derbey@bull.net \
    --cc=akpm@linux-foundation.org \
    --cc=jkosina@suse.cz \
    --cc=linux-kernel@vger.kernel.org \
    --cc=peifferp@gmail.com \
    --subject='Re: [BUG] soft lockup detected with ipcs' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).