[LU-6985] Interop 2.7.0<->master parallel-scale-nfsv3 test_iorfpp: nfsd in D state

• Status: Resolved
• Project: Lustre
• Affects Version/s: Lustre 2.8.0
• Type: Bug
• Priority: Minor
• Reporter: Maloo
• Assignee: WC Triage
• Resolution: Won't Fix

Environment

server: lustre-master build# 3122 RHEL6.6
client: 2.7.0

• Severity: 3

Description

This issue was created by maloo for sarah_lw <[e-mail]>

This issue relates to the following test suite run: https://testing.hpdd.intel.com/test_sets/16cb08be-378e-11e5-860b-5254006e85c2.

The sub-test test_iorfpp failed with the following error:

test failed to respond and timed out

09:38:07:Lustre: DEBUG MARKER: == parallel-scale-nfsv3 test iorfpp: iorfpp == 09:24:52 (1438334692)
09:38:07:Lustre: DEBUG MARKER: lfs setstripe /mnt/lustre/d0.ior.fpp -c -1
09:38:07:LustreError: 5137:0:(osc_request.c:1390:osc_brw_redo_request()) @@@ redo for recoverable error -5  req@ffff88002069a3c0 x1508190467091936/t0(0) o3->lustre-OST0000-osc-ffff88003e9eec00@10.1.4.182@tcp:6/4 lens 608/400 e 3 to 0 dl 1438335460 ref 2 fl Interpret:RM/0/0 rc -5/-5
09:38:07:INFO: task nfsd:12355 blocked for more than 120 seconds.
09:38:07:      Not tainted 2.6.32-504.30.3.el6_lustre.gc34ab89.x86_64 #1
09:38:07:"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
09:38:07:nfsd          D 0000000000000001     0 12355      2 0x00000080
09:40:08: ffff88007cbb9630 0000000000000046 0000000000000000 ffffffff81041e98
09:40:08: ffffffffffffffff 00009f4e35a9c990 0000394ac4051dd0 ffff880079107590
09:40:08: 00000000031f27de 0000000103bca005 ffff88007d8985f8 ffff88007cbb9fd8
09:40:08:Call Trace:
09:40:08: [<ffffffff81041e98>] ? pvclock_clocksource_read+0x58/0xd0
09:40:08: [<ffffffff81124900>] ? sync_page+0x0/0x50
09:40:08: [<ffffffff8152ab93>] io_schedule+0x73/0xc0
09:40:08: [<ffffffff8112493d>] sync_page+0x3d/0x50
09:40:08: [<ffffffff8152b42a>] __wait_on_bit_lock+0x5a/0xc0
09:40:08: [<ffffffff811248d7>] __lock_page+0x67/0x70
09:40:08: [<ffffffff8109eca0>] ? wake_bit_function+0x0/0x50
09:40:08: [<ffffffff811c0062>] __generic_file_splice_read+0x382/0x560
09:40:08: [<ffffffffa09bd27b>] ? cfs_set_ptldebug_header+0x2b/0xc0 [libcfs]
09:40:08: [<ffffffffa09c95c3>] ? libcfs_debug_vmsg2+0x5e3/0xbe0 [libcfs]
09:40:08: [<ffffffff811bdeb0>] ? spd_release_page+0x0/0x20
09:40:08: [<ffffffffa1b51933>] ? vvp_prep_size+0xd3/0x240 [lustre]
09:40:08: [<ffffffff811c028a>] generic_file_splice_read+0x4a/0x90
09:40:08: [<ffffffffa1b5361f>] vvp_io_read_start+0x3cf/0x480 [lustre]
09:40:08: [<ffffffffa11b4f8a>] cl_io_start+0x6a/0x140 [obdclass]
09:40:08: [<ffffffffa11b94d4>] cl_io_loop+0xb4/0x1b0 [obdclass]
09:40:08: [<ffffffffa1afdb3b>] ll_file_io_generic+0x6ab/0xab0 [lustre]
09:40:08: [<ffffffffa09ce4f4>] ? cfs_hash_dual_bd_unlock+0x34/0x60 [libcfs]
09:40:08: [<ffffffffa1afee94>] ll_file_splice_read+0xa4/0x1d0 [lustre]
09:40:08: [<ffffffff811be3ab>] do_splice_to+0x6b/0xa0
09:40:08: [<ffffffff811be70f>] splice_direct_to_actor+0xaf/0x1c0
09:40:08: [<ffffffffa0395430>] ? nfsd_direct_splice_actor+0x0/0x20 [nfsd]
09:40:08: [<ffffffffa0395b10>] nfsd_vfs_read+0x1a0/0x1c0 [nfsd]
09:40:08: [<ffffffffa0396eb9>] nfsd_read+0x1c9/0x2e0 [nfsd]
09:40:08: [<ffffffffa039fef5>] nfsd3_proc_read+0xd5/0x180 [nfsd]
09:40:08: [<ffffffffa0390425>] nfsd_dispatch+0xe5/0x230 [nfsd]
09:40:08: [<ffffffffa0276c84>] svc_process_common+0x344/0x640 [sunrpc]
09:40:08: [<ffffffff81064c00>] ? default_wake_function+0x0/0x20
09:40:08: [<ffffffffa02772c0>] svc_process+0x110/0x160 [sunrpc]
09:40:08: [<ffffffffa0390b52>] nfsd+0xc2/0x160 [nfsd]
09:40:08: [<ffffffffa0390a90>] ? nfsd+0x0/0x160 [nfsd]
09:40:08: [<ffffffff8109e78e>] kthread+0x9e/0xc0
09:40:08: [<ffffffff8100c28a>] child_rip+0xa/0x20
09:40:08: [<ffffffff8109e6f0>] ? kthread+0x0/0xc0
09:40:08: [<ffffffff8100c280>] ? child_rip+0x0/0x20
09:40:08:LustreError: 5137:0:(osc_request.c:1390:osc_brw_redo_request()) @@@ redo for recoverable error -5  req@ffff88001cee5980 x1508190467095116/t0(0) o3->lustre-OST0000-osc-ffff88003e9eec00@10.1.4.182@tcp:6/4 lens 608/400 e 0 to 0 dl 1438335584 ref 2 fl Interpret:RM/0/0 rc -5/-5
09:40:08:LustreError: 5137:0:(osc_request.c:1390:osc_brw_redo_request()) @@@ redo for recoverable error -5  req@ffff88001617d6c0 x1508190467098508/t0(0) o3->lustre-OST0000-osc-ffff88003e9eec00@10.1.4.182@tcp:6/4 lens 608/400 e 0 to 0 dl 1438335632 ref 2 fl Interpret:RM/0/0 rc -5/-5
09:40:08:LustreError: 5137:0:(osc_request.c:1390:osc_brw_redo_request()) @@@ redo for recoverable error -5  req@ffff880010146080 x1508190467103084/t0(0) o3->lustre-OST0000-osc-ffff88003e9eec00@10.1.4.182@tcp:6/4 lens 608/400 e 0 to 0 dl 1438335679 ref 2 fl Interpret:RM/0/0 rc -5/-5