[LU-3700] sanity-hsm test_21 Error: 'wrong block number'

• Type: Technical task
• Resolution: Duplicate
• Priority: Blocker
• Fix Version/s: Lustre 2.6.0
• Affects Version/s: Lustre 2.5.0
• Labels: HSM zfs
• Environment: Patches submitted to autotest
• Assignee: Bruno Faccini (Inactive)
• Reporter: Keith Mannthey (Inactive)

Description

from https://maloo.whamcloud.com/test_sets/0afc2c56-fc86-11e2-8ce2-52540035b04c

This sanity-hsm test 21 seems to be hitting a lot right now
Wrong block number is one of the errors seen.

test_21 	

    Error: 'wrong block number'
    Failure Rate: 33.00% of last 100 executions [all branches] 

== sanity-hsm test 21: Simple release tests == 23:18:20 (1375510700)
2+0 records in
2+0 records out
2097152 bytes (2.1 MB) copied, 0.353933 s, 5.9 MB/s
 sanity-hsm test_21: @@@@@@ FAIL: wrong block number 
  Trace dump:
  = /usr/lib64/lustre/tests/test-framework.sh:4202:error_noexit()

Issue Links

• is related to: LU-3704 sanity-hsm test_21 - test_24 Error: 'could not release file'

Comments

[Andreas Dilger]

I didn't see this comment before I inspected the patch. However, this implies a different bug in ZFS. Namely, the "small_file" helper in sanity-hsm is creating files with conv=fsync, so the fsync on close should flush all the blocks from the client cache and onto disk on the OST. After that point the blocks count for the file should not change. Likewise, if the locks are cancelled at the client, it should flush all the dirty blocks from cache to disk on the OST.

This makes me wonder if ZFS is implementing fsync properly at the server.

[Nathaniel Clark]

My previous patch actually skipped wrong test.

http://review.whamcloud.com/8575

[Nathaniel Clark]

ZFS reports blocks written to disk, and not # of blocks used if the file were fully written to disk, so the number actually changes after the write completes in ZFS. It's not a locking or consistency issue in Lustre.

[Nathaniel Clark]

The OSS is definitely returning a funny (not the same) number of blocks after doing hsm_archive. I checked this on my local setup with wireshark and OST_GETATTR is replying with different number of blocks than before doing hsm_archive.

It may be that the passing tests are the ones hitting the cached value on the client and the failure is the one getting the value from the OST.

OST debug log:

1386629604.515513:0:1344:0:(ldlm_lockd.c:1167:ldlm_handle_enqueue0()) ### server-side enqueue handler START
1386629604.515525:0:1344:0:(ldlm_lockd.c:1253:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: filter-lustre-OST0001_UUID lock: ffff880072cb7740/0xb2c4c9585d128715 lrc: 2/0,0 mode: --/PR res: [0x21aa:0x0:0x0].0 rrc: 2 type: EXT [0->0] (req 0->0) flags: 0x40000000000000 nid: local remote: 0x59a0a522abcc8a58 expref: -99 pid: 1344 timeout: 0 lvb_type: 0
1386629604.515559:0:1344:0:(client.c:1473:ptlrpc_send_new_req()) Sending RPC pname:cluuid:pid:xid:nid:opc ll_ost00_002:lustre-OST0001_UUID:1344:1453973284418480:10.10.16.236@tcp:106
1386629604.515582:0:1344:0:(client.c:2123:ptlrpc_set_wait()) set ffff880072921ec0 going to sleep for 6 seconds
1386629604.516784:0:1344:0:(ofd_lvb.c:195:ofd_lvbo_update()) res: [0x21aa:0x0:0x0] updating lvb size: 0 -> 2097152
1386629604.516789:0:1344:0:(ofd_lvb.c:207:ofd_lvbo_update()) res: [0x21aa:0x0:0x0] updating lvb atime: 0 -> 1386629600
1386629604.516799:0:1344:0:(ofd_lvb.c:265:ofd_lvbo_update()) res: [0x100000000:0x21aa:0x0] updating lvb blocks from disk: 1 -> 4103
1386629604.516813:0:1344:0:(client.c:1840:ptlrpc_check_set()) Completed RPC pname:cluuid:pid:xid:nid:opc ll_ost00_002:lustre-OST0001_UUID:1344:1453973284418480:10.10.16.236@tcp:106

[Bruno Faccini (Inactive)]

Andreas, I am not sure to understand you. Do you mean that on ZFS, to get the correct st_blocks from "stat -c %b" just after make_small(), we need to "cancel_lru_locks osc" in between ?

[Andreas Dilger]

Hmm, looking at the test more closely, now that we have a test failure, it seems the test itself is defective. The blocks count == 1 should not be true after ARCHIVE (as it was checked beofre the 8467 patch), only after RELEASE. The failed test reported:

# error "$f: wrong size after archive: $size != $orig_size"

wrong block number after archive:  4103 != 1

so it is setting "orig_size" == 1.

That the test passes on ldiskfs is likely just a race, because it is a bit faster and the client does not have the actual on-disk blocks count, so it will return "st_blocks=1" to userspace to avoid bugs in tar/rsync that think st_blocks=0 means the file has no data in it. The zfs test is a bit slower to archive, and the client gets the actual st_blocks value back, and (incorrectly) fails this check.

I suspect that even with make_small using conv=fsync that the client still has cached the original blocks count, so what is needed to fix this bug is to flush the locks on the client before getting orig_blocks:

cancel_lru_locks osc

That way, it returns an accurate value for st_blocks for later testing.

Nathaniel, can you please submit a patch ASAP so maybe we can land this by tomorrow.

[Nathaniel Clark]

There was a failure https://maloo.whamcloud.com/test_sets/8d7a2b66-6134-11e3-bd66-52540035b04c post #8467. It is, so far, unique (but not seemingly patch related).

[Nathaniel Clark]

In case 8467 doesn't fix 21 for ZFS, here is a patch to EXCEPT it: http://review.whamcloud.com/8503

[Andreas Dilger]

Nathaniel, can you please submit a separate patch to disable this test for ZFS only. That can test and possibly land in parallel with 8467 if that does not give us any relief.

[Bruno Faccini (Inactive)]

Patch is at http://review.whamcloud.com/8467.
But I wonder how, even for ZFS, released file st_blocks can be nothing else than 1 after my patch #7776 to force it as part of LU-3864 …

[Nathaniel Clark]

I'll work up and test a patch per Andreas's comment.