Re: virtio ring cleanups, which save stack on older gcc

[Minchan Kim]

On Fri, May 30, 2014 at 08:45:22AM +0900, Minchan Kim wrote:
> On Thu, May 29, 2014 at 08:38:33PM +0930, Rusty Russell wrote:
> > Minchan Kim <minchan@xxxxxxxxxx> writes:
> > > Hello Rusty,
> > >
> > > On Thu, May 29, 2014 at 04:56:41PM +0930, Rusty Russell wrote:
> > >> They don't make much difference: the easier fix is use gcc 4.8
> > >> which drops stack required across virtio block's virtio_queue_rq
> > >> down to that kmalloc in virtio_ring from 528 to 392 bytes.
> > >> 
> > >> Still, these (*lightly tested*) patches reduce to 432 bytes,
> > >> even for gcc 4.6.4.  Posted here FYI.
> > >
> > > I am testing with below which was hack for Dave's idea so don't have
> > > a machine to test your patches until tomorrow.
> > > So, I will queue your patches into testing machine tomorrow morning.
> > 
> > More interesting would be updating your compiler to 4.8, I think.
> > Saving <100 bytes on virtio is not going to save you, right?
> 
> But in my report, virtio_ring consumes more than yours.
> As I mentioned other thread to Steven, I don't know why stacktrace report
> vring_add_indirect consumes 376-byte. Apparently, objdump says it didn't
> consume too much so I'd like to test your patches and see the result.
> 
> Thanks.
> 
> [ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  10)     6376     376   vring_add_indirect+0x36/0x200
> [ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  11)     6000     144   virtqueue_add_sgs+0x2e2/0x320
> [ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  12)     5856     288   __virtblk_add_req+0xda/0x1b0
> [ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  13)     5568      96   virtio_queue_rq+0xd3/0x1d0
> 

As you expected, virtio_ring consumes less than before but not enough but
interesting thing is consumption of stack usage of __kmalloc and __slab_alloc
works right in this time. Hmm....

In my previous report,

[ 1065.604404] kworker/-5766    0d..2 1071625992us : stack_trace_call:   6)     6640       8   alloc_pages_current+0x10f/0x1f0
[ 1065.604404] kworker/-5766    0d..2 1071625992us : stack_trace_call:   7)     6632     168   new_slab+0x2c5/0x370
[ 1065.604404] kworker/-5766    0d..2 1071625992us : stack_trace_call:   8)     6464       8   __slab_alloc+0x3a9/0x501
[ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:   9)     6456      80   __kmalloc+0x1cb/0x200
[ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  10)     6376     376   vring_add_indirect+0x36/0x200
[ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  11)     6000     144   virtqueue_add_sgs+0x2e2/0x320
[ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  12)     5856     288   __virtblk_add_req+0xda/0x1b0
[ 1065.604404] kworker/-5766    0d..2 1071625993us : stack_trace_call:  13)     5568      96   virtio_queue_rq+0xd3/0x1d0
[ 1065.604404] kworker/-5766    0d..2 1071625994us : stack_trace_call:  14)     5472     128   __blk_mq_run_hw_queue+0x1ef/0x440
[ 1065.604404] kworker/-5766    0d..2 1071625994us : stack_trace_call:  15)     5344      16   blk_mq_run_hw_queue+0x35/0x40

In this time,

[ 2069.135929] kworker/u24:2 (26991) used greatest stack depth: 408 bytes left
[ 2580.413428] ------------[ cut here ]------------
[ 2580.413926] kernel BUG at kernel/trace/trace_stack.c:177!
[ 2580.414479] invalid opcode: 0000 [#1] SMP DEBUG_PAGEALLOC
[ 2580.415073] Dumping ftrace buffer:
[ 2580.415465] ---------------------------------
[ 2580.415763]    <...>-18634   9d..2 2598341673us : stack_trace_call:         Depth    Size   Location    (49 entries)
[ 2580.415763]         -----    ----   --------
[ 2580.415763]    <...>-18634   9d..2 2598341697us : stack_trace_call:   0)     7280       8   __alloc_pages_nodemask+0x199/0xb20
[ 2580.415763]    <...>-18634   9d..2 2598341698us : stack_trace_call:   1)     7272     352   alloc_pages_current+0x10f/0x1f0
[ 2580.415763]    <...>-18634   9d..2 2598341698us : stack_trace_call:   2)     6920     168   new_slab+0x2c5/0x370
[ 2580.415763]    <...>-18634   9d..2 2598341698us : stack_trace_call:   3)     6752     256   __slab_alloc+0x3a9/0x501
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   4)     6496     112   __kmalloc+0x1cb/0x200
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   5)     6384      32   alloc_indirect+0x1e/0x50
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   6)     6352     112   virtqueue_add_sgs+0xc7/0x300
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   7)     6240     288   __virtblk_add_req+0xda/0x1b0
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   8)     5952      96   virtio_queue_rq+0xd3/0x1d0
[ 2580.415763]    <...>-18634   9d..2 2598341699us : stack_trace_call:   9)     5856     128   __blk_mq_run_hw_queue+0x1ef/0x440
[ 2580.415763]    <...>-18634   9d..2 2598341700us : stack_trace_call:  10)     5728      16   blk_mq_run_hw_queue+0x35/0x40
[ 2580.415763]    <...>-18634   9d..2 2598341700us : stack_trace_call:  11)     5712      96   blk_mq_insert_requests+0xdb/0x160
[ 2580.415763]    <...>-18634   9d..2 2598341700us : stack_trace_call:  12)     5616     112   blk_mq_flush_plug_list+0x12b/0x140
[ 2580.415763]    <...>-18634   9d..2 2598341700us : stack_trace_call:  13)     5504     112   blk_flush_plug_list+0xc7/0x220
[ 2580.415763]    <...>-18634   9d..2 2598341700us : stack_trace_call:  14)     5392      64   io_schedule_timeout+0x88/0x100
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  15)     5328     128   mempool_alloc+0x145/0x170
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  16)     5200      96   bio_alloc_bioset+0x10b/0x1d0
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  17)     5104      48   get_swap_bio+0x30/0x90
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  18)     5056     160   __swap_writepage+0x150/0x230
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  19)     4896      32   swap_writepage+0x42/0x90
[ 2580.415763]    <...>-18634   9d..2 2598341701us : stack_trace_call:  20)     4864     320   shrink_page_list+0x676/0xa80
[ 2580.415763]    <...>-18634   9d..2 2598341702us : stack_trace_call:  21)     4544     208   shrink_inactive_list+0x262/0x4e0
[ 2580.415763]    <...>-18634   9d..2 2598341702us : stack_trace_call:  22)     4336     304   shrink_lruvec+0x3e1/0x6a0
[ 2580.415763]    <...>-18634   9d..2 2598341702us : stack_trace_call:  23)     4032      80   shrink_zone+0x3f/0x110
[ 2580.415763]    <...>-18634   9d..2 2598341702us : stack_trace_call:  24)     3952     128   do_try_to_free_pages+0x156/0x4c0
[ 2580.415763]    <...>-18634   9d..2 2598341702us : stack_trace_call:  25)     3824     208   try_to_free_pages+0xf7/0x1e0
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  26)     3616     352   __alloc_pages_nodemask+0x783/0xb20
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  27)     3264       8   alloc_pages_current+0x10f/0x1f0
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  28)     3256     200   __page_cache_alloc+0x13f/0x160
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  29)     3056      80   find_or_create_page+0x4c/0xb0
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  30)     2976     112   __getblk+0x109/0x2f0
[ 2580.415763]    <...>-18634   9d..2 2598341703us : stack_trace_call:  31)     2864      80   ext4_read_block_bitmap_nowait+0x5e/0x330
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  32)     2784     192   ext4_mb_init_cache+0x158/0x780
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  33)     2592      80   ext4_mb_load_buddy+0x28a/0x370
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  34)     2512     176   ext4_mb_regular_allocator+0x1b7/0x460
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  35)     2336     128   ext4_mb_new_blocks+0x458/0x5f0
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  36)     2208     256   ext4_ext_map_blocks+0x70b/0x1010
[ 2580.415763]    <...>-18634   9d..2 2598341704us : stack_trace_call:  37)     1952     160   ext4_map_blocks+0x325/0x530
[ 2580.415763]    <...>-18634   9d..2 2598341705us : stack_trace_call:  38)     1792     384   ext4_writepages+0x6d1/0xce0
[ 2580.415763]    <...>-18634   9d..2 2598341705us : stack_trace_call:  39)     1408      16   do_writepages+0x23/0x40
[ 2580.415763]    <...>-18634   9d..2 2598341705us : stack_trace_call:  40)     1392      96   __writeback_single_inode+0x45/0x2e0
[ 2580.415763]    <...>-18634   9d..2 2598341705us : stack_trace_call:  41)     1296     176   writeback_sb_inodes+0x2ad/0x500
[ 2580.415763]    <...>-18634   9d..2 2598341705us : stack_trace_call:  42)     1120      80   __writeback_inodes_wb+0x9e/0xd0
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  43)     1040     160   wb_writeback+0x29b/0x350
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  44)      880     208   bdi_writeback_workfn+0x11c/0x480
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  45)      672     144   process_one_work+0x1d2/0x570
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  46)      528     112   worker_thread+0x116/0x370
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  47)      416     240   kthread+0xf3/0x110
[ 2580.415763]    <...>-18634   9d..2 2598341706us : stack_trace_call:  48)      176     176   ret_from_fork+0x7c/0xb0
[ 2580.415763] ---------------------------------
[ 2580.415763] Modules linked in:
[ 2580.415763] CPU: 9 PID: 18634 Comm: kworker/u24:1 Not tainted 3.14.0+ #202
[ 2580.415763] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[ 2580.415763] Workqueue: writeback bdi_writeback_workfn (flush-253:0)
[ 2580.415763] task: ffff88001e9ca0e0 ti: ffff880029c52000 task.ti: ffff880029c52000
[ 2580.415763] RIP: 0010:[<ffffffff8112340f>]  [<ffffffff8112340f>] stack_trace_call+0x37f/0x390
[ 2580.415763] RSP: 0000:ffff880029c52270  EFLAGS: 00010096
[ 2580.415763] RAX: ffff880029c52000 RBX: 0000000000000009 RCX: 0000000000000002
[ 2580.415763] RDX: 0000000000000006 RSI: 0000000000000002 RDI: ffff88003780be00
[ 2580.415763] RBP: ffff880029c522d0 R08: 00000000000009e8 R09: ffffffffffffffff
[ 2580.415763] R10: ffff880029c53fd8 R11: 0000000000000001 R12: 000000000000f2e8
[ 2580.415763] R13: 0000000000000009 R14: ffffffff82768dfc R15: 00000000000000f8
[ 2580.415763] FS:  0000000000000000(0000) GS:ffff880037d20000(0000) knlGS:0000000000000000
[ 2580.415763] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2580.415763] CR2: 00002aea5db57000 CR3: 0000000001c0b000 CR4: 00000000000006e0
[ 2580.415763] Stack:
[ 2580.415763]  0000000000000009 ffffffff81150819 0000000000000083 0000000000001c70
[ 2580.415763]  ffff880029c52300 ffffffff81005e11 ffffffff81c55ef0 0000000000000000
[ 2580.415763]  0000000000000002 ffff88001e9ca0e0 ffff88001e9cb108 0000000000000000
[ 2580.415763] Call Trace:
[ 2580.415763]  [<ffffffff81150819>] ? __alloc_pages_nodemask+0x199/0xb20
[ 2580.415763]  [<ffffffff81005e11>] ? print_context_stack+0x81/0x140
[ 2580.415763]  [<ffffffff816eedbf>] ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff8119097f>] ? alloc_pages_current+0x10f/0x1f0
[ 2580.415763]  [<ffffffff8119097f>] ? alloc_pages_current+0x10f/0x1f0
[ 2580.415763]  [<ffffffff811650b5>] ? next_zones_zonelist+0x5/0x70
[ 2580.415763]  [<ffffffff810a22dd>] ? trace_hardirqs_off+0xd/0x10
[ 2580.415763]  [<ffffffff811650b5>] ? next_zones_zonelist+0x5/0x70
[ 2580.415763]  [<ffffffff81150819>] ? __alloc_pages_nodemask+0x199/0xb20
[ 2580.415763]  [<ffffffff8119097f>] ? alloc_pages_current+0x10f/0x1f0
[ 2580.415763]  [<ffffffff810a22dd>] ? trace_hardirqs_off+0xd/0x10
[ 2580.415763]  [<ffffffff811231a9>] ? stack_trace_call+0x119/0x390
[ 2580.415763]  [<ffffffff816eedbf>] ? ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff8119097f>] alloc_pages_current+0x10f/0x1f0
[ 2580.415763]  [<ffffffff81199d25>] ? new_slab+0x2c5/0x370
[ 2580.415763]  [<ffffffff81199d25>] new_slab+0x2c5/0x370
[ 2580.415763]  [<ffffffff816dafb2>] __slab_alloc+0x3a9/0x501
[ 2580.415763]  [<ffffffff8141daee>] ? alloc_indirect+0x1e/0x50
[ 2580.415763]  [<ffffffff8141daee>] ? alloc_indirect+0x1e/0x50
[ 2580.415763]  [<ffffffff8141daee>] ? alloc_indirect+0x1e/0x50
[ 2580.415763]  [<ffffffff8119afdb>] __kmalloc+0x1cb/0x200
[ 2580.415763]  [<ffffffff8141daee>] alloc_indirect+0x1e/0x50
[ 2580.415763]  [<ffffffff8141e297>] virtqueue_add_sgs+0xc7/0x300
[ 2580.415763]  [<ffffffff8148e2fa>] __virtblk_add_req+0xda/0x1b0
[ 2580.415763]  [<ffffffff8148e4a3>] virtio_queue_rq+0xd3/0x1d0
[ 2580.415763]  [<ffffffff8134aa5f>] __blk_mq_run_hw_queue+0x1ef/0x440
[ 2580.415763]  [<ffffffff8134b125>] blk_mq_run_hw_queue+0x35/0x40
[ 2580.415763]  [<ffffffff8134b80b>] blk_mq_insert_requests+0xdb/0x160
[ 2580.415763]  [<ffffffff8134beab>] blk_mq_flush_plug_list+0x12b/0x140
[ 2580.415763]  [<ffffffff81342287>] blk_flush_plug_list+0xc7/0x220
[ 2580.415763]  [<ffffffff816e609f>] ? _raw_spin_unlock_irqrestore+0x3f/0x70
[ 2580.415763]  [<ffffffff816e1698>] io_schedule_timeout+0x88/0x100
[ 2580.415763]  [<ffffffff816e1615>] ? io_schedule_timeout+0x5/0x100
[ 2580.415763]  [<ffffffff81149465>] mempool_alloc+0x145/0x170
[ 2580.415763]  [<ffffffff8109baf0>] ? __init_waitqueue_head+0x60/0x60
[ 2580.415763]  [<ffffffff811e24bb>] bio_alloc_bioset+0x10b/0x1d0
[ 2580.415763]  [<ffffffff81184280>] ? end_swap_bio_read+0xc0/0xc0
[ 2580.415763]  [<ffffffff81184280>] ? end_swap_bio_read+0xc0/0xc0
[ 2580.415763]  [<ffffffff81184160>] get_swap_bio+0x30/0x90
[ 2580.415763]  [<ffffffff81184280>] ? end_swap_bio_read+0xc0/0xc0
[ 2580.415763]  [<ffffffff811846b0>] __swap_writepage+0x150/0x230
[ 2580.415763]  [<ffffffff810ab405>] ? do_raw_spin_unlock+0x5/0xa0
[ 2580.415763]  [<ffffffff81184280>] ? end_swap_bio_read+0xc0/0xc0
[ 2580.415763]  [<ffffffff81184565>] ? __swap_writepage+0x5/0x230
[ 2580.415763]  [<ffffffff811847d2>] swap_writepage+0x42/0x90
[ 2580.415763]  [<ffffffff8115aee6>] shrink_page_list+0x676/0xa80
[ 2580.415763]  [<ffffffff816eedbf>] ? ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff8115b8c2>] shrink_inactive_list+0x262/0x4e0
[ 2580.415763]  [<ffffffff8115c211>] shrink_lruvec+0x3e1/0x6a0
[ 2580.415763]  [<ffffffff8115c50f>] shrink_zone+0x3f/0x110
[ 2580.415763]  [<ffffffff816eedbf>] ? ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff8115ca36>] do_try_to_free_pages+0x156/0x4c0
[ 2580.415763]  [<ffffffff8115cf97>] try_to_free_pages+0xf7/0x1e0
[ 2580.415763]  [<ffffffff81150e03>] __alloc_pages_nodemask+0x783/0xb20
[ 2580.415763]  [<ffffffff8119097f>] alloc_pages_current+0x10f/0x1f0
[ 2580.415763]  [<ffffffff81145c5f>] ? __page_cache_alloc+0x13f/0x160
[ 2580.415763]  [<ffffffff81145c5f>] __page_cache_alloc+0x13f/0x160
[ 2580.415763]  [<ffffffff81146cbc>] find_or_create_page+0x4c/0xb0
[ 2580.415763]  [<ffffffff811ded09>] __getblk+0x109/0x2f0
[ 2580.415763]  [<ffffffff8124629e>] ext4_read_block_bitmap_nowait+0x5e/0x330
[ 2580.415763]  [<ffffffff81282bf8>] ext4_mb_init_cache+0x158/0x780
[ 2580.415763]  [<ffffffff816eedbf>] ? ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff81155d15>] ? __lru_cache_add+0x5/0x90
[ 2580.415763]  [<ffffffff81146435>] ? find_get_page+0x5/0x130
[ 2580.415763]  [<ffffffff812838aa>] ext4_mb_load_buddy+0x28a/0x370
[ 2580.415763]  [<ffffffff81284c57>] ext4_mb_regular_allocator+0x1b7/0x460
[ 2580.415763]  [<ffffffff812810c0>] ? ext4_mb_use_preallocated+0x40/0x360
[ 2580.415763]  [<ffffffff816eedbf>] ? ftrace_call+0x5/0x2f
[ 2580.415763]  [<ffffffff81287f08>] ext4_mb_new_blocks+0x458/0x5f0
[ 2580.415763]  [<ffffffff8127d88b>] ext4_ext_map_blocks+0x70b/0x1010
[ 2580.415763]  [<ffffffff8124e725>] ext4_map_blocks+0x325/0x530
[ 2580.415763]  [<ffffffff812538c1>] ext4_writepages+0x6d1/0xce0
[ 2580.415763]  [<ffffffff812531f0>] ? ext4_journalled_write_end+0x330/0x330
[ 2580.415763]  [<ffffffff81153a03>] do_writepages+0x23/0x40
[ 2580.415763]  [<ffffffff811d23b5>] __writeback_single_inode+0x45/0x2e0
[ 2580.415763]  [<ffffffff811d373d>] writeback_sb_inodes+0x2ad/0x500
[ 2580.415763]  [<ffffffff811d3a2e>] __writeback_inodes_wb+0x9e/0xd0
[ 2580.415763]  [<ffffffff811d410b>] wb_writeback+0x29b/0x350
[ 2580.415763]  [<ffffffff81057c3d>] ? __local_bh_enable_ip+0x6d/0xd0
[ 2580.415763]  [<ffffffff811d6eec>] bdi_writeback_workfn+0x11c/0x480
[ 2580.415763]  [<ffffffff81070610>] ? process_one_work+0x170/0x570
[ 2580.415763]  [<ffffffff81070672>] process_one_work+0x1d2/0x570
[ 2580.415763]  [<ffffffff81070610>] ? process_one_work+0x170/0x570
[ 2580.415763]  [<ffffffff81071bb6>] worker_thread+0x116/0x370
[ 2580.415763]  [<ffffffff81071aa0>] ? manage_workers.isra.19+0x2e0/0x2e0
[ 2580.415763]  [<ffffffff81078e53>] kthread+0xf3/0x110
[ 2580.415763]  [<ffffffff81078d60>] ? flush_kthread_worker+0x150/0x150
[ 2580.415763]  [<ffffffff816ef06c>] ret_from_fork+0x7c/0xb0
[ 2580.415763]  [<ffffffff81078d60>] ? flush_kthread_worker+0x150/0x150

-- 
Kind regards,
Minchan Kim
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/