|
Given that the system is back operational, I don't have any specific thoughts on this one, but I wanted to point out that at least the log in the highlighted error message is a DOM lock:
|
|
Mike is investigating
|
|
The filesystem has worked okay all night, load on MDS was < 1 most of the time but this morning the issue is starting again and Fir just became unavailable, ls hangs on all clients.
Attaching recent syslog fir-md1-s1-20190213.log
Stephane
|
|
Some more MDS logs:
|
|
MDS completely hung. It looks like this task ldlm_bl_04 is stuck (100% cpu):
|
|
More info from sysrq trigger:
|
|
Stephane,
Let's get those MDT lock stats:
|
|
We started to fail over MDT0002 to the other server fir-md1-s2, it is currently in progress. But this is the output:
|
|
Could you also turn on some debug for just a moment, then disable it?
Then dump the logs.
That should tell us a lot about what the system is spinning on.
|
|
Hm. If you've got the sort of problem I suspect, which is "too many locks clogging up the machinery", failover may just kill your other MDT as it tries to bring them up.
We'll see!
|
|
Thanks Patrick! Attached fir-md1-s1-dk.log but please note that MDT0002 is still trying tu unmount:
syslog:
So not sure it'll be helpful. I think we'll dump and restart this MDS.
|
|
Ah, never mind. MDT2 stopped successfully on fir-md1-s1 and is now mounted on the failover partner fir-md1-s2.
Load on fir-md1-s1 has dropped and filesystem is back online. We'll see how it goes...
|
|
|
|
Interesting:
"00010000:00010000:5.0:1550079902.033681:0:22866:0:(ldlm_lock.c:197:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-fir-MDT0002_UUID lock: ffff9c9f27590240/0x6bcd99f6a7f88060 lrc: 0/0,0 mode: --/PR res: [0x2c00016d5:0x9c:0x0].0x0 bits 0x40/0x0 rrc: 265624 type: IBT flags: 0x44801400010020 nid: 10.9.105.71@o2ib4 remote: 0xf3592e10ff0a3e0d expref: 265633 pid: 20526 timeout: 62419 lvb_type: 0
00010000:00000040:5.0:1550079902.034443:0:22866:0:(ldlm_resource.c:1534:ldlm_resource_getref()) getref res: ffff9c9ceeeef8c0 count: 265623"
I wondered if we had something like this. There are 265 thousand locks on a single resource . That's going to gum up the works hugely whenever anything has to address that resource.
That's a DOM lock, too. Was every client and process in your system trying to read the same file? How many clients do you have?
|
|
At least in the DK log sample here, all the locks (only 526, but still) are from the same node.
I assume 10.9.105.71@o2ib4 is a client?
|
|
Yes, 10.9.105.71@o2ib4 is one of our Sherlock client (sh-105-71) and currently has multiple jobs running. We're investigating any time correlation. Is there a way to find the original file from the lock message above?
|
|
Yes - The resource ID should be the user visible FID, since it's the MDS:
[0x2c00016d5:0x9c:0x0]
|
|
Ok thanks! I tried that but unfortunately that returns "No such file or directory".
It looks like the lock count keeps increasing on MDT0002:
|
|
Let's take this to Skype (just in case you're not seeing that)
|
|
OK, I've found the proximate cause of lock accumulation. More to come.
There's one "normal" open lock (PR) with a DOM bit on the resource, and hundreds of thousands (literally) of DOM only PR locks.
We match the normal lock:
00010000:00010000:18.0:1550082656.372818:0:311279:0:(ldlm_lock.c:1476:ldlm_lock_match()) ### matched (0 0) ns: fir-MDT0002-mdc-ffff9bcb944b9000 lock: ffff9bc299f1a400/0x318ede82da06317f lrc: 2/1,0 mode: PR/PR res: [0x2c0003c05:0xe11c:0x0].0x0 bits 0x53/0x0 rrc: 299247 type: IBT flags: 0x60000000000 nid: local remote: 0xfbab35471d1f08c6 expref: -99 pid: 311279 timeout: 0 lvb_type: 3
The KMS ignore bit is set on the "normal" MDC lock:
The other bit (the '2' in '4|2 == 6') is LVB_READY.
If kms_ignore is set, we do not match the DOM lock (mdc_enqueue_send) :
Then we request another lock, which is what's going on here. But because this open lock matches and is then rejected (rather than being rejected in the match code), we do not match the later locks, so we request one for every read.
I'll dig in a bit more, but I see a few potential fixes.
|
|
Mike,
Interesting use of kms_ignore in the DOM code.
It looks like it's used to say "the DOM bit has been cancelled". (It would be good to add a comment in the KMS_IGNORE definition reflecting this.)
So either we need to sort out why it got set with the DOM bit still present and make that not happen, or we should we move the "ldlm_is_kms_ignore" check in to ldlm_lock_match, so we look for another matching lock and don't keep adding locks like this.
Probably both!
If the direction we go is the "how did this get set like this" direction, here's a thought:
The equivalent osc code doesn't do this, and the LDLM lock is still reachable. So perhaps the MDC object was pruned but the lock wasn't... Not 100% sure that can happen.
|
|
Attachments are a -1 dk log snippet from the client generating the lock requests (sh-106-60.dk.log.gz) and a short MDS log with dlmtrace set (fir-md1-s2-dk.log) (From Sebastien)
|
|
Appreciated all the help so far. Quick update as things are getting worse and worse and /fir is is barely usable. Using sysrq to dump the tasks, we found many jobs on clients blocked on vfs calls (vfs_mkdir, vfs_unlink) and Lustre was constantly trying to reconnect to the MDT (either MDT 0 or MDT 2).
Lock count on MDT 0 and 2 were > 2 million and increasing.
I just restarted MDT 2 and hopefully clients have resumed I/O operations. Earlier today, we had disabled DOM on MDT 2 as a test, but it didn't help, but because the filesystem already has 163M files with a mdt stripe so I'm not sure it can help. It would be great to have a patch ASAP to fix this high lock count. Thanks!
|
|
After 34 minutes of uptime, MDT 2's lock_count is already at 1,732,474, doh.
|
|
Patrick Farrell (pfarrell@whamcloud.com) uploaded a new patch: https://review.whamcloud.com/34255
Subject: LU-11964 ldlm: Don't match kms_ignore DOM locks
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 0ebed6aac0e2dee45c4e7bba213416eefd73788a
|
|
Copied from email:
"Just working on what I hope will be a fix. In the meantime, you might be able to limp along (better than with MDT restarts) by running this periodically on clients:
Perhaps once a minute...? The basic problem is that you're getting one lock in a weird state, and then you stop trying to match existing locks, so each read creates a new lock. I suspect you could probably clean out that first lock and the subsequent ones, avoiding the accumulation. (The "weird" state appears to be relatively rare - though common enough to cause trouble - so I think this should work.)"
|
|
Recent patch is passing some simple testing locally, but hasn't been through our suite yet. I'm pretty confident it's sound, but if you can stand to wait, it would be nice to get it some test exposure and an opinion from Mike.
|
|
Hi Patrick,
I just tried lctl set_param ldlm.namespaces.fir-MDT0002-*.lru_size=clear on all clients and the lock count for MDT 2 went from 10 million to 1.6 million so I guess it's working partially, which is good.
I'm gonna do this until the patch is ready (I prefer to wait for the patch to pass the tests yes 
Thanks!
|
|
Running lru_size=clear on all clients every 2 minutes for all Fir's MDTs and the lock count has dropped!
|
|
Glad it's helping. Especially glad because the patch isn't right and I'm going to need Mike to take a look.
|
|
Stephane,
for now let's disable the 'dom_lock' parameter on MDT:
lctl set_param mdt.*.dom_lock=0
that disables DOM lock combining with other lock bits and switches to a simpler locking scheme for DOM files.
also you've mentioned that DOM was disabled on MDT2, how exactly that was done?
|
|
Hi Mike!
So with a 2-min recurrent lru_size=clear on all clients, this morning I found the lock counts like that (looking good!):
I stopped lru_size=clear and set dom_lock=0:
But then the lock count was still increasing. Now on MDT1 even more than MDT2! After ~5 minutes, we have:
Re: MDT2, it is correct that we tried to disable DOM yesterday by using:
However, shortly after that, we noticed that new files were still having a mdt stripe of 128K (as our default stripping is configured), and seeing no improvement in lock count, we decided to put it back to 128K (131072). So DOM is still enabled on all four MDTs.
I have re-enabled the recurrent lru_size=clear for now. Let me know what I can try next to help resolve this. Thanks.
|
|
Stephane, I am preparing quick patch for the problem noticed by Patrick, meanwhile could you say what does that client do? I see in logs there is quite big files with PFL layout and size about 400Gb, is that known what is going on there, i.e. access pattern? That would be helpful to know, so I can try to reproduce that locally and make sure patch will solve that
|
|
Ok, sounds good! We have more than 1,300 active clients on this cluster, so this is a tough question! We currently have 4,912 jobs running on Sherlock with all kinds of jobs (using small or large files). So I'm not sure where to start. If there is a way to list the NIDs of clients holding the most MDT locks, that would really be helpful for job correlation, but I'm not sure that's currently possible.
|
|
Stephane,
No way to do exactly that, but you could just look at total lock counts on the client side, and look for large #s.
|
|
Great!
See attached file sherlocks.txt. The top one is a login node, with many users logged in, but really not many files open in /fir (< 10) when I check with lsof. There are several file descriptors open on the same file (a shell script), maybe that's a hint. Also I've noticed a few python processes doing a lot of newfstatat even on the same file again and again but nothing super unusual.
|
|
Stephane, that can be exactly the case, could you check does file exist with FID [0x2c0003c05:0xe11c:0x0] and its name?
|
|
Yes, this FID does exist and is relatively large:
|
|
Stephane, could you please check if it is being used in any python scripts you've mentioned before? Or any other? If that is not difficult to find out.
|
|
Mike, I checked and this file is currently open on at least 9 different compute nodes, but not by a python program, but qcprog.exe_s (Qchem software http://www.q-chem.com/doc_for_web/readme_par.shtml) The program is doing a lot of read, fadvise and lseek:
|
|
Ah, actually fd 16 is not that file but another one.... Sorry.
|
|
Stephane, thanks a lot, I think I am able to reproduce that behavior with quite simple test. It shows growing lock count without patch and no lock count increase with patch. I will push that patch to the gerrit as soon as local tests will end.
|
|
That's great news, I'm so glad you were able to reproduce the issue locally. We can stay with the lru_size=clear workaround for the time being until the patch is ready.
|
|
Mike Pershin (mpershin@whamcloud.com) uploaded a new patch: https://review.whamcloud.com/34261
Subject: LU-11964 mdc: prevent glimpse lock count grow
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 2f98ba5cf94352be6028bd9ddf93fe1f5623b347
|
|
Quick update: we're still using the lru_size=clear workaround and the servers have been stable. However, it would be nice to try a patch at some point. It looks like the patch didn't pass the DOM tests yet? In any case, let me know when it is ready. Of course, patching clients takes a lot more of effort. Is the patch client + server?
Thanks again,
Stephane
|
|
Stephane,
Patch is just client, and it has passed Maloo testing (including DOM). I think it's ready to try.
|
|
Ah great! Thanks Patrick, we'll work on it.
|
|
We have started the deployment of clients with 2.12.0 + the patch above on Sherlock. It will take some time to get all nodes up to date (at least 2 weeks), but we'll progressively remove the lru_size=clear workaround on the updated nodes. Thanks!
|
|
At this point we have upgraded more than 1300 clients with the patch (more than 90% of the cluster) and I just tried to remove the 2-min lru_size=clear workaround on those.
At first the lock counters increased a lot but I think they have stabilized below 1M per MDT:
I'll confirm/update tomorrow.
|
|
As of tonight, the situation is stable, and we didn't have any new server crash (yay). So I guess the patch is definitively working. I can't thank you enough Patrick and Mike! The lock counters are still relatively high but there are ~6,300 jobs running at the moment and probably most of them using /fir so I assume this is normal:
|
|
That is good news Stephane. Is the LU-11964 patch the only one applied on top of the vanilla 2.12.0 - or is there anything else?
|
|
Hi Peter, yes definitively a very good news!
I have applied the following patch on top of 2.12.0 (and only on the clients), this should be https://review.whamcloud.com/#/c/34261/ Patch Set 3:
This is the only patch we use right now. We have also disabled the idling connection feature, see LU-11976. I think the combination of the patch + disabling the idling connection feature have made 2.12 stable for us.
Thanks!
|
|
Oleg Drokin (green@whamcloud.com) merged in patch https://review.whamcloud.com/34261/
Subject: LU-11964 mdc: prevent glimpse lock count grow
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: b915221b6d0f3457fd9dd202a9d14c5f8385bf47
|
|
Landed for 2.13
|
|
I noticed that this patch is not in b2_12 yet, but it should be added.
|
|
sthiell that's what the LTS12 label means
|
|
Whoops! Great! 
|
|
Minh Diep (mdiep@whamcloud.com) uploaded a new patch: https://review.whamcloud.com/34504
Subject: LU-11964 mdc: prevent glimpse lock count grow
Project: fs/lustre-release
Branch: b2_12
Current Patch Set: 1
Commit: 6422dc451867239cb97a6ab864498077220dcbbb
|
|
Oleg Drokin (green@whamcloud.com) merged in patch https://review.whamcloud.com/34504/
Subject: LU-11964 mdc: prevent glimpse lock count grow
Project: fs/lustre-release
Branch: b2_12
Current Patch Set:
Commit: 82dad29511b32c844c849ac4ec3ec0214077f125
|
|
(Incorrect ticket, comment removed...)
|
Generated at Sat Feb 10 02:48:28 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.
fir-md1-s1-20190213.log
fir-md1-s1.syslog-20190212.log.gz