[LU-4125] sanity-hsm test_228 failure: 'request on 0x20000040b:0x61:0x0 is not SUCCEED'

• Type: Bug
• Resolution: Duplicate
• Priority: Minor
• Affects Version/s: Lustre 2.5.0
• Labels: HSM

Environment

Lustre 2.5.0-RC1, el6

OpenSFS cluster with combined MGS/MDS (c03), single OSS (c04) with two OSTs, archive MGS/MDS (c05), archive OST (c06) with two OSTs, archive OST2 (c07) with two OSTs, eight clients; one agent + client(c08), one robinhood/db + client(c09) and others just running as Lustre clients (c10, c11, c12, c13,c14, c15)

• Severity: 3
• Assignee: Bruno Faccini (Inactive)
• Reporter: James Nunez (Inactive)

Description

Test results at: https://maloo.whamcloud.com/test_sessions/af9dfc14-3834-11e3-8bc4-52540035b04c

From the test_log:

== sanity-hsm test 228: On released file, return extend to FIEMAP. For [cp,tar] --sparse == 08:09:43 (1382108983)
pdsh@c15: c08: ssh exited with exit code 1
Purging archive on c08
Starting copytool agt1 on c08
1+0 records in
1+0 records out
1048576 bytes (1.0 MB) copied, 0.145494 s, 7.2 MB/s
Changed after 0s: from '' to 'STARTED'
Waiting 100 secs for update
Changed after 1s: from 'STARTED' to 'FAILED'
Waiting 90 secs for update
Waiting 80 secs for update
Waiting 70 secs for update
Waiting 60 secs for update
Waiting 50 secs for update
Changed after 60s: from 'FAILED' to ''
Waiting 40 secs for update
Waiting 30 secs for update
Waiting 20 secs for update
Waiting 10 secs for update
Update not seen after 100s: wanted 'SUCCEED' got ''
 sanity-hsm test_228: @@@@@@ FAIL: request on 0x20000040b:0x61:0x0 is not SUCCEED 
  Trace dump:
  = /usr/lib64/lustre/tests/test-framework.sh:4264:error_noexit()
  = /usr/lib64/lustre/tests/test-framework.sh:4291:error()
  = /usr/lib64/lustre/tests/sanity-hsm.sh:474:wait_request_state()
  = /usr/lib64/lustre/tests/sanity-hsm.sh:3085:test_228()
  = /usr/lib64/lustre/tests/test-framework.sh:4530:run_one()
  = /usr/lib64/lustre/tests/test-framework.sh:4563:run_one_logged()
  = /usr/lib64/lustre/tests/test-framework.sh:4433:run_test()
  = /usr/lib64/lustre/tests/sanity-hsm.sh:3111:main()
Dumping lctl log to /tmp/test_logs/2013-10-18/074316/sanity-hsm.test_228.*.1382109102.log
Copytool is stopped on c08

From the copytool_log on c08:

lhsmtool_posix[26046]: action=0 src=(null) dst=(null) mount_point=/lustre/scratch
lhsmtool_posix[26047]: waiting for message from kernel
lhsmtool_posix[26047]: copytool fs=scratch archive#=2 item_count=1
lhsmtool_posix[26047]: waiting for message from kernel
lhsmtool_posix[26048]: '[0x20000040b:0x61:0x0]' action ARCHIVE reclen 72, cookie=0x52614df7
lhsmtool_posix[26048]: processing file 'f.sanity-hsm.228'
lhsmtool_posix[26048]: archiving '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0' to '/lustre/archive/0061/0000/040b/0000/0002/0000/0x20000040b:0x61:0x0_tmp'
lhsmtool_posix[26048]: saving stripe info of '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0' in /lustre/archive/0061/0000/040b/0000/0002/0000/0x20000040b:0x61:0x0_tmp.lov
lhsmtool_posix[26048]: going to copy data from '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0' to '/lustre/archive/0061/0000/040b/0000/0002/0000/0x20000040b:0x61:0x0_tmp'
lhsmtool_posix[26048]: progress ioctl for copy '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0'->'/lustre/archive/0061/0000/040b/0000/0002/0000/0x20000040b:0x61:0x0_tmp' failed: No such file or directory (2)
lhsmtool_posix[26048]: data copy failed from '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0' to '/lustre/archive/0061/0000/040b/0000/0002/0000/0x20000040b:0x61:0x0_tmp': No such file or directory (2)
lhsmtool_posix[26048]: Action completed, notifying coordinator cookie=0x52614df7, FID=[0x20000040b:0x61:0x0], hp_flags=0 err=2
lhsmtool_posix[26048]: llapi_hsm_action_end() on '/lustre/scratch/.lustre/fid/0x20000040b:0x61:0x0' failed: No such file or directory (2)
exiting: Interrupt

From dmesg on the MDS (c03):

Lustre: DEBUG MARKER: == sanity-hsm test 228: On released file, return extend to FIEMAP. For [cp,tar] --sparse == 08:09:43 (1382108983)
LustreError: 7622:0:(mdt_coordinator.c:1448:mdt_hsm_update_request_state()) scratch-MDT0000: Cannot find running request for cookie 0x52614df7 on fid=[0x20000040b:0x61:0x0]
LustreError: 7622:0:(mdt_coordinator.c:1448:mdt_hsm_update_request_state()) scratch-MDT0000: Cannot find running request for cookie 0x52614df7 on fid=[0x20000040b:0x61:0x0]
Lustre: DEBUG MARKER: sanity-hsm test_228: @@@@@@ FAIL: request on 0x20000040b:0x61:0x0 is not SUCCEED

Issue Links

• is duplicated by: LU-4343 sanity-hsm test_228 failure: FAIL: tar failed