[LU-8643] sanity test_123a: test failed to respond and timed out - Whamcloud Community JIRA

Details

Type: Bug
Resolution: Cannot Reproduce
Priority: Minor
Fix Version/s: None
Affects Version/s: None
Labels:
None

Severity:
3
Rank (Obsolete):
9223372036854775807

Description

This issue was created by maloo for Niu Yawei <yawei.niu@intel.com>

This issue relates to the following test suite run: https://testing.hpdd.intel.com/test_sets/e5c0755c-8420-11e6-a35f-5254006e85c2.

The sub-test test_123a failed with the following error:

test failed to respond and timed out

Please provide additional information about the failure here.

Info required for matching: sanity 123a

Attachments

Issue Links

is related to

LU-5106 Test failure sanity test_123a: ls 10000 files is slower with statahead!

Resolved

Activity

[LU-8643] sanity test_123a: test failed to respond and timed out

Niu Yawei (Inactive) added a comment - 27/Sep/16 5:40 AM

client console: https://testing.hpdd.intel.com/test_logs/ebae31a2-8420-11e6-a35f-5254006e85c2/show_text

05:54:14:[ 5898.103804] Lustre: DEBUG MARKER: == sanity test 123a: verify statahead work =========================================================== 05:54:10 (1474894450)
05:54:14:[ 5899.246107] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 100 files without statahead: 0 sec
05:54:14:[ 5899.507534] Lustre: DEBUG MARKER: ls 100 files without statahead: 0 sec
05:54:14:[ 5900.134354] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 100 files with statahead: 0 sec
05:54:14:[ 5900.309651] Lustre: DEBUG MARKER: ls 100 files with statahead: 0 sec
05:56:05:[ 5900.547980] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held!
05:56:05:[ 5900.769666] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held!
05:56:05:[ 5907.467726] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 1000 files without statahead: 3 sec
05:56:05:[ 5907.627435] Lustre: DEBUG MARKER: ls 1000 files without statahead: 3 sec
05:56:05:[ 5911.020397] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 1000 files with statahead: 3 sec
05:56:05:[ 5911.199707] Lustre: DEBUG MARKER: ls 1000 files with statahead: 3 sec
05:56:05:[ 5911.530930] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held!
05:56:05:[ 5911.707546] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held!
05:56:05:[ 5976.368202] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 10000 files without statahead: 29 sec
05:56:05:[ 5976.527783] Lustre: DEBUG MARKER: ls 10000 files without statahead: 29 sec
05:56:05:[ 6007.315699] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 10000 files with statahead: 29 sec
05:56:05:[ 6007.491491] Lustre: DEBUG MARKER: ls 10000 files with statahead: 29 sec
05:56:05:[ 6007.751989] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held!
05:56:05:[ 6007.949089] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held!
05:56:05:[ 6008.189559] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls done
05:56:05:[ 6008.383160] Lustre: DEBUG MARKER: ls done
05:56:05:[ 6011.942801] BUG: Bad page map in process master  pte:8000000000001163 pmd:01f38067
05:56:05:[ 6011.948377] page:ffffea0000000040 count:1 mapcount:-1 mapping:          (null) index:0x0
05:56:05:[ 6011.953687] page flags: 0xfffff00000414(referenced|dirty|reserved)
05:56:05:[ 6011.957739] page dumped because: bad pte
05:56:05:[ 6011.959498] addr:0000880000001000 vm_flags:00000070 anon_vma:          (null) mapping:ffff8800358d0e48 index:889c04cb
05:56:05:[ 6011.961648] vma->vm_ops->fault: filemap_fault+0x0/0x410
05:56:05:[ 6011.963502] vma->vm_file->f_op->mmap: ext4_file_mmap+0x0/0x30 [ext4]
05:56:05:[ 6011.965314] CPU: 0 PID: 25858 Comm: master Tainted: G           OE  ------------   3.10.0-327.28.3.el7.x86_64 #1
05:56:05:[ 6011.967569] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
05:56:05:[ 6011.969428]  0000880000001000 00000000bd1e5f65 ffff88004a203ac8 ffffffff81636453
05:56:05:[ 6011.971748]  ffff88004a203b10 ffffffff81192c3f 8000000000001163 00000000889c04cb
05:56:05:[ 6011.973937]  ffff880001f38008 ffffea0000000040 0000880000001000 0000880000200000
05:56:05:[ 6011.976048] Call Trace:
05:56:05:[ 6011.977593]  [<ffffffff81636453>] dump_stack+0x19/0x1b
05:56:05:[ 6011.979306]  [<ffffffff81192c3f>] print_bad_pte+0x1af/0x250
05:56:05:[ 6011.981092]  [<ffffffff81194727>] unmap_page_range+0x767/0x850
05:56:05:[ 6011.982838]  [<ffffffff81194891>] unmap_single_vma+0x81/0xf0
05:56:05:[ 6011.984595]  [<ffffffff81195989>] unmap_vmas+0x49/0x90
05:56:05:[ 6011.986311]  [<ffffffff8119ec9c>] exit_mmap+0xac/0x1a0
05:56:05:[ 6011.988055]  [<ffffffff810782b7>] mmput+0x67/0xf0
05:56:05:[ 6011.989716]  [<ffffffff811e5e82>] flush_old_exec+0x422/0x880
05:56:05:[ 6011.991474]  [<ffffffff81239c2c>] load_elf_binary+0x33c/0xdd0
05:56:05:[ 6011.993237]  [<ffffffff812a7bc3>] ? ima_get_action+0x23/0x30
05:56:05:[ 6011.995047]  [<ffffffff812a722e>] ? process_measurement+0x8e/0x250
05:56:05:[ 6011.996815]  [<ffffffff812a76e9>] ? ima_bprm_check+0x49/0x50
05:56:05:[ 6011.998553]  [<ffffffff812398f0>] ? load_elf_library+0x230/0x230
05:56:05:[ 6012.000285]  [<ffffffff811e55bd>] search_binary_handler+0xed/0x300
05:56:05:[ 6012.001961]  [<ffffffff811e6b19>] do_execve_common.isra.23+0x589/0x690
05:56:05:[ 6012.003629]  [<ffffffff811e6eb9>] SyS_execve+0x29/0x30
05:56:05:[ 6012.005192]  [<ffffffff816470e9>] stub_execve+0x69/0xa0
05:56:05:[ 6012.006759] Disabling lock debugging due to kernel taint
05:56:05:[ 6012.008263] BUG: Bad page map in process master  pte:8000000000002163 pmd:01f38067
05:56:05:[ 6012.010016] page:ffffea0000000080 count:1 mapcount:-1 mapping:          (null) index:0x0
05:56:05:[ 6012.011744] page flags: 0xfffff00000414(referenced|dirty|reserved)
05:56:05:[ 6012.013444] page dumped because: bad pte
05:56:05:[ 6012.014909] addr:0000880000002000 vm_flags:00000070 anon_vma:          (null) mapping:ffff8800358d0e48 index:889c04cc
05:56:05:[ 6012.016895] vma->vm_ops->fault: filemap_fault+0x0/0x410
05:56:05:[ 6012.018476] vma->vm_file->f_op->mmap: ext4_file_mmap+0x0/0x30 [ext4]
05:56:05:[ 6012.020129] CPU: 0 PID: 25858 Comm: master Tainted: G    B      OE  ------------   3.10.0-327.28.3.el7.x86_64 #1
05:56:05:[ 6012.022036] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
05:56:05:[ 6012.023662]  0000880000002000 00000000bd1e5f65 ffff88004a203ac8 ffffffff81636453
05:56:05:[ 6012.025451]  ffff88004a203b10 ffffffff81192c3f 8000000000002163 00000000889c04cc
05:56:05:[ 6012.027275]  ffff880001f38010 ffffea0000000080 0000880000002000 0000880000200000
05:56:05:[ 6012.029096] Call Trace:
05:56:05:[ 6012.030475]  [<ffffffff81636453>] dump_stack+0x19/0x1b
05:56:05:[ 6012.032037]  [<ffffffff81192c3f>] print_bad_pte+0x1af/0x250
05:56:05:[ 6012.033641]  [<ffffffff81194727>] unmap_page_range+0x767/0x850
05:56:05:[ 6012.035236]  [<ffffffff81194891>] unmap_single_vma+0x81/0xf0
05:56:05:[ 6012.036833]  [<ffffffff81195989>] unmap_vmas+0x49/0x90
05:56:05:[ 6012.038391]  [<ffffffff8119ec9c>] exit_mmap+0xac/0x1a0
05:56:05:[ 6012.039967]  [<ffffffff810782b7>] mmput+0x67/0xf0
05:56:05:[ 6012.041442]  [<ffffffff811e5e82>] flush_old_exec+0x422/0x880
05:56:05:[ 6012.042980]  [<ffffffff81239c2c>] load_elf_binary+0x33c/0xdd0
05:56:05:[ 6012.044476]  [<ffffffff812a7bc3>] ? ima_get_action+0x23/0x30
05:56:05:[ 6012.045943]  [<ffffffff812a722e>] ? process_measurement+0x8e/0x250
05:56:05:[ 6012.047460]  [<ffffffff812a76e9>] ? ima_bprm_check+0x49/0x50
05:56:05:[ 6012.048913]  [<ffffffff812398f0>] ? load_elf_library+0x230/0x230
05:56:05:[ 6012.050368]  [<ffffffff811e55bd>] search_binary_handler+0xed/0x300
05:56:05:[ 6012.051850]  [<ffffffff811e6b19>] do_execve_common.isra.23+0x589/0x690
05:56:05:[ 6012.053349]  [<ffffffff811e6eb9>] SyS_execve+0x29/0x30
05:56:05:[ 6012.054737]  [<ffffffff816470e9>] stub_execve+0x69/0xa0

Niu Yawei (Inactive) added a comment - 27/Sep/16 5:40 AM client console: https://testing.hpdd.intel.com/test_logs/ebae31a2-8420-11e6-a35f-5254006e85c2/show_text 05:54:14:[ 5898.103804] Lustre: DEBUG MARKER: == sanity test 123a: verify statahead work =========================================================== 05:54:10 (1474894450) 05:54:14:[ 5899.246107] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 100 files without statahead: 0 sec 05:54:14:[ 5899.507534] Lustre: DEBUG MARKER: ls 100 files without statahead: 0 sec 05:54:14:[ 5900.134354] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 100 files with statahead: 0 sec 05:54:14:[ 5900.309651] Lustre: DEBUG MARKER: ls 100 files with statahead: 0 sec 05:56:05:[ 5900.547980] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held! 05:56:05:[ 5900.769666] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held! 05:56:05:[ 5907.467726] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 1000 files without statahead: 3 sec 05:56:05:[ 5907.627435] Lustre: DEBUG MARKER: ls 1000 files without statahead: 3 sec 05:56:05:[ 5911.020397] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 1000 files with statahead: 3 sec 05:56:05:[ 5911.199707] Lustre: DEBUG MARKER: ls 1000 files with statahead: 3 sec 05:56:05:[ 5911.530930] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held! 05:56:05:[ 5911.707546] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held! 05:56:05:[ 5976.368202] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 10000 files without statahead: 29 sec 05:56:05:[ 5976.527783] Lustre: DEBUG MARKER: ls 10000 files without statahead: 29 sec 05:56:05:[ 6007.315699] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls 10000 files with statahead: 29 sec 05:56:05:[ 6007.491491] Lustre: DEBUG MARKER: ls 10000 files with statahead: 29 sec 05:56:05:[ 6007.751989] Lustre: DEBUG MARKER: /usr/sbin/lctl mark statahead was stopped, maybe too many locks held! 05:56:05:[ 6007.949089] Lustre: DEBUG MARKER: statahead was stopped, maybe too many locks held! 05:56:05:[ 6008.189559] Lustre: DEBUG MARKER: /usr/sbin/lctl mark ls done 05:56:05:[ 6008.383160] Lustre: DEBUG MARKER: ls done 05:56:05:[ 6011.942801] BUG: Bad page map in process master pte:8000000000001163 pmd:01f38067 05:56:05:[ 6011.948377] page:ffffea0000000040 count:1 mapcount:-1 mapping: ( null ) index:0x0 05:56:05:[ 6011.953687] page flags: 0xfffff00000414(referenced|dirty|reserved) 05:56:05:[ 6011.957739] page dumped because: bad pte 05:56:05:[ 6011.959498] addr:0000880000001000 vm_flags:00000070 anon_vma: ( null ) mapping:ffff8800358d0e48 index:889c04cb 05:56:05:[ 6011.961648] vma->vm_ops->fault: filemap_fault+0x0/0x410 05:56:05:[ 6011.963502] vma->vm_file->f_op->mmap: ext4_file_mmap+0x0/0x30 [ext4] 05:56:05:[ 6011.965314] CPU: 0 PID: 25858 Comm: master Tainted: G OE ------------ 3.10.0-327.28.3.el7.x86_64 #1 05:56:05:[ 6011.967569] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007 05:56:05:[ 6011.969428] 0000880000001000 00000000bd1e5f65 ffff88004a203ac8 ffffffff81636453 05:56:05:[ 6011.971748] ffff88004a203b10 ffffffff81192c3f 8000000000001163 00000000889c04cb 05:56:05:[ 6011.973937] ffff880001f38008 ffffea0000000040 0000880000001000 0000880000200000 05:56:05:[ 6011.976048] Call Trace: 05:56:05:[ 6011.977593] [<ffffffff81636453>] dump_stack+0x19/0x1b 05:56:05:[ 6011.979306] [<ffffffff81192c3f>] print_bad_pte+0x1af/0x250 05:56:05:[ 6011.981092] [<ffffffff81194727>] unmap_page_range+0x767/0x850 05:56:05:[ 6011.982838] [<ffffffff81194891>] unmap_single_vma+0x81/0xf0 05:56:05:[ 6011.984595] [<ffffffff81195989>] unmap_vmas+0x49/0x90 05:56:05:[ 6011.986311] [<ffffffff8119ec9c>] exit_mmap+0xac/0x1a0 05:56:05:[ 6011.988055] [<ffffffff810782b7>] mmput+0x67/0xf0 05:56:05:[ 6011.989716] [<ffffffff811e5e82>] flush_old_exec+0x422/0x880 05:56:05:[ 6011.991474] [<ffffffff81239c2c>] load_elf_binary+0x33c/0xdd0 05:56:05:[ 6011.993237] [<ffffffff812a7bc3>] ? ima_get_action+0x23/0x30 05:56:05:[ 6011.995047] [<ffffffff812a722e>] ? process_measurement+0x8e/0x250 05:56:05:[ 6011.996815] [<ffffffff812a76e9>] ? ima_bprm_check+0x49/0x50 05:56:05:[ 6011.998553] [<ffffffff812398f0>] ? load_elf_library+0x230/0x230 05:56:05:[ 6012.000285] [<ffffffff811e55bd>] search_binary_handler+0xed/0x300 05:56:05:[ 6012.001961] [<ffffffff811e6b19>] do_execve_common.isra.23+0x589/0x690 05:56:05:[ 6012.003629] [<ffffffff811e6eb9>] SyS_execve+0x29/0x30 05:56:05:[ 6012.005192] [<ffffffff816470e9>] stub_execve+0x69/0xa0 05:56:05:[ 6012.006759] Disabling lock debugging due to kernel taint 05:56:05:[ 6012.008263] BUG: Bad page map in process master pte:8000000000002163 pmd:01f38067 05:56:05:[ 6012.010016] page:ffffea0000000080 count:1 mapcount:-1 mapping: ( null ) index:0x0 05:56:05:[ 6012.011744] page flags: 0xfffff00000414(referenced|dirty|reserved) 05:56:05:[ 6012.013444] page dumped because: bad pte 05:56:05:[ 6012.014909] addr:0000880000002000 vm_flags:00000070 anon_vma: ( null ) mapping:ffff8800358d0e48 index:889c04cc 05:56:05:[ 6012.016895] vma->vm_ops->fault: filemap_fault+0x0/0x410 05:56:05:[ 6012.018476] vma->vm_file->f_op->mmap: ext4_file_mmap+0x0/0x30 [ext4] 05:56:05:[ 6012.020129] CPU: 0 PID: 25858 Comm: master Tainted: G B OE ------------ 3.10.0-327.28.3.el7.x86_64 #1 05:56:05:[ 6012.022036] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007 05:56:05:[ 6012.023662] 0000880000002000 00000000bd1e5f65 ffff88004a203ac8 ffffffff81636453 05:56:05:[ 6012.025451] ffff88004a203b10 ffffffff81192c3f 8000000000002163 00000000889c04cc 05:56:05:[ 6012.027275] ffff880001f38010 ffffea0000000080 0000880000002000 0000880000200000 05:56:05:[ 6012.029096] Call Trace: 05:56:05:[ 6012.030475] [<ffffffff81636453>] dump_stack+0x19/0x1b 05:56:05:[ 6012.032037] [<ffffffff81192c3f>] print_bad_pte+0x1af/0x250 05:56:05:[ 6012.033641] [<ffffffff81194727>] unmap_page_range+0x767/0x850 05:56:05:[ 6012.035236] [<ffffffff81194891>] unmap_single_vma+0x81/0xf0 05:56:05:[ 6012.036833] [<ffffffff81195989>] unmap_vmas+0x49/0x90 05:56:05:[ 6012.038391] [<ffffffff8119ec9c>] exit_mmap+0xac/0x1a0 05:56:05:[ 6012.039967] [<ffffffff810782b7>] mmput+0x67/0xf0 05:56:05:[ 6012.041442] [<ffffffff811e5e82>] flush_old_exec+0x422/0x880 05:56:05:[ 6012.042980] [<ffffffff81239c2c>] load_elf_binary+0x33c/0xdd0 05:56:05:[ 6012.044476] [<ffffffff812a7bc3>] ? ima_get_action+0x23/0x30 05:56:05:[ 6012.045943] [<ffffffff812a722e>] ? process_measurement+0x8e/0x250 05:56:05:[ 6012.047460] [<ffffffff812a76e9>] ? ima_bprm_check+0x49/0x50 05:56:05:[ 6012.048913] [<ffffffff812398f0>] ? load_elf_library+0x230/0x230 05:56:05:[ 6012.050368] [<ffffffff811e55bd>] search_binary_handler+0xed/0x300 05:56:05:[ 6012.051850] [<ffffffff811e6b19>] do_execve_common.isra.23+0x589/0x690 05:56:05:[ 6012.053349] [<ffffffff811e6eb9>] SyS_execve+0x29/0x30 05:56:05:[ 6012.054737] [<ffffffff816470e9>] stub_execve+0x69/0xa0

sanity test_123a: test failed to respond and timed out

Details

Description

Attachments

Issue Links

Activity

People

Dates