[LU-4035] sanity-hsm test_58 failure: 'truncate 3158 does not trig restore, state = '

• Type: Bug
• Resolution: Cannot Reproduce
• Priority: Minor
• Affects Version/s: Lustre 2.5.0, Lustre 2.6.0
• Labels: HSM
• Environment: Lustre 2.4.93 build # 1687; OpenSFS cluster with combined MGS/MDS, single OSS with two OSTs, four clients; one agent + Lustre client (c07), one Lustre client + with robinhood/db running (c08) and two Lustre clients (c09, c10)
• Severity: 3
• Assignee: Jinshan Xiong (Inactive)
• Reporter: James Nunez (Inactive)

Description

test results at: https://maloo.whamcloud.com/test_sessions/d9bd658c-2a2b-11e3-8527-52540035b04c

From the client test_log:

== sanity-hsm test 58: Truncate a released file will trigger restore == 14:49:23 (1380577763)
pdsh@c10: c07: ssh exited with exit code 1
Purging archive on c07
Starting copytool agt1 on c07
truncate up from 3158 to 6316
/lustre/scratch/d0.sanity-hsm/d58/f.sanity-hsm.58: (0x0000000b) exists dirty archived, archive_id:2
truncate down from 3158 to 1579
/lustre/scratch/d0.sanity-hsm/d58/f.sanity-hsm.58: (0x0000000b) exists dirty archived, archive_id:2
truncate to 0
/lustre/scratch/d0.sanity-hsm/d58/f.sanity-hsm.58: (0x0000000b) exists dirty archived, archive_id:2
 sanity-hsm test_58: @@@@@@ FAIL: truncate 3158 does not trig restore, state =  
  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:2158:truncate_released_file()
  = /usr/lib64/lustre/tests/sanity-hsm.sh:2181:test_58()
  = /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:2185:main()

From the copytool log, it looks like there are three file restores, one for each of the calls to truncate_release_file:

lhsmtool_posix[31629]: '[0x200000401:0x1ba:0x0]' action RESTORE reclen 72, cookie=0x5249f10d
lhsmtool_posix[31629]: processing file 'd0.sanity-hsm/d58/f.sanity-hsm.58'
lhsmtool_posix[31629]: reading stripe rules from '/archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0.lov' for '/archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0'
lhsmtool_posix[31629]: restoring data from '/archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0' to '{VOLATILE}=[0x200000402:0x18:0x0]'
lhsmtool_posix[31629]: going to copy data from '/archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0' to '{VOLATILE}=[0x200000402:0x18:0x0]'
lhsmtool_posix[31629]: Going to copy 0 bytes /archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0 -> {VOLATILE}=[0x200000402:0x18:0x0]

lhsmtool_posix[31629]: data restore from '/archive/scratch/01ba/0000/0401/0000/0002/0000/0x200000401:0x1ba:0x0' to '{VOLATILE}=[0x200000402:0x18:0x0]' done
lhsmtool_posix[31629]: Action completed, notifying coordinator cookie=0x5249f10d, FID=[0x200000401:0x1ba:0x0], hp_flags=0 err=0
lhsmtool_posix[31629]: llapi_hsm_action_end() on '/lustre/scratch/.lustre/fid/0x200000401:0x1ba:0x0' ok (rc=0)

It's not clear why the status for the file didn't return "SUCCEED".