sata_mv oops on module removal

sata_mv oops on module removal

[Tomasz Chmielewski]

This is what happened when I tried to remove sata_mv module:


ACPI: PCI interrupt for device 0000:01:00.0 disabled
BUG: unable to handle kernel paging request at virtual address e0122028
  printing eip:
e0015599
*pde = 1f557067
*pte = 00000000
Oops: 0000 [#1]
Modules linked in: cpufreq_ondemand p4_clockmod speedstep_lib iscsi_scst 
crc32c libcrc32c scst_vdisk scst bonding dm_mirror dm_snapshot sata_mv
CPU:    0
EIP:    0060:[<e0015599>]    Not tainted VLI
EFLAGS: 00010046   (2.6.23.14-N5200-3 #8)
EIP is at __mv_stop_dma+0x53/0xc2 [sata_mv]
eax: e0120000   ebx: 00000282   ecx: df629a0c   edx: df629a4c
esi: df494000   edi: e0122000   ebp: df44d048   esp: ddd07eb8
ds: 007b   es: 007b   fs: 0000  gs: 0033  ss: 0068
Process rmmod (pid: 2305, ti=ddd06000 task=df25aa80 task.ti=ddd06000)
Stack: df44d0ec 00000000 c01d14bc 00000001 00000282 df5aa4ec df44d14c 
e0015611
        00000000 c0219884 df5aa4e0 ddd07f00 df44d14c 00000000 c01f525f 
df44d14c
        df44d048 0000001d df5aa4e0 df7e5a00 00000292 e0018af0 c0347760 
ddd06000
Call Trace:
  [<c01d14bc>] acpi_pci_free_irq+0x0/0x12
  [<e0015611>] mv_stop_dma+0x9/0xd [sata_mv]
  [<c0219884>] ata_host_release+0x2f/0x87
  [<c01f525f>] release_nodes+0x102/0x122
  [<c01f5387>] devres_release_all+0x1b/0x1e
  [<c01f3422>] __device_release_driver+0x75/0x8b
  [<c01f37f3>] driver_detach+0x59/0x96
  [<c01f300d>] bus_remove_driver+0x57/0x75
  [<c01b250a>] pci_unregister_driver+0xc/0x45
  [<c012da39>] sys_delete_module+0x16f/0x196
  [<c013ceaa>] remove_vma+0x31/0x36
  [<c0103bd6>] syscall_call+0x7/0xb
  =======================
Code: 00 02 00 8b 96 70 20 00 00 8d b8 00 20 00 00 f6 42 20 01 74 16 c7 
80 28 20 00 00 02 00 00 00 8b 80 28 20 00 00 83 62 20 fe eb 33 <8b> 80 
28 20 00 00
EIP: [<e0015599>] __mv_stop_dma+0x53/0xc2 [sata_mv] SS:ESP 0068:ddd07eb8



If you need more info, please CC me, I'm not subscribed.



-- 
Tomasz Chmielewski
http://wpkg.org

Re: sata_mv oops on module removal

[Mark Lord]

Tomasz Chmielewski wrote:
> This is what happened when I tried to remove sata_mv module:
> 
> 
> ACPI: PCI interrupt for device 0000:01:00.0 disabled
> BUG: unable to handle kernel paging request at virtual address e0122028
>  printing eip:
> e0015599
> *pde = 1f557067
> *pte = 00000000
> Oops: 0000 [#1]
> Modules linked in: cpufreq_ondemand p4_clockmod speedstep_lib iscsi_scst 
> crc32c libcrc32c scst_vdisk scst bonding dm_mirror dm_snapshot sata_mv
> CPU:    0
> EIP:    0060:[<e0015599>]    Not tainted VLI
> EFLAGS: 00010046   (2.6.23.14-N5200-3 #8)
> EIP is at __mv_stop_dma+0x53/0xc2 [sata_mv]
> eax: e0120000   ebx: 00000282   ecx: df629a0c   edx: df629a4c
> esi: df494000   edi: e0122000   ebp: df44d048   esp: ddd07eb8
> ds: 007b   es: 007b   fs: 0000  gs: 0033  ss: 0068
> Process rmmod (pid: 2305, ti=ddd06000 task=df25aa80 task.ti=ddd06000)
> Stack: df44d0ec 00000000 c01d14bc 00000001 00000282 df5aa4ec df44d14c 
> e0015611
>        00000000 c0219884 df5aa4e0 ddd07f00 df44d14c 00000000 c01f525f 
> df44d14c
>        df44d048 0000001d df5aa4e0 df7e5a00 00000292 e0018af0 c0347760 
> ddd06000
> Call Trace:
>  [<c01d14bc>] acpi_pci_free_irq+0x0/0x12
>  [<e0015611>] mv_stop_dma+0x9/0xd [sata_mv]
>  [<c0219884>] ata_host_release+0x2f/0x87
>  [<c01f525f>] release_nodes+0x102/0x122
>  [<c01f5387>] devres_release_all+0x1b/0x1e
>  [<c01f3422>] __device_release_driver+0x75/0x8b
>  [<c01f37f3>] driver_detach+0x59/0x96
>  [<c01f300d>] bus_remove_driver+0x57/0x75
>  [<c01b250a>] pci_unregister_driver+0xc/0x45
>  [<c012da39>] sys_delete_module+0x16f/0x196
>  [<c013ceaa>] remove_vma+0x31/0x36
>  [<c0103bd6>] syscall_call+0x7/0xb
>  =======================
> Code: 00 02 00 8b 96 70 20 00 00 8d b8 00 20 00 00 f6 42 20 01 74 16 c7 
> 80 28 20 00 00 02 00 00 00 8b 80 28 20 00 00 83 62 20 fe eb 33 <8b> 80 
> 28 20 00 00
> EIP: [<e0015599>] __mv_stop_dma+0x53/0xc2 [sata_mv] SS:ESP 0068:ddd07eb8
..

You did not say which exact kernel version this is from.
A bug just like this was fixed not long ago.

-ml

Re: sata_mv oops on module removal

[Tomasz Chmielewski]

Mark Lord schrieb:
> Tomasz Chmielewski wrote:
>> This is what happened when I tried to remove sata_mv module:
>>
>>
>> ACPI: PCI interrupt for device 0000:01:00.0 disabled
>> BUG: unable to handle kernel paging request at virtual address e0122028
>>  printing eip:
>> e0015599
>> *pde = 1f557067
>> *pte = 00000000
>> Oops: 0000 [#1]
>> Modules linked in: cpufreq_ondemand p4_clockmod speedstep_lib 
>> iscsi_scst crc32c libcrc32c scst_vdisk scst bonding dm_mirror 
>> dm_snapshot sata_mv
>> CPU:    0
>> EIP:    0060:[<e0015599>]    Not tainted VLI
>> EFLAGS: 00010046   (2.6.23.14-N5200-3 #8)
                        ^^^^^^^^^

> You did not say which exact kernel version this is from.
> A bug just like this was fixed not long ago.

It's 2.6.23.14.
I didn't find anything similar.
Am I looking wrong, or was it a fix for 2.6.24?


-- 
Tomasz Chmielewski
http://wpkg.org

Re: sata_mv oops on module removal

[Mark Lord]

Tejun,

This Oops (2.6.23.13) looks very much like the same bug
you fixed recently for me in 2.6.24.

The bug was with sata_qstor and other drivers, in that
devres/libata were freeing the I/O resources before invoking
the LLD's host/port_stop routines .. which still need the I/O.

Did that patch get backported to 2.6.23 yet ?

Cheers

Tomasz Chmielewski wrote:
> This is what happened when I tried to remove sata_mv module:
> 
> 
> ACPI: PCI interrupt for device 0000:01:00.0 disabled
> BUG: unable to handle kernel paging request at virtual address e0122028
>  printing eip:
> e0015599
> *pde = 1f557067
> *pte = 00000000
> Oops: 0000 [#1]
> Modules linked in: cpufreq_ondemand p4_clockmod speedstep_lib iscsi_scst 
> crc32c libcrc32c scst_vdisk scst bonding dm_mirror dm_snapshot sata_mv
> CPU:    0
> EIP:    0060:[<e0015599>]    Not tainted VLI
> EFLAGS: 00010046   (2.6.23.14-N5200-3 #8)
> EIP is at __mv_stop_dma+0x53/0xc2 [sata_mv]
> eax: e0120000   ebx: 00000282   ecx: df629a0c   edx: df629a4c
> esi: df494000   edi: e0122000   ebp: df44d048   esp: ddd07eb8
> ds: 007b   es: 007b   fs: 0000  gs: 0033  ss: 0068
> Process rmmod (pid: 2305, ti=ddd06000 task=df25aa80 task.ti=ddd06000)
> Stack: df44d0ec 00000000 c01d14bc 00000001 00000282 df5aa4ec df44d14c 
> e0015611
>        00000000 c0219884 df5aa4e0 ddd07f00 df44d14c 00000000 c01f525f 
> df44d14c
>        df44d048 0000001d df5aa4e0 df7e5a00 00000292 e0018af0 c0347760 
> ddd06000
> Call Trace:
>  [<c01d14bc>] acpi_pci_free_irq+0x0/0x12
>  [<e0015611>] mv_stop_dma+0x9/0xd [sata_mv]
>  [<c0219884>] ata_host_release+0x2f/0x87
>  [<c01f525f>] release_nodes+0x102/0x122
>  [<c01f5387>] devres_release_all+0x1b/0x1e
>  [<c01f3422>] __device_release_driver+0x75/0x8b
>  [<c01f37f3>] driver_detach+0x59/0x96
>  [<c01f300d>] bus_remove_driver+0x57/0x75
>  [<c01b250a>] pci_unregister_driver+0xc/0x45
>  [<c012da39>] sys_delete_module+0x16f/0x196
>  [<c013ceaa>] remove_vma+0x31/0x36
>  [<c0103bd6>] syscall_call+0x7/0xb
>  =======================
> Code: 00 02 00 8b 96 70 20 00 00 8d b8 00 20 00 00 f6 42 20 01 74 16 c7 
> 80 28 20 00 00 02 00 00 00 8b 80 28 20 00 00 83 62 20 fe eb 33 <8b> 80 
> 28 20 00 00
> EIP: [<e0015599>] __mv_stop_dma+0x53/0xc2 [sata_mv] SS:ESP 0068:ddd07eb8
> 
> 
> 
> If you need more info, please CC me, I'm not subscribed.
> 
> 
> 

Re: sata_mv oops on module removal

[Tejun Heo]

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

Mark Lord wrote:
> Tejun,
> 
> This Oops (2.6.23.13) looks very much like the same bug
> you fixed recently for me in 2.6.24.
> 
> The bug was with sata_qstor and other drivers, in that
> devres/libata were freeing the I/O resources before invoking
> the LLD's host/port_stop routines .. which still need the I/O.
> 
> Did that patch get backported to 2.6.23 yet ?

No, it's not but yeah it probably should have.  Tomasz, can you please
test whether the attached patch fixes the problem?

-- 
tejun

[-- Attachment #2: patch --]
[-- Type: text/plain, Size: 2301 bytes --]

Index: tree0/drivers/ata/libata-core.c
===================================================================
--- tree0.orig/drivers/ata/libata-core.c
+++ tree0/drivers/ata/libata-core.c
@@ -6121,19 +6121,6 @@ static void ata_host_release(struct devi
 		if (!ap)
 			continue;
 
-		if ((host->flags & ATA_HOST_STARTED) && ap->ops->port_stop)
-			ap->ops->port_stop(ap);
-	}
-
-	if ((host->flags & ATA_HOST_STARTED) && host->ops->host_stop)
-		host->ops->host_stop(host);
-
-	for (i = 0; i < host->n_ports; i++) {
-		struct ata_port *ap = host->ports[i];
-
-		if (!ap)
-			continue;
-
 		if (ap->scsi_host)
 			scsi_host_put(ap->scsi_host);
 
@@ -6258,6 +6245,24 @@ struct ata_host *ata_host_alloc_pinfo(st
 	return host;
 }
 
+static void ata_host_stop(struct device *gendev, void *res)
+{
+	struct ata_host *host = dev_get_drvdata(gendev);
+	int i;
+
+	WARN_ON(!(host->flags & ATA_HOST_STARTED));
+
+	for (i = 0; i < host->n_ports; i++) {
+		struct ata_port *ap = host->ports[i];
+
+		if (ap->ops->port_stop)
+			ap->ops->port_stop(ap);
+	}
+
+	if (host->ops->host_stop)
+		host->ops->host_stop(host);
+}
+
 /**
  *	ata_host_start - start and freeze ports of an ATA host
  *	@host: ATA host to start ports for
@@ -6276,6 +6281,8 @@ struct ata_host *ata_host_alloc_pinfo(st
  */
 int ata_host_start(struct ata_host *host)
 {
+	int have_stop = 0;
+	void *start_dr = NULL;
 	int i, rc;
 
 	if (host->flags & ATA_HOST_STARTED)
@@ -6287,6 +6294,22 @@ int ata_host_start(struct ata_host *host
 		if (!host->ops && !ata_port_is_dummy(ap))
 			host->ops = ap->ops;
 
+		if (ap->ops->port_stop)
+			have_stop = 1;
+	}
+
+	if (host->ops->host_stop)
+		have_stop = 1;
+
+	if (have_stop) {
+		start_dr = devres_alloc(ata_host_stop, 0, GFP_KERNEL);
+		if (!start_dr)
+			return -ENOMEM;
+	}
+
+	for (i = 0; i < host->n_ports; i++) {
+		struct ata_port *ap = host->ports[i];
+
 		if (ap->ops->port_start) {
 			rc = ap->ops->port_start(ap);
 			if (rc) {
@@ -6299,6 +6322,8 @@ int ata_host_start(struct ata_host *host
 		ata_eh_freeze_port(ap);
 	}
 
+	if (start_dr)
+		devres_add(host->dev, start_dr);
 	host->flags |= ATA_HOST_STARTED;
 	return 0;
 
@@ -6309,6 +6334,7 @@ int ata_host_start(struct ata_host *host
 		if (ap->ops->port_stop)
 			ap->ops->port_stop(ap);
 	}
+	devres_free(start_dr);
 	return rc;
 }
 

Re: sata_mv oops on module removal

[Tomasz Chmielewski]

Tejun Heo schrieb:
> Mark Lord wrote:
>> Tejun,
>>
>> This Oops (2.6.23.13) looks very much like the same bug
>> you fixed recently for me in 2.6.24.
>>
>> The bug was with sata_qstor and other drivers, in that
>> devres/libata were freeing the I/O resources before invoking
>> the LLD's host/port_stop routines .. which still need the I/O.
>>
>> Did that patch get backported to 2.6.23 yet ?
> 
> No, it's not but yeah it probably should have.  Tomasz, can you please
> test whether the attached patch fixes the problem?

No oops anymore - I get those in the log instead (below).

START_STOP FAILED doesn't sound very good, but perhaps it's normal?



# rmmod sata_mv
# dmesg
ata1.00: disabled
scst: Detached SCSI target mid-level from scsi1, channel 0, id 0, lun 0, 
type 0
sd 1:0:0:0: [sdb] Synchronizing SCSI cache
sd 1:0:0:0: [sdb] Result: hostbyte=0x04 driverbyte=0x00
sd 1:0:0:0: [sdb] Stopping disk
sd 1:0:0:0: [sdb] START_STOP FAILED
sd 1:0:0:0: [sdb] Result: hostbyte=0x04 driverbyte=0x00
ata2.00: disabled
scst: Detached SCSI target mid-level from scsi2, channel 0, id 0, lun 0, 
type 0
sd 2:0:0:0: [sdc] Synchronizing SCSI cache
sd 2:0:0:0: [sdc] Result: hostbyte=0x04 driverbyte=0x00
sd 2:0:0:0: [sdc] Stopping disk
sd 2:0:0:0: [sdc] START_STOP FAILED
sd 2:0:0:0: [sdc] Result: hostbyte=0x04 driverbyte=0x00
ata3.00: disabled
scst: Detached SCSI target mid-level from scsi3, channel 0, id 0, lun 0, 
type 0
sd 3:0:0:0: [sdd] Synchronizing SCSI cache
sd 3:0:0:0: [sdd] Result: hostbyte=0x04 driverbyte=0x00
sd 3:0:0:0: [sdd] Stopping disk
sd 3:0:0:0: [sdd] START_STOP FAILED
sd 3:0:0:0: [sdd] Result: hostbyte=0x04 driverbyte=0x00
ata4.00: disabled
scst: Detached SCSI target mid-level from scsi4, channel 0, id 0, lun 0, 
type 0
sd 4:0:0:0: [sde] Synchronizing SCSI cache
sd 4:0:0:0: [sde] Result: hostbyte=0x04 driverbyte=0x00
sd 4:0:0:0: [sde] Stopping disk
sd 4:0:0:0: [sde] START_STOP FAILED
sd 4:0:0:0: [sde] Result: hostbyte=0x04 driverbyte=0x00
ata5.00: disabled
scst: Detached SCSI target mid-level from scsi5, channel 0, id 0, lun 0, 
type 0
sd 5:0:0:0: [sdf] Synchronizing SCSI cache
sd 5:0:0:0: [sdf] Result: hostbyte=0x04 driverbyte=0x00
sd 5:0:0:0: [sdf] Stopping disk
sd 5:0:0:0: [sdf] START_STOP FAILED
sd 5:0:0:0: [sdf] Result: hostbyte=0x04 driverbyte=0x00
ACPI: PCI interrupt for device 0000:01:00.0 disabled



-- 
Tomasz Chmielewski
http://wpkg.org

Re: sata_mv oops on module removal

[Tejun Heo]

Tomasz Chmielewski wrote:
> Tejun Heo schrieb:
>> Mark Lord wrote:
>>> Tejun,
>>>
>>> This Oops (2.6.23.13) looks very much like the same bug
>>> you fixed recently for me in 2.6.24.
>>>
>>> The bug was with sata_qstor and other drivers, in that
>>> devres/libata were freeing the I/O resources before invoking
>>> the LLD's host/port_stop routines .. which still need the I/O.
>>>
>>> Did that patch get backported to 2.6.23 yet ?
>>
>> No, it's not but yeah it probably should have.  Tomasz, can you please
>> test whether the attached patch fixes the problem?
> 
> No oops anymore - I get those in the log instead (below).

Great.

> START_STOP FAILED doesn't sound very good, but perhaps it's normal?

Yeap, that's normal.  ATA device goes away beneath the SCSI driver and
when the SCSI driver tries to stop the drive, it's already gone.  I'll
push the patch to -stable.

Thanks.

-- 
tejun