[LU-9683] Negative value reported for req_waittime mdt stat

• Type: Bug
• Resolution: Fixed
• Priority: Minor
• Fix Version/s: Lustre 2.10.1, Lustre 2.11.0
• Affects Version/s: Lustre 2.9.0
• Severity: 3
• Assignee: James A Simmons
• Reporter: Tom Nabarro (Inactive)

Description

On creating a lustre filesystem (in IML automated test) with lustre version 2.9.58_86_g2383a62, the following was reported indicating a negative value for req_waittime stat (causing IML to not report the stat):

[root@lotus-58vm16 ~]# less /proc/fs/lustre/mds/MDS/mdt/stats
snapshot_time             1497888436.757961280 secs.nsecs
req_waittime              54892 samples [usec] -8497 0 -4659765 1053607811
req_qdepth                54892 samples [reqs] 0 0 0 0
req_active                54892 samples [reqs] 1 1 54892 54892
req_timeout               54892 samples [sec] 1 10 54910 55090
reqbuf_avail              150546 samples [bufs] 63 64 9634690 616604158
ldlm_ibits_enqueue        13 samples [reqs] 1 1 13 13
mds_reint_setattr         1 samples [reqs] 1 1 1 1
mds_reint_open            8 samples [reqs] 1 1 8 8
mds_getattr               1 samples [usec] 44 44 44 1936
mds_connect               5 samples [usec] 27 16179 22451 297791095
mds_get_root              1 samples [usec] 15 15 15 225
mds_statfs                1 samples [usec] 26 26 26 676
mds_getxattr              2 samples [usec] 31 3259 3290 10622042
obd_ping                  54868 samples [usec] 12 548 2165145 95976761

Issue Links

• is related to: LU-17853 Negative value reported in req_waittime mdt
• is related to: LU-9019 Migrate lustre to standard 64 bit time kernel API

Comments

[Gerrit Updater]

John L. Hammond ([e-mail]) merged in patch https://review.whamcloud.com/28290/
Subject: LU-9683 ptlrpc: fix argument misorder
Project: fs/lustre-release
Branch: b2_10
Current Patch Set:
Commit: 907f35db14e5b796bc4d722e16dc206d759e4a9a

[Gerrit Updater]

James Simmons ([e-mail]) uploaded a new patch: https://review.whamcloud.com/28290
Subject: LU-9683 ptlrpc: fix argument misorder
Project: fs/lustre-release
Branch: b2_10
Current Patch Set: 1
Commit: dde04af12cddd05e5414184f428a303b911b40a9

[Peter Jones]

Landed for 2.11

[Gerrit Updater]

Oleg Drokin ([e-mail]) merged in patch https://review.whamcloud.com/28027/
Subject: LU-9683 ptlrpc: fix argument misorder
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 61c48e79fdfb825ea1ab2649cdadaccfb863155c

[Alex Zhuravlev]

https://review.whamcloud.com/#/c/28027/

[James A Simmons]

I can take a look at this when I port the code to 64 bit time handling

[Mikhail Pershin]

I want just confirm that this is not rare issue or something that happens time to time. It is always so and time stats are broken at the moment

[Alex Zhuravlev]

getting quite similar issue with sanity/127a:
osc.lustre-OST0000-osc-MDT0000.stats=
snapshot_time 1499863534.716076693 secs.nsecs
osc.lustre-OST0000-osc-ffff8800c24ba800.stats=
snapshot_time 1499863534.716169621 secs.nsecs
req_waittime 5 samples [usec] -980 0 -3637 2803447
req_active 5 samples [reqs] 1 1 5 5
ost_punch 1 samples [usec] -725 0 -725 525625
ldlm_cancel 1 samples [usec] -980 0 -980 960400