<div dir="ltr"><br><br><div class="gmail_quote"><div dir="ltr">On Thu, Nov 15, 2018 at 11:57 PM Naruto Nguyen <<a href="mailto:narutonguyen2018@gmail.com">narutonguyen2018@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi everyone,<br>
<br>
Recently when I upgrade my kernel from 3.12.61 to kernel 4.4.74, I<br></blockquote><div><br></div><div>Hi.</div><div><br></div><div>You need to upgrade, either using 4.19.2, 4.18.2, or 4.4.163 (if you prefer to stay with 4.4.x) and see if it still happens</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
find my system sometimes is very slow and unresponsive<br>
<br>
When my system is under a heavy IO load, I see the node start to<br>
respond very slow, the IO wait time keeps very high, and the node<br>
starts unresponsive. I try to dump all block task at that time and<br>
found some interesting things, look like under a heavy load I/O, the<br>
kswap start to hang in jbd2_log_wait_commit.<br>
<br>
Sep 07 12:25:35 myPC kernel: [11039.126514] kswapd0 D<br>
0000000000000000 0 26 2 0x00000000<br>
Sep 07 12:25:35 myPC kernel: [11039.126517] ffff88003da27b78<br>
ffff88000ce08280 ffff88003cdf0680 ffff88003da28000<br>
Sep 07 12:25:35 myPC kernel: [11039.126519] ffff88001a15c888<br>
ffff88001a15c824 ffff88003da27bb8 ffff88001a15c8a0<br>
Sep 07 12:25:35 myPC kernel: [11039.126521] ffff88003da27b90<br>
ffffffff815e4c85 ffff88001a15c800 0000000000013183<br>
Sep 07 12:25:35 myPC kernel: [11039.126522] Call Trace:<br>
Sep 07 12:25:35 myPC kernel: [11039.126539] [<ffffffff815e4c85>]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.126561] [<ffffffffa02faada>]<br>
jbd2_log_wait_commit+0x8a/0xf0 [jbd2]<br>
Sep 07 12:25:35 myPC kernel: [11039.126621] [<ffffffffa03b28a4>]<br>
ext4_evict_inode+0x2d4/0x4b0 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.126630] [<ffffffff81215a7a>]<br>
evict+0xba/0x190<br>
Sep 07 12:25:35 myPC kernel: [11039.126635] [<ffffffff81215b82>]<br>
dispose_list+0x32/0x50<br>
Sep 07 12:25:35 myPC kernel: [11039.126639] [<ffffffff81216e52>]<br>
prune_icache_sb+0x42/0x50<br>
Sep 07 12:25:35 myPC kernel: [11039.126644] [<ffffffff811ff8f6>]<br>
super_cache_scan+0x136/0x180<br>
Sep 07 12:25:35 myPC kernel: [11039.126653] [<ffffffff81196a1b>]<br>
shrink_slab.part.41+0x20b/0x3f0<br>
Sep 07 12:25:35 myPC kernel: [11039.126521] ffff88003da27b90<br>
ffffffff815e4c85 ffff88001a15c800 0000000000013183<br>
<br>
And after that more and more processes are hitting STAT D, nfsd is<br>
hang to wait or the inode deletion to complete in<br>
__wait_on_freeing_inode.<br>
<br>
Sep 07 12:25:35 myPC kernel: [11039.390218] nfsd D<br>
0000000000000000 0 30419 2 0x00000080<br>
Sep 07 12:25:35 myPC kernel: [11039.390221] ffff88000da47a98<br>
ffff8800277ec380 ffff8800374ec580 ffff88000da48000<br>
Sep 07 12:25:35 myPC kernel: [11039.390223] ffff88000da47ad8<br>
ffffc9000011edc8 0000000000000000 ffff88000e92e2f8<br>
Sep 07 12:25:35 myPC kernel: [11039.390225] ffff88000da47ab0<br>
ffffffff815e4c85 ffffffff81c094c0 ffff88003ff9d8b8<br>
Sep 07 12:25:35 myPC kernel: [11039.390225] Call Trace:<br>
Sep 07 12:25:35 myPC kernel: [11039.390231] [<ffffffff815e4c85>]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.390236] [<ffffffff812157fc>]<br>
__wait_on_freeing_inode+0x9c/0xc0<br>
Sep 07 12:25:35 myPC kernel: [11039.390241] [<ffffffff81215d83>]<br>
find_inode_fast+0x73/0xa0<br>
Sep 07 12:25:35 myPC kernel: [11039.390245] [<ffffffff81216052>]<br>
iget_locked+0x72/0x190<br>
Sep 07 12:25:35 myPC kernel: [11039.390284] [<ffffffffa03aeb8c>]<br>
ext4_iget+0x2c/0xb10 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.390314] [<ffffffffa03c1055>]<br>
ext4_nfs_get_inode+0x45/0x80 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.390320] [<ffffffff812211c4>]<br>
generic_fh_to_dentry+0x24/0x30<br>
Sep 07 12:25:35 myPC kernel: [11039.390326] [<ffffffff81277ede>]<br>
exportfs_decode_fh+0x5e/0x350<br>
Sep 07 12:25:35 myPC kernel: [11039.390347] [<ffffffffa047749a>]<br>
fh_verify+0x2da/0x5a0 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390362] [<ffffffffa0480933>]<br>
nfsd3_proc_getattr+0x63/0xd0 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390374] [<ffffffffa0473e23>]<br>
nfsd_dispatch+0xc3/0x260 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390411] [<ffffffffa0322108>]<br>
svc_process_common+0x418/0x6a0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.390439] [<ffffffffa032248d>]<br>
svc_process+0xfd/0x1b0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.390454] [<ffffffffa047389a>]<br>
nfsd+0xea/0x160 [nfsd]<br>
<br>
That causes the other nfs client is hang to wait nfsd to continue.<br>
<br>
Sep 07 12:25:35 myPC kernel: [11039.207987] Call Trace:<br>
Sep 07 12:25:35 myPC kernel: [11039.207994] [<ffffffff815e4c85>]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.208008] [<ffffffffa031acce>]<br>
rpc_wait_bit_killable+0x1e/0xa0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208055] [<ffffffff815e5098>]<br>
__wait_on_bit+0x58/0x90<br>
Sep 07 12:25:35 myPC kernel: [11039.208059] [<ffffffff815e513e>]<br>
out_of_line_wait_on_bit+0x6e/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.208082] [<ffffffffa031bd26>]<br>
__rpc_execute+0x146/0x440 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208104] [<ffffffffa0313049>]<br>
rpc_run_task+0x69/0x80 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208126] [<ffffffffa031309f>]<br>
rpc_call_sync+0x3f/0xa0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.204818] [<ffffffff81200d69>]<br>
vfs_fstatat+0x49/0x90<br>
Sep 07 12:25:35 myPC kernel: [11039.204821] [<ffffffff812011ea>]<br>
SYSC_newstat+0x1a/0x40<br>
Sep 07 12:25:35 myPC kernel: [11039.204826] [<ffffffff815e876e>]<br>
entry_SYSCALL_64_fastpath+0x12/0x6d<br>
Sep 07 12:25:35 myPC kernel: [11039.207972] DWARF2 unwinder stuck at<br>
entry_SYSCALL_64_fastpath+0x12/0x6d<br>
<br>
I guess under heavy load, somehow the inode cannot be evicted in<br>
kswap, so the nfsd just keeps waiting and cause the whole system ends<br>
up in unresponsive state. I found some related issues<br>
<a href="https://www.systutorials.com/linux-kernels/105429/nfsv4-1-prevent-a-3-way-deadlock-between-layoutreturn-open-and-state-recovery-linux-3-12-17/" rel="noreferrer" target="_blank">https://www.systutorials.com/linux-kernels/105429/nfsv4-1-prevent-a-3-way-deadlock-between-layoutreturn-open-and-state-recovery-linux-3-12-17/</a><br>
(it’s not the same as it’s nfsv4 but just refer for the same symptom.)<br>
<br>
My system has very limited resource, only 1 core and 1GB RAM and the<br>
issue is very easy to happen in a slow disk. However, I did not see<br>
the same issue in the older kernel 3.12.61. Could you please let me<br>
know if my analysis makes sense, if jbd2_log_wait_commit hang causes<br>
__wait_on_freeing_inode wait ? Is it a known issue in kernel? If any<br>
kernel change causes the issue?. And if we have any WA to avoid that<br>
like preventing kswapd kicks in (I have a 5G swap partition) or to<br>
make my system is not unresponsive like that (of course it is not to<br>
add more RAM :) ?<br>
<br>
Thanks a lot<br>
Brs,<br>
Naruto<br>
<br>
_______________________________________________<br>
Kernelnewbies mailing list<br>
<a href="mailto:Kernelnewbies@kernelnewbies.org" target="_blank">Kernelnewbies@kernelnewbies.org</a><br>
<a href="https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies" rel="noreferrer" target="_blank">https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies</a><br>
</blockquote></div><br clear="all"><br>-- <br><div dir="ltr" class="gmail_signature" data-smartmail="gmail_signature">regards,<br><br>Mulyadi Santosa<br>Freelance Linux trainer and consultant<br><br>blog: <a href="http://the-hydra.blogspot.com" target="_blank">the-hydra.blogspot.com</a><br>training: <a href="http://mulyaditraining.blogspot.com" target="_blank">mulyaditraining.blogspot.com</a></div></div>