|
Hello Stephane,
I ham presently having a look to the crash-dump you have provided for this issue, and seems to me that you face a very tricky dead-lock situation involving MD driver's management/sync, sysfs, lustre-quota routines and lu_cache_shrink().
I m presently trying to better detail this scenario
|
|
Hi Bruno!
Thanks much for taking a look at this! Let me know if I can help somehow or if you need more information... we do have several scripts periodically checking sysfs entries, mdraid status, etc. on the servers, but these have always been there. We think a change in 2.10.3 has triggered this situation. We have downgraded to 2.10.2 and I'll update this ticket of course if this problem happens again, but so far the rest of the weekend (in 2.10.2) has been stable.
|
|
Bruno,
After your comment, I can see indeed that kswapd0 is in qsd_op_adjust() from lu_cache_shrink() and has a lock on lu_sites_guard, blocking any other lu_cache_shrink().
Meanwhile I checked what could be the possible differences between 2.10.2 and 2.10.3, and I noticed something weird in one patch modifying osd-ldiskfs/osd_quota.c:
LU-7991
On master, this landed as a046e879fcadd601c9a19fd906f82ecbd2d4efd5
On 2.10 LTS, this landed as c5d4599cc56729281ce6d4fc59d17694c84333c8
diff --git a/lustre/osd-ldiskfs/osd_quota.c b/lustre/osd-ldiskfs/osd_quota.c
index 2345501..2ff5770 100644
--- a/lustre/osd-ldiskfs/osd_quota.c
+++ b/lustre/osd-ldiskfs/osd_quota.c
@@ -625,8 +625,8 @@ int osd_declare_inode_qid(const struct lu_env *env, qid_t uid, qid_t gid,
{
struct osd_thread_info *info = osd_oti_get(env);
struct lquota_id_info *qi = &info->oti_qi;
- int rcu, rcg, rcp;
- int force = osd_qid_declare_flags & OSD_QID_FORCE;
+ int rcu, rcg, rcp = 0;
+ bool force = !!(osd_qid_declare_flags & OSD_QID_FORCE);
ENTRY;
@@ -655,24 +655,20 @@ int osd_declare_inode_qid(const struct lu_env *env, qid_t uid, qid_t gid,
if (force && (rcg == -EDQUOT || rcg == -EINPROGRESS))
rcg = 0;
+
+#ifdef HAVE_PROJECT_QUOTA
if (rcg && (rcg != -EDQUOT || flags == NULL))
RETURN(rcg);
- qi->lqi_id.qid_gid = projid;
- qi->lqi_type = PRJQUOTA;
+ qi->lqi_id.qid_projid = projid;
+ qi->lqi_type = PRJQUOTA;
rcp = osd_declare_qid(env, oh, qi, obj, true, flags);
if (force && (rcp == -EDQUOT || rcp == -EINPROGRESS))
rcp = 0;
+#endif
- if (rcu)
- RETURN(rcu);
- if (rcg)
- RETURN(rcg);
- if (rcp)
- RETURN(rcp);
-
- RETURN(0);
+ RETURN(rcu ? rcu : (rcg ? rcg : rcp));
}
The added "#ifdef HAVE_PROJECT_QUOTA" doesn't seem at the right place to me. And if you check the very first versions of this patch, it seemed to be at the right place:
https://review.whamcloud.com/#/c/27093/1..40/lustre/osd-ldiskfs/osd_quota.c
Do you think this could be related? We're using group quotas, and I didn't enable project quota in our 2.10.3, so maybe the following lines were simply removed at compile time, leading to a wrong behavior?
if (rcg && (rcg != -EDQUOT || flags == NULL))
RETURN(rcg);
Sorry if I am off-topic, but I wanted to tell you just in case, we never know...
Thanks!
|
|
Well, according to my current crash-dump analysis results (details to come in a next comment) I don't think this could be related.
But I have an other question in mind, when you speak about down/up-grading your Lustre version, do you rebuild for the same Kernel or do you also change it following the latest version that is reported in Lustre ChangeLog ?
|
|
Here is the detail of my analysis concerning the deadlock scenario.
sas_counters/35683 owns sysfs_mutex and waits for lu_sites_guard after it has triggered memory reclaim :
kswapd0 owns lu_sites_guard and waits for &dqopt->dqio_mutex :
ll_ost_io00_018 owns &dqopt->dqio_mutex and waits for BH_Lock to be cleared in buffer_head at 0xffff8811e3343380 for journal on device /dev/md18 (/mnt/oak/ost/66) :
MD driver service threads associated with “md18” are mainly stuck waiting on sysfs_mutex to complete RAID device check/recovery operations :
and there a lot of threads hung in MD driver awaiting for md18 service threads to complete their current work in order to start write operations with very similar stacks than the 2 following :
A lot of these threads are hung since about 11000s, the impacted MD/Raid device/OST is "md18" (/mnt/oak/ost/66), and has it appears that the check/recovery operations have been started thru some admin commands or a programmed procedure (instead of due to some error handling) for all devices/OSTs, "md18" is the only that never reported “md: md18: data-check done“ msg like all others did.
At the moment, I have still not been able to prove that the BH_Lock'ed buffer_head causing thread ll_ost_io00_018/251676 to be hung, is also caused by MD/Raid operations being stuck waiting for last superblock update step upon end of check.
But we seems to end-up with a very complex and unlikely scenario that requires concurrent MD/Raid OSTs/devices (with running check/recovery), Lustre-quotas on, memory-reclaim to be triggered with lu_cache_shrink shrinker run requiring quota update upon object purge/delete, and a User process to read stuff from /sysfs.
|
|
Hi Bruno,
Wow. Great analysis! That looks like a complex issue indeed, doh! Thanks!
But I have an other question in mind, when you speak about down/up-grading your Lustre version, do you rebuild for the same Kernel or do you also change it following the latest version that is reported in Lustre ChangeLog ?
I did rebuild Lustre for the same Kernel. We're running 3.10.0-693.2.2.el7_lustre.pl1.x86_64 since the beginning of October 2017. This kernel is based on 3.10.0-693.2.2.el7.x86_64 with lustre patches + one mdraid patch (see --LU-8917
This Kernel itself with Lustre 2.10.x has worked great since October. We had several Lustre issues with 2.10.0 and 2.10.1 (eg. nodemap), but most of them have been fixed in 2.10.2.
(...) it appears that the check/recovery operations have been started thru some admin commands or a programmed procedure (instead of due to some error handling) for all devices/OSTs, "md18" is the only that never reported “md: md18: data-check done“ msg like all others did.
Exactly, we're using mdadm's raid-check cron script, which starts a batch of md checks every Sunday, and then usually the second batch starts on next Wednesday, which was the case for md18. So you are correct, it's started by a programmed procedure, but this is normal and not something new on this system.
But we seems to end-up with a very complex and unlikely scenario that requires concurrent MD/Raid OSTs/devices (with running check/recovery), Lustre-quotas on, memory-reclaim to be triggered with lu_cache_shrink shrinker run requiring quota update upon object purge/delete, and a User process to read stuff from /sysfs.
Well doesn't look like so unlikely to us!  And I do have several other crash dumps, all of them when running Lustre 2.10.3 in February. I quickly checked at least four of them, and the stack traces look very similar (a lot of threads look blocked in the same way). Maybe the following crash dumps could help find the root cause:
oak-io1-s1 2018-02-19-13:54:27
https://stanford.box.com/s/ggaau7vdzrz3ziaob7nsmdlvxtpvnun2
oak-io1-s1-vmcore-2018-02-19-13:54:27.gz
oak-io2-s2 2018-02-21-11:10:27
https://stanford.box.com/s/bm7kgo5vndy6wylmnmo24qx26d377wge
vmcore-oak-io2-s2-2018-02-21-11-10-27.gz
And it occurred on different I/O cells (oak-io1 and oak-io2, different hardware), so probably not related to a single md issue.
One thing I changed on this system is vm.zone_reclaim_mode from 1 to 0 on all OSS on February 8 (we were already in 2.10.3). Don't know if that can lead to this kind of scenario, and if it does, I should see the same issue on 2.10.2 soon...
Thanks again!
Stephane
|
|
Having a look in Kernel source code to understand the impact of setting vm.zone_reclaim_mode=0, it looks like that, regarding to the deadlock scenario I have described before and the different pieces of code being involved, this will allow to run the memory allocation slow-path, and thus to run the shrinkers, much more frequently. Instead, with vm.zone_reclaim_mode=1, should allow to get new pages from the current/preferred node+zone (where it seems there plenty, at least at the time of the crash-dump).
What is the reason you have decided to change this parameter?
On the other hand, I have analyzed the 2 others crash-dumps you have provided :
_ oak-io1-s1-vmcore-2018-02-19-13:54:27.gz, it looks like it has been truncated because exits due to a read-error for a virtual-address of type "pglist node_id".
_ vmcore-oak-io2-s2-2018-02-21-11-10-27.gz, shows about the same dead-lock situation, with one less thread being involved, as it has been able to itself grab 2 of the locks/mutexes, but the overall scenario is the same with thread sas_counters holding the sysfs_mutex and then to block for memory_reclaim (either on lu_sites_guard trying to execute lu_cache_shrink(), or on dqio_mutex during lu_cache_shrink() execution), and the other thread owning dqio_mutex being stuck waiting for a buffer_head to be unlock'ed after I/O completion on an OST/MD-Raid device where this will never happen due to associated service threads waiting on sysfs_mutex.
So could you try to run with vm.zone_reclaim_mode=1 and/or without sas_counters ?
|
|
Hi Bruno,
Thanks, this is super helpful!!!
> What is the reason you have decided to change this parameter?
Changing zone_reclaim_mode to 0 wasn't specifically done for an issue on the OSS, but more for the MDS, as recommended by Andreas in LU-5841LU-9196.
My current plan is to stay a bit with 2.10.2 and zone_reclaim_mode=0. It has been working smoothly since last Saturday. I would like to see the same issue happening in 2.10.2, just to confirm it is not related to a change in 2.10.3. If/when the issue occurs, I'll upgrade to 2.10.3 and switch zone_reclaim_mode back to 1 on all OSS.
sas_counters is really useful to us, as it monitors the large sas fabric for any errors. It "just" periodically checks sysfs entries (I wrote it  ). We have it running since a while now and it's not related to Lustre (but I understand it is triggering memory reclaim). If needed, I could reduce the frequency of the checks.
Again, thanks much for your time!
|
|
Hi Bruno,
We found an OSS unresponsive this morning (running 2.10.2 and zone_reclaim_mode=0). I believe the problem is the same, although I am not able to open the crash dump (still, it should be complete):
crash: invalid structure size: tnt
FILE: kernel.c LINE: 10220 FUNCTION: show_kernel_taints()
[/usr/bin/crash] error trace: 4e45f5 => 4d6c04 => 4d33cc => 52ab62
52ab62: SIZE_verify+130
4d33cc: (undetermined)
4d6c04: (undetermined)
4e45f5: display_sys_stats+2213
I'm attaching the vmcore-dmesg.txt as oak-io1-s2-2018-03-05-09-33-02_vmcore-dmesg.txt, which shows some lustre stack traces that look (somehow) similar to the ones seen in 2.10.3.
I'll first switch zone_reclaim_mode to 1 on all OSS, and when possible I'll upgrade Lustre to 2.10.3 again.
|
|
Hey Bruno,
In your opinion, do you think it's more a md issue or a Lustre issue? I see two possible arguments here:
- (Lustre's fault) Do we really want that Lustre's memory reclaim code path performs locking on lu_sites_guard? which then can trigger I/Os that may try to acquire sysfs_mutex like md does?
- (md's fault) I/O can be performed within the context of sysfs (eg. memory reclaim) so MD service threads shouldn't try to acquire sysfs_mutex (eg. through sysfs_notify)?
Last question, do you think this deadlock could be related to the recent procfs to sysfs migration in Lustre? I have no memory of such deadlock in 2.9 for example.
|
|
Hi Bruno,
Just got another occurrence on the failover partner that took over the OSTs after the first issue. This time the crash dump is valid, I was able to open it, so in case you want to double check:
Note: oak-io1-s1 was running Lustre 2.10.2 and vm.zone_reclaim_mode=1 (but changed to 1 on the fly, not 1 since boot time).
|
|
Hello Stephane,
Yes, the stacks in oak-io1-s2-2018-03-05-09-33-02_vmcore-dmesg.txt clearly indicate that this is the same problem/dead-lock.
I am still working/thinking to find the main reason of the deadlock, but at the moment I guess that it could be fixed if the memory reclaim, that occurs when sas_counters owns sysfs_mutex (due to gathering its stats from there I presume), could be done by avoiding file-system operations (!GFP_FS) and thus can't block anymore to release mutex and let MD operations able to continue.
BTW, I think that MD layer may need some improvement to become less dependent on sysfs.
I will have a look on this new crash-dump.
|
|
Stephane,
I am presently unable to download this last crash-dump directly to one of our internal system where I am usually using lynx to do so. Seems that using google drive is much more complex than previous stanford repository. Can you use this same/previous way for it too ?
|
|
Hey Bruno,
Yeah, the last one is about 29GB and that is too big for Box (which has a file size limit of 15GB). Hmm, I could split it in two, which should work with Box (but won't be until tomorrow).
|
|
Hello Bruno,
Please find the last (and big) crash dump below, in two parts:
MD5 (vmcore_oak-io1-s1-2018-03-05-14_06_57.1) = 60c66a81c9acc1675a41722d6016efcc
https://stanford.box.com/s/nsdwy6bind6l48spesjg76uv2tb9jmrp
MD5 (vmcore_oak-io1-s1-2018-03-05-14_06_57.2) = a17323c3afbdf8fc970d430c35ac864c
https://stanford.box.com/s/3idy1mv956cf0l1a9dj6c9otulmtmnd4
Simply use cat to aggregate the parts:
you should get:
MD5 (vmcore_oak-io1-s1-2018-03-05-14_06_57) = 14752f1c982d5011c0375fcca8c3ebbe
Thanks!!
|
|
Got it! Thanks and sorry for the extra work.
This crash-dump shows almost the same scenario, with the little difference that with zone_reclaim=1 direct reclaim will occur as later as possible, but it will finally be under memory high pressure with the shrinkers being run then :
So, I think that at the moment if you want to prevent this problem to happen again, you will need to remove one of the involved actor/feature, i.e. either sas_counters, or MD devices regular check/sync, or Lustre quotas.
And on the other hand, I wonder if the final solution could not be to have a new sysfs_alloc_inode() method be available in "struct super_operations sysfs_ops", where the kmem_cache_alloc() will occur with GFP_NOFS, this to avoid fair shrinkers testing it (like in lu_cache_shrink() !!) to do their job.
I wonder if you would be ok to test this as it will be a Kernel patch??
|
|
Thanks Bruno! Does that mean that the MD layer would then have to use this new sysfs_alloc_inode() method? Or everyone?
But yes, we'd be very interested to test such a patch!
|
|
> Does that mean that the MD layer would then have to use this new sysfs_alloc_inode() method? Or everyone?
Everyone. BTW, in the deadlock scenario, this is sas_counters user-land thread that triggers the memory reclaim during sysfs inode allocation.
> But yes, we'd be very interested to test such a patch!
Attached sysfs_alloc_inode_GFP_NOFS.patch file.
sysfs_alloc_inode_GFP_NOFS.patch
|
|
OK. Excellent, thank you!! I just built a new kernel with this patch. No kernel update, just the same as before plus this patch added (new version is kernel-3.10.0-693.2.2.el7_lustre.pl2.x86_64). I'll perform the kernel change on all Oak servers tomorrow early morning (Pacific time), when fewer users are connected to the system and report back.
|
|
Hey Bruno,
Quick status update.. patch was deployed last Sunday morning (3/18) only due to production constraints before. sas_counters is running quite frequently again and I started the mdraid checks manually (because usually they start on Saturday night). So far, no issue to report, looking good, but we need more time to be sure (at least a week). Will keep you posted!
|
|
Stephane, thanks for the update, and let's cross the fingers now...
|
|
Hi Bruno,
The system has been very stable lately with the patch. I think we can consider the issue fixed by next week (just to be sure ).
Few questions for you when you have time (no rush):
- do you plan to submit the sysfs patch upstream to Red Hat?
- do you want to notify linux-raid about this sysfs race condition (or do you want me to do it?)
- do you think this issue is automatically fixed when using more recent 4.x kernels because the sysfs interface has changed?
Thanks!!
Stephane
|
|
Stephane,
Thanks for your help and patch testing!
Will do soon for both sysfs patch submission and reporting to linux-raid.
Will double-check for 4.x kernels and give you an answer soon.
|
|
Bruno,
Great, I'll follow that with much attention. Thank you again, your patch has really saved us.
Stephane
|
|
Hello Stephane,
Following your previous requests for external reporting of this problem/bug :
_ I have created a bug report at kernel.org, https://bugzilla.kernel.org/show_bug.cgi?id=199589.
_ I have also asked MD-Raid maintainers their feeling thru an email to linux-raid@vger.kernel.org, using the title "Deadlock during memory reclaim path involving sysfs and MD-Raid layers".
Last, recent 4.x Kernels code seems to indicate that problem is still there, but now in kernfs instead of sysfs, as the latter uses the former's methods internally but where the same potential dead-lock seems to exist around kernfs_mutex .
|
|
Hey Bruno,
Great, thanks! It would definitely be nice to get some feedback from the kernel developers and/or have this patch integrated upstream.
Our Oak system has been rock solid since this patch. Right now ~45 days uptime without any server crash, and the filesystem is still very busy, and mdraid checks are running almost all the time with sas_counters launched every minute on all OSS
Note: I can't find your email to linux-raid@, maybe it didn't go through?
Thanks!
Stephane
|
|
We upgraded our Kernel on Oak from CentOS 7.4-patched-by-Bruno to CentOS 7.6 (3.10.0-957.27.2.el7.x86_64 + Lustre patches = 3.10.0-957.27.2.el7_lustre.pl1.x86_64). After one or two days, a similar deadlock occurred. It looks like the kernfs interface still has the same issue.
- vmcore uploaded to the WC ftp server as vmcore-oak-io1-s1-2019-09-01-21-43-46
- kernel-debuginfo available there too for 3.10.0-957.27.2.el7_lustre.pl1.x86_64
- foreach bt attached as foreach_bt-oak-io1-s1-2019-09-01-21-43-46.log
I know this is a kernel bug but I wanted to update this ticket for the sake of completeness, and the deadlock is somehow triggered by Lustre through lu_cache_shrink.
User tool accessing the kernfs interface and triggering lu_cache_shrink:
mdraid task blocked on kernfs too:
The original kernel report (https://bugzilla.kernel.org/show_bug.cgi?id=199589) has been dismissed and I'm not sure this was reported to Red Hat actually.
|
|
This deadlock is still not fixed upstream, and we hit the same issue with CentOS 7.6. We have opened a new case at Red Hat (case 02514526) but my expectation is low. Meanwhile, I've ported Bruno's kernel patch from sysfs to the newer kernfs interface (it's very similar - unless I missed something). We have it on two updated OSS on Oak right now and it seems to work fine.
As a reminder, the problem is complex but solved by allocating sysfs/kernfs inodes using GFP_NOFS so that they don't trigger lu_cache_shrink() while holding a sysfs/kernfs inode lock. I'm not sure where to draw the line, ie. if it's a kernel or a lustre bug at this point.
|
|
I've attached foreach_bt_oak-io4-s1.log just in case someone wants to take a look at a newer trace. This was without Bruno's patch running CentOS 7.6.
In my understanding, this task is part of the deadlock:
As Bruno explained before, ( retranscribed in my less good understanding here), this involves an external tool accessing sysfs/kernfs like the task above (although I've seen systemd accessing it too), under memory pressure -> zone_reclaim -> shrink_slab -> flush I/O due to quotas I guess -> I/O deadlock mdraid because of md_check_recovery() running and accessing kernfs:
|
Generated at Sat Feb 10 02:37:30 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.
foreach_bt-oak-io1-s1-2019-09-01-21-43-46.log
oak_io2-s1_foreach_bt.xt