From mboxrd@z Thu Jan  1 00:00:00 1970
From: mulyadi.santosa@gmail.com (Mulyadi Santosa)
Date: Sun, 18 Nov 2018 22:40:23 +0700
Subject: High IO load cause kswapd hang and unresponsive system
In-Reply-To: <CANpxKHHUO-qCLQaaCeb7PqPd7MZ8kymObJ-FyUEihGZnkGq5XQ@mail.gmail.com>
References: <CANpxKHF+2XVbH4FTn+trOh0tsUxh0TT3d4puqr-ynLEUtTg8fg@mail.gmail.com>
 <CAGdaadYNLeEcRCSda9t3wqASRXYfMmN4ywrLG87Menort_++ag@mail.gmail.com>
 <CANpxKHHUO-qCLQaaCeb7PqPd7MZ8kymObJ-FyUEihGZnkGq5XQ@mail.gmail.com>
Message-ID: <CAGdaada=7wTz0X4qtrQTPHPeuBzAS0vz5xnVLCG5t7=iYdnbOg@mail.gmail.com>
To: kernelnewbies@lists.kernelnewbies.org
List-Id: kernelnewbies.lists.kernelnewbies.org

On Sat, Nov 17, 2018 at 4:36 PM Naruto Nguyen <narutonguyen2018@gmail.com>
wrote:

> Hi Mulyadi,
>
> Thanks for your answer. I have updated to kernel 4.4.121 but the issue
> still exists. I will try to update to kernel 4.4.163. But if you could
> provide any reason that why i did not see the issue in the 3.12 kernel and
> now it happens in 4.4, any changes in 4.4 can trigger the issue? And if
> kernel 4.4.163 has any changes to fix the issue?
>
>
Hi..

Please don't top post.

As for the "why", that I don't know. There are too many changes between 3.x
and 4.x. That's why checking if the issue still happens with latest stable
version IS the first logical step .




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

-- 
regards,

Mulyadi Santosa
Freelance Linux trainer and consultant

blog: the-hydra.blogspot.com
training: mulyaditraining.blogspot.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kernelnewbies.org/pipermail/kernelnewbies/attachments/20181118/0870ea50/attachment.html>

From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <kernelnewbies-bounces@kernelnewbies.org>
Received: from mail-lf1-x143.google.com ([2a00:1450:4864:20::143])
 by shelob.surriel.com with esmtps (TLSv1.2:ECDHE-RSA-AES128-GCM-SHA256:128)
 (Exim 4.91) (envelope-from <mulyadi.santosa@gmail.com>)
 id 1gOPCJ-0005t5-Rg
 for kernelnewbies@kernelnewbies.org; Sun, 18 Nov 2018 10:41:20 -0500
Received: by mail-lf1-x143.google.com with SMTP id u18so19581716lff.10
 for <kernelnewbies@kernelnewbies.org>; Sun, 18 Nov 2018 07:41:19 -0800 (PST)
MIME-Version: 1.0
References: <CANpxKHF+2XVbH4FTn+trOh0tsUxh0TT3d4puqr-ynLEUtTg8fg@mail.gmail.com>
 <CAGdaadYNLeEcRCSda9t3wqASRXYfMmN4ywrLG87Menort_++ag@mail.gmail.com>
 <CANpxKHHUO-qCLQaaCeb7PqPd7MZ8kymObJ-FyUEihGZnkGq5XQ@mail.gmail.com>
In-Reply-To: <CANpxKHHUO-qCLQaaCeb7PqPd7MZ8kymObJ-FyUEihGZnkGq5XQ@mail.gmail.com>
From: Mulyadi Santosa <mulyadi.santosa@gmail.com>
Date: Sun, 18 Nov 2018 22:40:23 +0700
Message-ID:
 <CAGdaada=7wTz0X4qtrQTPHPeuBzAS0vz5xnVLCG5t7=iYdnbOg@mail.gmail.com>
Subject: Re: High IO load cause kswapd hang and unresponsive system
To: kernelnewbies <kernelnewbies@kernelnewbies.org>
List-Id: Learn about the Linux kernel <kernelnewbies.kernelnewbies.org>
List-Unsubscribe: <https://lists.kernelnewbies.org/mailman/options/kernelnewbies>,
 <mailto:kernelnewbies-request@kernelnewbies.org?subject=unsubscribe>
List-Archive: <http://lists.kernelnewbies.org/pipermail/kernelnewbies/>
List-Post: <mailto:kernelnewbies@kernelnewbies.org>
List-Help: <mailto:kernelnewbies-request@kernelnewbies.org?subject=help>
List-Subscribe: <https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies>,
 <mailto:kernelnewbies-request@kernelnewbies.org?subject=subscribe>
Content-Type: multipart/mixed; boundary="===============1601557651052839022=="
Errors-To: kernelnewbies-bounces@kernelnewbies.org
Message-ID: <20181118154023.VZB7c51GS9AvHEUn6c3ITWlvVJl07ANoUG13vgMqUBM@z>

--===============1601557651052839022==
Content-Type: multipart/alternative; boundary="000000000000259471057af23b06"

--000000000000259471057af23b06
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

On Sat, Nov 17, 2018 at 4:36 PM Naruto Nguyen <narutonguyen2018@gmail.com>
wrote:

> Hi Mulyadi,
>
> Thanks for your answer. I have updated to kernel 4.4.121 but the issue
> still exists. I will try to update to kernel 4.4.163. But if you could
> provide any reason that why i did not see the issue in the 3.12 kernel an=
d
> now it happens in 4.4, any changes in 4.4 can trigger the issue? And if
> kernel 4.4.163 has any changes to fix the issue?
>
>
Hi..

Please don't top post.

As for the "why", that I don't know. There are too many changes between 3.x
and 4.x. That's why checking if the issue still happens with latest stable
version IS the first logical step .




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

--=20
regards,

Mulyadi Santosa
Freelance Linux trainer and consultant

blog: the-hydra.blogspot.com
training: mulyaditraining.blogspot.com

--000000000000259471057af23b06
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><br><br><div class=3D"gmail_quote"><div dir=3D"ltr">On Sat=
, Nov 17, 2018 at 4:36 PM Naruto Nguyen &lt;<a href=3D"mailto:narutonguyen2=
018@gmail.com">narutonguyen2018@gmail.com</a>&gt; wrote:<br></div><blockquo=
te class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;border-left:1px #ccc so=
lid;padding-left:1ex">Hi Mulyadi,<div><br></div><div>Thanks for your answer=
. I have updated to kernel 4.4.121 but the issue still exists. I will try t=
o update to kernel 4.4.163. But if you could provide any reason that why i =
did not see the issue in the 3.12 kernel and now it happens in 4.4, any cha=
nges in 4.4 can trigger the issue? And if kernel 4.4.163 has any changes to=
 fix the issue?</div><div><br></div></blockquote><div><br></div><div>Hi..</=
div><div><br></div><div>Please don&#39;t top post.</div><div><br></div><div=
>As for the &quot;why&quot;, that I don&#39;t know. There are too many chan=
ges between 3.x and 4.x. That&#39;s why checking if the issue still happens=
 with latest stable version IS the first logical step .</div><div><br></div=
><div><br></div><div>=C2=A0</div><blockquote class=3D"gmail_quote" style=3D=
"margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div></div>=
<div>Thanks,</div><div>Naruto<br><br>On Friday, 16 November 2018, Mulyadi S=
antosa &lt;<a href=3D"mailto:mulyadi.santosa@gmail.com" target=3D"_blank">m=
ulyadi.santosa@gmail.com</a>&gt; wrote:<br><blockquote class=3D"gmail_quote=
" style=3D"margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><=
div dir=3D"ltr"><br><br><div class=3D"gmail_quote"><div dir=3D"ltr">On Thu,=
 Nov 15, 2018 at 11:57 PM Naruto Nguyen &lt;<a href=3D"mailto:narutonguyen2=
018@gmail.com" target=3D"_blank">narutonguyen2018@gmail.com</a>&gt; wrote:<=
br></div><blockquote class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;borde=
r-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></blo=
ckquote><div><br></div><div>Hi.</div><div><br></div><div>You need to upgrad=
e, 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=3D"gma=
il_quote" style=3D"margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-lef=
t: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=C2=A0 =C2=A0 =C2=A0 =C2=
=A0 =C2=A0D<br>
0000000000000000=C2=A0 =C2=A0 =C2=A00=C2=A0 =C2=A0 26=C2=A0 =C2=A0 =C2=A0 2=
 0x00000000<br>
Sep 07 12:25:35 myPC kernel: [11039.126517]=C2=A0 ffff88003da27b78<br>
ffff88000ce08280 ffff88003cdf0680 ffff88003da28000<br>
Sep 07 12:25:35 myPC kernel: [11039.126519]=C2=A0 ffff88001a15c888<br>
ffff88001a15c824 ffff88003da27bb8 ffff88001a15c8a0<br>
Sep 07 12:25:35 myPC kernel: [11039.126521]=C2=A0 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]=C2=A0 [&lt;ffffffff815e4c85&gt;=
]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.126561]=C2=A0 [&lt;ffffffffa02faada&gt;=
]<br>
jbd2_log_wait_commit+0x8a/0xf0 [jbd2]<br>
Sep 07 12:25:35 myPC kernel: [11039.126621]=C2=A0 [&lt;ffffffffa03b28a4&gt;=
]<br>
ext4_evict_inode+0x2d4/0x4b0 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.126630]=C2=A0 [&lt;ffffffff81215a7a&gt;=
]<br>
evict+0xba/0x190<br>
Sep 07 12:25:35 myPC kernel: [11039.126635]=C2=A0 [&lt;ffffffff81215b82&gt;=
]<br>
dispose_list+0x32/0x50<br>
Sep 07 12:25:35 myPC kernel: [11039.126639]=C2=A0 [&lt;ffffffff81216e52&gt;=
]<br>
prune_icache_sb+0x42/0x50<br>
Sep 07 12:25:35 myPC kernel: [11039.126644]=C2=A0 [&lt;ffffffff811ff8f6&gt;=
]<br>
super_cache_scan+0x136/0x180<br>
Sep 07 12:25:35 myPC kernel: [11039.126653]=C2=A0 [&lt;ffffffff81196a1b&gt;=
]<br>
shrink_slab.part.41+0x20b/0x3f0<br>
Sep 07 12:25:35 myPC kernel: [11039.126521]=C2=A0 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=C2=A0 =C2=A0 =C2=A0 =C2=A0=
 =C2=A0 =C2=A0 D<br>
0000000000000000=C2=A0 =C2=A0 =C2=A00 30419=C2=A0 =C2=A0 =C2=A0 2 0x0000008=
0<br>
Sep 07 12:25:35 myPC kernel: [11039.390221]=C2=A0 ffff88000da47a98<br>
ffff8800277ec380 ffff8800374ec580 ffff88000da48000<br>
Sep 07 12:25:35 myPC kernel: [11039.390223]=C2=A0 ffff88000da47ad8<br>
ffffc9000011edc8 0000000000000000 ffff88000e92e2f8<br>
Sep 07 12:25:35 myPC kernel: [11039.390225]=C2=A0 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]=C2=A0 [&lt;ffffffff815e4c85&gt;=
]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.390236]=C2=A0 [&lt;ffffffff812157fc&gt;=
]<br>
__wait_on_freeing_inode+0x9c/0xc0<br>
Sep 07 12:25:35 myPC kernel: [11039.390241]=C2=A0 [&lt;ffffffff81215d83&gt;=
]<br>
find_inode_fast+0x73/0xa0<br>
Sep 07 12:25:35 myPC kernel: [11039.390245]=C2=A0 [&lt;ffffffff81216052&gt;=
]<br>
iget_locked+0x72/0x190<br>
Sep 07 12:25:35 myPC kernel: [11039.390284]=C2=A0 [&lt;ffffffffa03aeb8c&gt;=
]<br>
ext4_iget+0x2c/0xb10 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.390314]=C2=A0 [&lt;ffffffffa03c1055&gt;=
]<br>
ext4_nfs_get_inode+0x45/0x80 [ext4]<br>
Sep 07 12:25:35 myPC kernel: [11039.390320]=C2=A0 [&lt;ffffffff812211c4&gt;=
]<br>
generic_fh_to_dentry+0x24/0x30<br>
Sep 07 12:25:35 myPC kernel: [11039.390326]=C2=A0 [&lt;ffffffff81277ede&gt;=
]<br>
exportfs_decode_fh+0x5e/0x350<br>
Sep 07 12:25:35 myPC kernel: [11039.390347]=C2=A0 [&lt;ffffffffa047749a&gt;=
]<br>
fh_verify+0x2da/0x5a0 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390362]=C2=A0 [&lt;ffffffffa0480933&gt;=
]<br>
nfsd3_proc_getattr+0x63/0xd0 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390374]=C2=A0 [&lt;ffffffffa0473e23&gt;=
]<br>
nfsd_dispatch+0xc3/0x260 [nfsd]<br>
Sep 07 12:25:35 myPC kernel: [11039.390411]=C2=A0 [&lt;ffffffffa0322108&gt;=
]<br>
svc_process_common+0x418/0x6a0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.390439]=C2=A0 [&lt;ffffffffa032248d&gt;=
]<br>
svc_process+0xfd/0x1b0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.390454]=C2=A0 [&lt;ffffffffa047389a&gt;=
]<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]=C2=A0 [&lt;ffffffff815e4c85&gt;=
]<br>
schedule+0x35/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.208008]=C2=A0 [&lt;ffffffffa031acce&gt;=
]<br>
rpc_wait_bit_killable+0x1e/0xa0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208055]=C2=A0 [&lt;ffffffff815e5098&gt;=
]<br>
__wait_on_bit+0x58/0x90<br>
Sep 07 12:25:35 myPC kernel: [11039.208059]=C2=A0 [&lt;ffffffff815e513e&gt;=
]<br>
out_of_line_wait_on_bit+0x6e/0x80<br>
Sep 07 12:25:35 myPC kernel: [11039.208082]=C2=A0 [&lt;ffffffffa031bd26&gt;=
]<br>
__rpc_execute+0x146/0x440 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208104]=C2=A0 [&lt;ffffffffa0313049&gt;=
]<br>
rpc_run_task+0x69/0x80 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.208126]=C2=A0 [&lt;ffffffffa031309f&gt;=
]<br>
rpc_call_sync+0x3f/0xa0 [sunrpc]<br>
Sep 07 12:25:35 myPC kernel: [11039.204818]=C2=A0 [&lt;ffffffff81200d69&gt;=
]<br>
vfs_fstatat+0x49/0x90<br>
Sep 07 12:25:35 myPC kernel: [11039.204821]=C2=A0 [&lt;ffffffff812011ea&gt;=
]<br>
SYSC_newstat+0x1a/0x40<br>
Sep 07 12:25:35 myPC kernel: [11039.204826]=C2=A0 [&lt;ffffffff815e876e&gt;=
]<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=3D"https://www.systutorials.com/linux-kernels/105429/nfsv4-1-preven=
t-a-3-way-deadlock-between-layoutreturn-open-and-state-recovery-linux-3-12-=
17/" rel=3D"noreferrer" target=3D"_blank">https://www.systutorials.com/linu=
x-kernels/105429/nfsv4-1-prevent-a-3-way-deadlock-between-layoutreturn-open=
-and-state-recovery-linux-3-12-17/</a><br>
(it=E2=80=99s not the same as it=E2=80=99s nfsv4 but just refer for the sam=
e symptom.)<br>
<br>
My system has very limited resource, only 1 core and=C2=A0 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=3D"mailto:Kernelnewbies@kernelnewbies.org" target=3D"_blank">Kernel=
newbies@kernelnewbies.org</a><br>
<a href=3D"https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies" =
rel=3D"noreferrer" target=3D"_blank">https://lists.kernelnewbies.org/mailma=
n/listinfo/kernelnewbies</a><br>
</blockquote></div><br clear=3D"all"><br>-- <br><div dir=3D"ltr" data-smart=
mail=3D"gmail_signature">regards,<br><br>Mulyadi Santosa<br>Freelance Linux=
 trainer and consultant<br><br>blog: <a href=3D"http://the-hydra.blogspot.c=
om" target=3D"_blank">the-hydra.blogspot.com</a><br>training: <a href=3D"ht=
tp://mulyaditraining.blogspot.com" target=3D"_blank">mulyaditraining.blogsp=
ot.com</a></div></div>
</blockquote></div>
</blockquote></div><br clear=3D"all"><br>-- <br><div dir=3D"ltr" class=3D"g=
mail_signature" data-smartmail=3D"gmail_signature">regards,<br><br>Mulyadi =
Santosa<br>Freelance Linux trainer and consultant<br><br>blog: <a href=3D"h=
ttp://the-hydra.blogspot.com" target=3D"_blank">the-hydra.blogspot.com</a><=
br>training: <a href=3D"http://mulyaditraining.blogspot.com" target=3D"_bla=
nk">mulyaditraining.blogspot.com</a></div></div>

--000000000000259471057af23b06--


--===============1601557651052839022==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

--===============1601557651052839022==--