|
Niu
Could you please assist with this one?
Thanks
Peter
|
|
The log has only one line of such message at the very beginning of the log file, do you have other logs which includes more messages before and after this error? What about the disk usage on this OST? Is it almost full or quite empty? Any disconnect/reconnect happened when this error showed up? Thanks.
|
|
Hi Niu,
The error is gone, I cannot see it anymore... I found another trace that I took at almost the same time (attaching as oak_dbg_2_oak-io1-s1.log just in case). The disk usage is pretty low on all OSTs, from 1% to 31% (we recently added more OSTs, hence the disparity in OST usage).
I will update the case if I see this error again.
Thanks!
Stephane
|
|
Looks the 'granted' value on client and server is inconsistent somehow, and it happened only on one client (with one OST server), I guess such inconsistency could be brought by some rare defect in reconnecting. Please keep updating when you see it again, thanks in advance.
|
|
I can consistently have this happen with 2.9.59_15_g107b2cb by running
ost-survey -s 10 /LUSTRE/
on a client.
On the system with OST0, I get:
[24348.020466] LustreError: 10346:0:(tgt_grant.c:733:tgt_grant_check()) lustre-OST0000: cli bafa5b19-f11b-9bfc-c44b-60ea94d9382d claims 4292608 GRANT, real grant 0
[24348.020475] LustreError: 10346:0:(tgt_grant.c:733:tgt_grant_check()) Skipped 2 previous similar messages
As I increase the size option, the number of skipped messages also increases.
|
|
Hey Niu,
The error messages are back for us too, after having performed OST failovers (might give some hint...). We're still on 2.9 though.
[2682214.198182] LustreError: 361698:0:(ofd_grant.c:641:ofd_grant_check()) oak-OST0003: cli bf793f06-a9f4-4e4a-85c9-79e10ac88ed7 claims 32768 GRANT, real grant 0
[2682214.214014] LustreError: 361698:0:(ofd_grant.c:641:ofd_grant_check()) Skipped 1647 previous similar messages
[2682817.076669] LustreError: 361674:0:(ofd_grant.c:641:ofd_grant_check()) oak-OST0003: cli bf793f06-a9f4-4e4a-85c9-79e10ac88ed7 claims 40960 GRANT, real grant 0
[2682817.092530] LustreError: 361674:0:(ofd_grant.c:641:ofd_grant_check()) Skipped 748 previous similar messages
[2683417.826667] LustreError: 361684:0:(ofd_grant.c:641:ofd_grant_check()) oak-OST0011: cli 7b5cc9f0-1221-60e2-0871-2105cd878e21 claims 32768 GRANT, real grant 0
[2683417.842515] LustreError: 361684:0:(ofd_grant.c:641:ofd_grant_check()) Skipped 760 previous similar messages
[2684036.203234] LustreError: 156433:0:(ofd_grant.c:641:ofd_grant_check()) oak-OST0011: cli 875f290d-d0a2-a84a-c1f4-05a972b31461 claims 847872 GRANT, real grant 0
[2684036.219161] LustreError: 156433:0:(ofd_grant.c:641:ofd_grant_check()) Skipped 736 previous similar messages
[2684646.921608] LustreError: 156521:0:(ofd_grant.c:641:ofd_grant_check()) oak-OST0025: cli 0e6972c3-d679-e536-aa5f-ceff2d42a2c4 claims 28672 GRANT, real grant 0
[2684646.937477] LustreError: 156521:0:(ofd_grant.c:641:ofd_grant_check()) Skipped 917 previous similar messages
|
|
Faced with this error message on one of the systems
claims 4218880 GRANT, real grant 0
Do you have an idea where to move investigating this issue?
There are other credits-related messages in logs
kernel: LustreError: 28855:0:(ofd_grant.c:358:ofd_grant_space_left()) ... left 2232417341440 < tot_grant 2232417341504 unstable 0 pending 0 dirty 29528064
|
|
Mike
Can you please advise?
Peter
|
|
We are also seeing this issue on v2_10_2 servers with v2_7_21 client.
[Fri Mar 2 23:12:13 2018] LustreError: 15798:0:(tgt_grant.c:733:tgt_grant_check()) gdata1b-OST0029: cli 6e512e04-c8a3-bdcc-f61e-bb0e3977633d claims 4849664 GRANT, real grant 0
[Fri Mar 2 23:12:13 2018] LustreError: 15798:0:(tgt_grant.c:733:tgt_grant_check()) Skipped 834 previous similar messages
[Fri Mar 2 23:22:18 2018] LustreError: 28124:0:(tgt_grant.c:733:tgt_grant_check()) gdata1b-OST0029: cli 6e512e04-c8a3-bdcc-f61e-bb0e3977633d claims 1703936 GRANT, real grant 0
[Fri Mar 2 23:22:18 2018] LustreError: 28124:0:(tgt_grant.c:733:tgt_grant_check()) Skipped 1150 previous similar messages
[Fri Mar 2 23:32:18 2018] LustreError: 28124:0:(tgt_grant.c:733:tgt_grant_check()) gdata1b-OST0029: cli 6e512e04-c8a3-bdcc-f61e-bb0e3977633d claims 5505024 GRANT, real grant 0
[Fri Mar 2 23:32:18 2018] LustreError: 28124:0:(tgt_grant.c:733:tgt_grant_check()) Skipped 1136 previous similar messages
Can we also get this looked at?
We are downgrading the client to our stable 2.5 build so we no longer have exp_grant_param_supp flag and fall back to the other behaviour of simply expanding the grant to match.
This is a workaround but it looks like the client is having its data dropped:
[Sat Mar 03 00:32:42 2018] LustreError: 11-0: gdata1b-OST000c-osc-ffff8807f41f1c00: operation ost_write to node 10.112.1.53@o2ib8 failed: rc = -107
[Sat Mar 03 00:32:42 2018] Lustre: 4848:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13300:0x0]// may get corrupted (rc -108)
[Sat Mar 03 00:32:42 2018] Lustre: 4844:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13d2a:0x0]// may get corrupted (rc -108)
[Sat Mar 03 00:32:42 2018] Lustre: 4842:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13598:0x0]/ may get corrupted (rc -108)
[Sat Mar 03 00:32:42 2018] Lustre: 4843:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13291:0x0]/ may get corrupted (rc -108)
[Sat Mar 03 00:32:42 2018] Lustre: 4854:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13cfb:0x0]/ may get corrupted (rc -108)
[Sat Mar 03 00:32:43 2018] Lustre: 4840:0:(llite_lib.c:2818:ll_dirty_page_discard_warn()) gdata1b: dirty page discard: 10.112.1.41@o2ib8:10.112.1.42@o2ib8:/gdata1b/fj7/fid: [0x2400101ea:0x13cfa:0x0]// may get corrupted (rc -108)
|
|
I'm seeing this while testing on our ARM system running 2.11 and 2.11 servers on x86 boxes.
|
|
I'm now seeing this with v2_10_2 servers and v2_5_43 client.
Interestingly I have the same client on other nodes who aren't seeing the issue. Could this be MOFED related? It's one of the few differences between the nodes.
|
|
I'm not sure whether or not the grant messages and the disconnect (that's what -107 is) are related or not. I'm curious, has anyone explored a possible connection to LU-10776
Basically, the client (with or without OBD_GRANT_PARAM, it's a long story) has several grant bugs where it can ask for more than it is allowed or the grant calculation can overflow the 32 bit integer used to store it, resulting in weirdly small grant #s showing up at various points. That patch should resolve all of them in a slightly brute force manner by fixing the arithmetic and capping the resultant request at 2 GiB - some margin.
If the problem is relatively easy to reproduce, it would be very interesting to see the effect of that patch on the clients. (Note that patch doesn't change anything on the server - It modifies a server-side file, but only to replace a numeric constant with a #define. No behavioral change to the server code.)
It would also be interesting if that patch resolved the grant message but the disconnects and lost data continued. (In fact, that's sort of what I would expect to happen if I'm right.)
|
|
I had a look at LU-10776. We are using 1MB RPC's and only 8 in flight RPC's. So I'm not sure if that is related.
However I do think there is value in testing this patch.
|
|
We hit similar trouble on BGI site, server is 2.10.2, client is 2.7.19.10:
00002000:00020000:9.0:1526810613.427919:0:16020:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 4849664 GRANT, real grant 0
00002000:00020000:10.0:1526810619.171036:0:16033:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 917504 GRANT, real grant 0
00002000:00020000:0.0:1526810624.176488:0:16007:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 917504 GRANT, real grant 0
00002000:00020000:6.0:1526810648.251551:0:16035:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 4849664 GRANT, real grant 0
00002000:00020000:11.0:1526810649.207223:0:16007:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 786432 GRANT, real grant 0
00002000:00020000:11.0:1526810649.655100:0:16035:0:(tgt_grant.c:733:tgt_grant_check()) zfsz2-OST0009: cli ab95b9a6-6564-3cd9-cdc8-75af4a40f6b9 claims 4849664 GRANT, real grant 0
|
|
I still don't know if these messages have a bad effect but they appeared again for us on a full 2.12.0 config (servers and clients) yesterday (on March 23, 20:11:59) and this is still ongoing.
I checked and this is only on one OST with a single client uuid:
client is sh-01-31, in production, quiet / no kernel logs at all (since Mar 23 02:52:28). On this node, I have found only one job and so a single user that is accessing the filesystem at the moment, and his quota values seem ok, I guess...
|
|
Is this still valid? A solution landed to 2.12.
|
|
"Vladimir Saveliev <vlaidimir.saveliev@hpe.com>" uploaded a new patch: https://review.whamcloud.com/45371
Subject: LU-9704 grant: ignore grant info on read resend
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 18332a73752be688e69ead3e8d5ac8edb7d45c82
|
|
The following scenario makes a message like "claims 28672 GRANT, real
grant 0" to appear:
1. client owns X grants and run rpcs to shrink part of those
2. server fails over so that the shrink rpc is to be resent.
3. on the clinet reconnect server and client sync on initial amount
of grants for the client.
4. shrink rpc is resend, if server disk space is enough, shrink does
not happen and the client adds amount of grants it was going to
shrink to its newly initial amount of grants. Now, client thinks that
it owns more grants than it does from server points of view.
5. the client consumes grants and sends rpcs to server. Server avoids
allocating new grants for the client if the current amount of grant
is big enough:
static long tgt_grant_alloc(struct obd_export *exp, u64 curgrant,
...
if (curgrant >= want || curgrant >= ted->ted_grant + chunk)
RETURN(0);
6. client continues grants consuming which eventually leads to
complains like "claims 28672 GRANT, real grant 0".
|
|
"Mike Pershin <mpershin@whamcloud.com>" uploaded a new patch: https://review.whamcloud.com/45474
Subject: LU-9704 grant: ignore grant info on read resend
Project: fs/lustre-release
Branch: b2_12
Current Patch Set: 1
Commit: 4162f0d61b762f70e5eb6d099291fad9f836de9d
|
|
"Oleg Drokin <green@whamcloud.com>" merged in patch https://review.whamcloud.com/45474/
Subject: LU-9704 grant: ignore grant info on read resend
Project: fs/lustre-release
Branch: b2_12
Current Patch Set:
Commit: e1d132acf58c3e6a90a527a0a09cdd0fff7fc392
|
|
"Oleg Drokin <green@whamcloud.com>" merged in patch https://review.whamcloud.com/45371/
Subject: LU-9704 grant: ignore grant info on read resend
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 38c78ac2e390b30106f3e185d8c4d92b8cb19c2b
|
|
Landed for 2.15
|
Generated at Sat Feb 10 02:28:30 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.
dbg_lquota_oak-io1-s1.log.gz
oak_dbg_2_oak-io1-s1.log
oak_ofd_grant_check_splunk.png