[LU-13989] BL AST vs failed lock enqueue race

• Type: Bug
• Resolution: Fixed
• Priority: Minor
• Fix Version/s: Lustre 2.14.0
• Severity: 3
• Assignee: Andriy Skulysh
• Reporter: Andriy Skulysh

Description

[ 3186.720231] LustreError: 11321:0:(ldlm_lockd.c:256:expired_lock_main()) ### lock callback timer expired after 99s: evicting client at 192.168.103.31@tcp  ns: mdt-lustre-MDT0001_UUID lock: ffff9190a3c818c0/0x7b3cb60baf4c8164 lrc: 3/0,0 mode: CR/CR res: [0x240000402:0x62cc:0x0].0x0 bits 0x9/0x0 rrc: 3 type: IBT flags: 0x60200400000020 nid: 192.168.103.31@tcp remote: 0x3bb5cf764dc821c1 expref: 4134 pid: 14104 timeout: 3186 lvb_type: 0

00010000:00010000:1.0:1581381210.075626:0:23979:0:(ldlm_request.c:1090:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 3/0,1 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00010000:00010000:1.0:1581381212.641875:0:29373:0:(ldlm_lockd.c:1775:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 4/0,1 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT flags: 0x400000000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00010000:00010000:1.0:1581381212.641889:0:29373:0:(ldlm_lockd.c:1797:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 4/0,1 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT flags: 0x400400000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00000100:00100000:1.0:1581381221.075338:0:23979:0:(client.c:2283:ptlrpc_interrupted_set()) INTERRUPTED SET ffff882c8364f700
00000100:00100000:1.0:1581381221.075343:0:23979:0:(client.c:2091:ptlrpc_check_set()) Completed RPC req@ffff882ca5628900 pname:cluuid:pid:xid:nid:opc:job dir_create.sh:465e5615-54aa-7d62-ef39-d58e2ad3afe5:23979:1658195275648912:192.168.103.29@tcp:101:dir_create.sh.0
00010000:00010000:1.0:1581381221.075365:0:23979:0:(ldlm_request.c:619:ldlm_cli_enqueue_fini()) ### client-side enqueue END (FAILED) ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 4/0,1 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT flags: 0x400400000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00010000:00010000:1.0:1581381221.075375:0:23979:0:(ldlm_request.c:551:failed_lock_cleanup()) ### setting FL_LOCAL_ONLY | LDLM_FL_FAILED | LDLM_FL_ATOMIC_CB | LDLM_FL_CBPENDING ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 4/0,1 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT flags: 0x606400000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00010000:00010000:1.0:1581381221.075415:0:23979:0:(ldlm_request.c:1204:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 5/0,0 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT flags: 0x60e400000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0
00010000:00010000:1.0:1581381221.075421:0:23979:0:(ldlm_request.c:1220:ldlm_cli_cancel_local()) not sending request (at caller's instruction)
00010000:00010000:1.0:1581381221.075429:0:23979:0:(ldlm_lockd.c:1797:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0001-mdc-ffff882cbb8ce800 lock: ffff882c9e60ed80/0x3bb5cf764dc821c1 lrc: 3/0,0 mode: --/CW res: [0x240000402:0x62cb:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT flags: 0x4e0f400000000 nid: local remote: 0x0 expref: -99 pid: 23979 timeout: 0 lvb_type: 0

[