<div>Kernel: 2.6.30.9</div>
<div> </div>
<div>I am trouble shooting a hang in XFS during umount.</div>
<div>Test scenerio: Copy large number of files files using below script, and remove the USB after 3-5 second</div>
<div> </div>
<div>index=0<br>while [ "$?" == 0 ]<br>do<br> index=$((index+1))<br> sync<br> cp $1/1KB.txt $2/"$index".test<br>done</div>
<div> </div>
<div>In rare scenerio during USB unplug the umount process hang at xfs_buf_lock. Below log shows the hung process</div>
<div> </div>
<div>We have put printk to buffer handling functions xfs_buf_iodone_callbacks(), xfs_buf_error_relse(), xfs_buf_relse() and xfs_buf_rele()</div>
<div> </div>
<div>We always observed the hang only comes when bp->b_relse = xfs_buf_error_relse(). i.e when xfs_buf_iodone_callbacks() execute </div>
<div>XFS_BUF_SET_BRELSE_FUNC(bp,xfs_buf_error_relse);<br>XFS_BUF_DONE(bp);<br>XFS_BUF_FINISH_IOWAIT(bp); </div>
<div> </div>
<div>
<div>buf its never called by xfs_buf_relse() because b_hold = 3.</div>
<div> </div>
<div>Also we have seen that this problem always comes when bp->relse != NULL && bp->hold > 1.</div>
<div> </div>
<div>I do not know whether below prints will help you, but I have taken printk for super block buffer tracing</div>
<div>S-functionname ( Start of function)</div>
<div>E-functionname (End of function)</div>
<div> </div>
<div>I think the problem is related to xfs_buf_iodone_callbacks synchronous buffer error handling path and release buffer.</div>
<div>------------------------------------------------</div></div>
<div>buf_lock (Here buffer lock success, taken after down())<br>S-xfs_buf_rele - 3 (Start of xfs_buf_rele(), b_hold = 3)</div>
<div>Call Trace:<br>[<8032c1bc>] dump_stack+0x8/0x34 from[<801cab2c>] xfs_buf_rele+0xc8/0x28c<br>[<801cab2c>] xfs_buf_rele+0xc8/0x28c from[<801cad9c>] xfs_buf_delwri_dequeue+0xac/0x13c<br>[<801cad9c>] xfs_buf_delwri_dequeue+0xac/0x13c from[<801cb798>] xfs_bwrite+0x5c/0x128<br>
[<801cb798>] xfs_bwrite+0x5c/0x128 from[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c<br>[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c from[<801d690c>] xfs_quiesce_data+0x34/0x68<br>[<801d690c>] xfs_quiesce_data+0x34/0x68 from[<801d2b34>] xfs_fs_sync_fs+0x30/0xec<br>
[<801d2b34>] xfs_fs_sync_fs+0x30/0xec<7>hub 2-0:1.0: state 7 ports 1 chg 0000 evt 0002<br></div>
<div>usb 2-1: USB disconnect, address 3<br></div>
<div> from[<800b7ff0>] sync_filesystems+0x118/0x19c<br>[<800b7ff0>] sync_filesystems+0x118/0x19c from[<800db490>] do_sync+0x38/0x7c<br>[<800db490>] do_sync+0x38/0x7c from[<800db510>] sys_sync+0x10/0x20<br>
[<800db510>] sys_sync+0x10/0x20 from[<8000ff44>] stack_done+0x20/0x3c</div>
<div><br>E-xfs_buf_rele (End of function)</div>
<div> </div>
<div>S-xfs_bdstrat_cb</div>
<div>S-xfs_buf_rele - 3<br>S-xfs_buf_iodone_callbacks<br>Device sda2, XFS metadata write error block 0x0 in sda2</div>
<div><br>E-xfs_buf_iodone_callbacks<br>Call Trace:<br>[<8032c1bc>] dump_stack+0x8/0x34 from[<801cab2c>] xfs_buf_rele+0xc8/0x28c<br>[<801cab2c>] xfs_buf_rele+0xc8/0x28c from[<801cb2fc>] xfs_buf_iorequest+0xe8/0x104<br>
[<801cb2fc>] xfs_buf_iorequest+0xe8/0x104 from[<801cbd2c>] xfs_bdstrat_cb+0x140/0x178<br>[<801cbd2c>] xfs_bdstrat_cb+0x140/0x178 from[<801cb7ac>] xfs_bwrite+0x70/0x128<br>[<801cb7ac>] xfs_bwrite+0x70/0x128 from[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c<br>
[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c from[<801d690c>] xfs_quiesce_data+0x34/0x68<br>[<801d690c>] xfs_quiesce_data+0x34/0x68 from[<801d2b34>] xfs_fs_sync_fs+0x30/0xec<br>[<801d2b34>] xfs_fs_sync_fs+0x30/0xec from[<800b7ff0>] sync_filesystems+0x118/0x19c<br>
[<800b7ff0>] sync_filesystems+0x118/0x19c from[<800db490>] do_sync+0x38/0x7c<br>[<800db490>] do_sync+0x38/0x7c from[<800db510>] sys_sync+0x10/0x20<br>[<800db510>] sys_sync+0x10/0x20 from[<8000ff44>] stack_done+0x20/0x3c</div>
<div><br>E-xfs_buf_rele<br>E-xfs_bdstrat_cb<br>xfs_force_shutdown(sda2,0x1) called from line 1020 of file fs/xfs/linux-2.6/xfs_buf.c. Return address = 0x801cb7f0<br>Filesystem "sda2": I/O Error Detected. Shutting down filesystem: sda2<br>
Please umount the filesystem, and rectify the problem(s)</div>
<div>S-xfs_buf_relse<br>S-xfs_buf_rele - 2</div>
<div>Call Trace:<br>[<8032c1bc>] dump_stack+0x8/0x34 from[<801cab2c>] xfs_buf_rele+0xc8/0x28c<br>[<801cab2c>] xfs_buf_rele+0xc8/0x28c from[<801cb828>] xfs_bwrite+0xec/0x128<br>[<801cb828>] xfs_bwrite+0xec/0x128 from[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c<br>
[<801d5b48>] xfs_sync_fsdata+0xbc/0x17c from[<801d690c>] xfs_quiesce_data+0x34/0x68<br>[<801d690c>] xfs_quiesce_data+0x34/0x68 from[<801d2b34>] xfs_fs_sync_fs+0x30/0xec<br>[<801d2b34>] xfs_fs_sync_fs+0x30/0xec from[<800b7ff0>] sync_filesystems+0x118/0x19c<br>
[<800b7ff0>] sync_filesystems+0x118/0x19c from[<800db490>] do_sync+0x38/0x7c<br>[<800db490>] do_sync+0x38/0x7c from[<800db510>] sys_sync+0x10/0x20<br>[<800db510>] sys_sync+0x10/0x20 from[<8000ff44>] stack_done+0x20/0x3c</div>
<div><br>E-xfs_buf_rele<br>E-xfs_buf_relse<br>cp: cannot stat '/dtv/usb/sda2/6.test': Input/output error<br>Filesystem "sda2": xfs_log_force: error 5 returned.<br>INFO: task khubd:56 blocked for more than 120 seconds.<br>
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.<br>khubd D [86a516a8] 8032cb2c 0 56 2 237 26 (kernel thread)<br>Stack : 00000000 801a2a6c 8643ebe0 86b43a8c 86a51830 8032cb2c 7fffffff 86a516a8<br>
00000002 00000001 86b6dc00 80243a10 e0364448 8032c344 e0373f10 8032cb2c<br> 00000087 0000000b 86b43ab8 801d61bc 3b9aca00 8032d16c 00000008 8019f0dc<br> 86b43a88 00008000 8643ebe0 8616d900 0000000b 00000000 00000000 86bae000<br>
86b43b08 801d62e0 7fffffff 86a516a8 00000002 8032e374 00000000 8008fae4<br> ...<br>Call Trace:<br>[<8032ca74>] __schedule+0x618/0x6b8 from[<8032cb2c>] schedule+0x18/0x3c<br>[<8032cb2c>] schedule+0x18/0x3c from[<8032d16c>] schedule_timeout+0x2c/0x1c0<br>
[<8032d16c>] schedule_timeout+0x2c/0x1c0 from[<8032e374>] __down+0x8c/0xdc<br>[<8032e374>] __down+0x8c/0xdc from[<8004500c>] down+0x40/0x88<br>[<8004500c>] down+0x40/0x88 from[<801c9c10>] xfs_buf_lock+0xcc/0x178<br>
[<801c9c10>] xfs_buf_lock+0xcc/0x178 from[<801b6550>] xfs_getsb+0x38/0x54<br>[<801b6550>] xfs_getsb+0x38/0x54 from[<801d5b00>] xfs_sync_fsdata+0x74/0x17c<br>[<801d5b00>] xfs_sync_fsdata+0x74/0x17c from[<801d690c>] xfs_quiesce_data+0x34/0x68<br>
[<801d690c>] xfs_quiesce_data+0x34/0x68 from[<801d2b34>] xfs_fs_sync_fs+0x30/0xec<br>[<801d2b34>] xfs_fs_sync_fs+0x30/0xec from[<800b878c>] __fsync_super+0xa4/0xc8<br>[<800b878c>] __fsync_super+0xa4/0xc8 from[<800b87c4>] fsync_super+0x14/0x28<br>
[<800b87c4>] fsync_super+0x14/0x28 from[<800e5cc4>] fsync_bdev+0x28/0x64<br>[<800e5cc4>] fsync_bdev+0x28/0x64 from[<801faaa8>] invalidate_partition+0x28/0x60<br>[<801faaa8>] invalidate_partition+0x28/0x60 from[<801001b0>] del_gendisk+0x40/0xf0<br>
[<801001b0>] del_gendisk+0x40/0xf0 from[<8025cb50>] sd_remove+0x40/0xc8<br>[<8025cb50>] sd_remove+0x40/0xc8 from[<80259b5c>] scsi_bus_remove+0x44/0x5c<br>[<80259b5c>] scsi_bus_remove+0x44/0x5c from[<802463d4>] __device_release_driver+0x80/0xbc<br>
[<802463d4>] __device_release_driver+0x80/0xbc from[<80246540>] device_release_driver+0x28/0x40<br>[<80246540>] device_release_driver+0x28/0x40 from[<802457b8>] bus_remove_device+0xb0/0xf0<br>[<802457b8>] bus_remove_device+0xb0/0xf0 from[<80243b30>] device_del+0x120/0x1a8<br>
[<80243b30>] device_del+0x120/0x1a8 from[<80259f50>] __scsi_remove_device+0x40/0x98<br>[<80259f50>] __scsi_remove_device+0x40/0x98 from[<802569cc>] scsi_forget_host+0x88/0xfc<br>[<802569cc>] scsi_forget_host+0x88/0xfc from[<8024f34c>] scsi_remove_host+0xf8/0x1ac<br>
[<8024f34c>] scsi_remove_host+0xf8/0x1ac from[<e039d6bc>] quiesce_and_remove_host+0x9c/0x12c [usb_storage]<br>[<e039d6bc>] quiesce_and_remove_host+0x9c/0x12c [usb_storage] from[<e039d83c>] usb_stor_disconnect+0x20/0x3c [usb_storage]<br>
[<e039d83c>] usb_stor_disconnect+0x20/0x3c [usb_storage] from[<e0367c58>] usb_unbind_interface+0x68/0x128 [usbcore]<br>[<e0367c58>] usb_unbind_interface+0x68/0x128 [usbcore] from[<802463d4>] __device_release_driver+0x80/0xbc<br>
[<802463d4>] __device_release_driver+0x80/0xbc from[<80246540>] device_release_driver+0x28/0x40<br>[<80246540>] device_release_driver+0x28/0x40 from[<802457b8>] bus_remove_device+0xb0/0xf0<br>[<802457b8>] bus_remove_device+0xb0/0xf0 from[<80243b30>] device_del+0x120/0x1a8<br>
[<80243b30>] device_del+0x120/0x1a8 from[<e0364854>] usb_disable_device+0x14c/0x234 [usbcore]<br>[<e0364854>] usb_disable_device+0x14c/0x234 [usbcore] from[<e035d6b8>] usb_disconnect+0x170/0x37c [usbcore]<br>
[<e035d6b8>] usb_disconnect+0x170/0x37c [usbcore] from[<e035f264>] hub_thread+0x85c/0x18f8 [usbcore]<br>[<e035f264>] hub_thread+0x85c/0x18f8 [usbcore] from[<8003ff3c>] kthread+0x5c/0xa0<br>[<8003ff3c>] kthread+0x5c/0xa0 from[<80008908>] kernel_thread_helper+0x10/0x18</div>
<div>-------------------------------------------------------------------------------------<br>INFO: task usb_mount:395 blocked for more than 120 seconds.<br>"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.<br>
usb_mount D [86163ae8] 8032cb2c 0 395 371 (user thread)<br>Stack : ffffff9c 86b71ef0 00400ae0 800c0150 86163c70 8032cb2c 86163ae8 00000002<br> 86bbbf18 86bbbf00 00000000 00000000 86b71f00 86b71ef8 7f8b0670 8032cb2c<br>
86bbb780 800b2510 00000001 86bbbf00 86bbbf00 8032f024 86bbbf00 800b21c0<br> 86bbbf00 86bbbf00 86b6dc44 86b6dc44 86163ae8 00000002 86b6dc00 86b6dc00<br> 803fe190 800b9350 86bbbf00 86bbbf18 86bbbef8 86bbbf00 86bbbef8 86bbbef8<br>
...<br>Call Trace:<br>[<8032ca74>] __schedule+0x618/0x6b8 from[<8032cb2c>] schedule+0x18/0x3c<br>[<8032cb2c>] schedule+0x18/0x3c from[<8032f024>] __down_write_nested+0x104/0x128<br>[<8032f024>] __down_write_nested+0x104/0x128 from[<800b9350>] deactivate_super+0x70/0x110<br>
[<800b9350>] deactivate_super+0x70/0x110 from[<800d122c>] sys_umount+0x310/0x358<br>[<800d122c>] sys_umount+0x310/0x358 from[<8000ff44>] stack_done+0x20/0x3c</div>
<div>-------------------------------------------------------------------------------------<br>Filesystem "sda2": xfs_log_force: error 5 returned.<br></div>