lkml.org 
[lkml]   [2010]   [May]   [10]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: INFO: task umount:1524 blocked for more than 120 seconds
On 05/10/2010 04:04 PM, Stefan Richter wrote:
> Justin P. Mattock wrote:
>> On 05/10/2010 02:46 PM, Justin Mattock wrote:
>>> I have a reproduceable problem happening over here
>>> with unmount and ext4
>>> if I sudo cp -R xserver(all libs/apps from git)
>>> to an external
>>> SmartDsk FireLite
>>> then after the cp is done
>>> sudo umount /dev/sdb1
>>>
>>> I get this:
>>>
>>> type=1400 audit(1273526248.814:27): avc: denied { unmount } for
>>> pid=1524 comm="umount" scontext=justin:staff_r:staff_sudo_t:s0
>>> tcontext=system_u:object_r:fs_t:s0 tclass=filesystem
>>> [ 360.669140] INFO: task umount:1524 blocked for more than 120 seconds.
>>> [ 360.685771] "echo 0> /proc/sys/kernel/hung_task_timeout_secs"
>>> disables this message.
>>> [ 360.702221] umount D 0000000000000000 0 1524 1472
>>> 0x00000080
>>> [ 360.702227] ffff880080909c88 0000000000000086 ffff880080909da8
>>> 0000000000000000
>>> [ 360.702233] ffff880080909fd8 ffff88013845c4a0 0000000000013fc0
>>> ffff880080909fd8
>>> [ 360.702238] 0000000000013fc0 0000000000013fc0 0000000000013fc0
>>> 0000000000013fc0
>>> [ 360.702243] Call Trace:
>>> [ 360.702252] [<ffffffff8106e3f4>] ? spin_unlock_irqrestore+0x9/0xb
>>> [ 360.702266] [<ffffffff810fb214>] ? bdi_sched_wait+0x0/0xd
>>> [ 360.702270] [<ffffffff810fb21d>] bdi_sched_wait+0x9/0xd
>>> [ 360.702276] [<ffffffff813e2126>] __wait_on_bit+0x43/0x76
>>> [ 360.702342] [<ffffffff813e21c2>] out_of_line_wait_on_bit+0x69/0x74
>>> [ 360.702346] [<ffffffff810fb214>] ? bdi_sched_wait+0x0/0xd
>>> [ 360.702350] [<ffffffff8106e3bd>] ? wake_bit_function+0x0/0x2e
>>> [ 360.702356] [<ffffffff81051599>] ? wake_up_process+0x10/0x12
>>> [ 360.702360] [<ffffffff810fc00b>] T.732+0x19/0x1b
>>> [ 360.702364] [<ffffffff810fc06c>] bdi_sync_writeback+0x5f/0x66
>>> [ 360.702368] [<ffffffff810fc090>] sync_inodes_sb+0x1d/0xde
>>> [ 360.702373] [<ffffffff810ff04b>] __sync_filesystem+0x47/0x7e
>>> [ 360.702377] [<ffffffff810ff229>] sync_filesystem+0x47/0x4b
>>> [ 360.702382] [<ffffffff810e2df4>] generic_shutdown_super+0x22/0xf4
>>> [ 360.702386] [<ffffffff810e2ee8>] kill_block_super+0x22/0x3a
>>> [ 360.702390] [<ffffffff810e35f4>] deactivate_super+0x4c/0x64
>>> [ 360.702394] [<ffffffff810f6221>] mntput_no_expire+0xb0/0xde
>>> [ 360.702397] [<ffffffff810f679a>] sys_umount+0x2d9/0x304
>>> [ 360.702402] [<ffffffff810e899e>] ? path_put+0x1d/0x21
>>> [ 360.702408] [<ffffffff81024502>] system_call_fastpath+0x16/0x1b
>>> [ 400.536564] ieee1394: Node changed: 0-01:1023 -> 0-00:1023
>>> [ 400.536587] ieee1394: Node paused: ID:BUS[0-00:1023] GUID[00d0010d0001eaa9]
>>> [ 403.551124] ieee1394: Node removed: ID:BUS[0-00:1023] GUID[00d0010d0001eaa9]
>>> [ 403.551263] end_request: I/O error, dev sdb, sector 54795503
>>> [ 403.564505] Aborting journal on device sdb1-8.
>>> [ 403.577816] JBD2: I/O error detected when updating journal superblock for sdb1-8.
>>> [ 403.591168] journal commit I/O error
>>>
>>>
>>> disk just sits there with the light on.
>>>
>>> if I disconnect, then re execute mount,cp,umount
>>> I can get this again:
> [...]
>
>> maybe this is cable related i.g.
>> using a firewire cable from the apple
>> store($40big ones),on an imac gives this
>> message., but if I use the
>> cable from the firewire(slighty thicker), on
>> a macbook, I can do the above mount,cp,unmount
>> with the kernel, and hit nothing.
>
> It is strange then that you don't get any I/O error messages from sbp2
> or from scsi. Or do you?

the above happens when I umount /dev/sdb1
seems to only happen on my imac9,1,with large files
i.g. umounting after transferring small packages
works o.k.



>
> Was the "Node paused" message in the log above from when you actually
> unplugged or switched off the disk, or didn't do you anything to it at
> that moment?

this happens after I umount(but I'll double check
to make sure).

>
>> (both xserver
>> and all its libs etc.. and the kernel both seem to
>> be pretty large to transfer).
>
> Depends on how much RAM you have. Could be that there isn't a lot of IO
> going on until umount.
>
> Perhaps there is a bug in the disk's IDE-to-FireWire bridge that went
> unnoticed with older kernels but is now exhibited due to different
> kernel behaviour (writeback related changes, larger requests...).
> Several SmartDisk products have an old Symbios chip that require
> requests limited to 128 kB each. When sbp2 logs in to the device, does
> it print a "Workarounds for node "... message? If yes, do the
> workaround flags contain 0x1?

yes, after echoing..

>
> If not, run "echo 1> /sys/module/sbp2/parameters/workarounds" before
> you plug in the disk. *If* this fixes the issue, we should add the
> device IDs to sbp2's and firewire-sbp2's hardcoded quirks lists.
>

here is what dmesg shows after doing the echo call to workarounds
(before doing so the workarounds is not present)
this is plugging, and un-plugging the device a few times:

[ 806.109104] ieee1394: Error parsing configrom for node 0-00:1023
[ 806.109259] ieee1394: Node changed: 0-00:1023 -> 0-01:1023
[ 809.877527] ieee1394: Node added: ID:BUS[0-00:1023]
GUID[00d0010d0001eaa9]
[ 809.879303] scsi9 : SBP-2 IEEE-1394
[ 809.879459] ieee1394: sbp2: Workarounds for node 0-00:1023: 0x1
(firmware_revision 0x000470, vendor_id 0x00d001, model_id 0x000000)
[ 810.881090] ieee1394: sbp2: Logged into SBP-2 device
[ 810.881181] ieee1394: sbp2: Node 0-00:1023: Max speed [S400] - Max
payload [2048]
[ 810.882537] scsi 9:0:0:0: Direct-Access SmartDsk FireLite
4.70 PQ: 0 ANSI: 0
[ 810.882958] sd 9:0:0:0: Attached scsi generic sg2 type 0
[ 810.885443] sd 9:0:0:0: [sdb] 117210240 512-byte logical blocks:
(60.0 GB/55.8 GiB)
[ 810.886699] sd 9:0:0:0: [sdb] Write Protect is off
[ 810.886703] sd 9:0:0:0: [sdb] Mode Sense: 86 0b 00 02
[ 810.888146] sd 9:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 810.889415] sd 9:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 810.893453] sd 9:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 810.894696] sdb: sdb1
[ 810.972390] sd 9:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 810.973927] sd 9:0:0:0: [sdb] Attached SCSI disk
[ 834.638222] ieee1394: Node changed: 0-01:1023 -> 0-00:1023
[ 834.638241] ieee1394: Node paused: ID:BUS[0-00:1023]
GUID[00d0010d0001eaa9]
[ 837.653064] ieee1394: Node removed: ID:BUS[0-00:1023]
GUID[00d0010d0001eaa9]
[ 837.656224] sd 9:0:0:0: [sdb] Synchronizing SCSI cache
[ 837.656278] sd 9:0:0:0: [sdb] Result: hostbyte=DID_NO_CONNECT
driverbyte=DRIVER_OK
[ 837.656281] sd 9:0:0:0: [sdb] Stopping disk
[ 837.656292] sd 9:0:0:0: [sdb] START_STOP FAILED
[ 837.656294] sd 9:0:0:0: [sdb] Result: hostbyte=DID_NO_CONNECT
driverbyte=DRIVER_OK
[ 840.493108] ieee1394: Error parsing configrom for node 0-00:1023
[ 840.493268] ieee1394: Node changed: 0-00:1023 -> 0-01:1023
[ 844.261523] ieee1394: Node added: ID:BUS[0-00:1023]
GUID[00d0010d0001eaa9]
[ 844.261962] scsi10 : SBP-2 IEEE-1394
[ 844.262126] ieee1394: sbp2: Workarounds for node 0-00:1023: 0x1
(firmware_revision 0x000470, vendor_id 0x00d001, model_id 0x000000)
[ 845.264030] ieee1394: sbp2: Logged into SBP-2 device
[ 845.264108] ieee1394: sbp2: Node 0-00:1023: Max speed [S400] - Max
payload [2048]
[ 845.265477] scsi 10:0:0:0: Direct-Access SmartDsk FireLite
4.70 PQ: 0 ANSI: 0
[ 845.265906] sd 10:0:0:0: Attached scsi generic sg2 type 0
[ 845.267651] sd 10:0:0:0: [sdb] 117210240 512-byte logical blocks:
(60.0 GB/55.8 GiB)
[ 845.268925] sd 10:0:0:0: [sdb] Write Protect is off
[ 845.268929] sd 10:0:0:0: [sdb] Mode Sense: 86 0b 00 02
[ 845.270196] sd 10:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 845.271406] sd 10:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 845.275385] sd 10:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 845.276686] sdb: sdb1
[ 845.350665] sd 10:0:0:0: [sdb] Missing header in MODE_SENSE response
[ 845.351927] sd 10:0:0:0: [sdb] Attached SCSI disk

> (By the way, ieee1394/ ohci1394/ sbp2 are kind of end-of-life products;
> firewire-core/ firewire-ohci/ firewire-sbp2 are more actively
> maintained. OTOH there shouldn't be regressions in the 1394 stack.)

I'll remove ieee1394.ko and use firewire to see if I hit this


Justin P. Mattock



\
 
 \ /
  Last update: 2010-05-12 10:15    [W:0.137 / U:0.388 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site