[Scst-devel] scst_user kernel module hangs after ioctl

[David P. <dav...@gm...>]

Hello,

I'm currently working on an implementation of a target driver through scst_user.

I recently encountered an issue, where my daemon hanged (or was quite
slow). This occurred during a 'mkfs.ext2' on a 8TB exported block
device (through scst_local).
After looking through the logs, here is the (possibly relevant) kernel
trace I could find :

Feb 14 12:15:06 blockserver kernel: [ 5990.526260] INFO: task
blockd:6267 blocked for more than 120 seconds.
Feb 14 12:15:06 blockserver kernel: [ 5990.526263] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 14 12:15:06 blockserver kernel: [ 5990.526266] blockd         D
0000000000000001     0  6267   6021 0x00000000
Feb 14 12:15:06 blockserver kernel: [ 5990.526270]  ffff88005deb7338
0000000000000082 ffff88005deb7fd8 ffff88005deb6000
Feb 14 12:15:06 blockserver kernel: [ 5990.526276]  0000000000013d00
ffff88005deb9a98 ffff88005deb7fd8 0000000000013d00
Feb 14 12:15:06 blockserver kernel: [ 5990.526281]  ffff880137720000
ffff88005deb96e0 ffff880040d7fc80 ffff8800bf233d00
Feb 14 12:15:06 blockserver kernel: [ 5990.526286] Call Trace:
Feb 14 12:15:06 blockserver kernel: [ 5990.526291]
[<ffffffff815c0ea0>] io_schedule+0x70/0xc0
Feb 14 12:15:06 blockserver kernel: [ 5990.526296]
[<ffffffff812c2f49>] get_request_wait+0xc9/0x1a0
Feb 14 12:15:06 blockserver kernel: [ 5990.526301]
[<ffffffff81087fb0>] ? autoremove_wake_function+0x0/0x40
Feb 14 12:15:06 blockserver kernel: [ 5990.526305]
[<ffffffff812bc1e8>] ? elv_merge+0x108/0x120
Feb 14 12:15:06 blockserver kernel: [ 5990.526310]
[<ffffffff812c3706>] __make_request+0x76/0x4c0
Feb 14 12:15:06 blockserver kernel: [ 5990.526314]
[<ffffffff81038c79>] ? default_spin_lock_flags+0x9/0x10
Feb 14 12:15:06 blockserver kernel: [ 5990.526319]
[<ffffffff812c0bf8>] generic_make_request+0x2d8/0x5c0
Feb 14 12:15:06 blockserver kernel: [ 5990.526324]
[<ffffffff8110e7a5>] ? mempool_alloc_slab+0x15/0x20
Feb 14 12:15:06 blockserver kernel: [ 5990.526328]
[<ffffffff8110eae9>] ? mempool_alloc+0x59/0x140
Feb 14 12:15:06 blockserver kernel: [ 5990.526332]
[<ffffffff812c0f69>] submit_bio+0x89/0x120
Feb 14 12:15:06 blockserver kernel: [ 5990.526337]
[<ffffffff8119776b>] ? bio_alloc_bioset+0x5b/0xf0
Feb 14 12:15:06 blockserver kernel: [ 5990.526342]
[<ffffffff8119195b>] submit_bh+0xeb/0x120
Feb 14 12:15:06 blockserver kernel: [ 5990.526346]
[<ffffffff811936a0>] __block_write_full_page+0x210/0x3a0
Feb 14 12:15:06 blockserver kernel: [ 5990.526350]
[<ffffffff812df229>] ? prio_tree_next+0x199/0x1a0
Feb 14 12:15:06 blockserver kernel: [ 5990.526354]
[<ffffffff81192790>] ? end_buffer_async_write+0x0/0x170
Feb 14 12:15:06 blockserver kernel: [ 5990.526359]
[<ffffffff81197fc0>] ? blkdev_get_block+0x0/0x70
Feb 14 12:15:06 blockserver kernel: [ 5990.526363]
[<ffffffff81197fc0>] ? blkdev_get_block+0x0/0x70
Feb 14 12:15:06 blockserver kernel: [ 5990.526367]
[<ffffffff81194543>] block_write_full_page_endio+0xe3/0x120
Feb 14 12:15:06 blockserver kernel: [ 5990.526372]
[<ffffffff81194595>] block_write_full_page+0x15/0x20
Feb 14 12:15:06 blockserver kernel: [ 5990.526376]
[<ffffffff81198b48>] blkdev_writepage+0x18/0x20
Feb 14 12:15:06 blockserver kernel: [ 5990.526381]
[<ffffffff811594c7>] fallback_migrate_page+0xc7/0x130
Feb 14 12:15:06 blockserver kernel: [ 5990.526386]
[<ffffffff81159633>] move_to_new_page+0x103/0x120
Feb 14 12:15:06 blockserver kernel: [ 5990.526391]
[<ffffffff81159ae6>] unmap_and_move+0x2f6/0x350
Feb 14 12:15:06 blockserver kernel: [ 5990.526396]
[<ffffffff8114e7f0>] ? compaction_alloc+0x0/0x70
Feb 14 12:15:06 blockserver kernel: [ 5990.526400]
[<ffffffff81159d32>] migrate_pages+0xa2/0x150
Feb 14 12:15:06 blockserver kernel: [ 5990.526405]
[<ffffffff8114e9c4>] compact_zone+0xa4/0x220
Feb 14 12:15:06 blockserver kernel: [ 5990.526410]
[<ffffffff8114ed0c>] compact_zone_order+0xac/0xf0
Feb 14 12:15:06 blockserver kernel: [ 5990.526415]
[<ffffffff8114ee1d>] try_to_compact_pages+0xcd/0x100
Feb 14 12:15:06 blockserver kernel: [ 5990.526420]
[<ffffffff8111411f>] __alloc_pages_direct_compact+0xcf/0x190
Feb 14 12:15:06 blockserver kernel: [ 5990.526425]
[<ffffffff8111461d>] __alloc_pages_nodemask+0x43d/0x840
Feb 14 12:15:06 blockserver kernel: [ 5990.526431]
[<ffffffff81149f85>] alloc_pages_current+0xa5/0x110
Feb 14 12:15:06 blockserver kernel: [ 5990.526435]
[<ffffffff811536d5>] new_slab+0x1f5/0x290
Feb 14 12:15:06 blockserver kernel: [ 5990.526440]
[<ffffffff81155172>] __slab_alloc+0x1b2/0x390
Feb 14 12:15:06 blockserver kernel: [ 5990.526465]
[<ffffffffa047a4e5>] ? sgv_pool_alloc+0x455/0xa50 [scst]
Feb 14 12:15:06 blockserver kernel: [ 5990.526470]
[<ffffffff81155e4d>] __kmalloc+0x14d/0x160
Feb 14 12:15:06 blockserver kernel: [ 5990.526492]
[<ffffffffa047a4e5>] ? sgv_pool_alloc+0x455/0xa50 [scst]
Feb 14 12:15:06 blockserver kernel: [ 5990.526513]
[<ffffffffa047a4e5>] sgv_pool_alloc+0x455/0xa50 [scst]
Feb 14 12:15:06 blockserver kernel: [ 5990.526520]
[<ffffffffa04eda4e>] ? dev_user_add_to_ready_head+0xae/0x1d0
[scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526527]
[<ffffffffa04eb606>] dev_user_alloc_sg+0x146/0x6e0 [scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526534]
[<ffffffffa04eee2e>] dev_user_alloc_space+0x6e/0x260 [scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526541]
[<ffffffffa04ef07a>] dev_user_alloc_data_buf+0x5a/0x130 [scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526555]
[<ffffffffa044b189>] scst_prepare_space+0x99/0x670 [scst]
Feb 14 12:15:06 blockserver kernel: [ 5990.526570]
[<ffffffffa04506a5>] scst_process_active_cmd+0x3f5/0x720 [scst]
Feb 14 12:15:06 blockserver kernel: [ 5990.526577]
[<ffffffffa04effa8>] dev_user_process_reply_alloc.clone.9+0xb8/0x210
[scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526584]
[<ffffffffa04f2014>] dev_user_process_reply+0x1f4/0x3e0 [scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526592]
[<ffffffffa04f33bc>] dev_user_reply_get_cmd.clone.13+0x20c/0x4b0
[scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526599]
[<ffffffffa04f4092>] dev_user_ioctl+0x222/0x6b4 [scst_user]
Feb 14 12:15:06 blockserver kernel: [ 5990.526605]
[<ffffffff8118332f>] ? mntput+0x1f/0x30
Feb 14 12:15:06 blockserver kernel: [ 5990.526609]
[<ffffffff811764ef>] do_vfs_ioctl+0x8f/0x360
Feb 14 12:15:06 blockserver kernel: [ 5990.526614]
[<ffffffff81176851>] sys_ioctl+0x91/0xa0
Feb 14 12:15:06 blockserver kernel: [ 5990.526618]
[<ffffffff8100c002>] system_call_fastpath+0x16/0x1b


This trace was accompanied by other traces of the same kind. As far as
I understand, this is the trace at the time where the unusual wait
occurred, but I have no way of identifying the cause.

Is there anything you could notice that I didn't through this trace ?

Thanks for the help,

-- 
David Pineau