Re: BUG in: Driver core: convert block from raw kobjects to coredevices

From: Alan Stern
Date: Fri Oct 19 2007 - 13:11:54 EST


On Fri, 19 Oct 2007, Kay Sievers wrote:

> > Don't you have a USB storage device? It should be easy for you to test
> > this on your own system.
>
> Sure, I have, and tried a lot of times, and all seemed correct here with
> the final put. I don't say that it's the right fix, but without it, the
> disk device object is never released here, it only gets removed from
> sysfs.

Well, attached is a testing patch. It should apply to 2.6.23 together
with gregkh-all-2.6.23. Here's the output on my system using your
original code:

Plug in USB drive:

[ 75.555077] usb-storage: device found at 3
[ 75.558052] scsi 0:0:0:0: Direct-Access UDISK PDU01_1G 65G2.0 0.00 PQ: 0 ANSI: 2
[ 75.568248] usb-storage: device scan complete
[ 75.917139] sd 0:0:0:0: [sda] 1967616 512-byte hardware sectors (1007 MB)
[ 75.918463] sd 0:0:0:0: [sda] Write Protect is off
[ 75.919011] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[ 75.919263] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 75.919397] sd_probe: call add_disk
[ 75.919615] start of register_disk: 1
[ 75.920402] after device_add: 3
[ 75.920692] after disk_sysfs_add_subdirs: 5
[ 75.921173] after get_capacity: 5
[ 75.921461] after bdget_disk: 5
[ 75.927996] sd 0:0:0:0: [sda] 1967616 512-byte hardware sectors (1007 MB)
[ 75.929405] sd 0:0:0:0: [sda] Write Protect is off
[ 75.929801] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[ 75.929960] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 75.930202] sda: sda1
[ 75.966112] after blkdev_get: 8
[ 75.966648] after blkdev_put: 7
[ 75.968997] end of register_disk: 7
[ 75.969327] after blk_register_queue: 9
[ 75.969823] sd 0:0:0:0: [sda] Attached SCSI removable disk
[ 76.448192] sd 0:0:0:0: Attached scsi generic sg0 type 0

Unplug USB drive:

[ 92.852078] usb 6-4: USB disconnect, address 3
[ 92.853389] usb 6-4: unregistering device
[ 92.853507] usb 6-4: usb_disable_device nuking all URBs
[ 92.853783] usb 6-4: unregistering interface 6-4:1.0
[ 92.863556] sd_remove: call del_gendisk
[ 92.864043] start of del_gendisk: 9
[ 92.866551] after deleting subpartitions: 7
[ 92.866880] after invalidate_partition(0): 7
[ 92.867469] after unlink_gendisk: 5
[ 92.867738] after kobject_unregister subdirs: 3
[ 92.869450] after device_del: 1
[ 92.869741] after put_device: 1802201963
[ 92.870267] BUG: unable to handle kernel paging request at virtual address 6b6b6b6f
[ 92.870494] printing eip:
[ 92.870547] d09639d2
[ 92.870597] *pde = 00000000
[ 92.870747] Oops: 0000 [#1]
[ 92.870797] PREEMPT SMP
[ 92.870915] last sysfs file: /block/sda/sda1/dev
[ 92.870968] Modules linked in: sg sd_mod usb_storage scsi_mod fan container battery ac evdev thermal button processor ohci_hcd e100 mii ehci_hcd uhci_hcd pcspkr usbcore
[ 92.871749] CPU: 0
[ 92.871751] EIP: 0060:[<d09639d2>] Not tainted VLI
[ 92.871753] EFLAGS: 00010202 (2.6.23 #7)
[ 92.871905] EIP is at __scsi_disk_get+0xd/0x2a [sd_mod]
[ 92.871958] eax: 6b6b6b6b ebx: 6b6b6b6b ecx: 00000000 edx: 00000008
[ 92.872014] esi: cd7359a0 edi: cd7359a8 ebp: cf6edd6c esp: cf6edd68
[ 92.872069] ds: 007b es: 007b fs: 00d8 gs: 0000 ss: 0068
[ 92.872124] Process khubd (pid: 970, ti=cf6ec000 task=cf6f0a90 task.ti=cf6ec000)
[ 92.872179] Stack: 00000000 cf6edd78 d0963a13 cfb32910 cf6edd9c d0963bfd cf6edd9c c0194e69
[ 92.872555] c032351e 6b6b6b6b cfb32910 cd7359a0 cd7359a8 cf6eddb4 d0964096 d09659fa
[ 92.872932] cfb32910 d09670a4 00000292 cf6eddc4 c022303e cfb32910 cfb32910 cf6eddd0
[ 92.873310] Call Trace:
[ 92.873400] [<c01050fd>] show_trace_log_lvl+0x1a/0x2f
[ 92.873496] [<c01051af>] show_stack_log_lvl+0x9d/0xa5
[ 92.873584] [<c01053a4>] show_registers+0x1ed/0x32c
[ 92.873672] [<c01055fa>] die+0x117/0x236
[ 92.873758] [<c02ac046>] do_page_fault+0x4c0/0x591
[ 92.873849] [<c02aa69a>] error_code+0x72/0x78
[ 92.873936] [<d0963a13>] scsi_disk_get_from_dev+0x24/0x35 [sd_mod]
[ 92.874029] [<d0963bfd>] sd_shutdown+0xe/0xfd [sd_mod]
[ 92.874122] [<d0964096>] sd_remove+0x40/0x77 [sd_mod]
[ 92.874213] [<c022303e>] __device_release_driver+0x74/0x90
[ 92.874306] [<c022342c>] device_release_driver+0x30/0x47
[ 92.874394] [<c02229c3>] bus_remove_device+0x73/0x82
[ 92.874482] [<c02211ac>] device_del+0x206/0x27c
[ 92.874569] [<d0988b4e>] __scsi_remove_device+0x3c/0x6d [scsi_mod]
[ 92.874678] [<d0986509>] scsi_forget_host+0x30/0x4f [scsi_mod]
[ 92.874781] [<d0981543>] scsi_remove_host+0x6a/0xdf [scsi_mod]
[ 92.874882] [<d099f7b1>] quiesce_and_remove_host+0xa5/0xb5 [usb_storage]
[ 92.874983] [<d099f893>] storage_disconnect+0x11/0x1b [usb_storage]
[ 92.875079] [<d0847a52>] usb_unbind_interface+0x47/0x99 [usbcore]
[ 92.875191] [<c022303e>] __device_release_driver+0x74/0x90
[ 92.875280] [<c022342c>] device_release_driver+0x30/0x47
[ 92.875369] [<c02229c3>] bus_remove_device+0x73/0x82
[ 92.875456] [<c02211ac>] device_del+0x206/0x27c
[ 92.875543] [<d0844fee>] usb_disable_device+0xe2/0x145 [usbcore]
[ 92.875648] [<d08407e6>] usb_disconnect+0xce/0x167 [usbcore]
[ 92.875751] [<d0841b97>] hub_thread+0x646/0xea7 [usbcore]
[ 92.875852] [<c0131c9e>] kthread+0x3b/0x61
[ 92.875940] [<c0104d53>] kernel_thread_helper+0x7/0x10
[ 92.876028] =======================
[ 92.876077] Code: e8 e1 6a 86 ef 8b 43 04 05 b0 00 00 00 e8 e6 d1 8b ef 89 d8 e8 45 e6 7f ef 58 5b 5e 5d c3 55 89 e5 53 8b 40 38 85 c0 74 18 89 c3 <8b> 40 04 e8 fb c6 01 00 85 c0 75 0a 8d 43 08 e8 79 fd 8b ef eb
[ 92.878418] EIP: [<d09639d2>] __scsi_disk_get+0xd/0x2a [sd_mod] SS:ESP 0068:cf6edd68


And here is the output with the put_device() call removed (the
plug-in part is the same as before):

Plug in USB drive:

[ 74.683198] usb-storage: device found at 3
[ 74.685229] scsi 0:0:0:0: Direct-Access UDISK PDU01_1G 65G2.0 0.00 PQ: 0 ANSI: 2
[ 74.692196] usb-storage: device scan complete
[ 75.018341] sd 0:0:0:0: [sda] 1967616 512-byte hardware sectors (1007 MB)
[ 75.019465] sd 0:0:0:0: [sda] Write Protect is off
[ 75.019624] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[ 75.019745] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 75.019872] sd_probe: call add_disk
[ 75.019986] start of register_disk: 1
[ 75.020234] after device_add: 3
[ 75.020387] after disk_sysfs_add_subdirs: 5
[ 75.020519] after get_capacity: 5
[ 75.020672] after bdget_disk: 5
[ 75.023582] sd 0:0:0:0: [sda] 1967616 512-byte hardware sectors (1007 MB)
[ 75.024637] sd 0:0:0:0: [sda] Write Protect is off
[ 75.024905] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[ 75.025115] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 75.025264] sda: sda1
[ 75.054655] after blkdev_get: 8
[ 75.054924] after blkdev_put: 7
[ 75.057048] end of register_disk: 7
[ 75.057628] after blk_register_queue: 9
[ 75.057871] sd 0:0:0:0: [sda] Attached SCSI removable disk
[ 75.464875] sd 0:0:0:0: Attached scsi generic sg0 type 0

Unplug USB drive:

[ 85.266412] usb 4-4: USB disconnect, address 3
[ 85.266719] usb 4-4: unregistering device
[ 85.266831] usb 4-4: usb_disable_device nuking all URBs
[ 85.266961] usb 4-4: unregistering interface 4-4:1.0
[ 85.271229] sd_remove: call del_gendisk
[ 85.275622] start of del_gendisk: 9
[ 85.276204] after deleting subpartitions: 7
[ 85.276336] after invalidate_partition(0): 7
[ 85.276512] after unlink_gendisk: 5
[ 85.276644] after kobject_unregister subdirs: 3
[ 85.276966] after device_del: 1
[ 85.277095] scsi_disk_release: call put_disk
[ 85.292153] usb 4-4:1.0: uevent
[ 85.292468] usb 4-4:1.0: uevent
[ 85.293458] usb 4-4: uevent

As you can see, this definitely proves that the final put is done at
the right time.

See what the patch shows on your system. One extra thing to check for:
When you plug in a USB drive, the SCSI core starts up an error-handler
process for it. When you unplug the drive, the error-handler task
should exit. If it doesn't then there's an extra reference somewhere
that never got released.

Alan Stern
Index: usb-2.6/block/genhd.c
===================================================================
--- usb-2.6.orig/block/genhd.c
+++ usb-2.6/block/genhd.c
@@ -17,6 +17,10 @@
#include <linux/buffer_head.h>
#include <linux/mutex.h>

+extern int alantest;
+#define alanp(msg, disk) if (alantest) printk(KERN_INFO msg ": %d\n", \
+ atomic_read(&disk->dev.kobj.kref.refcount))
+
extern struct class block_class;
extern struct device_type disk_type;
extern struct device_type part_type;
@@ -185,6 +189,7 @@ void add_disk(struct gendisk *disk)
disk->minors, NULL, exact_match, exact_lock, disk);
register_disk(disk);
blk_register_queue(disk);
+ alanp("after blk_register_queue", disk);
}

EXPORT_SYMBOL(add_disk);
Index: usb-2.6/drivers/scsi/sd.c
===================================================================
--- usb-2.6.orig/drivers/scsi/sd.c
+++ usb-2.6/drivers/scsi/sd.c
@@ -62,6 +62,8 @@

#include "scsi_logging.h"

+extern int alantest;
+
MODULE_AUTHOR("Eric Youngdale");
MODULE_DESCRIPTION("SCSI disk (sd) driver");
MODULE_LICENSE("GPL");
@@ -1677,7 +1679,10 @@ static int sd_probe(struct device *dev)
gd->flags |= GENHD_FL_REMOVABLE;

dev_set_drvdata(dev, sdkp);
+ printk(KERN_INFO "sd_probe: call add_disk\n");
+ alantest = 1;
add_disk(gd);
+ alantest = 0;

sd_printk(KERN_NOTICE, sdkp, "Attached SCSI %sdisk\n",
sdp->removable ? "removable " : "");
@@ -1708,6 +1713,8 @@ static int sd_remove(struct device *dev)
struct scsi_disk *sdkp = dev_get_drvdata(dev);

class_device_del(&sdkp->cdev);
+ printk(KERN_INFO "sd_remove: call del_gendisk\n");
+ alantest = 1;
del_gendisk(sdkp->disk);
sd_shutdown(dev);

@@ -1716,6 +1723,7 @@ static int sd_remove(struct device *dev)
class_device_put(&sdkp->cdev);
mutex_unlock(&sd_ref_mutex);

+ alantest = 0;
return 0;
}

@@ -1738,6 +1746,7 @@ static void scsi_disk_release(struct cla
spin_unlock(&sd_index_lock);

disk->private_data = NULL;
+ printk(KERN_INFO "scsi_disk_release: call put_disk\n");
put_disk(disk);
put_device(&sdkp->device->sdev_gendev);

Index: usb-2.6/fs/partitions/check.c
===================================================================
--- usb-2.6.orig/fs/partitions/check.c
+++ usb-2.6/fs/partitions/check.c
@@ -36,6 +36,11 @@
#include "karma.h"
#include "sysv68.h"

+int alantest;
+EXPORT_SYMBOL(alantest);
+#define alanp(msg, disk) if (alantest) printk(KERN_INFO msg ": %d\n", \
+ atomic_read(&disk->dev.kobj.kref.refcount))
+
extern struct kobject block_depr;
extern struct class block_class;

@@ -378,6 +383,7 @@ void register_disk(struct gendisk *disk)
struct hd_struct *p;
int err;

+ alanp("start of register_disk", disk);
disk->dev.parent = disk->driverfs_dev;
disk->dev.devt = MKDEV(disk->major, disk->first_minor);

@@ -392,6 +398,7 @@ void register_disk(struct gendisk *disk)

if (device_add(&disk->dev))
return;
+ alanp("after device_add", disk);
#ifndef CONFIG_SYSFS_DEPRECATED
err = sysfs_create_link(&block_depr, &disk->dev.kobj,
kobject_name(&disk->dev.kobj));
@@ -399,8 +406,10 @@ void register_disk(struct gendisk *disk)
device_del(&disk->dev);
return;
}
+ alanp("after sysfs_create_link", disk);
#endif
disk_sysfs_add_subdirs(disk);
+ alanp("after disk_sysfs_add_subdirs", disk);

/* No minors to use for partitions */
if (disk->minors == 1)
@@ -409,16 +418,20 @@ void register_disk(struct gendisk *disk)
/* No such device (e.g., media were just removed) */
if (!get_capacity(disk))
goto exit;
+ alanp("after get_capacity", disk);

bdev = bdget_disk(disk, 0);
if (!bdev)
goto exit;
+ alanp("after bdget_disk", disk);

bdev->bd_invalidated = 1;
err = blkdev_get(bdev, FMODE_READ, 0);
if (err < 0)
goto exit;
+ alanp("after blkdev_get", disk);
blkdev_put(bdev);
+ alanp("after blkdev_put", disk);

exit:
/* announce disk after possible partitions are created */
@@ -432,6 +445,7 @@ exit:
continue;
kobject_uevent(&p->dev.kobj, KOBJ_ADD);
}
+ alanp("end of register_disk", disk);
}

int rescan_partitions(struct gendisk *disk, struct block_device *bdev)
@@ -497,24 +511,34 @@ void del_gendisk(struct gendisk *disk)
{
int p;

+ alanp("start of del_gendisk", disk);
+
/* invalidate stuff */
for (p = disk->minors - 1; p > 0; p--) {
invalidate_partition(disk, p);
delete_partition(disk, p);
}
+ alanp("after deleting subpartitions", disk);
invalidate_partition(disk, 0);
+ alanp("after invalidate_partition(0)", disk);
+
disk->capacity = 0;
disk->flags &= ~GENHD_FL_UP;
unlink_gendisk(disk);
+ alanp("after unlink_gendisk", disk);
disk_stat_set_all(disk, 0);
disk->stamp = 0;

kobject_unregister(disk->holder_dir);
kobject_unregister(disk->slave_dir);
+ alanp("after kobject_unregister subdirs", disk);
disk->driverfs_dev = NULL;
#ifndef CONFIG_SYSFS_DEPRECATED
sysfs_remove_link(&block_depr, disk->dev.bus_id);
+ alanp("after sysfs_remove_link", disk);
#endif
device_del(&disk->dev);
+ alanp("after device_del", disk);
put_device(&disk->dev);
+ alanp("after put_device", disk);
}