Ilya,
I've not used rbd map on older kernels. Just experimenting with rbd map to have an iscsi and nfs gateway service for hypervisors such as xenserver and vmware. I've tried it with the latest ubuntu LTS kernel 3.13 I believe and noticed the issue.
Can you not reproduce the hang tasks when doing dd testing? have you tried 4K block sizes and running it for sometime, like I have done?
Thanks
Andrei
----- Original Message -----
> From: "Ilya Dryomov" <ilya.dryomov at inktank.com>
> To: "Andrei Mikhailovsky" <andrei at arhont.com>
> Cc: "Micha Krause" <micha at krausam.de>, ceph-users at lists.ceph.com
> Sent: Thursday, 25 September, 2014 12:04:37 PM
> Subject: Re: Frequent Crashes on rbd to nfs gateway
> Server
> On Thu, Sep 25, 2014 at 1:58 PM, Andrei Mikhailovsky
> <andrei at arhont.com> wrote:
> > Guys,
> >
> > Have done some testing with 3.16.3-031603-generic downloaded from
> > Ubuntu
> > utopic branch. The hang task problem is gone when using large block
> > size
> > (tested with 1M and 4M) and I could no longer preproduce the hang
> > tasks
> > while doing 100 dd tests in a for loop.
> >
> >
> >
> > However, I can confirm that I am still getting hang tasks while
> > working with
> > a 4K block size. The hang tasks start after about an hour, but they
> > do not
> > cause the server crash. After a while the dd test times out and
> > continues
> > with the loop. This is what I was running:
> >
> > for i in {1..100} ; do time dd if=/dev/zero of=/tmp/mount/1G bs=4K
> > count=25K
> > oflag=direct ; done
> >
> > The following test definately produces the hang tasks like these:
> >
> > [23160.549785] INFO: task dd:2033 blocked for more than 120
> > seconds.
> > [23160.588364] Tainted: G OE 3.16.3-031603-generic
> > #201409171435
> > [23160.627998] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables
> > this message.
> > [23160.706856] dd D 000000000000000b 0 2033 23859
> > 0x00000000
> > [23160.706861] ffff88011cec78c8 0000000000000082 ffff88011cec78d8
> > ffff88011cec7fd8
> > [23160.706865] 00000000000143c0 00000000000143c0 ffff88048661bcc0
> > ffff880113441440
> > [23160.706868] ffff88011cec7898 ffff88067fd54cc0 ffff880113441440
> > ffff880113441440
> > [23160.706871] Call Trace:
> > [23160.706883] [<ffffffff81791f69>] schedule+0x29/0x70
> > [23160.706887] [<ffffffff8179203f>] io_schedule+0x8f/0xd0
> > [23160.706893] [<ffffffff81219e74>] dio_await_completion+0x54/0xd0
> > [23160.706897] [<ffffffff8121c6a8>]
> > do_blockdev_direct_IO+0x958/0xcc0
> > [23160.706903] [<ffffffff810ba81e>] ? wake_up_bit+0x2e/0x40
> > [23160.706908] [<ffffffff812aa865>] ?
> > jbd2_journal_dirty_metadata+0xc5/0x260
> > [23160.706914] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23160.706919] [<ffffffff8121ca5c>] __blockdev_direct_IO+0x4c/0x50
> > [23160.706922] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23160.706928] [<ffffffff8129f44e>] ext4_ind_direct_IO+0xce/0x410
> > [23160.706931] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23160.706935] [<ffffffff81261fbb>] ext4_ext_direct_IO+0x1bb/0x2a0
> > [23160.706938] [<ffffffff81290158>] ? __ext4_journal_stop+0x78/0xa0
> > [23160.706942] [<ffffffff812627fc>] ext4_direct_IO+0xec/0x1e0
> > [23160.706946] [<ffffffff8120a003>] ? __mark_inode_dirty+0x53/0x2d0
> > [23160.706952] [<ffffffff8116d39b>]
> > generic_file_direct_write+0xbb/0x180
> > [23160.706957] [<ffffffff811ffbe2>] ? mnt_clone_write+0x12/0x30
> > [23160.706960] [<ffffffff8116d707>]
> > __generic_file_write_iter+0x2a7/0x350
> > [23160.706963] [<ffffffff8125c2b1>]
> > ext4_file_write_iter+0x111/0x3d0
> > [23160.706969] [<ffffffff81192fd4>] ? iov_iter_init+0x14/0x40
> > [23160.706976] [<ffffffff811e0c8b>] new_sync_write+0x7b/0xb0
> > [23160.706978] [<ffffffff811e19a7>] vfs_write+0xc7/0x1f0
> > [23160.706980] [<ffffffff811e1eaf>] SyS_write+0x4f/0xb0
> > [23160.706985] [<ffffffff81795ded>] system_call_fastpath+0x1a/0x1f
> > [23280.705400] INFO: task dd:2033 blocked for more than 120
> > seconds.
> > [23280.745358] Tainted: G OE 3.16.3-031603-generic
> > #201409171435
> > [23280.785069] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables
> > this message.
> > [23280.864158] dd D 000000000000000b 0 2033 23859
> > 0x00000000
> > [23280.864164] ffff88011cec78c8 0000000000000082 ffff88011cec78d8
> > ffff88011cec7fd8
> > [23280.864167] 00000000000143c0 00000000000143c0 ffff88048661bcc0
> > ffff880113441440
> > [23280.864170] ffff88011cec7898 ffff88067fd54cc0 ffff880113441440
> > ffff880113441440
> > [23280.864173] Call Trace:
> > [23280.864185] [<ffffffff81791f69>] schedule+0x29/0x70
> > [23280.864197] [<ffffffff8179203f>] io_schedule+0x8f/0xd0
> > [23280.864203] [<ffffffff81219e74>] dio_await_completion+0x54/0xd0
> > [23280.864207] [<ffffffff8121c6a8>]
> > do_blockdev_direct_IO+0x958/0xcc0
> > [23280.864213] [<ffffffff810ba81e>] ? wake_up_bit+0x2e/0x40
> > [23280.864218] [<ffffffff812aa865>] ?
> > jbd2_journal_dirty_metadata+0xc5/0x260
> > [23280.864224] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23280.864229] [<ffffffff8121ca5c>] __blockdev_direct_IO+0x4c/0x50
> > [23280.864239] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23280.864244] [<ffffffff8129f44e>] ext4_ind_direct_IO+0xce/0x410
> > [23280.864247] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23280.864251] [<ffffffff81261fbb>] ext4_ext_direct_IO+0x1bb/0x2a0
> > [23280.864254] [<ffffffff81290158>] ? __ext4_journal_stop+0x78/0xa0
> > [23280.864258] [<ffffffff812627fc>] ext4_direct_IO+0xec/0x1e0
> > [23280.864263] [<ffffffff8120a003>] ? __mark_inode_dirty+0x53/0x2d0
> > [23280.864268] [<ffffffff8116d39b>]
> > generic_file_direct_write+0xbb/0x180
> > [23280.864273] [<ffffffff811ffbe2>] ? mnt_clone_write+0x12/0x30
> > [23280.864284] [<ffffffff8116d707>]
> > __generic_file_write_iter+0x2a7/0x350
> > [23280.864289] [<ffffffff8125c2b1>]
> > ext4_file_write_iter+0x111/0x3d0
> > [23280.864295] [<ffffffff81192fd4>] ? iov_iter_init+0x14/0x40
> > [23280.864300] [<ffffffff811e0c8b>] new_sync_write+0x7b/0xb0
> > [23280.864302] [<ffffffff811e19a7>] vfs_write+0xc7/0x1f0
> > [23280.864307] [<ffffffff811e1eaf>] SyS_write+0x4f/0xb0
> > [23280.864314] [<ffffffff81795ded>] system_call_fastpath+0x1a/0x1f
> > [23400.861043] INFO: task dd:2033 blocked for more than 120
> > seconds.
> > [23400.901529] Tainted: G OE 3.16.3-031603-generic
> > #201409171435
> > [23400.942255] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables
> > this message.
> > [23401.020985] dd D 000000000000000b 0 2033 23859
> > 0x00000000
> > [23401.020991] ffff88011cec78c8 0000000000000082 ffff88011cec78d8
> > ffff88011cec7fd8
> > [23401.020995] 00000000000143c0 00000000000143c0 ffff88048661bcc0
> > ffff880113441440
> > [23401.020997] ffff88011cec7898 ffff88067fd54cc0 ffff880113441440
> > ffff880113441440
> > [23401.021001] Call Trace:
> > [23401.021014] [<ffffffff81791f69>] schedule+0x29/0x70
> > [23401.021025] [<ffffffff8179203f>] io_schedule+0x8f/0xd0
> > [23401.021031] [<ffffffff81219e74>] dio_await_completion+0x54/0xd0
> > [23401.021035] [<ffffffff8121c6a8>]
> > do_blockdev_direct_IO+0x958/0xcc0
> > [23401.021041] [<ffffffff810ba81e>] ? wake_up_bit+0x2e/0x40
> > [23401.021046] [<ffffffff812aa865>] ?
> > jbd2_journal_dirty_metadata+0xc5/0x260
> > [23401.021052] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23401.021057] [<ffffffff8121ca5c>] __blockdev_direct_IO+0x4c/0x50
> > [23401.021067] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23401.021072] [<ffffffff8129f44e>] ext4_ind_direct_IO+0xce/0x410
> > [23401.021075] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23401.021079] [<ffffffff81261fbb>] ext4_ext_direct_IO+0x1bb/0x2a0
> > [23401.021082] [<ffffffff81290158>] ? __ext4_journal_stop+0x78/0xa0
> > [23401.021086] [<ffffffff812627fc>] ext4_direct_IO+0xec/0x1e0
> > [23401.021091] [<ffffffff8120a003>] ? __mark_inode_dirty+0x53/0x2d0
> > [23401.021096] [<ffffffff8116d39b>]
> > generic_file_direct_write+0xbb/0x180
> > [23401.021101] [<ffffffff811ffbe2>] ? mnt_clone_write+0x12/0x30
> > [23401.021112] [<ffffffff8116d707>]
> > __generic_file_write_iter+0x2a7/0x350
> > [23401.021116] [<ffffffff8125c2b1>]
> > ext4_file_write_iter+0x111/0x3d0
> > [23401.021122] [<ffffffff81192fd4>] ? iov_iter_init+0x14/0x40
> > [23401.021129] [<ffffffff811e0c8b>] new_sync_write+0x7b/0xb0
> > [23401.021134] [<ffffffff811e19a7>] vfs_write+0xc7/0x1f0
> > [23401.021137] [<ffffffff811e1eaf>] SyS_write+0x4f/0xb0
> > [23401.021141] [<ffffffff81795ded>] system_call_fastpath+0x1a/0x1f
> > [23521.020639] INFO: task dd:2033 blocked for more than 120
> > seconds.
> > [23521.060586] Tainted: G OE 3.16.3-031603-generic
> > #201409171435
> > [23521.101349] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables
> > this message.
> > [23521.182678] dd D 000000000000000b 0 2033 23859
> > 0x00000000
> > [23521.182684] ffff88011cec78c8 0000000000000082 ffff88011cec78d8
> > ffff88011cec7fd8
> > [23521.182690] 00000000000143c0 00000000000143c0 ffff88048661bcc0
> > ffff880113441440
> > [23521.182693] ffff88011cec7898 ffff88067fd54cc0 ffff880113441440
> > ffff880113441440
> > [23521.182703] Call Trace:
> > [23521.182715] [<ffffffff81791f69>] schedule+0x29/0x70
> > [23521.182718] [<ffffffff8179203f>] io_schedule+0x8f/0xd0
> > [23521.182731] [<ffffffff81219e74>] dio_await_completion+0x54/0xd0
> > [23521.182734] [<ffffffff8121c6a8>]
> > do_blockdev_direct_IO+0x958/0xcc0
> > [23521.182741] [<ffffffff810ba81e>] ? wake_up_bit+0x2e/0x40
> > [23521.182749] [<ffffffff812aa865>] ?
> > jbd2_journal_dirty_metadata+0xc5/0x260
> > [23521.182762] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23521.182767] [<ffffffff8121ca5c>] __blockdev_direct_IO+0x4c/0x50
> > [23521.182770] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23521.182775] [<ffffffff8129f44e>] ext4_ind_direct_IO+0xce/0x410
> > [23521.182778] [<ffffffff81265320>] ?
> > ext4_get_block_write+0x20/0x20
> > [23521.182788] [<ffffffff81261fbb>] ext4_ext_direct_IO+0x1bb/0x2a0
> > [23521.182791] [<ffffffff81290158>] ? __ext4_journal_stop+0x78/0xa0
> > [23521.182794] [<ffffffff812627fc>] ext4_direct_IO+0xec/0x1e0
> > [23521.182803] [<ffffffff8120a003>] ? __mark_inode_dirty+0x53/0x2d0
> > [23521.182808] [<ffffffff8116d39b>]
> > generic_file_direct_write+0xbb/0x180
> > [23521.182816] [<ffffffff811ffbe2>] ? mnt_clone_write+0x12/0x30
> > [23521.182819] [<ffffffff8116d707>]
> > __generic_file_write_iter+0x2a7/0x350
> > [23521.182822] [<ffffffff8125c2b1>]
> > ext4_file_write_iter+0x111/0x3d0
> > [23521.182828] [<ffffffff81192fd4>] ? iov_iter_init+0x14/0x40
> > [23521.182835] [<ffffffff811e0c8b>] new_sync_write+0x7b/0xb0
> > [23521.182838] [<ffffffff811e19a7>] vfs_write+0xc7/0x1f0
> > [23521.182840] [<ffffffff811e1eaf>] SyS_write+0x4f/0xb0
> > [23521.182844] [<ffffffff81795ded>] system_call_fastpath+0x1a/0x1f
> >
> >
> >
> > According to syslog, two dd processes produced hang tasks from the
> > total of
> > 100 runs. Overall, the latest kernels tend to perform very poorly
> > with rbd
> > mounted volumes. The single dd process with block size of 1M or 4M
> > was only
> > producing on average 16MB/s, while the 4K block size was not even
> > getting
> > past 900KB/s. From the client side, rbd caching was enabled. I will
> > now try
> > to run the same test without rbd caching to see if the results are
> > different.
> >
> > But from what i've seen so far, there seems to be a big performance
> > regression with the latest Ubuntu kernels.
> Well, since this slowdown issue is the only thing that reproduces for
> me, I'll bump the priority and try to investigate. Maybe that will
> uncover the nfs gateway problems as well..
> Andrei, what's the last kernel you didn't have any issues on?
> Thanks,
> Ilya
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ceph.com/pipermail/ceph-users-ceph.com/attachments/20140925/02d3bfc3/attachment-0001.htm>
