[Pkg-xen-devel] Bug#820862: xen-hypervisor-4.4-amd64: Xen VM on Jessie freezes often with INFO: task jbd2/xvda2-8:111 blocked for more than 120 seconds

Christoph Keller debianbug at mysign.ch
Wed Apr 13 08:57:45 UTC 2016 

Package: xen-hypervisor-4.4-amd64
Version: 4.4.1-9+deb8u4
Severity: grave
Justification: renders package unusable

Dear Maintainer,

   * What led up to the situation?
   Running Backup Exec or a copy command to NFS-Share causes the VM regurarly to freeze. First message on VM-Console:
   ---------------------------------------------------------------------------------------------------------------
[ 1680.060125] INFO: task jbd2/xvda2-8:111 blocked for more than 120 seconds.
[ 1680.060139] Not tainted 3.16.0-4-amd64 #1
[ 1680.060144] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1680.060150] jbd2/xvda2-8 D ffff88000408c768 0 111 2 0x00000000
[ 1680.060159] ffff88000408c310 0000000000000246 0000000000012f00 ffff8801f103ffd8
[ 1680.060167] 0000000000012f00 ffff88000408c310 ffff8801fea937b0 ffff8801fefeea88
[ 1680.060175] 0000000000000002 ffffffff8113d0e0 ffff8801f103fbd0 ffff8801f103fc50
[ 1680.060183] Call Trace:
[ 1680.060196] [<ffffffff8113d0e0>] ? wait_on_page_read+0x60/0x60
[ 1680.060204] [<ffffffff815114a9>] ? io_schedule+0x99/0x120
[ 1680.060210] [<ffffffff8113d0ea>] ? sleep_on_page+0xa/0x10
[ 1680.060216] [<ffffffff8151182c>] ? __wait_on_bit+0x5c/0x90
[ 1680.060222] [<ffffffff8113cedf>] ? wait_on_page_bit+0x7f/0x90
[ 1680.060231] [<ffffffff810a7e90>] ? autoremove_wake_function+0x30/0x30
[ 1680.060246] [<ffffffff8114a46d>] ? pagevec_lookup_tag+0x1d/0x30
[ 1680.060254] [<ffffffff8113cfc0>] ? filemap_fdatawait_range+0xd0/0x160
[ 1680.060260] [<ffffffff8127d941>] ? submit_bio+0x71/0x150
[ 1680.060266] [<ffffffff81279118>] ? bio_alloc_bioset+0x198/0x290
[ 1680.060275] [<ffffffffa001172c>] ? jbd2_journal_commit_transaction+0xa5c/0x1950 [jbd2]
[ 1680.060283] [<ffffffff8100331e>] ? xen_end_context_switch+0xe/0x20
[ 1680.060292] [<ffffffff810912f6>] ? finish_task_switch+0x46/0xf0
[ 1680.060297] [<ffffffff815141a3>] ? _raw_spin_unlock_irqrestore+0x13/0x20
[ 1680.060304] [<ffffffffa0015be2>] ? kjournald2+0xb2/0x240 [jbd2]
[ 1680.060309] [<ffffffff810a7e60>] ? prepare_to_wait_event+0xf0/0xf0
[ 1680.060314] [<ffffffffa0015b30>] ? commit_timeout+0x10/0x10 [jbd2]
[ 1680.060321] [<ffffffff8108809d>] ? kthread+0xbd/0xe0
[ 1680.060326] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1680.060332] [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
[ 1680.060336] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1920.060121] INFO: task jbd2/xvda2-8:111 blocked for more than 120 seconds.
[ 1920.060133] Not tainted 3.16.0-4-amd64 #1
[ 1920.060138] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1920.060144] jbd2/xvda2-8 D ffff88000408c768 0 111 2 0x00000000
[ 1920.060153] ffff88000408c310 0000000000000246 0000000000012f00 ffff8801f103ffd8
[ 1920.060163] 0000000000012f00 ffff88000408c310 ffff8801fea937b0 ffff8801fefeea88
[ 1920.060172] 0000000000000002 ffffffff8113d0e0 ffff8801f103fbd0 ffff8801f103fc50
[ 1920.060181] Call Trace:
[ 1920.060189] [<ffffffff8113d0e0>] ? wait_on_page_read+0x60/0x60
[ 1920.060197] [<ffffffff815114a9>] ? io_schedule+0x99/0x120
[ 1920.060203] [<ffffffff8113d0ea>] ? sleep_on_page+0xa/0x10
[ 1920.060209] [<ffffffff8151182c>] ? __wait_on_bit+0x5c/0x90
[ 1920.060216] [<ffffffff8113cedf>] ? wait_on_page_bit+0x7f/0x90
[ 1920.060223] [<ffffffff810a7e90>] ? autoremove_wake_function+0x30/0x30
[ 1920.060231] [<ffffffff8114a46d>] ? pagevec_lookup_tag+0x1d/0x30
[ 1920.060243] [<ffffffff8113cfc0>] ? filemap_fdatawait_range+0xd0/0x160
[ 1920.060251] [<ffffffff8127d941>] ? submit_bio+0x71/0x150
[ 1920.060262] [<ffffffff81279118>] ? bio_alloc_bioset+0x198/0x290
[ 1920.060269] [<ffffffffa001172c>] ? jbd2_journal_commit_transaction+0xa5c/0x1950 [jbd2]
[ 1920.060275] [<ffffffff8100331e>] ? xen_end_context_switch+0xe/0x20
[ 1920.060280] [<ffffffff810912f6>] ? finish_task_switch+0x46/0xf0
[ 1920.060285] [<ffffffff815141a3>] ? _raw_spin_unlock_irqrestore+0x13/0x20
[ 1920.060291] [<ffffffffa0015be2>] ? kjournald2+0xb2/0x240 [jbd2]
[ 1920.060296] [<ffffffff810a7e60>] ? prepare_to_wait_event+0xf0/0xf0
[ 1920.060303] [<ffffffffa0015b30>] ? commit_timeout+0x10/0x10 [jbd2]
[ 1920.060308] [<ffffffff8108809d>] ? kthread+0xbd/0xe0
[ 1920.060312] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1920.060318] [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
[ 1920.060322] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1920.060328] INFO: task rs:main Q:Reg:338 blocked for more than 120 seconds.
[ 1920.060332] Not tainted 3.16.0-4-amd64 #1 
    ---------------------------------- ------ or   --------------------------------------------- 
INFO: task systemd-tmpfile:1304 blocked for more than 120 seconds.
[ 1080.060138] Not tainted 3.16.0-4-amd64 #1
[ 1080.060142] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1080.060149] systemd-tmpfile D ffff8801f3b4ee38 0 1304 1 0x00000000
[ 1080.060158] ffff8801f3b4e9e0 0000000000000286 0000000000012f00 ffff88000367bfd8
[ 1080.060166] 0000000000012f00 ffff8801f3b4e9e0 ffff8801feb937b0 ffff8801ff009158
[ 1080.060174] 0000000000000002 ffffffff811d7620 ffff88000367bc70 ffff8800042933a8
[ 1080.060182] Call Trace:
[ 1080.060194] [<ffffffff811d7620>] ? generic_block_bmap+0x50/0x50
[ 1080.060203] [<ffffffff815114a9>] ? io_schedule+0x99/0x120
[ 1080.060209] [<ffffffff811d762a>] ? sleep_on_buffer+0xa/0x10
[ 1080.060215] [<ffffffff8151182c>] ? __wait_on_bit+0x5c/0x90
[ 1080.060223] [<ffffffff811d7620>] ? generic_block_bmap+0x50/0x50
[ 1080.060227] [<ffffffff815118d7>] ? out_of_line_wait_on_bit+0x77/0x90
[ 1080.060233] [<ffffffff810a7e90>] ? autoremove_wake_function+0x30/0x30
[ 1080.060246] [<ffffffffa007160b>] ? ext4_bread+0x5b/0x90 [ext4]
[ 1080.060253] [<ffffffffa007931a>] ? __ext4_read_dirblock+0x3a/0x3c0 [ext4]
[ 1080.060262] [<ffffffffa0079b80>] ? htree_dirblock_to_tree+0x40/0x190 [ext4]
[ 1080.060269] [<ffffffffa007aed1>] ? ext4_htree_fill_tree+0xc1/0x250 [ext4]
[ 1080.060274] [<ffffffff811b7b78>] ? path_openat+0x158/0x680
[ 1080.060279] [<ffffffff8117abb5>] ? free_pages_and_swap_cache+0x95/0xb0
[ 1080.060285] [<ffffffffa0069efb>] ? ext4_readdir+0x17b/0x8d0 [ext4]
[ 1080.060289] [<ffffffff811b884a>] ? do_filp_open+0x3a/0x90
[ 1080.060294] [<ffffffff811bafff>] ? iterate_dir+0x9f/0x120
[ 1080.060297] [<ffffffff811bb459>] ? SyS_getdents+0x89/0x100
[ 1080.060300] [<ffffffff811bb150>] ? fillonedir+0xd0/0xd0
[ 1080.060305] [<ffffffff81514a0d>] ? system_call_fast_compare_end+0x10/0x15
[ 1200.060128] INFO: task jbd2/xvda2-8:109 blocked for more than 120 seconds.
[ 1200.060144] Not tainted 3.16.0-4-amd64 #1
[ 1200.060148] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1200.060155] jbd2/xvda2-8 D ffff8801f1462628 0 109 2 0x00000000
[ 1200.060165] ffff8801f14621d0 0000000000000246 0000000000012f00 ffff88000496ffd8
[ 1200.060174] 0000000000012f00 ffff8801f14621d0 ffff8801feb137b0 ffff8801ff003f68
[ 1200.060183] 0000000000000002 ffffffff8113d0e0 ffff88000496fbd0 ffff88000496fc50
[ 1200.060192] Call Trace:
[ 1200.060204] [<ffffffff8113d0e0>] ? wait_on_page_read+0x60/0x60
[ 1200.060213] [<ffffffff815114a9>] ? io_schedule+0x99/0x120
[ 1200.060220] [<ffffffff8113d0ea>] ? sleep_on_page+0xa/0x10
[ 1200.060226] [<ffffffff8151182c>] ? __wait_on_bit+0x5c/0x90
[ 1200.060232] [<ffffffff8113cedf>] ? wait_on_page_bit+0x7f/0x90
[ 1200.060241] [<ffffffff810a7e90>] ? autoremove_wake_function+0x30/0x30
[ 1200.060251] [<ffffffff8114a46d>] ? pagevec_lookup_tag+0x1d/0x30
[ 1200.060262] [<ffffffff8113cfc0>] ? filemap_fdatawait_range+0xd0/0x160
[ 1200.060276] [<ffffffff8127d941>] ? submit_bio+0x71/0x150
[ 1200.060282] [<ffffffff81279118>] ? bio_alloc_bioset+0x198/0x290
[ 1200.060295] [<ffffffffa003472c>] ? jbd2_journal_commit_transaction+0xa5c/0x1950 [jbd2]
[ 1200.060304] [<ffffffff8100331e>] ? xen_end_context_switch+0xe/0x20
[ 1200.060314] [<ffffffff810912f6>] ? finish_task_switch+0x46/0xf0
[ 1200.060321] [<ffffffff815141a3>] ? _raw_spin_unlock_irqrestore+0x13/0x20
[ 1200.060329] [<ffffffffa0038be2>] ? kjournald2+0xb2/0x240 [jbd2]
[ 1200.060337] [<ffffffff810a7e60>] ? prepare_to_wait_event+0xf0/0xf0
[ 1200.060344] [<ffffffffa0038b30>] ? commit_timeout+0x10/0x10 [jbd2]
[ 1200.060352] [<ffffffff8108809d>] ? kthread+0xbd/0xe0
[ 1200.060358] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1200.060365] [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
[ 1200.060372] [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[ 1200.060379] INFO: task rs:main Q:Reg:316 blocked for more than 120 seconds.
[ 1200.060385] Not tainted 3.16.0-4-amd64 #1
[ 1200.060389] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1200.060394] rs:main Q:Reg D ffff8800035d3a48 0 316 1 0x00000000
[ 1200.060401] ffff8800035d35f0 0000000000000286 0000000000012f00 ffff8800036dbfd8
[ 1200.060410] 0000000000012f00 ffff8800035d35f0 ffff8801feb137b0 ffff8801feffc4f8
[ 1200.060417] 0000000000000002 ffffffffa00316c0 ffff8800036dbb30 ffff880004414368
[ 1200.060426] Call Trace:
[ 1200.060432] [<ffffffffa00316c0>] ? start_this_handle+0x5a0/0x5a0 [jbd2]
[ 1200.060439] [<ffffffff815114a9>] ? io_schedule+0x99/0x120
[ 1200.060447] [<ffffffffa00316ca>] ? sleep_on_shadow_bh+0xa/0x10 [jbd2]
[ 1200.060452] [<ffffffff8151182c>] ? __wait_on_bit+0x5c/0x90
[ 1200.060459] [<ffffffffa00316c0>] ? start_this_handle+0x5a0/0x5a0 [jbd2]
[ 1200.060466] [<ffffffff815118d7>] ? out_of_line_wait_on_bit+0x77/0x90
[ 1200.060473] [<ffffffff810a7e90>] ? autoremove_wake_function+0x30/0x30
[ 1200.060480] [<ffffffff811d8c54>] ? __find_get_block+0xb4/0x250
[ 1200.060487] [<ffffffffa0032a25>] ? do_get_write_access+0x2a5/0x4b0 [jbd2]
[ 1200.060494] [<ffffffff811d90d6>] ? __getblk_gfp+0x26/0x60
[ 1200.060501] [<ffffffffa0032c52>] ? jbd2_journal_get_write_access+0x22/0x40 [jbd2]
[ 1200.060518] [<ffffffffa009d326>] ? __ext4_journal_get_write_access+0x36/0x80 [ext4]
[ 1200.060528] [<ffffffffa0073558>] ? ext4_reserve_inode_write+0x68/0x90 [ext4]
[ 1200.060539] [<ffffffffa007679b>] ? ext4_dirty_inode+0x3b/0x60 [ext4]
[ 1200.060547] [<ffffffffa00735bf>] ? ext4_mark_inode_dirty+0x3f/0x1d0 [ext4]
[ 1200.060554] [<ffffffffa007679b>] ? ext4_dirty_inode+0x3b/0x60 [ext4]
[ 1200.060558] [<ffffffff811cf682>] ? __mark_inode_dirty+0x172/0x270
[ 1200.060563] [<ffffffff811c1f41>] ? update_time+0x81/0xc0
[ 1200.060568] [<ffffffff8106b432>] ? current_fs_time+0x12/0x60
[ 1200.060572] [<ffffffff811c2140>] ? file_update_time+0x80/0xd0
[ 1200.060576] [<ffffffff8113f352>] ? __generic_file_write_iter+0x132/0x340
    -------------------------------------------------------------------------------------------------
   * What exactly did you do (or not do) that was effective (or
     ineffective)?
     I changed the values of vm.dirty_background_ratio and vm.dirty_ratio, but had no influence

   * What was the outcome of this action?
     nothing

   * What outcome did you expect instead?
     I expected, the VM does not freeze



-- System Information:
Debian Release: 8.4
  APT prefers stable-updates
  APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 3.16.0-4-amd64 (SMP w/16 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash
Init: systemd (via /run/systemd/system)

xen-hypervisor-4.4-amd64 depends on no packages.

Versions of packages xen-hypervisor-4.4-amd64 recommends:
ii  xen-utils-4.4  4.4.1-9+deb8u4

xen-hypervisor-4.4-amd64 suggests no packages.

-- no debconf information

More information about the Pkg-xen-devel mailing list