Re: [lkp-robot] [scsi, block] 0dba1314d4: WARNING:at_fs/sysfs/dir.c:#sysfs_warn_dup

[Dan Williams <dan.j.williams@intel.com>]

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

On Wed, Feb 8, 2017 at 4:08 PM, James Bottomley
<James.Bottomley@hansenpartnership.com> wrote:
> On Mon, 2017-02-06 at 21:42 -0800, Dan Williams wrote:
[..]
>> ...but it reproduces on current mainline with the same config. I
>> haven't spotted what makes scsi_debug behave like this.
>
> Looking at the config, it's a static debug with report luns enabled.
>  Is it as simple as the fact that we probe lun 0 manually to see if the
> target exists, but then we don't account for the fact that we already
> did this, so if it turns up again in the report lun scan, we'll probe
> it again leading to a double add.  If that theory is correct, this may
> be the fix (compile tested only).
>
> James
>
> ---
>
> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
> index 6f7128f..ba4be08 100644
> --- a/drivers/scsi/scsi_scan.c
> +++ b/drivers/scsi/scsi_scan.c
> @@ -1441,6 +1441,10 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
>         for (lunp = &lun_data[1]; lunp <= &lun_data[num_luns]; lunp++) {
>                 lun = scsilun_to_int(lunp);
>
> +               if (lun == 0)
> +                       /* already scanned LUN 0 */
> +                       continue;
> +
>                 if (lun > sdev->host->max_lun) {
>                         sdev_printk(KERN_WARNING, sdev,
>                                     "lun%llu has a LUN larger than"

I gave this a shot on top of linux-next, but still hit the failure.
Log attached.

[-- Attachment #2: log --]
[-- Type: application/octet-stream, Size: 8819 bytes --]

[    5.980959] st: Version 20160209, fixed bufsize 32768, s/g segs 256
[    5.991170] osst :I: Tape driver with OnStream support version 0.99.4
[    5.991170] osst :I: $Id: osst.c,v 1.73 2005/01/01 21:13:34 wriede Exp $
[    5.993376] SCSI Media Changer driver v0.25 
[    5.995157] scsi host0: scsi_debug: version 1.86 [20160430]
[    5.995157]   dev_size_mb=8, opts=0x0, submit_queues=1, statistics=0
[    5.997479] scsi 0:0:0:0: Direct-Access     Linux    scsi_debug       0186 PQ: 0 ANSI: 7
[    6.030073] sd 0:0:0:0: [sda] 16384 512-byte logical blocks: (8.39 MB/8.00 MiB)
[    6.050047] sd 0:0:0:0: [sda] Write Protect is off
[    6.051006] sd 0:0:0:0: [sda] Mode Sense: 73 00 10 08
[    6.090067] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
[    6.510044] sd 0:0:0:0: [sda] Attached SCSI disk
[    6.511614] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[    6.512740] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    6.550065] sd 0:0:0:0: [sdb] 16384 512-byte logical blocks: (8.39 MB/8.00 MiB)
[    6.570050] sd 0:0:0:0: [sdb] Write Protect is off
[    6.570996] sd 0:0:0:0: [sdb] Mode Sense: 73 00 10 08
[    6.610113] sd 0:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
[    6.670309] kobject (d5cb36a4): tried to init an initialized object, something is seriously wrong.
[    6.673969] CPU: 0 PID: 100 Comm: kworker/u2:1 Not tainted 4.10.0-rc7-next-20170207-00005-g43256e7301aa #950
[    6.678132] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
[    6.680063] Workqueue: events_unbound async_run_entry_fn
[    6.680063] Call Trace:
[    6.680063]  dump_stack+0x79/0xa4
[    6.680063]  kobject_init+0x75/0x90
[    6.680063]  ? blk_mq_disable_hotplug+0xf/0x20
[    6.680063]  blk_mq_register_dev+0x2a/0x120
[    6.680063]  blk_register_queue+0x7f/0x160
[    6.680063]  device_add_disk+0x1e3/0x480
[    6.680063]  sd_probe_async+0xf1/0x1c0
[    6.680063]  ? __lock_acquire.isra.14+0x43b/0x940
[    6.680063]  async_run_entry_fn+0x30/0x190
[    6.680063]  ? process_one_work+0x12f/0x430
[    6.680063]  process_one_work+0x1aa/0x430
[    6.680063]  ? process_one_work+0x12f/0x430
[    6.680063]  worker_thread+0x1dd/0x470
[    6.680063]  kthread+0xd4/0x100
[    6.680063]  ? process_one_work+0x430/0x430
[    6.680063]  ? __kthread_create_on_node+0x180/0x180
[    6.680063]  ret_from_fork+0x21/0x2c
[    6.706694] kobject (ffab2dec): tried to init an initialized object, something is seriously wrong.
[    6.709061] CPU: 0 PID: 100 Comm: kworker/u2:1 Not tainted 4.10.0-rc7-next-20170207-00005-g43256e7301aa #950
[    6.711577] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
[    6.713896] Workqueue: events_unbound async_run_entry_fn
[    6.715240] Call Trace:
[    6.716160]  dump_stack+0x79/0xa4
[    6.716677]  kobject_init+0x75/0x90
[    6.716677]  blk_mq_register_dev+0x4c/0x120
[    6.716677]  blk_register_queue+0x7f/0x160
[    6.716677]  device_add_disk+0x1e3/0x480
[    6.716677]  sd_probe_async+0xf1/0x1c0
[    6.716677]  ? __lock_acquire.isra.14+0x43b/0x940
[    6.716677]  async_run_entry_fn+0x30/0x190
[    6.716677]  ? process_one_work+0x12f/0x430
[    6.716677]  process_one_work+0x1aa/0x430
[    6.716677]  ? process_one_work+0x12f/0x430
[    6.716677]  worker_thread+0x1dd/0x470
[    6.716677]  kthread+0xd4/0x100
[    6.716677]  ? process_one_work+0x430/0x430
[    6.716677]  ? __kthread_create_on_node+0x180/0x180
[    6.716677]  ret_from_fork+0x21/0x2c
[    6.734034] ------------[ cut here ]------------
[    6.735233] WARNING: CPU: 0 PID: 100 at ./include/linux/kref.h:54 kobject_get+0x7f/0x90
[    6.737285] CPU: 0 PID: 100 Comm: kworker/u2:1 Not tainted 4.10.0-rc7-next-20170207-00005-g43256e7301aa #950
[    6.739579] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
[    6.741722] Workqueue: events_unbound async_run_entry_fn
[    6.742966] Call Trace:
[    6.743809]  dump_stack+0x79/0xa4
[    6.743899]  __warn+0xd2/0xf0
[    6.743899]  ? kobject_get+0x7f/0x90
[    6.743899]  warn_slowpath_null+0x25/0x30
[    6.743899]  kobject_get+0x7f/0x90
[    6.743899]  kobject_add_internal+0x2e/0x360
[    6.743899]  ? kfree_const+0x18/0x20
[    6.743899]  ? kobject_set_name_vargs+0x62/0x80
[    6.743899]  kobject_add+0x35/0x80
[    6.743899]  ? up_write+0x16/0x40
[    6.743899]  blk_mq_register_hctx+0x95/0xc0
[    6.743899]  blk_mq_register_dev+0xd9/0x120
[    6.743899]  blk_register_queue+0x7f/0x160
[    6.743899]  device_add_disk+0x1e3/0x480
[    6.743899]  sd_probe_async+0xf1/0x1c0
[    6.743899]  ? __lock_acquire.isra.14+0x43b/0x940
[    6.743899]  async_run_entry_fn+0x30/0x190
[    6.743899]  ? process_one_work+0x12f/0x430
[    6.743899]  process_one_work+0x1aa/0x430
[    6.743899]  ? process_one_work+0x12f/0x430
[    6.743899]  worker_thread+0x1dd/0x470
[    6.743899]  kthread+0xd4/0x100
[    6.743899]  ? process_one_work+0x430/0x430
[    6.743899]  ? __kthread_create_on_node+0x180/0x180
[    6.743899]  ret_from_fork+0x21/0x2c
[    6.768405] ---[ end trace 7b77f5d77668026b ]---
[    6.920058] sd 0:0:0:0: [sdb] Attached SCSI disk
[    6.921534] sd 0:0:0:0: [sdb] Synchronizing SCSI cache
[    6.950611] scsi host0: scsi_debug: version 1.86 [20160430]
[    6.950611]   dev_size_mb=8, opts=0x0, submit_queues=1, statistics=0
[    6.953078] scsi 0:0:0:0: Direct-Access     Linux    scsi_debug       0186 PQ: 0 ANSI: 7
[    6.955028] ------------[ cut here ]------------
[    6.956026] WARNING: CPU: 0 PID: 1 at fs/sysfs/dir.c:31 sysfs_warn_dup+0x58/0x70
[    6.957731] sysfs: cannot create duplicate filename '/class/scsi_disk/0:0:0:0'
[    6.959408] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G        W       4.10.0-rc7-next-20170207-00005-g43256e7301aa #950
[    6.960027] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
[    6.960027] Call Trace:
[    6.960027]  dump_stack+0x79/0xa4
[    6.960027]  __warn+0xd2/0xf0
[    6.960027]  ? sysfs_warn_dup+0x58/0x70
[    6.960027]  warn_slowpath_fmt+0x36/0x40
[    6.960027]  sysfs_warn_dup+0x58/0x70
[    6.960027]  sysfs_do_create_link_sd.isra.0+0x9e/0xb0
[    6.960027]  sysfs_create_link+0x20/0x40
[    6.960027]  device_add+0x218/0x610
[    6.960027]  ? kvasprintf_const+0x49/0x60
[    6.960027]  ? kobject_set_name_vargs+0x62/0x80
[    6.960027]  sd_probe+0x31a/0x390
[    6.960027]  ? _raw_spin_unlock+0x1d/0x30
[    6.960027]  driver_probe_device+0x190/0x4a0
[    6.960027]  __device_attach_driver+0x6f/0x100
[    6.960027]  ? klist_next+0x6e/0x100
[    6.960027]  ? __driver_attach+0xf0/0xf0
[    6.960027]  bus_for_each_drv+0x47/0x80
[    6.960027]  __device_attach+0xa8/0x120
[    6.960027]  ? __driver_attach+0xf0/0xf0
[    6.960027]  device_initial_probe+0xd/0x10
[    6.960027]  bus_probe_device+0x77/0x80
[    6.960027]  device_add+0x320/0x610
[    6.960027]  scsi_sysfs_add_sdev+0x85/0x2b0
[    6.960027]  ? scsi_attach_vpd+0x1f9/0x210
[    6.960027]  scsi_probe_and_add_lun+0xd44/0xe70
[    6.960027]  __scsi_scan_target+0xd8/0x690
[    6.960027]  ? __pm_runtime_resume+0x37/0x90
[    6.960027]  scsi_scan_channel+0x8f/0xb0
[    6.960027]  scsi_scan_host_selected+0x100/0x180
[    6.960027]  do_scsi_scan_host+0x8a/0x90
[    6.960027]  scsi_scan_host+0x15a/0x1a0
[    6.960027]  sdebug_driver_probe+0x14f/0x3d0
[    6.960027]  ? _raw_spin_unlock+0x1d/0x30
[    6.960027]  ? devices_kset_move_last+0x71/0xc0
[    6.960027]  ? sysfs_create_link+0x20/0x40
[    6.960027]  driver_probe_device+0xd4/0x4a0
[    6.960027]  __device_attach_driver+0x6f/0x100
[    6.960027]  ? klist_next+0x6e/0x100
[    6.960027]  ? __driver_attach+0xf0/0xf0
[    6.960027]  bus_for_each_drv+0x47/0x80
[    6.960027]  __device_attach+0xa8/0x120
[    6.960027]  ? __driver_attach+0xf0/0xf0
[    6.960027]  device_initial_probe+0xd/0x10
[    6.960027]  bus_probe_device+0x77/0x80
[    6.960027]  device_add+0x320/0x610
[    6.960027]  ? pm_runtime_init+0xea/0xf0
[    6.960027]  device_register+0x12/0x20
[    6.960027]  sdebug_add_adapter+0xda/0x1e0
[    6.960027]  ? driver_register+0x83/0xe0
[    6.960027]  scsi_debug_init+0x5a0/0x6eb
[    6.960027]  ? kobject_uevent+0xa/0x10
[    6.960027]  ? driver_register+0x83/0xe0
[    6.960027]  ? scsi_register_driver+0xf/0x20
[    6.960027]  ? init_ch_module+0x9d/0x9d
[    6.960027]  do_one_initcall+0x7b/0x132
[    6.960027]  ? kernel_init_freeable+0xe7/0x183
[    6.960027]  kernel_init_freeable+0x10a/0x183
[    6.960027]  ? rest_init+0xb0/0xb0
[    6.960027]  kernel_init+0xb/0x100
[    6.960027]  ? schedule_tail+0xc/0x70
[    6.960027]  ? rest_init+0xb0/0xb0
[    6.960027]  ret_from_fork+0x21/0x2c
[    7.030980] ---[ end trace 7b77f5d77668026c ]---
[    7.032025] sd: probe of 0:0:0:0 failed with error -17
[    7.033172] scsi 0:0:0:0: Attached scsi generic sg0 type 0