* BUG: Null pointer dereference (2.6.21-rc7)
@ 2007-04-22 23:13 William Heimbigner
2007-04-23 8:00 ` Andrew Morton
0 siblings, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-22 23:13 UTC (permalink / raw)
To: linux-kernel
On running "pktsetup 0 /dev/hdd", I get the following:
[ 3970.461403] =============================================
[ 3970.482051] [ INFO: possible recursive locking detected ]
[ 3970.498210] 2.6.21-rc7 #2
[ 3970.506062] ---------------------------------------------
[ 3970.522228] vol_id/8686 is trying to acquire lock:
[ 3970.536576] (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
[ 3970.557104]
[ 3970.557109] but task is already holding lock:
[ 3970.574627] (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
[ 3970.595160]
[ 3970.595161] other info that might help us debug this:
[ 3970.614757] 2 locks held by vol_id/8686:
[ 3970.626505] #0: (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
[ 3970.648388] #1: (&ctl_mutex#2){--..}, at: [<c03d6b54>] mutex_lock+0x1c/0x1f
[ 3970.670065]
[ 3970.670070] stack backtrace:
[ 3970.683165] [<c0104df5>] show_trace_log_lvl+0x1a/0x2f
[ 3970.698604] [<c010544b>] show_trace+0x12/0x14
[ 3970.711964] [<c01054fd>] dump_stack+0x16/0x18
[ 3970.725322] [<c013150a>] __lock_acquire+0x12e/0xb93
[ 3970.740243] [<c0131fd7>] lock_acquire+0x68/0x82
[ 3970.754122] [<c03d6c46>] mutex_lock_nested+0xef/0x275
[ 3970.769560] [<c01826b2>] do_open+0x65/0x285
[ 3970.782397] [<c0182945>] __blkdev_get+0x73/0x7e
[ 3970.796279] [<c0182965>] blkdev_get+0x15/0x17
[ 3970.809638] [<c027dbde>] pkt_open+0x95/0xc4e
[ 3970.822737] [<c01826e1>] do_open+0x94/0x285
[ 3970.835578] [<c0182a93>] blkdev_open+0x28/0x51
[ 3970.849196] [<c0161918>] __dentry_open+0xff/0x1b1
[ 3970.863594] [<c0161a4b>] nameidata_to_filp+0x27/0x37
[ 3970.878770] [<c0161a8e>] do_filp_open+0x33/0x3b
[ 3970.892654] [<c0161ad9>] do_sys_open+0x43/0xc2
[ 3970.906274] [<c0161b90>] sys_open+0x1c/0x1e
[ 3970.919113] [<c0103e24>] sysenter_past_esp+0x5d/0x99
[ 3970.934292] =======================
[ 3971.630710] pktcdvd: pkt_get_last_written failed
[ 3971.645027] BUG: unable to handle kernel NULL pointer dereference at virtual address 0000000e
[ 3971.670652] printing eip:
[ 3971.678786] c0161aef
[ 3971.685361] *pde = 00000000
[ 3971.693761] Oops: 0000 [#1]
[ 3971.702120] PREEMPT
[ 3971.708722] Modules linked in: udf snd_intel8x0 snd_ac97_codec ac97_bus i810_audio ac97_codec 8139cp 8139too iTCO_wdt
[ 3971.741005] CPU: 0
[ 3971.741006] EIP: 0060:[<c0161aef>] Not tainted VLI
[ 3971.741008] EFLAGS: 00010203 (2.6.21-rc7 #2)
[ 3971.777034] EIP is at do_sys_open+0x59/0xc2
[ 3971.789555] eax: 00000002 ebx: 00008000 ecx: c0182a6b edx: dc8df650
[ 3971.809878] esi: ffffff9c edi: 00000002 ebp: de336fa4 esp: de336f88
[ 3971.830200] ds: 007b es: 007b fs: 00d8 gs: 0033 ss: 0068
[ 3971.847674] Process vol_id (pid: 8686, ti=de336000 task=d0b90de0 task.ti=de336000)
[ 3971.869812] Stack: 00000000 00000000 cef97000 00000003 bf9d7f65 00008000 b7facff4 de336fb0
[ 3971.895286] c0161b90 00000000 de336000 c0103e24 bf9d7f65 00008000 00000000 00008000
[ 3971.920755] b7facff4 bf9d5e08 00000005 0000007b 0000007b 00000000 00000005 ffffe410
[ 3971.946228] Call Trace:
[ 3971.954126] [<c0104df5>] show_trace_log_lvl+0x1a/0x2f
[ 3971.969563] [<c0104ea7>] show_stack_log_lvl+0x9d/0xa5
[ 3971.985004] [<c01050aa>] show_registers+0x1fb/0x33c
[ 3971.999924] [<c01052f2>] die+0x107/0x21f
[ 3972.011984] [<c03d9d20>] do_page_fault+0x448/0x520
[ 3972.026644] [<c03d8594>] error_code+0x74/0x7c
[ 3972.040003] [<c0161b90>] sys_open+0x1c/0x1e
[ 3972.052841] [<c0103e24>] sysenter_past_esp+0x5d/0x99
[ 3972.068022] =======================
[ 3972.078728] Code: f0 78 7e 8b 45 08 89 d9 8b 55 ec 89 04 24 89 f0 e8 82 ff ff ff 3d 00 f0 ff ff 89 c7 76 0d 8b 45 f0 e8 dc fb ff ff 89 7d f0 eb 56 <8b> 40 0c bb 20 00 00 40 8b 70 30 0f b7 56 66 81 e2 00 f0 00 00
[ 3972.138557] EIP: [<c0161aef>] do_sys_open+0x59/0xc2 SS:ESP 0068:de336f88
Is this a bug?
If any more information is necessary, I'd be happy to provide it.
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference (2.6.21-rc7)
2007-04-22 23:13 BUG: Null pointer dereference (2.6.21-rc7) William Heimbigner
@ 2007-04-23 8:00 ` Andrew Morton
2007-04-23 13:58 ` William Heimbigner
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Morton @ 2007-04-23 8:00 UTC (permalink / raw)
To: William Heimbigner; +Cc: linux-kernel, Peter Osterlund
On Sun, 22 Apr 2007 23:13:54 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> On running "pktsetup 0 /dev/hdd", I get the following:
>
> [ 3970.461403] =============================================
> [ 3970.482051] [ INFO: possible recursive locking detected ]
> [ 3970.498210] 2.6.21-rc7 #2
> [ 3970.506062] ---------------------------------------------
> [ 3970.522228] vol_id/8686 is trying to acquire lock:
> [ 3970.536576] (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
> [ 3970.557104]
> [ 3970.557109] but task is already holding lock:
> [ 3970.574627] (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
> [ 3970.595160]
> [ 3970.595161] other info that might help us debug this:
> [ 3970.614757] 2 locks held by vol_id/8686:
> [ 3970.626505] #0: (&bdev->bd_mutex){--..}, at: [<c01826b2>] do_open+0x65/0x285
> [ 3970.648388] #1: (&ctl_mutex#2){--..}, at: [<c03d6b54>] mutex_lock+0x1c/0x1f
> [ 3970.670065]
> [ 3970.670070] stack backtrace:
> [ 3970.683165] [<c0104df5>] show_trace_log_lvl+0x1a/0x2f
> [ 3970.698604] [<c010544b>] show_trace+0x12/0x14
> [ 3970.711964] [<c01054fd>] dump_stack+0x16/0x18
> [ 3970.725322] [<c013150a>] __lock_acquire+0x12e/0xb93
> [ 3970.740243] [<c0131fd7>] lock_acquire+0x68/0x82
> [ 3970.754122] [<c03d6c46>] mutex_lock_nested+0xef/0x275
> [ 3970.769560] [<c01826b2>] do_open+0x65/0x285
> [ 3970.782397] [<c0182945>] __blkdev_get+0x73/0x7e
> [ 3970.796279] [<c0182965>] blkdev_get+0x15/0x17
> [ 3970.809638] [<c027dbde>] pkt_open+0x95/0xc4e
> [ 3970.822737] [<c01826e1>] do_open+0x94/0x285
> [ 3970.835578] [<c0182a93>] blkdev_open+0x28/0x51
> [ 3970.849196] [<c0161918>] __dentry_open+0xff/0x1b1
> [ 3970.863594] [<c0161a4b>] nameidata_to_filp+0x27/0x37
> [ 3970.878770] [<c0161a8e>] do_filp_open+0x33/0x3b
> [ 3970.892654] [<c0161ad9>] do_sys_open+0x43/0xc2
> [ 3970.906274] [<c0161b90>] sys_open+0x1c/0x1e
> [ 3970.919113] [<c0103e24>] sysenter_past_esp+0x5d/0x99
> [ 3970.934292] =======================
> [ 3971.630710] pktcdvd: pkt_get_last_written failed
> [ 3971.645027] BUG: unable to handle kernel NULL pointer dereference at virtual address 0000000e
> [ 3971.670652] printing eip:
> [ 3971.678786] c0161aef
> [ 3971.685361] *pde = 00000000
> [ 3971.693761] Oops: 0000 [#1]
> [ 3971.702120] PREEMPT
> [ 3971.708722] Modules linked in: udf snd_intel8x0 snd_ac97_codec ac97_bus i810_audio ac97_codec 8139cp 8139too iTCO_wdt
> [ 3971.741005] CPU: 0
> [ 3971.741006] EIP: 0060:[<c0161aef>] Not tainted VLI
> [ 3971.741008] EFLAGS: 00010203 (2.6.21-rc7 #2)
> [ 3971.777034] EIP is at do_sys_open+0x59/0xc2
> [ 3971.789555] eax: 00000002 ebx: 00008000 ecx: c0182a6b edx: dc8df650
> [ 3971.809878] esi: ffffff9c edi: 00000002 ebp: de336fa4 esp: de336f88
> [ 3971.830200] ds: 007b es: 007b fs: 00d8 gs: 0033 ss: 0068
> [ 3971.847674] Process vol_id (pid: 8686, ti=de336000 task=d0b90de0 task.ti=de336000)
> [ 3971.869812] Stack: 00000000 00000000 cef97000 00000003 bf9d7f65 00008000 b7facff4 de336fb0
> [ 3971.895286] c0161b90 00000000 de336000 c0103e24 bf9d7f65 00008000 00000000 00008000
> [ 3971.920755] b7facff4 bf9d5e08 00000005 0000007b 0000007b 00000000 00000005 ffffe410
> [ 3971.946228] Call Trace:
> [ 3971.954126] [<c0104df5>] show_trace_log_lvl+0x1a/0x2f
> [ 3971.969563] [<c0104ea7>] show_stack_log_lvl+0x9d/0xa5
> [ 3971.985004] [<c01050aa>] show_registers+0x1fb/0x33c
> [ 3971.999924] [<c01052f2>] die+0x107/0x21f
> [ 3972.011984] [<c03d9d20>] do_page_fault+0x448/0x520
> [ 3972.026644] [<c03d8594>] error_code+0x74/0x7c
> [ 3972.040003] [<c0161b90>] sys_open+0x1c/0x1e
> [ 3972.052841] [<c0103e24>] sysenter_past_esp+0x5d/0x99
> [ 3972.068022] =======================
> [ 3972.078728] Code: f0 78 7e 8b 45 08 89 d9 8b 55 ec 89 04 24 89 f0 e8 82 ff ff ff 3d 00 f0 ff ff 89 c7 76 0d 8b 45 f0 e8 dc fb ff ff 89 7d f0 eb 56 <8b> 40 0c bb 20 00 00 40 8b 70 30 0f b7 56 66 81 e2 00 f0 00 00
> [ 3972.138557] EIP: [<c0161aef>] do_sys_open+0x59/0xc2 SS:ESP 0068:de336f88
>
> Is this a bug?
>
It certainly is. Are you able to identify an earlier kernel in which this
didn't happen? 2.6.20? An earlier 2.6.21-rcX?
Thanks.
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference (2.6.21-rc7)
2007-04-23 8:00 ` Andrew Morton
@ 2007-04-23 13:58 ` William Heimbigner
2007-04-23 16:39 ` William Heimbigner
0 siblings, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-23 13:58 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Peter Osterlund
On Mon, 23 Apr 2007, Andrew Morton wrote:
> It certainly is. Are you able to identify an earlier kernel in which this
> didn't happen? 2.6.20? An earlier 2.6.21-rcX?
I'll try .18 and .20 and see where that gets me - this is my first time
trying to set up packet writing.
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference (2.6.21-rc7)
2007-04-23 13:58 ` William Heimbigner
@ 2007-04-23 16:39 ` William Heimbigner
2007-04-24 4:09 ` BUG: Null pointer dereference in fs/open.c William Heimbigner
0 siblings, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-23 16:39 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Peter Osterlund
On Mon, 23 Apr 2007, William Heimbigner wrote:
> On Mon, 23 Apr 2007, Andrew Morton wrote:
>> It certainly is. Are you able to identify an earlier kernel in which this
>> didn't happen? 2.6.20? An earlier 2.6.21-rcX?
>
> I'll try .18 and .20 and see where that gets me - this is my first time
> trying to set up packet writing.
Ok, on 2.6.18, I still get the warning about a recursive lock, but no dump
regarding a null pointer dereference. The command still fails, however,
with pkt_get_last_written_failed. On 2.6.20, I get an error similar to the
one I orignally posted (first the recursive lock warning, seconds later,
null pointer dereference).
Not sure about the recursive lock, but something between .18 and .20
happened such that the packet writing driver didn't fail gracefully.
On a side (offtopic) note, I noticed that ACPI support changed for the
better in very recent kernels - on both .18 and .20, there were severe
and early errors unless I specified acpi=off
I'll see if I can figure out exactly where from 2.6.18 to .20 things went
wrong,
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-23 16:39 ` William Heimbigner
@ 2007-04-24 4:09 ` William Heimbigner
[not found] ` <20070423215810.5a24ed9a.akpm@linux-foundation.org>
0 siblings, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-24 4:09 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Peter Osterlund
This bug occurs in linux-2.6.20 and 2.6.21-rc7-git5, and does not occur in
linux-2.6.19-git22.
After running "pktsetup 0 /dev/hdd", I get (timestamps removed):
pktcdvd: pkt_get_last_written failed
BUG: unable to handle kernel NULL pointer dereference at virtual address 0000000e
printing eip:
c0173f69
*pde = 00000000
Oops: 0000 [#1]
PREEMPT
Modules linked in: snd_ca0106 snd_ac97_codec ac97_bus 8139cp 8139too iTCO_wdt
CPU: 0
EIP: 0060:[<c0173f69>] Not tainted VLI
EFLAGS: 00010203 (2.6.21-rc7-git5 #22)
EIP is at do_sys_open+0x59/0xd0
eax: 00000002 ebx: 40000020 ecx: 00000001 edx: 00000002
esi: df1e3000 edi: 00000003 ebp: de17bfa4 esp: de17bf84
ds: 007b es: 007b fs: 00d8 gs: 0033 ss: 0068
Process vol_id (pid: 4273, ti=de17b000 task=df4143f0 task.ti=de17b000)
Stack: 00000000 c013d2a5 ffffff9c 00000002 c059cea3 bfb6bf64 00008000 b7f60ff4
de17bfb0 c017401c 00000000 de17b000 c01041c6 bfb6bf64 00008000 00000000
00008000 b7f60ff4 bfb6a798 00000005 0000007b 0000007b 00000000 00000005
Call Trace:
[<c010521a>] show_trace_log_lvl+0x1a/0x30
[<c01052d9>] show_stack_log_lvl+0xa9/0xd0
[<c010551c>] show_registers+0x21c/0x3a0
[<c01057a4>] die+0x104/0x260
[<c04c5947>] do_page_fault+0x277/0x610
[<c04c408c>] error_code+0x74/0x7c
[<c017401c>] sys_open+0x1c/0x20
[<c01041c6>] sysenter_past_esp+0x5f/0x99
=======================
Code: ff 85 c0 89 c7 78 77 8b 45 08 89 d9 89 f2 89 04 24 8b 45 e8 e8 69 ff
ff ff 3d 00 f0 ff ff 89 45 ec 77 71 8b 55 ec bb 20 00 00 40 <8b> 42 0c 8b
48 30 89 4d f0 0f b7 51 66 81 e2 00 f0 00 00 81 fa
EIP: [<c0173f69>] do_sys_open+0x59/0xd0 SS:ESP 0068:de17bf84
from fs/open.c, comments added:
// do_sys_open is consistently called with dfd=0xffffff9c,
// filename="/dev/.tmp-254-0", flags=0x8000, mode=0)
long do_sys_open(int dfd, const char __user *filename, int flags, int mode)
{
char *tmp = getname(filename);
int fd = PTR_ERR(tmp);
if (!IS_ERR(tmp)) {
fd = get_unused_fd();
if (fd >= 0) {
// do_filp_open consistently returns 2, in this case
struct file *f = do_filp_open(dfd, tmp, flags, mode);
// IS_ERR always returns 0 for this command
if (IS_ERR(f)) {
put_unused_fd(fd);
fd = PTR_ERR(f);
} else {
// null pointer dereference occurs here
fsnotify_open(f->f_path.dentry);
fd_install(fd, f);
}
}
putname(tmp);
}
return fd;
}
I was able to workaround this, by testing if do_filp_open was returning
2 or not, but obviously this is a very temporal solution to a very
specific circumstance.
If there is any more information I can provide, let me know.
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
[not found] ` <20070423215810.5a24ed9a.akpm@linux-foundation.org>
@ 2007-04-24 5:10 ` William Heimbigner
2007-04-24 5:17 ` Andrew Morton
2007-04-24 20:46 ` Peter Osterlund
1 sibling, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-24 5:10 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Peter Osterlund, Jens Axboe
On Mon, 23 Apr 2007, Andrew Morton wrote:
> On Tue, 24 Apr 2007 04:09:18 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
>
>> This bug occurs in linux-2.6.20 and 2.6.21-rc7-git5, and does not occur in
>> linux-2.6.19-git22.
>>
>> After running "pktsetup 0 /dev/hdd", I get (timestamps removed):
>>
>> pktcdvd: pkt_get_last_written failed
>> BUG: unable to handle kernel NULL pointer dereference at virtual address 0000000e
>> printing eip:
>> c0173f69
>> *pde = 00000000
>> Oops: 0000 [#1]
>> PREEMPT
>> Modules linked in: snd_ca0106 snd_ac97_codec ac97_bus 8139cp 8139too iTCO_wdt
>> CPU: 0
>> EIP: 0060:[<c0173f69>] Not tainted VLI
>> EFLAGS: 00010203 (2.6.21-rc7-git5 #22)
>> EIP is at do_sys_open+0x59/0xd0
>> eax: 00000002 ebx: 40000020 ecx: 00000001 edx: 00000002
>> esi: df1e3000 edi: 00000003 ebp: de17bfa4 esp: de17bf84
>> ds: 007b es: 007b fs: 00d8 gs: 0033 ss: 0068
>> Process vol_id (pid: 4273, ti=de17b000 task=df4143f0 task.ti=de17b000)
>> Stack: 00000000 c013d2a5 ffffff9c 00000002 c059cea3 bfb6bf64 00008000 b7f60ff4
>> de17bfb0 c017401c 00000000 de17b000 c01041c6 bfb6bf64 00008000 00000000
>> 00008000 b7f60ff4 bfb6a798 00000005 0000007b 0000007b 00000000 00000005
>> Call Trace:
>> [<c010521a>] show_trace_log_lvl+0x1a/0x30
>> [<c01052d9>] show_stack_log_lvl+0xa9/0xd0
>> [<c010551c>] show_registers+0x21c/0x3a0
>> [<c01057a4>] die+0x104/0x260
>> [<c04c5947>] do_page_fault+0x277/0x610
>> [<c04c408c>] error_code+0x74/0x7c
>> [<c017401c>] sys_open+0x1c/0x20
>> [<c01041c6>] sysenter_past_esp+0x5f/0x99
>> =======================
>> Code: ff 85 c0 89 c7 78 77 8b 45 08 89 d9 89 f2 89 04 24 8b 45 e8 e8 69 ff
>> ff ff 3d 00 f0 ff ff 89 45 ec 77 71 8b 55 ec bb 20 00 00 40 <8b> 42 0c 8b
>> 48 30 89 4d f0 0f b7 51 66 81 e2 00 f0 00 00 81 fa
>> EIP: [<c0173f69>] do_sys_open+0x59/0xd0 SS:ESP 0068:de17bf84
>
> Try this:
>
> --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
> +++ a/drivers/block/pktcdvd.c
> @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
> rq->cmd_flags |= REQ_QUIET;
>
> blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
> - ret = rq->errors;
> + if (rq->errors)
> + ret = -EIO;
> out:
> blk_put_request(rq);
> return ret;
> _
This patch fixes (or conceals?) the oops.
>
>
> The packet driver was assuming that request.errors is an errno, but it
> isn't - it's some sort of diagnostic bitfield thing. Now why would the
> packet driver have though that? Let's go read the comments:
>
> unsigned short nr_hw_segments;
>
> unsigned short ioprio;
>
> void *special;
> char *buffer;
>
> int tag;
> int errors;
>
> int ref_count;
>
>
> Well there's your root cause right there.
>
>
> I don't know why this wasn't oopsing in eariler kernels. Perhaps something
> else is broken. Please test this urgently.
>
>
> There's a locking problem in there too. `pktsetup 0 /dev/scd0' gives me
>
> [ 77.720000] pktcdvd: writer pktcdvd0 mapped to sr0
> [ 77.860000]
> [ 77.860000] =============================================
> [ 77.860000] [ INFO: possible recursive locking detected ]
> [ 77.860000] 2.6.21-rc7 #19
> [ 77.860000] ---------------------------------------------
> [ 77.860000] vol_id/2508 is trying to acquire lock:
> [ 77.860000] (&bdev->bd_mutex){--..}, at: [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000]
> [ 77.860000] but task is already holding lock:
> [ 77.860000] (&bdev->bd_mutex){--..}, at: [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000]
> [ 77.860000] other info that might help us debug this:
> [ 77.860000] 2 locks held by vol_id/2508:
> [ 77.860000] #0: (&bdev->bd_mutex){--..}, at: [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] #1: (&ctl_mutex#2){--..}, at: [<f8dc6986>] pkt_open+0x1a/0xcbc [pktcdvd]
> [ 77.860000]
> [ 77.860000] stack backtrace:
> [ 77.860000] [<c01323c1>] __lock_acquire+0x11e/0xb3b
> [ 77.860000] [<c02efe4e>] __mutex_unlock_slowpath+0x109/0x113
> [ 77.860000] [<c0132166>] trace_hardirqs_on+0x11e/0x141
> [ 77.860000] [<c0132e34>] lock_acquire+0x56/0x6e
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c02f01a5>] mutex_lock_nested+0xf4/0x24f
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c024020c>] kobj_lookup+0xda/0x104
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c018184a>] __blkdev_get+0x5b/0x66
> [ 77.860000] [<c0181867>] blkdev_get+0x12/0x14
> [ 77.860000] [<f8dc69f9>] pkt_open+0x8d/0xcbc [pktcdvd]
> [ 77.860000] [<c0170949>] __d_lookup+0x66/0xed
> [ 77.860000] [<c0170949>] __d_lookup+0x66/0xed
> [ 77.860000] [<c01ce919>] _atomic_dec_and_lock+0xd/0x2c
> [ 77.860000] [<c01ce919>] _atomic_dec_and_lock+0xd/0x2c
> [ 77.860000] [<c01ce919>] _atomic_dec_and_lock+0xd/0x2c
> [ 77.860000] [<c015f655>] cache_alloc_refill+0x4a/0x444
> [ 77.860000] [<c0240165>] kobj_lookup+0x33/0x104
> [ 77.860000] [<c0132166>] trace_hardirqs_on+0x11e/0x141
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c02f007f>] __mutex_lock_slowpath+0x222/0x235
> [ 77.860000] [<c02f02ed>] mutex_lock_nested+0x23c/0x24f
> [ 77.860000] [<c0131f85>] mark_held_locks+0x46/0x62
> [ 77.860000] [<c02f02ed>] mutex_lock_nested+0x23c/0x24f
> [ 77.860000] [<c02f02ed>] mutex_lock_nested+0x23c/0x24f
> [ 77.860000] [<c0132166>] trace_hardirqs_on+0x11e/0x141
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c02f02f8>] mutex_lock_nested+0x247/0x24f
> [ 77.860000] [<c01815e2>] do_open+0x5a/0x267
> [ 77.860000] [<c024020c>] kobj_lookup+0xda/0x104
> [ 77.860000] [<c018160f>] do_open+0x87/0x267
> [ 77.860000] [<c0181977>] blkdev_open+0x0/0x4d
> [ 77.860000] [<c018199c>] blkdev_open+0x25/0x4d
> [ 77.860000] [<c0160b77>] __dentry_open+0xb8/0x16e
> [ 77.860000] [<c0160ca7>] nameidata_to_filp+0x24/0x33
> [ 77.860000] [<c0160ce8>] do_filp_open+0x32/0x39
> [ 77.860000] [<c02f1232>] _spin_unlock+0x14/0x1c
> [ 77.860000] [<c0160ab5>] get_unused_fd+0xaa/0xb4
> [ 77.860000] [<c01619da>] do_sys_open+0x42/0xbe
> [ 77.860000] [<c0161a8f>] sys_open+0x1c/0x1e
> [ 77.860000] [<c0103c58>] syscall_call+0x7/0xb
> [ 77.860000] =======================
> [ 77.900000] pktcdvd: pkt_get_last_written failed
>
> What the heck _is_ in request.errors?
>
> Should the packet driver even be looking at it?
>
I got a similar recursive lock warning too, though I hadn't included it in
the last message:
[10349.402613] =============================================
[10349.423972] [ INFO: possible recursive locking detected ]
[10349.440138] 2.6.21-rc7-git5 #23
[10349.449541] ---------------------------------------------
[10349.465685] vol_id/4312 is trying to acquire lock:
[10349.480033] (&bdev->bd_mutex){--..}, at: [<c019a82f>] do_open+0x4f/0x2c0
[10349.500561]
[10349.500566] but task is already holding lock:
[10349.518079] (&bdev->bd_mutex){--..}, at: [<c019a82f>] do_open+0x4f/0x2c0
[10349.538590]
[10349.538591] other info that might help us debug this:
[10349.558186] 2 locks held by vol_id/4312:
[10349.569934] #0: (&bdev->bd_mutex){--..}, at: [<c019a82f>] do_open+0x4f/0x2c0
[10349.591767] #1: (&ctl_mutex#2){--..}, at: [<c04c221c>] mutex_lock+0x1c/0x20
[10349.613389]
[10349.613390] stack backtrace:
[10349.626463] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[10349.641904] [<c0105952>] show_trace+0x12/0x20
[10349.655234] [<c0105a46>] dump_stack+0x16/0x20
[10349.668594] [<c013e410>] __lock_acquire+0xbc0/0x1040
[10349.683752] [<c013e900>] lock_acquire+0x70/0x90
[10349.697626] [<c04c229e>] mutex_lock_nested+0x7e/0x2e0
[10349.713067] [<c019a82f>] do_open+0x4f/0x2c0
[10349.725905] [<c019ab19>] __blkdev_get+0x79/0x90
[10349.739783] [<c019ab45>] blkdev_get+0x15/0x20
[10349.753121] [<c03298f7>] pkt_open+0xb7/0xd80
[10349.766221] [<c019a865>] do_open+0x85/0x2c0
[10349.779030] [<c019acc3>] blkdev_open+0x33/0x70
[10349.792652] [<c0173ce4>] __dentry_open+0xf4/0x220
[10349.807048] [<c0173eb5>] nameidata_to_filp+0x35/0x40
[10349.822232] [<c0173f09>] do_filp_open+0x49/0x50
[10349.836107] [<c0173f57>] do_sys_open+0x47/0xd0
[10349.849729] [<c017401c>] sys_open+0x1c/0x20
[10349.862566] [<c01041c6>] sysenter_past_esp+0x5f/0x99
[10349.877749] =======================
[10350.141702] pktcdvd: pkt_get_last_written failed
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-24 5:10 ` William Heimbigner
@ 2007-04-24 5:17 ` Andrew Morton
2007-04-24 5:44 ` William Heimbigner
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Morton @ 2007-04-24 5:17 UTC (permalink / raw)
To: William Heimbigner; +Cc: linux-kernel, Peter Osterlund, Jens Axboe
On Tue, 24 Apr 2007 05:10:04 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> > --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
> > +++ a/drivers/block/pktcdvd.c
> > @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
> > rq->cmd_flags |= REQ_QUIET;
> >
> > blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
> > - ret = rq->errors;
> > + if (rq->errors)
> > + ret = -EIO;
> > out:
> > blk_put_request(rq);
> > return ret;
> > _
>
> This patch fixes (or conceals?) the oops.
>
Fixes. But does the packet driver actually work OK for you? Writes
files and stuff like that?
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-24 5:17 ` Andrew Morton
@ 2007-04-24 5:44 ` William Heimbigner
2007-04-24 5:56 ` Andrew Morton
2007-04-25 7:48 ` Andrew Morton
0 siblings, 2 replies; 16+ messages in thread
From: William Heimbigner @ 2007-04-24 5:44 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Peter Osterlund, Jens Axboe
On Mon, 23 Apr 2007, Andrew Morton wrote:
> On Tue, 24 Apr 2007 05:10:04 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
>
>>> --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
>>> +++ a/drivers/block/pktcdvd.c
>>> @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
>>> rq->cmd_flags |= REQ_QUIET;
>>>
>>> blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
>>> - ret = rq->errors;
>>> + if (rq->errors)
>>> + ret = -EIO;
>>> out:
>>> blk_put_request(rq);
>>> return ret;
>>> _
>>
>> This patch fixes (or conceals?) the oops.
>>
>
> Fixes. But does the packet driver actually work OK for you? Writes
> files and stuff like that?
>
Short answer, no.
Long answer:
# pktsetup 0 /dev/hdc
[11508.006818] =============================================
[11508.028248] [ INFO: possible recursive locking detected ]
[11508.044413] 2.6.21-rc7-git5 #23
[11508.053818] ---------------------------------------------
[11508.069989] vol_id/4315 is trying to acquire lock:
[11508.084332] (&bdev->bd_mutex){--..}, at: [<c019a82f>]
do_open+0x4f/0x2c0
[11508.104867]
[11508.104868] but task is already holding lock:
[11508.122359] (&bdev->bd_mutex){--..}, at: [<c019a82f>]
do_open+0x4f/0x2c0
[11508.142862]
[11508.142863] other info that might help us debug this:
[11508.162460] 2 locks held by vol_id/4315:
[11508.174212] #0: (&bdev->bd_mutex){--..}, at: [<c019a82f>]
do_open+0x4f/0x2c0
[11508.196066] #1: (&ctl_mutex#2){--..}, at: [<c04c221c>]
mutex_lock+0x1c/0x20
[11508.217720]
[11508.217721] stack backtrace:
[11508.230821] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[11508.246255] [<c0105952>] show_trace+0x12/0x20
[11508.259619] [<c0105a46>] dump_stack+0x16/0x20
[11508.272974] [<c013e410>] __lock_acquire+0xbc0/0x1040
[11508.288157] [<c013e900>] lock_acquire+0x70/0x90
[11508.302035] [<c04c229e>] mutex_lock_nested+0x7e/0x2e0
[11508.317475] [<c019a82f>] do_open+0x4f/0x2c0
[11508.330314] [<c019ab19>] __blkdev_get+0x79/0x90
[11508.344189] [<c019ab45>] blkdev_get+0x15/0x20
[11508.357554] [<c03298f7>] pkt_open+0xb7/0xd80
[11508.370651] [<c019a865>] do_open+0x85/0x2c0
[11508.383491] [<c019acc3>] blkdev_open+0x33/0x70
[11508.397107] [<c0173ce4>] __dentry_open+0xf4/0x220
[11508.411509] [<c0173eb5>] nameidata_to_filp+0x35/0x40
[11508.426684] [<c0173f09>] do_filp_open+0x49/0x50
[11508.440567] [<c0173f57>] do_sys_open+0x47/0xd0
[11508.454188] [<c017401c>] sys_open+0x1c/0x20
[11508.467023] [<c01041c6>] sysenter_past_esp+0x5f/0x99
[11508.482202] =======================
[11508.520800] pktcdvd: pkt_get_last_written failed
# mkudffs /dev/pktcdvd/0
[11539.953560] pktcdvd: pkt_get_last_written failed
trying to change type of multiple extents
I get the same error with /dev/hdd as well (hdc and hdd are both dvd
burners, hdd has a cd-rw and hdc had a dvd-rw)
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-24 5:44 ` William Heimbigner
@ 2007-04-24 5:56 ` Andrew Morton
2007-04-25 7:48 ` Andrew Morton
1 sibling, 0 replies; 16+ messages in thread
From: Andrew Morton @ 2007-04-24 5:56 UTC (permalink / raw)
To: William Heimbigner; +Cc: linux-kernel, Peter Osterlund, Jens Axboe
On Tue, 24 Apr 2007 05:44:42 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> On Mon, 23 Apr 2007, Andrew Morton wrote:
> > On Tue, 24 Apr 2007 05:10:04 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> >
> >>> --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
> >>> +++ a/drivers/block/pktcdvd.c
> >>> @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
> >>> rq->cmd_flags |= REQ_QUIET;
> >>>
> >>> blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
> >>> - ret = rq->errors;
> >>> + if (rq->errors)
> >>> + ret = -EIO;
> >>> out:
> >>> blk_put_request(rq);
> >>> return ret;
> >>> _
> >>
> >> This patch fixes (or conceals?) the oops.
> >>
> >
> > Fixes. But does the packet driver actually work OK for you? Writes
> > files and stuff like that?
> >
> Short answer, no.
>
> Long answer:
> # pktsetup 0 /dev/hdc
>
> ...
>
> [11508.520800] pktcdvd: pkt_get_last_written failed
>
> # mkudffs /dev/pktcdvd/0
> [11539.953560] pktcdvd: pkt_get_last_written failed
> trying to change type of multiple extents
>
> I get the same error with /dev/hdd as well (hdc and hdd are both dvd
> burners, hdd has a cd-rw and hdc had a dvd-rw)
Yes, I get the same on a sata (piix) dvd burner.
We need to work out who is setting rq->errors and why - should be pretty
simple. I'll take a look at that after I've nailed one of these other bugs
over here.
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
[not found] ` <20070423215810.5a24ed9a.akpm@linux-foundation.org>
2007-04-24 5:10 ` William Heimbigner
@ 2007-04-24 20:46 ` Peter Osterlund
1 sibling, 0 replies; 16+ messages in thread
From: Peter Osterlund @ 2007-04-24 20:46 UTC (permalink / raw)
To: Andrew Morton; +Cc: William Heimbigner, linux-kernel, Jens Axboe
On Mon, 23 Apr 2007, Andrew Morton wrote:
> Try this:
>
> --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
> +++ a/drivers/block/pktcdvd.c
> @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
> rq->cmd_flags |= REQ_QUIET;
>
> blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
> - ret = rq->errors;
> + if (rq->errors)
> + ret = -EIO;
> out:
> blk_put_request(rq);
> return ret;
> _
>
>
> The packet driver was assuming that request.errors is an errno, but it
> isn't - it's some sort of diagnostic bitfield thing. Now why would the
> packet driver have though that? Let's go read the comments:
...
> Well there's your root cause right there.
>
> I don't know why this wasn't oopsing in eariler kernels. Perhaps something
> else is broken. Please test this urgently.
The code used to return -EIO until commit
406c9b605cbc45151c03ac9a3f95e9acf050808c, which was commited 2007-01-05,
so that would explain why older kernels didn't crash.
> What the heck _is_ in request.errors?
According to linux/Documentation/block/request.txt, it is an error
counter. The info in that text file would probably do a lot more good as
comments in the structure definition though.
> Should the packet driver even be looking at it?
I think so. How else is it supposed to know if the request failed?
--
Peter Osterlund - petero2@telia.com
http://web.telia.com/~u89404340
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-24 5:44 ` William Heimbigner
2007-04-24 5:56 ` Andrew Morton
@ 2007-04-25 7:48 ` Andrew Morton
2007-04-25 22:53 ` William Heimbigner
1 sibling, 1 reply; 16+ messages in thread
From: Andrew Morton @ 2007-04-25 7:48 UTC (permalink / raw)
To: William Heimbigner; +Cc: linux-kernel, Peter Osterlund, Jens Axboe
On Tue, 24 Apr 2007 05:44:42 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> On Mon, 23 Apr 2007, Andrew Morton wrote:
> > On Tue, 24 Apr 2007 05:10:04 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> >
> >>> --- a/drivers/block/pktcdvd.c~packet-fix-error-handling
> >>> +++ a/drivers/block/pktcdvd.c
> >>> @@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
> >>> rq->cmd_flags |= REQ_QUIET;
> >>>
> >>> blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
> >>> - ret = rq->errors;
> >>> + if (rq->errors)
> >>> + ret = -EIO;
> >>> out:
> >>> blk_put_request(rq);
> >>> return ret;
> >>> _
> >>
> >> This patch fixes (or conceals?) the oops.
> >>
> >
> > Fixes. But does the packet driver actually work OK for you? Writes
> > files and stuff like that?
> >
> Short answer, no.
>
> Long answer:
> # pktsetup 0 /dev/hdc
>
> ...
>
> # mkudffs /dev/pktcdvd/0
> [11539.953560] pktcdvd: pkt_get_last_written failed
> trying to change type of multiple extents
>
> I get the same error with /dev/hdd as well (hdc and hdd are both dvd
> burners, hdd has a cd-rw and hdc had a dvd-rw)
>
OK. I am able to use the pktcdvd driver OK in mainline with a piix/sata
drive. It could be that something is going wrong at the IDE level for you.
Are you able to identify the most recent kernel which actually worked?
Here's the bugfix which we already worked out:
--- a/drivers/block/pktcdvd.c~packet-fix-error-handling
+++ a/drivers/block/pktcdvd.c
@@ -777,7 +777,8 @@ static int pkt_generic_packet(struct pkt
rq->cmd_flags |= REQ_QUIET;
blk_execute_rq(rq->q, pd->bdev->bd_disk, rq, 0);
- ret = rq->errors;
+ if (rq->errors)
+ ret = -EIO;
out:
blk_put_request(rq);
return ret;
_
And here's a debug patch which will hopefully tell us where we're detecting
an error. Please apply both patches to 2.6.21-rc7 and retest?
Also, please send the full boot-time dmesg output.
drivers/ide/ide-cd.c | 6 +++++-
drivers/ide/ide-io.c | 24 +++++++++++++++++++-----
drivers/scsi/scsi_lib.c | 2 ++
include/linux/kernel.h | 9 +++++++++
4 files changed, 35 insertions(+), 6 deletions(-)
diff -puN drivers/ide/ide-cd.c~block-debug drivers/ide/ide-cd.c
--- a/drivers/ide/ide-cd.c~block-debug
+++ a/drivers/ide/ide-cd.c
@@ -724,8 +724,10 @@ static int cdrom_decode_status(ide_drive
* if we have an error, pass back CHECK_CONDITION as the
* scsi status byte
*/
- if (blk_pc_request(rq) && !rq->errors)
+ if (blk_pc_request(rq) && !rq->errors) {
rq->errors = SAM_STAT_CHECK_CONDITION;
+ MMMMM(rq->errors);
+ }
/* Check for tray open. */
if (sense_key == NOT_READY) {
@@ -791,6 +793,7 @@ static int cdrom_decode_status(ide_drive
if (!rq->errors)
info->write_timeout = jiffies + ATAPI_WAIT_WRITE_BUSY;
rq->errors = 1;
+ MMMMM(rq->errors);
if (time_after(jiffies, info->write_timeout))
do_end_request = 1;
else {
@@ -3127,6 +3130,7 @@ static int ide_cdrom_prep_pc(struct requ
*/
if (c[0] == MODE_SENSE || c[0] == MODE_SELECT) {
rq->errors = ILLEGAL_REQUEST;
+ MMMMM(rq->errors);
return BLKPREP_KILL;
}
diff -puN drivers/ide/ide-io.c~block-debug drivers/ide/ide-io.c
--- a/drivers/ide/ide-io.c~block-debug
+++ a/drivers/ide/ide-io.c
@@ -66,8 +66,10 @@ static int __ide_end_request(ide_drive_t
if (blk_noretry_request(rq) && end_io_error(uptodate))
nr_sectors = rq->hard_nr_sectors;
- if (!blk_fs_request(rq) && end_io_error(uptodate) && !rq->errors)
+ if (!blk_fs_request(rq) && end_io_error(uptodate) && !rq->errors) {
rq->errors = -EIO;
+ MMMMM(rq->errors);
+ }
/*
* decide whether to reenable DMA -- 3 is a random magic for now,
@@ -265,8 +267,10 @@ int ide_end_dequeued_request(ide_drive_t
if (blk_noretry_request(rq) && end_io_error(uptodate))
nr_sectors = rq->hard_nr_sectors;
- if (!blk_fs_request(rq) && end_io_error(uptodate) && !rq->errors)
+ if (!blk_fs_request(rq) && end_io_error(uptodate) && !rq->errors) {
rq->errors = -EIO;
+ MMMMM(rq->errors);
+ }
/*
* decide whether to reenable DMA -- 3 is a random magic for now,
@@ -380,8 +384,10 @@ void ide_end_drive_cmd (ide_drive_t *dri
if (rq->cmd_type == REQ_TYPE_ATA_CMD) {
u8 *args = (u8 *) rq->buffer;
- if (rq->errors == 0)
+ if (rq->errors == 0) {
rq->errors = !OK_STAT(stat,READY_STAT,BAD_STAT);
+ MMMMM(rq->errors);
+ }
if (args) {
args[0] = stat;
@@ -390,8 +396,10 @@ void ide_end_drive_cmd (ide_drive_t *dri
}
} else if (rq->cmd_type == REQ_TYPE_ATA_TASK) {
u8 *args = (u8 *) rq->buffer;
- if (rq->errors == 0)
+ if (rq->errors == 0) {
rq->errors = !OK_STAT(stat,READY_STAT,BAD_STAT);
+ MMMMM(rq->errors);
+ }
if (args) {
args[0] = stat;
@@ -404,8 +412,10 @@ void ide_end_drive_cmd (ide_drive_t *dri
}
} else if (rq->cmd_type == REQ_TYPE_ATA_TASKFILE) {
ide_task_t *args = (ide_task_t *) rq->special;
- if (rq->errors == 0)
+ if (rq->errors == 0) {
rq->errors = !OK_STAT(stat,READY_STAT,BAD_STAT);
+ MMMMM(rq->errors);
+ }
if (args) {
if (args->tf_in_flags.b.data) {
@@ -448,6 +458,7 @@ void ide_end_drive_cmd (ide_drive_t *dri
blkdev_dequeue_request(rq);
HWGROUP(drive)->rq = NULL;
rq->errors = err;
+ MMMMM(rq->errors);
end_that_request_last(rq, !rq->errors);
spin_unlock_irqrestore(&ide_lock, flags);
}
@@ -510,6 +521,7 @@ static ide_startstop_t ide_ata_error(ide
} else if (err & (BBD_ERR | ECC_ERR)) {
/* retries won't help these */
rq->errors = ERROR_MAX;
+ MMMMM(rq->errors);
} else if (err & TRK0_ERR) {
/* help it find track zero */
rq->errors |= ERROR_RECAL;
@@ -604,6 +616,7 @@ ide_startstop_t ide_error (ide_drive_t *
/* retry only "normal" I/O: */
if (!blk_fs_request(rq)) {
rq->errors = 1;
+ MMMMM(rq->errors);
ide_end_drive_cmd(drive, stat, err);
return ide_stopped;
}
@@ -655,6 +668,7 @@ ide_startstop_t ide_abort(ide_drive_t *d
/* retry only "normal" I/O: */
if (!blk_fs_request(rq)) {
rq->errors = 1;
+ MMMMM(rq->errors);
ide_end_drive_cmd(drive, BUSY_STAT, 0);
return ide_stopped;
}
diff -puN drivers/scsi/scsi_lib.c~block-debug drivers/scsi/scsi_lib.c
--- a/drivers/scsi/scsi_lib.c~block-debug
+++ a/drivers/scsi/scsi_lib.c
@@ -835,6 +835,7 @@ void scsi_io_completion(struct scsi_cmnd
if (blk_pc_request(req)) { /* SG_IO ioctl from block level */
req->errors = result;
+ MMMMM(req->errors);
if (result) {
clear_errors = 0;
if (sense_valid && req->sense) {
@@ -1252,6 +1253,7 @@ static int scsi_prep_fn(struct request_q
switch (ret) {
case BLKPREP_KILL:
req->errors = DID_NO_CONNECT << 16;
+ MMMMM(req->errors);
break;
case BLKPREP_DEFER:
/*
diff -puN include/linux/kernel.h~block-debug include/linux/kernel.h
--- a/include/linux/kernel.h~block-debug
+++ a/include/linux/kernel.h
@@ -20,6 +20,15 @@
extern const char linux_banner[];
extern const char linux_proc_banner[];
+#define MMMMM(n) \
+ do { \
+ if (n) { \
+ printk("%s:%d: setting error to %d\n", \
+ __FILE__, __LINE__, (int)n); \
+ dump_stack(); \
+ } \
+ } while (0)
+
#define INT_MAX ((int)(~0U>>1))
#define INT_MIN (-INT_MAX - 1)
#define UINT_MAX (~0U)
_
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-25 7:48 ` Andrew Morton
@ 2007-04-25 22:53 ` William Heimbigner
2007-04-25 23:05 ` Andrew Morton
0 siblings, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-25 22:53 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Jens Axboe
[-- Attachment #1: Type: TEXT/PLAIN, Size: 14474 bytes --]
On Wed, 25 Apr 2007, Andrew Morton wrote:
<snip>
> OK. I am able to use the pktcdvd driver OK in mainline with a piix/sata
> drive. It could be that something is going wrong at the IDE level for you.
Perhaps; I'll try an external usb cd burner, and see where that goes.
> Are you able to identify the most recent kernel which actually worked?
No, because I haven't set packet writing up in Linux before - however, I do know
that I've successfully set up packet writing (using 2 of the 3 cd burners I
have) in another operating system before. I'll try 2.6.18 and see if that gets
me anywhere different, though.
dmesg.1.txt is the dmesg output from immediately after system finishes booting
(the unusually large printk times are due to kexec)
# pktsetup 0 /dev/hdc
[19861.831160] pktcdvd: writer pktcdvd0 mapped to hdc
[19861.837138]
[19861.837142] =============================================
[19861.844343] [ INFO: possible recursive locking detected ]
[19861.849738] 2.6.21-rc7 #2
[19861.852361] ---------------------------------------------
[19861.857750] vol_id/4433 is trying to acquire lock:
[19861.862533] (&bdev->bd_mutex){--..}, at: [<c019bb8f>] do_open+0x4f/0x2c0
[19861.869386]
[19861.869387] but task is already holding lock:
[19861.875225] (&bdev->bd_mutex){--..}, at: [<c019bb8f>] do_open+0x4f/0x2c0
[19861.882070]
[19861.882071] other info that might help us debug this:
[19861.888602] 2 locks held by vol_id/4433:
[19861.892518] #0: (&bdev->bd_mutex){--..}, at: [<c019bb8f>]
do_open+0x4f/0x2c0
[19861.899813] #1: (&ctl_mutex#2){--..}, at: [<c04c615c>] mutex_lock+0x1c/0x20
[19861.907046]
[19861.907047] stack backtrace:
[19861.911415] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19861.916569] [<c0105952>] show_trace+0x12/0x20
[19861.921021] [<c0105a46>] dump_stack+0x16/0x20
[19861.925475] [<c013ede0>] __lock_acquire+0xbc0/0x1040
[19861.930542] [<c013f2d0>] lock_acquire+0x70/0x90
[19861.935169] [<c04c61de>] mutex_lock_nested+0x7e/0x2e0
[19861.940315] [<c019bb8f>] do_open+0x4f/0x2c0
[19861.944595] [<c019be79>] __blkdev_get+0x79/0x90
[19861.949222] [<c019bea5>] blkdev_get+0x15/0x20
[19861.953674] [<c032a987>] pkt_open+0xb7/0xd80
[19861.958050] [<c019bbc5>] do_open+0x85/0x2c0
[19861.962330] [<c019c023>] blkdev_open+0x33/0x70
[19861.966870] [<c0175084>] __dentry_open+0xf4/0x220
[19861.971678] [<c0175255>] nameidata_to_filp+0x35/0x40
[19861.976738] [<c01752a9>] do_filp_open+0x49/0x50
[19861.981365] [<c01752f7>] do_sys_open+0x47/0xd0
[19861.985904] [<c01753bc>] sys_open+0x1c/0x20
[19861.990184] [<c01041c6>] sysenter_past_esp+0x5f/0x99
[19861.995243] =======================
# pktsetup 1 /dev/hdd
[19909.635795] cdrom: This disc doesn't have any tracks I recognize!
[19909.689394] pktcdvd: writer pktcdvd1 mapped to hdd
[19909.820337] drivers/ide/ide-cd.c:729: setting error to 2
[19909.825649] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19909.830810] [<c0105952>] show_trace+0x12/0x20
[19909.835263] [<c0105a46>] dump_stack+0x16/0x20
[19909.839716] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[19909.845131] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[19909.850190] [<c0331106>] ide_intr+0x96/0x200
[19909.854557] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[19909.859538] [<c0151f96>] handle_edge_irq+0xa6/0x130
[19909.864511] [<c0106449>] do_IRQ+0x49/0xa0
[19909.868618] [<c0104c3a>] common_interrupt+0x2e/0x34
[19909.873591] [<c01022d2>] mwait_idle+0x12/0x20
[19909.878044] [<c01023ca>] cpu_idle+0x4a/0x80
[19909.882324] [<c0101147>] rest_init+0x37/0x40
[19909.886690] [<c068ac7b>] start_kernel+0x34b/0x420
[19909.891499] [<00000000>] 0x0
[19909.894488] =======================
[19909.921518] pktcdvd: pkt_get_last_written failed
# pktsetup 2 /dev/sr0
[19982.934793] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19982.941070] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19982.946256] [<c0105952>] show_trace+0x12/0x20
[19982.950744] [<c0105a46>] dump_stack+0x16/0x20
[19982.955232] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19982.960586] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19982.965594] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19982.970861] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19982.975955] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19982.980962] [<c01243a2>] __do_softirq+0x62/0xc0
[19982.985624] [<c0124455>] do_softirq+0x55/0x60
[19982.990112] [<c0124be5>] ksoftirqd+0x65/0x100
[19982.994599] [<c0132963>] kthread+0xa3/0xd0
[19982.998827] [<c0104e17>] kernel_thread_helper+0x7/0x10
[19983.004095] =======================
[19983.009065] cdrom: This disc doesn't have any tracks I recognize!
[19983.017405] pktcdvd: writer pktcdvd2 mapped to sr0
[19983.032012] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19983.038295] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19983.043481] [<c0105952>] show_trace+0x12/0x20
[19983.047977] [<c0105a46>] dump_stack+0x16/0x20
[19983.052465] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19983.057819] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19983.062826] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19983.068093] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19983.073188] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19983.078196] [<c01243a2>] __do_softirq+0x62/0xc0
[19983.082857] [<c0124455>] do_softirq+0x55/0x60
[19983.087345] [<c0124be5>] ksoftirqd+0x65/0x100
[19983.091832] [<c0132963>] kthread+0xa3/0xd0
[19983.096060] [<c0104e17>] kernel_thread_helper+0x7/0x10
[19983.101328] =======================
[19983.124101] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19983.130380] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19983.135558] [<c0105952>] show_trace+0x12/0x20
[19983.140045] [<c0105a46>] dump_stack+0x16/0x20
[19983.144534] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19983.149887] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19983.154895] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19983.160163] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19983.165257] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19983.170265] [<c01243a2>] __do_softirq+0x62/0xc0
[19983.174934] [<c0124455>] do_softirq+0x55/0x60
[19983.179422] [<c0124be5>] ksoftirqd+0x65/0x100
[19983.183911] [<c0132963>] kthread+0xa3/0xd0
[19983.188138] [<c0104e17>] kernel_thread_helper+0x7/0x10
[19983.193405] =======================
[19983.198099] pktcdvd: pkt_get_last_written failed
# mkudffs /dev/pktcdvd/0
[20417.848314] drivers/ide/ide-cd.c:729: setting error to 2
[20417.853630] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[20417.858791] [<c0105952>] show_trace+0x12/0x20
[20417.863243] [<c0105a46>] dump_stack+0x16/0x20
[20417.867696] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[20417.873112] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[20417.878171] [<c0331106>] ide_intr+0x96/0x200
[20417.882546] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[20417.887528] [<c0151f96>] handle_edge_irq+0xa6/0x130
[20417.892501] [<c0106449>] do_IRQ+0x49/0xa0
[20417.896607] [<c0104c3a>] common_interrupt+0x2e/0x34
[20417.901580] [<c01022d2>] mwait_idle+0x12/0x20
[20417.906034] [<c01023ca>] cpu_idle+0x4a/0x80
[20417.910313] [<c0101147>] rest_init+0x37/0x40
[20417.914680] [<c068ac7b>] start_kernel+0x34b/0x420
[20417.919488] [<00000000>] 0x0
[20417.922468] =======================
[20417.928941] pktcdvd: write speed 5540kB/s
[20424.114292] pktcdvd: 2816kB available on disc
start=0, blocks=16, type=RESERVED
start=16, blocks=3, type=VRS
start=19, blocks=237, type=USPACE
start=256, blocks=1, type=ANCHOR
start=257, blocks=16, type=PVDS
start=273, blocks=1, type=LVID
start=274, blocks=877, type=PSPACE
start=1151, blocks=1, type=ANCHOR
start=1152, blocks=239, type=USPACE
start=1391, blocks=16, type=RVDS
start=1407, blocks=1, type=ANCHOR
^ This was on a dvd, and it's reporting 2816kB ?
# mkudffs /dev/pktcdvd/1
[20712.696994] drivers/ide/ide-cd.c:729: setting error to 2
[20712.702306] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[20712.707467] [<c0105952>] show_trace+0x12/0x20
[20712.711919] [<c0105a46>] dump_stack+0x16/0x20
[20712.716373] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[20712.721788] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[20712.726848] [<c0331106>] ide_intr+0x96/0x200
[20712.731214] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[20712.736195] [<c0151f96>] handle_edge_irq+0xa6/0x130
[20712.741168] [<c0106449>] do_IRQ+0x49/0xa0
[20712.745275] [<c0104c3a>] common_interrupt+0x2e/0x34
[20712.750248] [<c01022d2>] mwait_idle+0x12/0x20
[20712.754701] [<c01023ca>] cpu_idle+0x4a/0x80
[20712.758981] [<c0101147>] rest_init+0x37/0x40
[20712.763348] [<c068ac7b>] start_kernel+0x34b/0x420
[20712.768156] [<00000000>] 0x0
[20712.771136] =======================
[20712.798160] pktcdvd: pkt_get_last_written failed
trying to change type of multiple extents
# mkudffs /dev/pktcdvd/2
[20742.293998] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[20742.300273] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[20742.305460] [<c0105952>] show_trace+0x12/0x20
[20742.309947] [<c0105a46>] dump_stack+0x16/0x20
[20742.314436] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[20742.319790] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[20742.324797] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[20742.330065] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[20742.335158] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[20742.340167] [<c01243a2>] __do_softirq+0x62/0xc0
[20742.344827] [<c0124455>] do_softirq+0x55/0x60
[20742.349314] [<c0124be5>] ksoftirqd+0x65/0x100
[20742.353802] [<c0132963>] kthread+0xa3/0xd0
[20742.358030] [<c0104e17>] kernel_thread_helper+0x7/0x10
[20742.363298] =======================
[20742.385965] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[20742.392247] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[20742.397425] [<c0105952>] show_trace+0x12/0x20
[20742.401912] [<c0105a46>] dump_stack+0x16/0x20
[20742.406400] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[20742.411754] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[20742.416761] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[20742.422029] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[20742.427124] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[20742.432131] [<c01243a2>] __do_softirq+0x62/0xc0
[20742.436792] [<c0124455>] do_softirq+0x55/0x60
[20742.441280] [<c0124be5>] ksoftirqd+0x65/0x100
[20742.445767] [<c0132963>] kthread+0xa3/0xd0
[20742.449996] [<c0104e17>] kernel_thread_helper+0x7/0x10
[20742.455263] =======================
[20742.460038] pktcdvd: pkt_get_last_written failed
trying to change type of multiple extents
# mount -t udf /dev/pktcdvd/0 /mnt/pkt0
[20912.824545] drivers/ide/ide-cd.c:729: setting error to 2
[20912.829857] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[20912.835019] [<c0105952>] show_trace+0x12/0x20
[20912.839472] [<c0105a46>] dump_stack+0x16/0x20
[20912.843924] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[20912.849338] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[20912.854399] [<c0331106>] ide_intr+0x96/0x200
[20912.858765] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[20912.863746] [<c0151f96>] handle_edge_irq+0xa6/0x130
[20912.868720] [<c0106449>] do_IRQ+0x49/0xa0
[20912.872826] [<c0104c3a>] common_interrupt+0x2e/0x34
[20912.877799] [<c01022d2>] mwait_idle+0x12/0x20
[20912.882252] [<c01023ca>] cpu_idle+0x4a/0x80
[20912.886532] [<c0101147>] rest_init+0x37/0x40
[20912.890899] [<c068ac7b>] start_kernel+0x34b/0x420
[20912.895707] [<00000000>] 0x0
[20912.898696] =======================
[20912.905058] pktcdvd: write speed 5540kB/s
[20919.178571] pktcdvd: 2816kB available on disc
[20920.682973] UDF-fs INFO UDF 0.9.8.1 (2004/29/09) Mounting volume 'LinuxUDF',
timestamp 2007/04/26 17:34 (1ed4)
# mount -t udf /dev/pktcdvd/1 /mnt/pkt1
[21007.153670] drivers/ide/ide-cd.c:729: setting error to 2
[21007.158985] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[21007.164146] [<c0105952>] show_trace+0x12/0x20
[21007.168599] [<c0105a46>] dump_stack+0x16/0x20
[21007.173052] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[21007.178466] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[21007.183527] [<c0331106>] ide_intr+0x96/0x200
[21007.187892] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[21007.192874] [<c0151f96>] handle_edge_irq+0xa6/0x130
[21007.197848] [<c0106449>] do_IRQ+0x49/0xa0
[21007.201954] [<c0104c3a>] common_interrupt+0x2e/0x34
[21007.206927] [<c01022d2>] mwait_idle+0x12/0x20
[21007.211380] [<c01023ca>] cpu_idle+0x4a/0x80
[21007.215660] [<c0101147>] rest_init+0x37/0x40
[21007.220026] [<c068ac7b>] start_kernel+0x34b/0x420
[21007.224835] [<00000000>] 0x0
[21007.227823] =======================
[21007.254866] pktcdvd: pkt_get_last_written failed
mount: /dev/pktcdvd/1: can't read superblock
# mount -t udf /dev/pktcdvd/2 /mnt/pkt2
[21025.193414] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[21025.199694] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[21025.204880] [<c0105952>] show_trace+0x12/0x20
[21025.209368] [<c0105a46>] dump_stack+0x16/0x20
[21025.213856] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[21025.219210] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[21025.224217] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[21025.229486] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[21025.234579] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[21025.239586] [<c01243a2>] __do_softirq+0x62/0xc0
[21025.244248] [<c0124455>] do_softirq+0x55/0x60
[21025.248735] [<c0124be5>] ksoftirqd+0x65/0x100
[21025.253223] [<c0132963>] kthread+0xa3/0xd0
[21025.257452] [<c0104e17>] kernel_thread_helper+0x7/0x10
[21025.262719] =======================
[21025.285506] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[21025.291781] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[21025.296959] [<c0105952>] show_trace+0x12/0x20
[21025.301446] [<c0105a46>] dump_stack+0x16/0x20
[21025.305933] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[21025.311287] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[21025.316295] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[21025.321563] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[21025.326657] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[21025.331665] [<c01243a2>] __do_softirq+0x62/0xc0
[21025.336325] [<c0124455>] do_softirq+0x55/0x60
[21025.340814] [<c0124be5>] ksoftirqd+0x65/0x100
[21025.345301] [<c0132963>] kthread+0xa3/0xd0
[21025.349529] [<c0104e17>] kernel_thread_helper+0x7/0x10
[21025.354797] =======================
[21025.359503] pktcdvd: pkt_get_last_written failed
mount: /dev/pktcdvd/2: can't read superblock
/dev/sr0 is the USB cd-rw burner.
William Heimbigner
icxcnika@mar.tar.cc
[-- Attachment #2: Type: TEXT/plain, Size: 37167 bytes --]
[ 0.000000] Linux version 2.6.21-rc7 (root@toothfairy) (gcc version 4.1.1 (Gentoo 4.1.1-r3)) #2 PREEMPT Thu Apr 26 15:13:20 CDT 2007
[ 0.000000] BIOS-provided physical RAM map:
[ 0.000000] sanitize start
[ 0.000000] sanitize end
[ 0.000000] copy_e820_map() start: 0000000000000100 size: 000000000009fb00 end: 000000000009fc00 type: 1
[ 0.000000] copy_e820_map() type is E820_RAM
[ 0.000000] copy_e820_map() start: 000000000009fc00 size: 0000000000000400 end: 00000000000a0000 type: 2
[ 0.000000] copy_e820_map() start: 0000000000100000 size: 000000001f6f0000 end: 000000001f7f0000 type: 1
[ 0.000000] copy_e820_map() type is E820_RAM
[ 0.000000] copy_e820_map() start: 000000001f7f0000 size: 0000000000003000 end: 000000001f7f3000 type: 4
[ 0.000000] copy_e820_map() start: 000000001f7f3000 size: 000000000000d000 end: 000000001f800000 type: 3
[ 0.000000] copy_e820_map() start: 00000000fec00000 size: 0000000001400000 end: 0000000100000000 type: 2
[ 0.000000] BIOS-e820: 0000000000000100 - 000000000009fc00 (usable)
[ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
[ 0.000000] BIOS-e820: 0000000000100000 - 000000001f7f0000 (usable)
[ 0.000000] BIOS-e820: 000000001f7f0000 - 000000001f7f3000 (ACPI NVS)
[ 0.000000] BIOS-e820: 000000001f7f3000 - 000000001f800000 (ACPI data)
[ 0.000000] BIOS-e820: 00000000fec00000 - 0000000100000000 (reserved)
[ 0.000000] 503MB LOWMEM available.
[ 0.000000] found SMP MP-table at 000f61b0
[ 0.000000] Entering add_active_range(0, 0, 129008) 0 entries of 256 used
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0 -> 4096
[ 0.000000] Normal 4096 -> 129008
[ 0.000000] early_node_map[1] active PFN ranges
[ 0.000000] 0: 0 -> 129008
[ 0.000000] On node 0 totalpages: 129008
[ 0.000000] DMA zone: 32 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 4064 pages, LIFO batch:0
[ 0.000000] Normal zone: 975 pages used for memmap
[ 0.000000] Normal zone: 123937 pages, LIFO batch:31
[ 0.000000] DMI 2.4 present.
[ 0.000000] Intel MultiProcessor Specification v1.4
[ 0.000000] Virtual Wire compatibility mode.
[ 0.000000] OEM ID: OEM00000 Product ID: PROD00000000 APIC at: 0xFEE00000
[ 0.000000] Processor #0 15:3 APIC version 17
[ 0.000000] I/O APIC #2 Version 17 at 0xFEC00000.
[ 0.000000] Enabling APIC mode: Flat. Using 1 I/O APICs
[ 0.000000] Processors: 1
[ 0.000000] Allocating PCI resources starting at 20000000 (gap: 1f800000:df400000)
[ 0.000000] Built 1 zonelists. Total pages: 128001
[ 0.000000] Kernel command line: root=/dev/hda3 console=ttyS0,115200,8,n,1 rootfstype=ext3 acpi=off noacpi panic=15
[ 0.000000] mapped APIC to ffffd000 (fee00000)
[ 0.000000] mapped IOAPIC to ffffc000 (fec00000)
[ 0.000000] Enabling fast FPU save and restore... done.
[ 0.000000] Enabling unmasked SIMD FPU exception support... done.
[ 0.000000] Initializing CPU#0
[ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes)
[ 0.000000] Detected 2666.399 MHz processor.
[19477.912597] Console: colour dummy device 80x25
[19478.153250] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[19478.160978] ... MAX_LOCKDEP_SUBCLASSES: 8
[19478.165240] ... MAX_LOCK_DEPTH: 30
[19478.169416] ... MAX_LOCKDEP_KEYS: 2048
[19478.173765] ... CLASSHASH_SIZE: 1024
[19478.178201] ... MAX_LOCKDEP_ENTRIES: 8192
[19478.182550] ... MAX_LOCKDEP_CHAINS: 16384
[19478.186985] ... CHAINHASH_SIZE: 8192
[19478.191335] memory used by lock dependency info: 1096 kB
[19478.196724] per task-struct memory footprint: 1200 bytes
[19478.202113] ------------------------
[19478.205682] | Locking API testsuite:
[19478.209251] ----------------------------------------------------------------------------
[19478.217325] | spin |wlock |rlock |mutex | wsem | rsem |
[19478.225401] --------------------------------------------------------------------------
[19478.233482] A-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.242243] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.250959] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.259675] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok |
[19478.268390] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.277115] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.285838] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok |
[19478.294590] double unlock: ok | ok | ok | ok | ok | ok |
[19478.303278] initialize held: ok | ok | ok | ok | ok | ok |
[19478.311959] bad unlock order: ok | ok | ok | ok | ok | ok |
[19478.320676] --------------------------------------------------------------------------
[19478.328750] recursive read-lock: | ok | | ok |
[19478.337067] recursive read-lock #2: | ok | | ok |
[19478.345385] mixed read-write-lock: | ok | | ok |
[19478.353701] mixed write-read-lock: | ok | | ok |
[19478.362018] --------------------------------------------------------------------------
[19478.370093] hard-irqs-on + irq-safe-A/12: ok | ok | ok |
[19478.376678] soft-irqs-on + irq-safe-A/12: ok | ok | ok |
[19478.383244] hard-irqs-on + irq-safe-A/21: ok | ok | ok |
[19478.389803] soft-irqs-on + irq-safe-A/21: ok | ok | ok |
[19478.396362] sirq-safe-A => hirqs-on/12: ok | ok | ok |
[19478.402928] sirq-safe-A => hirqs-on/21: ok | ok | ok |
[19478.409512] hard-safe-A + irqs-on/12: ok | ok | ok |
[19478.416097] soft-safe-A + irqs-on/12: ok | ok | ok |
[19478.422681] hard-safe-A + irqs-on/21: ok | ok | ok |
[19478.429266] soft-safe-A + irqs-on/21: ok | ok | ok |
[19478.435850] hard-safe-A + unsafe-B #1/123: ok | ok | ok |
[19478.442435] soft-safe-A + unsafe-B #1/123: ok | ok | ok |
[19478.449019] hard-safe-A + unsafe-B #1/132: ok | ok | ok |
[19478.455603] soft-safe-A + unsafe-B #1/132: ok | ok | ok |
[19478.462188] hard-safe-A + unsafe-B #1/213: ok | ok | ok |
[19478.468773] soft-safe-A + unsafe-B #1/213: ok | ok | ok |
[19478.475357] hard-safe-A + unsafe-B #1/231: ok | ok | ok |
[19478.481942] soft-safe-A + unsafe-B #1/231: ok | ok | ok |
[19478.488526] hard-safe-A + unsafe-B #1/312: ok | ok | ok |
[19478.495111] soft-safe-A + unsafe-B #1/312: ok | ok | ok |
[19478.501694] hard-safe-A + unsafe-B #1/321: ok | ok | ok |
[19478.508296] soft-safe-A + unsafe-B #1/321: ok | ok | ok |
[19478.514881] hard-safe-A + unsafe-B #2/123: ok | ok | ok |
[19478.521465] soft-safe-A + unsafe-B #2/123: ok | ok | ok |
[19478.528050] hard-safe-A + unsafe-B #2/132: ok | ok | ok |
[19478.534634] soft-safe-A + unsafe-B #2/132: ok | ok | ok |
[19478.541244] hard-safe-A + unsafe-B #2/213: ok | ok | ok |
[19478.547846] soft-safe-A + unsafe-B #2/213: ok | ok | ok |
[19478.554431] hard-safe-A + unsafe-B #2/231: ok | ok | ok |
[19478.561015] soft-safe-A + unsafe-B #2/231: ok | ok | ok |
[19478.567599] hard-safe-A + unsafe-B #2/312: ok | ok | ok |
[19478.574183] soft-safe-A + unsafe-B #2/312: ok | ok | ok |
[19478.580768] hard-safe-A + unsafe-B #2/321: ok | ok | ok |
[19478.587352] soft-safe-A + unsafe-B #2/321: ok | ok | ok |
[19478.593936] hard-irq lock-inversion/123: ok | ok | ok |
[19478.600521] soft-irq lock-inversion/123: ok | ok | ok |
[19478.607106] hard-irq lock-inversion/132: ok | ok | ok |
[19478.613691] soft-irq lock-inversion/132: ok | ok | ok |
[19478.620275] hard-irq lock-inversion/213: ok | ok | ok |
[19478.626859] soft-irq lock-inversion/213: ok | ok | ok |
[19478.633443] hard-irq lock-inversion/231: ok | ok | ok |
[19478.640028] soft-irq lock-inversion/231: ok | ok | ok |
[19478.646612] hard-irq lock-inversion/312: ok | ok | ok |
[19478.653197] soft-irq lock-inversion/312: ok | ok | ok |
[19478.659781] hard-irq lock-inversion/321: ok | ok | ok |
[19478.666365] soft-irq lock-inversion/321: ok | ok | ok |
[19478.672959] hard-irq read-recursion/123: ok |
[19478.678122] soft-irq read-recursion/123: ok |
[19478.683286] hard-irq read-recursion/132: ok |
[19478.688448] soft-irq read-recursion/132: ok |
[19478.693613] hard-irq read-recursion/213: ok |
[19478.698776] soft-irq read-recursion/213: ok |
[19478.703939] hard-irq read-recursion/231: ok |
[19478.709103] soft-irq read-recursion/231: ok |
[19478.714267] hard-irq read-recursion/312: ok |
[19478.719431] soft-irq read-recursion/312: ok |
[19478.724594] hard-irq read-recursion/321: ok |
[19478.729757] soft-irq read-recursion/321: ok |
[19478.734921] -------------------------------------------------------
[19478.741177] Good, all 218 testcases passed! |
[19478.745525] ---------------------------------
[19478.750200] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[19478.757542] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[19478.774121] Memory: 501716k/516032k available (3886k kernel code, 13844k reserved, 1773k data, 260k init, 0k highmem)
[19478.784719] virtual kernel memory layout:
[19478.784720] fixmap : 0xfffb7000 - 0xfffff000 ( 288 kB)
[19478.784722] vmalloc : 0xe0000000 - 0xfffb5000 ( 511 MB)
[19478.784723] lowmem : 0xc0000000 - 0xdf7f0000 ( 503 MB)
[19478.784725] .init : 0xc068a000 - 0xc06cb000 ( 260 kB)
[19478.784726] .data : 0xc04cb98f - 0xc0686eb0 (1773 kB)
[19478.784728] .text : 0xc0100000 - 0xc04cb98f (3886 kB)
[19478.823143] Checking if this processor honours the WP bit even in supervisor mode... Ok.
[19478.891678] Calibrating delay using timer specific routine.. 5337.07 BogoMIPS (lpj=2668538)
[19478.900208] Mount-cache hash table entries: 512
[19478.905275] CPU: After generic identify, caps: bfebfbff 00000000 00000000 00000000 0000441d 00000000 00000000
[19478.905287] monitor/mwait feature present.
[19478.909398] using mwait in idle threads.
[19478.913328] CPU: Trace cache: 12K uops, L1 D cache: 16K
[19478.918582] CPU: L2 cache: 256K
[19478.921728] CPU: After all inits, caps: bfebfbff 00000000 00000000 00003180 0000441d 00000000 00000000
[19478.921737] Intel machine check architecture supported.
[19478.926965] Intel machine check reporting enabled on CPU#0.
[19478.932543] CPU0: Intel P4/Xeon Extended MCE MSRs (12) available
[19478.938555] CPU0: Thermal monitoring enabled
[19478.942854] CPU: Intel(R) Celeron(R) CPU 2.66GHz stepping 04
[19478.948571] Checking 'hlt' instruction... OK.
[19478.956658] ENABLING IO-APIC IRQs
[19478.960205] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=0 pin2=0
[19479.180382] NET: Registered protocol family 16
[19479.213236] PCI: PCI BIOS revision 2.10 entry at 0xfbc60, last bus=1
[19479.219596] PCI: Using configuration type 1
[19479.223787] Setting up standard PCI resources
[19479.267588] ACPI: Interpreter disabled.
[19479.271680] Linux Plug and Play Support v0.97 (c) Adam Belay
[19479.277401] pnp: PnP ACPI: disabled
[19479.282128] SCSI subsystem initialized
[19479.286100] libata version 2.20 loaded.
[19479.286547] usbcore: registered new interface driver usbfs
[19479.292313] usbcore: registered new interface driver hub
[19479.297945] usbcore: registered new device driver usb
[19479.303579] PCI: Probing PCI hardware
[19479.307314] PCI: Probing PCI hardware (bus 00)
[19479.307823] Boot video device is 0000:00:02.0
[19479.308321] * The chipset may have PM-Timer Bug. Due to workarounds for a bug,
[19479.308323] * this clock source is slow. If you are sure your timer does not have
[19479.308325] * this bug, please use "acpi_pm_good" to disable the workaround
[19479.330052] PCI quirk: region 0400-047f claimed by ICH4 ACPI/GPIO/TCO
[19479.336497] PCI quirk: region 0480-04bf claimed by ICH4 GPIO
[19479.342255] 0000:00:1f.1: trying to change BAR0 from 01F0 to 01F0
[19479.348348] 0000:00:1f.1: trying to change BAR1 from 03F4 to 03F4
[19479.354446] 0000:00:1f.1: trying to change BAR2 from 0170 to 0170
[19479.360544] 0000:00:1f.1: trying to change BAR3 from 0374 to 0374
[19479.367215] PCI: Transparent bridge - 0000:00:1e.0
[19479.375379] PCI: Using IRQ router PIIX/ICH [8086/24c0] at 0000:00:1f.0
[19479.381932] PCI->APIC IRQ transform: 0000:00:02.0[A] -> IRQ 16
[19479.387886] PCI->APIC IRQ transform: 0000:00:1d.0[A] -> IRQ 16
[19479.393722] PCI->APIC IRQ transform: 0000:00:1d.1[B] -> IRQ 19
[19479.399558] PCI->APIC IRQ transform: 0000:00:1d.2[C] -> IRQ 18
[19479.405398] PCI->APIC IRQ transform: 0000:00:1d.7[D] -> IRQ 23
[19479.411242] PCI->APIC IRQ transform: 0000:00:1f.1[A] -> IRQ 16
[19479.417076] PCI->APIC IRQ transform: 0000:00:1f.3[B] -> IRQ 17
[19479.422916] PCI->APIC IRQ transform: 0000:01:09.0[A] -> IRQ 21
[19479.428754] PCI->APIC IRQ transform: 0000:01:0c.0[A] -> IRQ 23
[19479.445494] Time: tsc clocksource has been installed.
[19479.452132] PCI: Ignore bogus resource 6 [0:0] of 0000:00:02.0
[19479.457987] PCI: Bridge: 0000:00:1e.0
[19479.461760] IO window: c000-cfff
[19479.465174] MEM window: ec000000-edffffff
[19479.469363] PREFETCH window: 20000000-200fffff
[19479.474006] PCI: Setting latency timer of device 0000:00:1e.0 to 64
[19479.474091] NET: Registered protocol family 2
[19479.488585] IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
[19479.495854] TCP established hash table entries: 16384 (order: 7, 720896 bytes)
[19479.505329] TCP bind hash table entries: 16384 (order: 7, 720896 bytes)
[19479.514091] TCP: Hash tables configured (established 16384 bind 16384)
[19479.520680] TCP reno registered
[19479.528509] Machine check exception polling timer started.
[19479.535082] IA-32 Microcode Update Driver: v1.14a <tigran@aivazian.fsnet.co.uk>
[19479.542513] apm: BIOS not found.
[19479.549631] Initializing RT-Tester: OK
[19479.553433] audit: initializing netlink socket (disabled)
[19479.558985] audit(1177625944.309:1): initialized
[19479.563987] Total HugeTLB memory allocated, 0
[19479.569369] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[19479.576992] io scheduler noop registered
[19479.580932] io scheduler anticipatory registered
[19479.585548] io scheduler deadline registered
[19479.589855] io scheduler cfq registered (default)
[19479.596113] vga16fb: initializing
[19479.596125] vga16fb: mapped to 0xc00a0000
[19479.709449] Console: switching to colour frame buffer device 80x30
[19479.720099] fb0: VGA16 VGA frame buffer device
[19479.761064] Real Time Clock Driver v1.12ac
[19479.765583] Non-volatile memory driver v1.2
[19479.769811] intel_rng: FWH not detected
[19479.774014] Software Watchdog Timer: 0.07 initialized. soft_noboot=0 soft_margin=60 sec (nowayout= 0)
[19479.783237] Linux agpgart interface v0.102 (c) Dave Jones
[19479.788907] agpgart: Detected an Intel 845G Chipset.
[19479.794044] agpgart: Detected 8060K stolen memory.
[19479.812253] agpgart: AGP aperture is 128M @ 0xe0000000
[19479.817507] [drm] Initialized drm 1.1.0 20060810
[19479.822555] [drm] Initialized i830 1.3.2 20021108 on minor 0
[19479.828462] ipmi message handler version 39.1
[19479.832841] ipmi device interface
[19479.836472] IPMI System Interface driver.
[19479.850783] ipmi_si: Unable to find any System Interface(s)
[19479.856375] IPMI Watchdog: driver initialized
[19479.860733] Copyright (C) 2004 MontaVista Software - IPMI Powerdown via sys_reboot.
[19479.868387] Hangcheck: starting hangcheck timer 0.9.0 (tick is 180 seconds, margin is 60 seconds).
[19479.877340] Hangcheck: Using get_cycles().
[19479.882056] intelfb: Framebuffer driver for Intel(R) 830M/845G/852GM/855GM/865G/915G/915GM/945G/945GM chipsets
[19479.892062] intelfb: Version 0.9.4
[19479.896199] intelfb: 00:02.0: Intel(R) 845G, aperture size 128MB, stolen memory 8060kB
[19479.904488] intelfb: Mode is interlaced.
[19479.908425] intelfb: Initial video mode is 1024x768-32@70.
[19479.915353] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled
[19479.923718] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[19479.936201] RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
[19479.945955] loop: loaded (max 8 devices)
[19479.950949] netconsole: not configured, aborting
[19479.955590] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
[19479.962058] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
[19479.970165] ICH4: IDE controller at PCI slot 0000:00:1f.1
[19479.975590] ICH4: chipset revision 2
[19479.979174] ICH4: not 100% native mode: will probe irqs later
[19479.984930] ide0: BM-DMA at 0xf000-0xf007, BIOS settings: hda:DMA, hdb:DMA
[19479.992216] ide1: BM-DMA at 0xf008-0xf00f, BIOS settings: hdc:DMA, hdd:DMA
[19479.999498] Probing IDE interface ide0...
[19480.263326] hda: Maxtor 91024U3, ATA DISK drive
[19480.522220] hdb: Maxtor 6L100P0, ATA DISK drive
[19480.580651] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[19480.585782] Probing IDE interface ide1...
[19481.256928] hdc: PLEXTOR DVDR PX-740A, ATAPI CD/DVD-ROM drive
[19481.976642] hdd: DV-W22E, ATAPI CD/DVD-ROM drive
[19482.033055] ide1 at 0x170-0x177,0x376 on irq 15
[19482.039285] hda: max request size: 128KiB
[19482.050092] hda: 19541088 sectors (10005 MB) w/2048KiB Cache, CHS=19386/16/63, UDMA(66)
[19482.058191] hda: cache flushes not supported
[19482.062652] hda: hda1 hda2 hda3
[19482.071875] hdb: max request size: 512KiB
[19482.075905] hdb: 195371568 sectors (100030 MB) w/8192KiB Cache, CHS=16383/255/63, UDMA(100)
[19482.116714] hdb: cache flushes supported
[19482.120797] hdb: hdb1
[19482.133445] drivers/ide/ide-io.c:71: setting error to -5
[19482.138756] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19482.143910] [<c0105952>] show_trace+0x12/0x20
[19482.148363] [<c0105a46>] dump_stack+0x16/0x20
[19482.152816] [<c03304fa>] ide_end_request+0x12a/0x130
[19482.157875] [<c033ed85>] cdrom_end_request+0x55/0x130
[19482.163021] [<c033fe68>] cdrom_pc_intr+0x98/0x290
[19482.167821] [<c0331106>] ide_intr+0x96/0x200
[19482.172188] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[19482.177169] [<c0151f96>] handle_edge_irq+0xa6/0x130
[19482.182143] [<c0106449>] do_IRQ+0x49/0xa0
[19482.186250] [<c0104c3a>] common_interrupt+0x2e/0x34
[19482.191222] [<c01022d2>] mwait_idle+0x12/0x20
[19482.195675] [<c01023ca>] cpu_idle+0x4a/0x80
[19482.199955] [<c0101147>] rest_init+0x37/0x40
[19482.204322] [<c068ac7b>] start_kernel+0x34b/0x420
[19482.209129] [<00000000>] 0x0
[19482.212111] =======================
[19482.215711] Clocksource tsc unstable (delta = 106845200 ns)
[19482.221391] Time: pit clocksource has been installed.
[19482.226769] hdc: ATAPI 94X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33)
[19482.234291] Uniform CD-ROM driver Revision: 3.20
[19482.254141] hdd: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 1419kB Cache, UDMA(33)
[19502.687658] PCI: Setting latency timer of device 0000:00:1d.7 to 64
[19502.687667] ehci_hcd 0000:00:1d.7: EHCI Host Controller
[19502.693450] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
[19502.701050] PCI: cache line size of 128 is not supported by device 0000:00:1d.7
[19502.701072] ehci_hcd 0000:00:1d.7: irq 23, io mem 0xee080000
[19502.710635] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
[19502.719086] usb usb1: configuration #1 chosen from 1 choice
[19502.725050] hub 1-0:1.0: USB hub found
[19502.728868] hub 1-0:1.0: 6 ports detected
[19502.834025] ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
[19502.834394] USB Universal Host Controller Interface driver v3.0
[19502.840647] PCI: Setting latency timer of device 0000:00:1d.0 to 64
[19502.840656] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[19502.846260] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
[19502.853746] uhci_hcd 0000:00:1d.0: irq 16, io base 0x0000d800
[19502.860350] usb usb2: configuration #1 chosen from 1 choice
[19502.866275] hub 2-0:1.0: USB hub found
[19502.870169] hub 2-0:1.0: 2 ports detected
[19502.975858] PCI: Setting latency timer of device 0000:00:1d.1 to 64
[19502.975866] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[19502.981450] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
[19502.988911] uhci_hcd 0000:00:1d.1: irq 19, io base 0x0000d000
[19502.995485] usb usb3: configuration #1 chosen from 1 choice
[19503.001444] hub 3-0:1.0: USB hub found
[19503.005248] hub 3-0:1.0: 2 ports detected
[19503.110750] PCI: Setting latency timer of device 0000:00:1d.2 to 64
[19503.110757] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[19503.116336] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
[19503.123794] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000d400
[19503.130394] usb usb4: configuration #1 chosen from 1 choice
[19503.136314] hub 4-0:1.0: USB hub found
[19503.140116] hub 4-0:1.0: 2 ports detected
[19503.273996] usb 1-4: new high speed USB device using ehci_hcd and address 3
[19503.459552] usb 1-4: configuration #1 chosen from 1 choice
[19503.671827] usb 2-2: new low speed USB device using uhci_hcd and address 2
[19503.843931] usb 2-2: configuration #1 chosen from 1 choice
[19503.957798] usbcore: registered new interface driver usblp
[19503.963313] drivers/usb/class/usblp.c: v0.13: USB Printer Device Class driver
[19503.970463] Initializing USB Mass Storage driver...
[19503.975958] scsi0 : SCSI emulation for USB Mass Storage devices
[19503.982328] usb-storage: device found at 3
[19503.982333] usb-storage: waiting for device to settle before scanning
[19503.982401] usbcore: registered new interface driver usb-storage
[19503.988450] USB Mass Storage support registered.
[19504.007896] input: Logitech USB Receiver as /class/input/input0
[19504.013952] input: USB HID v1.10 Keyboard [Logitech USB Receiver] on usb-0000:00:1d.0-2
[19504.052120] input: Logitech USB Receiver as /class/input/input1
[19504.058122] input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-2
[19504.066053] usbcore: registered new interface driver usbhid
[19504.071669] drivers/usb/input/hid-core.c: v2.6:USB HID core driver
[19504.078795] PNP: No PS/2 controller found. Probing ports directly.
[19504.087675] serio: i8042 KBD port at 0x60,0x64 irq 1
[19504.092865] serio: i8042 AUX port at 0x60,0x64 irq 12
[19504.099189] mice: PS/2 mouse device common for all mice
[19504.105569] input: PC Speaker as /class/input/input2
[19504.111192] I2O subsystem v1.325
[19504.114455] i2o: max drivers = 8
[19504.118478] I2O Configuration OSM v1.323
[19504.122960] I2O Bus Adapter OSM v1.317
[19504.126948] I2O Block Device OSM v1.325
[19504.131589] I2O SCSI Peripheral OSM v1.316
[19504.135926] I2O ProcFS OSM v1.316
[19504.157657] rtc-test rtc-test.0: rtc core: registered test as rtc0
[19504.164725] rtc-test rtc-test.1: rtc core: registered test as rtc1
[19504.188876] i2c /dev entries driver
[19504.199116] i2c-parport: adapter type unspecified
[19504.465520] abituguru: no Abit uGuru found, data = 0xFF, cmd = 0xFF
[19504.545480] i2c_adapter i2c-3: detect fail: address match, 0x2f
[19504.583482] hdaps: supported laptop not found!
[19504.587951] hdaps: driver init failed (ret=-19)!
[19505.074276] pc87360: PC8736x not detected, module not inserted.
[19505.084830] w83627ehf: unsupported chip ID: 0x8283
[19505.089660] w83627ehf: unsupported chip ID: 0xffff
[19505.096284] EDAC MC: Ver: 2.0.1 Apr 26 2007
[19505.103502] Advanced Linux Sound Architecture Driver Version 1.0.14rc3 (Wed Mar 14 07:25:50 2007 UTC).
[19505.115984] no UART detected at 0x1
[19505.121053] ALSA device list:
[19505.124061] No soundcards found.
[19505.127764] oprofile: using NMI interrupt.
[19505.131979] TCP cubic registered
[19505.135343] NET: Registered protocol family 1
[19505.139845] NET: Registered protocol family 10
[19505.144713] NET: Registered protocol family 17
[19505.149913] p4-clockmod: P4/Xeon(TM) CPU On-Demand Clock Modulation available
[19505.157080] Using IPI Shortcut mode
[19505.161249] rtc-test rtc-test.0: setting the system clock to 2007-04-26 22:19:29 (1177625969)
[19505.189749] kjournald starting. Commit interval 5 seconds
[19505.195358] EXT3-fs: mounted filesystem with ordered data mode.
[19505.201590] VFS: Mounted root (ext3 filesystem) readonly.
[19505.207405] Freeing unused kernel memory: 260k freed
[19505.212536] Write protecting the kernel read-only data: 1338k
[19509.172734] scsi 0:0:0:0: CD-ROM CDWRITER IDE5232 0009 PQ: 0 ANSI: 0 CCS
[19509.174566] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19509.174573] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.174586] [<c0105952>] show_trace+0x12/0x20
[19509.174590] [<c0105a46>] dump_stack+0x16/0x20
[19509.174610] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.174615] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.174620] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.174625] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.174629] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.174636] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.174641] [<c0124455>] do_softirq+0x55/0x60
[19509.174645] [<c0124713>] irq_exit+0x83/0x90
[19509.174649] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.174653] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.174658] =======================
[19509.177228] sr0: scsi3-mmc drive: 32x/32x writer cd/rw xa/form2 cdda tray
[19509.177486] sr 0:0:0:0: Attached scsi CD-ROM sr0
[19509.177818] sr 0:0:0:0: Attached scsi generic sg0 type 5
[19509.178568] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.178574] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.178585] [<c0105952>] show_trace+0x12/0x20
[19509.178589] [<c0105a46>] dump_stack+0x16/0x20
[19509.178611] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.178617] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.178622] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.178627] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.178631] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.178637] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.178642] [<c0124455>] do_softirq+0x55/0x60
[19509.178646] [<c0124713>] irq_exit+0x83/0x90
[19509.178650] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.178654] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.178658] =======================
[19509.179571] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.179577] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.179587] [<c0105952>] show_trace+0x12/0x20
[19509.179610] [<c0105a46>] dump_stack+0x16/0x20
[19509.179614] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.179620] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.179624] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.179629] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.179633] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.179640] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.179644] [<c0124455>] do_softirq+0x55/0x60
[19509.179648] [<c0124713>] irq_exit+0x83/0x90
[19509.179652] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.179656] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.179660] =======================
[19509.180565] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.180571] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.180581] [<c0105952>] show_trace+0x12/0x20
[19509.180586] [<c0105a46>] dump_stack+0x16/0x20
[19509.180608] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.180614] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.180618] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.180624] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.180628] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.180634] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.180639] [<c0124455>] do_softirq+0x55/0x60
[19509.180643] [<c0124713>] irq_exit+0x83/0x90
[19509.180647] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.180651] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.180655] =======================
[19509.181564] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.181570] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.181580] [<c0105952>] show_trace+0x12/0x20
[19509.181584] [<c0105a46>] dump_stack+0x16/0x20
[19509.181588] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.181611] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.181615] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.181620] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.181624] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.181630] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.181635] [<c0124455>] do_softirq+0x55/0x60
[19509.181638] [<c0124713>] irq_exit+0x83/0x90
[19509.181642] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.181647] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.181651] =======================
[19509.182564] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.182571] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.182581] [<c0105952>] show_trace+0x12/0x20
[19509.182585] [<c0105a46>] dump_stack+0x16/0x20
[19509.182606] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.182612] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.182616] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.182621] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.182625] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.182631] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.182636] [<c0124455>] do_softirq+0x55/0x60
[19509.182640] [<c0124713>] irq_exit+0x83/0x90
[19509.182643] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.182648] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.182652] =======================
[19509.183564] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.183571] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.183580] [<c0105952>] show_trace+0x12/0x20
[19509.183585] [<c0105a46>] dump_stack+0x16/0x20
[19509.183606] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.183613] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.183617] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.183623] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.183627] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.183633] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.183637] [<c0124455>] do_softirq+0x55/0x60
[19509.183641] [<c0124713>] irq_exit+0x83/0x90
[19509.183645] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.183649] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.183653] =======================
[19509.184562] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.184569] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.184578] [<c0105952>] show_trace+0x12/0x20
[19509.184582] [<c0105a46>] dump_stack+0x16/0x20
[19509.184586] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.184609] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.184613] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.184618] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.184622] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.184629] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.184633] [<c0124455>] do_softirq+0x55/0x60
[19509.184637] [<c0124713>] irq_exit+0x83/0x90
[19509.184641] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.184645] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.184650] =======================
[19509.185563] drivers/scsi/scsi_lib.c:838: setting error to 262144
[19509.185570] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19509.185580] [<c0105952>] show_trace+0x12/0x20
[19509.185585] [<c0105a46>] dump_stack+0x16/0x20
[19509.185605] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19509.185611] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19509.185615] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19509.185621] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19509.185625] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19509.185631] [<c01243a2>] __do_softirq+0x62/0xc0
[19509.185636] [<c0124455>] do_softirq+0x55/0x60
[19509.185639] [<c0124713>] irq_exit+0x83/0x90
[19509.185643] [<c010644e>] do_IRQ+0x4e/0xa0
[19509.185648] [<c0104c3a>] common_interrupt+0x2e/0x34
[19509.185652] =======================
[19509.185775] usb-storage: device scan complete
[19510.133841] i8xx TCO timer: cannot register miscdev on minor=130 (err=-16)
[19510.140087] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.01 (21-Jan-2007)
[19510.140447] iTCO_wdt: Found a ICH4 TCO device (Version=1, TCOBASE=0x0460)
[19510.140528] iTCO_wdt: cannot register miscdev on minor=130 (err=-16)
[19510.140538] iTCO_wdt: No card detected
[19510.212389] 8139too Fast Ethernet driver 0.9.28
[19510.213290] eth0: RealTek RTL8139 at 0xe0046000, 00:11:09:3c:07:c2, IRQ 23
[19510.213296] eth0: Identified 8139 chip type 'RTL-8101'
[19510.217011] 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[19510.229231] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19510.229239] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19510.229251] [<c0105952>] show_trace+0x12/0x20
[19510.229256] [<c0105a46>] dump_stack+0x16/0x20
[19510.229260] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19510.229266] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19510.229270] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19510.229276] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19510.229280] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19510.229286] [<c01243a2>] __do_softirq+0x62/0xc0
[19510.229292] [<c0124455>] do_softirq+0x55/0x60
[19510.229296] [<c0124713>] irq_exit+0x83/0x90
[19510.229300] [<c01148ca>] smp_apic_timer_interrupt+0x4a/0x80
[19510.229306] [<c0104c73>] apic_timer_interrupt+0x33/0x38
[19510.229311] [<c016299e>] __handle_mm_fault+0x7ae/0x9b0
[19510.229317] [<c04c9737>] do_page_fault+0x117/0x610
[19510.229324] [<c04c7fdc>] error_code+0x74/0x7c
[19510.229328] =======================
[19510.236218] drivers/scsi/scsi_lib.c:838: setting error to 134217730
[19510.236226] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[19510.236237] [<c0105952>] show_trace+0x12/0x20
[19510.236242] [<c0105a46>] dump_stack+0x16/0x20
[19510.236246] [<c034543a>] scsi_io_completion+0x28a/0x3a0
[19510.236252] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
[19510.236256] [<c0340d0c>] scsi_finish_command+0x4c/0x60
[19510.236262] [<c0345c07>] scsi_softirq_done+0x77/0xe0
[19510.236266] [<c0257f8b>] blk_done_softirq+0x6b/0x80
[19510.236273] [<c01243a2>] __do_softirq+0x62/0xc0
[19510.236278] [<c0124455>] do_softirq+0x55/0x60
[19510.236282] [<c0124713>] irq_exit+0x83/0x90
[19510.236286] [<c01148ca>] smp_apic_timer_interrupt+0x4a/0x80
[19510.236292] [<c0104c73>] apic_timer_interrupt+0x33/0x38
[19510.236297] [<c0164a36>] exit_mmap+0x66/0x100
[19510.236302] [<c011d1f7>] mmput+0x47/0xb0
[19510.236307] [<c0120f87>] exit_mm+0x67/0xc0
[19510.236311] [<c01224ca>] do_exit+0x12a/0x840
[19510.236316] [<c0122c09>] do_group_exit+0x29/0x70
[19510.236320] [<c0122c5f>] sys_exit_group+0xf/0x20
[19510.236325] [<c01041c6>] sysenter_past_esp+0x5f/0x99
[19510.236329] =======================
[19510.545779] snd-ca0106: Model 1006 Rev 00000000 Serial 10061102
[19511.069534] EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
[19511.069820] EXT3 FS on hda3, internal journal
[19511.591169] kjournald starting. Commit interval 5 seconds
[19511.591426] EXT3 FS on hda1, internal journal
[19511.591440] EXT3-fs: mounted filesystem with ordered data mode.
[19511.645321] kjournald2 starting. Commit interval 5 seconds
[19511.645378] EXT4-fs warning: maximal mount count reached, running e2fsck is recommended
[19511.645585] EXT4 FS on hdb1, internal journal
[19511.645697] EXT4-fs: mounted filesystem with ordered data mode.
[19511.645700] EXT4-fs: file extents enabled
[19511.766517] Adding 750448k swap on /dev/hda2. Priority:-1 extents:1 across:750448k
[19521.930371] eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1
[19524.564290] NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
[19524.576088] NFSD: starting 90-second grace period
[19532.228389] eth0: no IPv6 routers present
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-25 22:53 ` William Heimbigner
@ 2007-04-25 23:05 ` Andrew Morton
2007-04-26 0:48 ` William Heimbigner
2007-04-26 6:33 ` Jens Axboe
0 siblings, 2 replies; 16+ messages in thread
From: Andrew Morton @ 2007-04-25 23:05 UTC (permalink / raw)
To: William Heimbigner; +Cc: linux-kernel, Jens Axboe, Christoph Hellwig, linux-ide
On Wed, 25 Apr 2007 22:53:00 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
> On Wed, 25 Apr 2007, Andrew Morton wrote:
> <snip>
> > OK. I am able to use the pktcdvd driver OK in mainline with a piix/sata
> > drive. It could be that something is going wrong at the IDE level for you.
> Perhaps; I'll try an external usb cd burner, and see where that goes.
>
> > Are you able to identify the most recent kernel which actually worked?
> No, because I haven't set packet writing up in Linux before - however, I do know
> that I've successfully set up packet writing (using 2 of the 3 cd burners I
> have) in another operating system before. I'll try 2.6.18 and see if that gets
> me anywhere different, though.
OK.
A quick summary: mainline's pktcdvd isn't working for William using IDE.
It is working for me using sata.
> dmesg.1.txt is the dmesg output from immediately after system finishes booting
> (the unusually large printk times are due to kexec)
>
> # pktsetup 0 /dev/hdc
> [19861.831160] pktcdvd: writer pktcdvd0 mapped to hdc
> [19861.837138]
> [19861.837142] =============================================
> [19861.844343] [ INFO: possible recursive locking detected ]
> [19861.849738] 2.6.21-rc7 #2
> [19861.852361] ---------------------------------------------
> [19861.857750] vol_id/4433 is trying to acquire lock:
> [19861.862533] (&bdev->bd_mutex){--..}, at: [<c019bb8f>] do_open+0x4f/0x2c0
> [19861.869386]
> [19861.869387] but task is already holding lock:
> [19861.875225] (&bdev->bd_mutex){--..}, at: [<c019bb8f>] do_open+0x4f/0x2c0
> [19861.882070]
> [19861.882071] other info that might help us debug this:
> [19861.888602] 2 locks held by vol_id/4433:
> [19861.892518] #0: (&bdev->bd_mutex){--..}, at: [<c019bb8f>]
> do_open+0x4f/0x2c0
> [19861.899813] #1: (&ctl_mutex#2){--..}, at: [<c04c615c>] mutex_lock+0x1c/0x20
> [19861.907046]
> [19861.907047] stack backtrace:
> [19861.911415] [<c010521a>] show_trace_log_lvl+0x1a/0x30
> [19861.916569] [<c0105952>] show_trace+0x12/0x20
> [19861.921021] [<c0105a46>] dump_stack+0x16/0x20
> [19861.925475] [<c013ede0>] __lock_acquire+0xbc0/0x1040
> [19861.930542] [<c013f2d0>] lock_acquire+0x70/0x90
> [19861.935169] [<c04c61de>] mutex_lock_nested+0x7e/0x2e0
> [19861.940315] [<c019bb8f>] do_open+0x4f/0x2c0
> [19861.944595] [<c019be79>] __blkdev_get+0x79/0x90
> [19861.949222] [<c019bea5>] blkdev_get+0x15/0x20
> [19861.953674] [<c032a987>] pkt_open+0xb7/0xd80
> [19861.958050] [<c019bbc5>] do_open+0x85/0x2c0
> [19861.962330] [<c019c023>] blkdev_open+0x33/0x70
> [19861.966870] [<c0175084>] __dentry_open+0xf4/0x220
> [19861.971678] [<c0175255>] nameidata_to_filp+0x35/0x40
> [19861.976738] [<c01752a9>] do_filp_open+0x49/0x50
> [19861.981365] [<c01752f7>] do_sys_open+0x47/0xd0
> [19861.985904] [<c01753bc>] sys_open+0x1c/0x20
> [19861.990184] [<c01041c6>] sysenter_past_esp+0x5f/0x99
> [19861.995243] =======================
Yeah, I'm not worrying about that one for now.
> # pktsetup 1 /dev/hdd
> [19909.635795] cdrom: This disc doesn't have any tracks I recognize!
> [19909.689394] pktcdvd: writer pktcdvd1 mapped to hdd
> [19909.820337] drivers/ide/ide-cd.c:729: setting error to 2
> [19909.825649] [<c010521a>] show_trace_log_lvl+0x1a/0x30
> [19909.830810] [<c0105952>] show_trace+0x12/0x20
> [19909.835263] [<c0105a46>] dump_stack+0x16/0x20
> [19909.839716] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
> [19909.845131] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
> [19909.850190] [<c0331106>] ide_intr+0x96/0x200
> [19909.854557] [<c0150cf8>] handle_IRQ_event+0x28/0x60
> [19909.859538] [<c0151f96>] handle_edge_irq+0xa6/0x130
> [19909.864511] [<c0106449>] do_IRQ+0x49/0xa0
> [19909.868618] [<c0104c3a>] common_interrupt+0x2e/0x34
> [19909.873591] [<c01022d2>] mwait_idle+0x12/0x20
> [19909.878044] [<c01023ca>] cpu_idle+0x4a/0x80
> [19909.882324] [<c0101147>] rest_init+0x37/0x40
> [19909.886690] [<c068ac7b>] start_kernel+0x34b/0x420
> [19909.891499] [<00000000>] 0x0
> [19909.894488] =======================
> [19909.921518] pktcdvd: pkt_get_last_written failed
>
> # pktsetup 2 /dev/sr0
> [19982.934793] drivers/scsi/scsi_lib.c:838: setting error to 134217730
> [19982.941070] [<c010521a>] show_trace_log_lvl+0x1a/0x30
> [19982.946256] [<c0105952>] show_trace+0x12/0x20
> [19982.950744] [<c0105a46>] dump_stack+0x16/0x20
> [19982.955232] [<c034543a>] scsi_io_completion+0x28a/0x3a0
> [19982.960586] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
> [19982.965594] [<c0340d0c>] scsi_finish_command+0x4c/0x60
> [19982.970861] [<c0345c07>] scsi_softirq_done+0x77/0xe0
> [19982.975955] [<c0257f8b>] blk_done_softirq+0x6b/0x80
> [19982.980962] [<c01243a2>] __do_softirq+0x62/0xc0
> [19982.985624] [<c0124455>] do_softirq+0x55/0x60
> [19982.990112] [<c0124be5>] ksoftirqd+0x65/0x100
> [19982.994599] [<c0132963>] kthread+0xa3/0xd0
> [19982.998827] [<c0104e17>] kernel_thread_helper+0x7/0x10
> [19983.004095] =======================
> [19983.009065] cdrom: This disc doesn't have any tracks I recognize!
So what has happened here is that this code, in ide-cd.c's
cdrom_decode_status() is now triggering:
} else if (blk_pc_request(rq) || rq->cmd_type == REQ_TYPE_ATA_PC) {
/* All other functions, except for READ. */
unsigned long flags;
/*
* if we have an error, pass back CHECK_CONDITION as the
* scsi status byte
*/
if (blk_pc_request(rq) && !rq->errors)
rq->errors = SAM_STAT_CHECK_CONDITION;
I suspect this is a bug introduced by
406c9b605cbc45151c03ac9a3f95e9acf050808c (in which case it'll be the third
bug so far).
Perhaps the IDE driver was previously not considering these requests to be
of type blk_pc_request(), and after
406c9b605cbc45151c03ac9a3f95e9acf050808c it _is_ treating them as
blk_pc_request() and is incorrectly reporting an error. Or something like
that.
Guys: help!
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-25 23:05 ` Andrew Morton
@ 2007-04-26 0:48 ` William Heimbigner
2007-04-26 6:39 ` Jens Axboe
2007-04-26 6:33 ` Jens Axboe
1 sibling, 1 reply; 16+ messages in thread
From: William Heimbigner @ 2007-04-26 0:48 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, Jens Axboe, Christoph Hellwig, linux-ide
On Wed, 25 Apr 2007, Andrew Morton wrote:
> On Wed, 25 Apr 2007 22:53:00 +0000 (GMT) William Heimbigner <icxcnika@mar.tar.cc> wrote:
>
>> On Wed, 25 Apr 2007, Andrew Morton wrote:
>> <snip>
>>> OK. I am able to use the pktcdvd driver OK in mainline with a piix/sata
>>> drive. It could be that something is going wrong at the IDE level for you.
>> Perhaps; I'll try an external usb cd burner, and see where that goes.
>>
>>> Are you able to identify the most recent kernel which actually worked?
>> No, because I haven't set packet writing up in Linux before - however, I do know
>> that I've successfully set up packet writing (using 2 of the 3 cd burners I
>> have) in another operating system before. I'll try 2.6.18 and see if that gets
>> me anywhere different, though.
>
> OK.
>
> A quick summary: mainline's pktcdvd isn't working for William using IDE.
> It is working for me using sata.
>
<snip>
>
> So what has happened here is that this code, in ide-cd.c's
> cdrom_decode_status() is now triggering:
>
> } else if (blk_pc_request(rq) || rq->cmd_type == REQ_TYPE_ATA_PC) {
> /* All other functions, except for READ. */
> unsigned long flags;
>
> /*
> * if we have an error, pass back CHECK_CONDITION as the
> * scsi status byte
> */
> if (blk_pc_request(rq) && !rq->errors)
> rq->errors = SAM_STAT_CHECK_CONDITION;
>
>
> I suspect this is a bug introduced by
> 406c9b605cbc45151c03ac9a3f95e9acf050808c (in which case it'll be the third
> bug so far).
>
> Perhaps the IDE driver was previously not considering these requests to be
> of type blk_pc_request(), and after
> 406c9b605cbc45151c03ac9a3f95e9acf050808c it _is_ treating them as
> blk_pc_request() and is incorrectly reporting an error. Or something like
> that.
>
> Guys: help!
>
A follow-up: after looking around a bit, I have managed to get packet writing to
work properly on /dev/hdc (before, it was reporting only 1.8 MB available or so;
this was a formatting issue).
I've also gotten the external cd-rw drive to work. However, I'm still at a loss
as to why /dev/hdd won't work. I tried formatting a dvd-rw for this drive,
however, it consistently gives me:
[27342.503933] drivers/ide/ide-cd.c:729: setting error to 2
[27342.509251] [<c010521a>] show_trace_log_lvl+0x1a/0x30
[27342.514411] [<c0105952>] show_trace+0x12/0x20
[27342.518864] [<c0105a46>] dump_stack+0x16/0x20
[27342.523317] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
[27342.528732] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
[27342.533791] [<c0331106>] ide_intr+0x96/0x200
[27342.538157] [<c0150cf8>] handle_IRQ_event+0x28/0x60
[27342.543139] [<c0151f96>] handle_edge_irq+0xa6/0x130
[27342.548121] [<c0106449>] do_IRQ+0x49/0xa0
[27342.552228] [<c0104c3a>] common_interrupt+0x2e/0x34
[27342.557200] [<c01022d2>] mwait_idle+0x12/0x20
[27342.561653] [<c01023ca>] cpu_idle+0x4a/0x80
[27342.565934] [<c0101147>] rest_init+0x37/0x40
[27342.570300] [<c068ac7b>] start_kernel+0x34b/0x420
[27342.575109] [<00000000>] 0x0
[27342.578089] =======================
and doesn't work (the above output was generated by Andrew's patch to log
certain areas).
# dvd+rw-format /dev/hdd -force
* BD/DVDRW/-RAM format utility by <appro@fy.chalmers.se>, version 7.0.
:-( failed to locate "Quick Format" descriptor.
* 4.7GB DVD-RW media in Sequential mode detected.
* formatting 0.0\:-[ READ TRACK INFORMATION failed with SK=3h/ASC=11h/ACQ=05h]: Input/output error
I tried putting in a different dvd-rw, and this time I get:
# dvd+rw-format /dev/hdd -force
* BD/DVDRW/-RAM format utility by <appro@fy.chalmers.se>, version 7.0.
* 4.7GB DVD-RW media in Sequential mode detected.
* formatting 0.0|:-[ FORMAT UNIT failed with SK=5h/ASC=26h/ACQ=00h]: Input/output error
William Heimbigner
icxcnika@mar.tar.cc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-25 23:05 ` Andrew Morton
2007-04-26 0:48 ` William Heimbigner
@ 2007-04-26 6:33 ` Jens Axboe
1 sibling, 0 replies; 16+ messages in thread
From: Jens Axboe @ 2007-04-26 6:33 UTC (permalink / raw)
To: Andrew Morton
Cc: William Heimbigner, linux-kernel, Christoph Hellwig, linux-ide
On Wed, Apr 25 2007, Andrew Morton wrote:
> > # pktsetup 2 /dev/sr0
> > [19982.934793] drivers/scsi/scsi_lib.c:838: setting error to 134217730
> > [19982.941070] [<c010521a>] show_trace_log_lvl+0x1a/0x30
> > [19982.946256] [<c0105952>] show_trace+0x12/0x20
> > [19982.950744] [<c0105a46>] dump_stack+0x16/0x20
> > [19982.955232] [<c034543a>] scsi_io_completion+0x28a/0x3a0
> > [19982.960586] [<c034556b>] scsi_blk_pc_done+0x1b/0x30
> > [19982.965594] [<c0340d0c>] scsi_finish_command+0x4c/0x60
> > [19982.970861] [<c0345c07>] scsi_softirq_done+0x77/0xe0
> > [19982.975955] [<c0257f8b>] blk_done_softirq+0x6b/0x80
> > [19982.980962] [<c01243a2>] __do_softirq+0x62/0xc0
> > [19982.985624] [<c0124455>] do_softirq+0x55/0x60
> > [19982.990112] [<c0124be5>] ksoftirqd+0x65/0x100
> > [19982.994599] [<c0132963>] kthread+0xa3/0xd0
> > [19982.998827] [<c0104e17>] kernel_thread_helper+0x7/0x10
> > [19983.004095] =======================
> > [19983.009065] cdrom: This disc doesn't have any tracks I recognize!
>
> So what has happened here is that this code, in ide-cd.c's
> cdrom_decode_status() is now triggering:
>
> } else if (blk_pc_request(rq) || rq->cmd_type == REQ_TYPE_ATA_PC) {
> /* All other functions, except for READ. */
> unsigned long flags;
>
> /*
> * if we have an error, pass back CHECK_CONDITION as the
> * scsi status byte
> */
> if (blk_pc_request(rq) && !rq->errors)
> rq->errors = SAM_STAT_CHECK_CONDITION;
>
>
> I suspect this is a bug introduced by
> 406c9b605cbc45151c03ac9a3f95e9acf050808c (in which case it'll be the third
> bug so far).
>
> Perhaps the IDE driver was previously not considering these requests to be
> of type blk_pc_request(), and after
> 406c9b605cbc45151c03ac9a3f95e9acf050808c it _is_ treating them as
> blk_pc_request() and is incorrectly reporting an error. Or something like
> that.
But it IS a block pc request. We've been setting the sam stats on
->errors for block pc request for a long time.
> Guys: help!
I'm not sure what your question is, if someone can some up what the what
goes wrong and what the expected result is, I can try and help.
--
Jens Axboe
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: BUG: Null pointer dereference in fs/open.c
2007-04-26 0:48 ` William Heimbigner
@ 2007-04-26 6:39 ` Jens Axboe
0 siblings, 0 replies; 16+ messages in thread
From: Jens Axboe @ 2007-04-26 6:39 UTC (permalink / raw)
To: William Heimbigner
Cc: Andrew Morton, linux-kernel, Christoph Hellwig, linux-ide
On Thu, Apr 26 2007, William Heimbigner wrote:
> On Wed, 25 Apr 2007, Andrew Morton wrote:
> >On Wed, 25 Apr 2007 22:53:00 +0000 (GMT) William Heimbigner
> ><icxcnika@mar.tar.cc> wrote:
> >
> >>On Wed, 25 Apr 2007, Andrew Morton wrote:
> >><snip>
> >>>OK. I am able to use the pktcdvd driver OK in mainline with a piix/sata
> >>>drive. It could be that something is going wrong at the IDE level for
> >>>you.
> >>Perhaps; I'll try an external usb cd burner, and see where that goes.
> >>
> >>>Are you able to identify the most recent kernel which actually worked?
> >>No, because I haven't set packet writing up in Linux before - however, I
> >>do know
> >>that I've successfully set up packet writing (using 2 of the 3 cd burners
> >>I
> >>have) in another operating system before. I'll try 2.6.18 and see if that
> >>gets
> >>me anywhere different, though.
> >
> >OK.
> >
> >A quick summary: mainline's pktcdvd isn't working for William using IDE.
> >It is working for me using sata.
> >
> <snip>
> >
> >So what has happened here is that this code, in ide-cd.c's
> >cdrom_decode_status() is now triggering:
> >
> > } else if (blk_pc_request(rq) || rq->cmd_type == REQ_TYPE_ATA_PC) {
> > /* All other functions, except for READ. */
> > unsigned long flags;
> >
> > /*
> > * if we have an error, pass back CHECK_CONDITION as the
> > * scsi status byte
> > */
> > if (blk_pc_request(rq) && !rq->errors)
> > rq->errors = SAM_STAT_CHECK_CONDITION;
> >
> >
> >I suspect this is a bug introduced by
> >406c9b605cbc45151c03ac9a3f95e9acf050808c (in which case it'll be the third
> >bug so far).
> >
> >Perhaps the IDE driver was previously not considering these requests to be
> >of type blk_pc_request(), and after
> >406c9b605cbc45151c03ac9a3f95e9acf050808c it _is_ treating them as
> >blk_pc_request() and is incorrectly reporting an error. Or something like
> >that.
> >
> >Guys: help!
> >
> A follow-up: after looking around a bit, I have managed to get packet
> writing to work properly on /dev/hdc (before, it was reporting only 1.8 MB
> available or so; this was a formatting issue).
> I've also gotten the external cd-rw drive to work. However, I'm still at a
> loss as to why /dev/hdd won't work. I tried formatting a dvd-rw for this
> drive, however, it consistently gives me:
> [27342.503933] drivers/ide/ide-cd.c:729: setting error to 2
> [27342.509251] [<c010521a>] show_trace_log_lvl+0x1a/0x30
> [27342.514411] [<c0105952>] show_trace+0x12/0x20
> [27342.518864] [<c0105a46>] dump_stack+0x16/0x20
> [27342.523317] [<c033f6e4>] cdrom_decode_status+0x1f4/0x3b0
> [27342.528732] [<c033fae8>] cdrom_newpc_intr+0x38/0x320
> [27342.533791] [<c0331106>] ide_intr+0x96/0x200
> [27342.538157] [<c0150cf8>] handle_IRQ_event+0x28/0x60
> [27342.543139] [<c0151f96>] handle_edge_irq+0xa6/0x130
> [27342.548121] [<c0106449>] do_IRQ+0x49/0xa0
> [27342.552228] [<c0104c3a>] common_interrupt+0x2e/0x34
> [27342.557200] [<c01022d2>] mwait_idle+0x12/0x20
> [27342.561653] [<c01023ca>] cpu_idle+0x4a/0x80
> [27342.565934] [<c0101147>] rest_init+0x37/0x40
> [27342.570300] [<c068ac7b>] start_kernel+0x34b/0x420
> [27342.575109] [<00000000>] 0x0
> [27342.578089] =======================
> and doesn't work (the above output was generated by Andrew's patch to log
> certain areas).
>
> # dvd+rw-format /dev/hdd -force
> * BD/DVDRW/-RAM format utility by <appro@fy.chalmers.se>, version 7.0.
> :-( failed to locate "Quick Format" descriptor.
> * 4.7GB DVD-RW media in Sequential mode detected.
> * formatting 0.0\:-[ READ TRACK INFORMATION failed with
> SK=3h/ASC=11h/ACQ=05h]: Input/output error
That's an uncorrectable read error. Is the media good?
> I tried putting in a different dvd-rw, and this time I get:
> # dvd+rw-format /dev/hdd -force
> * BD/DVDRW/-RAM format utility by <appro@fy.chalmers.se>, version 7.0.
> * 4.7GB DVD-RW media in Sequential mode detected.
> * formatting 0.0|:-[ FORMAT UNIT failed with SK=5h/ASC=26h/ACQ=00h]:
> Input/output error
That's the drive complaining about an invalid bit being set in the
command descriptor block. That's usually a bug in the issuer.
--
Jens Axboe
^ permalink raw reply [flat|nested] 16+ messages in thread
end of thread, other threads:[~2007-04-26 6:40 UTC | newest]
Thread overview: 16+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2007-04-22 23:13 BUG: Null pointer dereference (2.6.21-rc7) William Heimbigner
2007-04-23 8:00 ` Andrew Morton
2007-04-23 13:58 ` William Heimbigner
2007-04-23 16:39 ` William Heimbigner
2007-04-24 4:09 ` BUG: Null pointer dereference in fs/open.c William Heimbigner
[not found] ` <20070423215810.5a24ed9a.akpm@linux-foundation.org>
2007-04-24 5:10 ` William Heimbigner
2007-04-24 5:17 ` Andrew Morton
2007-04-24 5:44 ` William Heimbigner
2007-04-24 5:56 ` Andrew Morton
2007-04-25 7:48 ` Andrew Morton
2007-04-25 22:53 ` William Heimbigner
2007-04-25 23:05 ` Andrew Morton
2007-04-26 0:48 ` William Heimbigner
2007-04-26 6:39 ` Jens Axboe
2007-04-26 6:33 ` Jens Axboe
2007-04-24 20:46 ` Peter Osterlund
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox