Re: [mm] 4e2c82a409: ltp.overcommit_memory01.fail

[Qian Cai <cai@lca.pw>]

On Thu, Jul 02, 2020 at 03:12:30PM +0800, Feng Tang wrote:
> Hi,
> 
> On Thu, Jul 02, 2020 at 02:32:01PM +0800, kernel test robot wrote:
> > Greeting,
> > 
> > FYI, we noticed the following commit (built with gcc-9):
> > 
> > commit: 4e2c82a40911c19419349918e675aa202b113b4d ("[PATCH v5 3/3] mm: adjust vm_committed_as_batch according to vm overcommit policy")
> > url: https://github.com/0day-ci/linux/commits/Feng-Tang/make-vm_committed_as_batch-aware-of-vm-overcommit-policy/20200621-153906
> > 
> > 
> > in testcase: ltp
> > with following parameters:
> > 
> > 	disk: 1HDD
> > 	test: mm-01
> > 
> > test-description: The LTP testsuite contains a collection of tools for testing the Linux kernel and related features.
> > test-url: http://linux-test-project.github.io/
> > 
> > 
> > on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
> > 
> > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
> > 
> > 
> > 
> > 
> > If you fix the issue, kindly add following tag
> > Reported-by: kernel test robot <rong.a.chen@intel.com>
> > 
> > 
> > 
> > <<<test_start>>>
> > tag=overcommit_memory01 stime=1593425044
> > cmdline="overcommit_memory"
> > contacts=""
> > analysis=exit
> > <<<test_output>>>
> > tst_test.c:1247: INFO: Timeout per run is 0h 05m 00s
> > overcommit_memory.c:116: INFO: MemTotal is 16394252 kB
> > overcommit_memory.c:118: INFO: SwapTotal is 268435452 kB
> > overcommit_memory.c:122: INFO: CommitLimit is 276632576 kB
> > mem.c:817: INFO: set overcommit_ratio to 50
> > mem.c:817: INFO: set overcommit_memory to 2
> > overcommit_memory.c:187: INFO: malloc 551061440 kB failed
> > overcommit_memory.c:208: PASS: alloc failed as expected
> > overcommit_memory.c:183: INFO: malloc 276632576 kB successfully
> > overcommit_memory.c:210: FAIL: alloc passed, expected to fail
> 
> Thanks for the report!
> 
> I took a rough look, and it all happens after changing the
> overcommit policy from a looser one to OVERCOMMIT_NEVER. I suspect 
> it is due to the same cause as the previous warning message reported
> by Qian Cai https://lore.kernel.org/lkml/20200526181459.GD991@lca.pw/ 

Hmm, the LTP test [1] looks like a faithful implementation of
Documentation/vm/overcommit-accounting.rst which is now failing because
of this patchset.

Also, It was a mistake to merge c571686a92ff ("mm/util.c: remove the
VM_WARN_ONCE for vm_committed_as underflow check") separately (I am
taking a blame to ACK it separately and I forgot to run those tests to
double-check earlier) which is now making me wonder that VM_WARN_ONCE is
actually legitimate to catch the sign of brokenness in the first place.

[1] https://github.com/linux-test-project/ltp/blob/master/testcases/kernel/mem/tunable/overcommit_memory.c

> 
> Will further check it.
> 
> Thanks,
> Feng
> 
> > overcommit_memory.c:183: INFO: malloc 137765294 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > mem.c:817: INFO: set overcommit_memory to 0
> > overcommit_memory.c:183: INFO: malloc 140770308 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:187: INFO: malloc 569659408 kB failed
> > overcommit_memory.c:208: PASS: alloc failed as expected
> > mem.c:817: INFO: set overcommit_memory to 1
> > overcommit_memory.c:183: INFO: malloc 142414852 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:183: INFO: malloc 284829704 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:183: INFO: malloc 569659408 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > mem.c:817: INFO: set overcommit_memory to 0
> > mem.c:817: INFO: set overcommit_ratio to 50
> > 
> > Summary:
> > passed   7
> > failed   1
> > skipped  0
> > warnings 0
> > <<<execution_status>>>
> > initiation_status="ok"
> > duration=0 termination_type=exited termination_id=1 corefile=no
> > cutime=0 cstime=1
> > <<<test_end>>>
> > <<<test_start>>>
> > tag=overcommit_memory02 stime=1593425044
> > cmdline="overcommit_memory -R 0"
> > contacts=""
> > analysis=exit
> > <<<test_output>>>
> > tst_test.c:1247: INFO: Timeout per run is 0h 05m 00s
> > overcommit_memory.c:116: INFO: MemTotal is 16394252 kB
> > overcommit_memory.c:118: INFO: SwapTotal is 268435452 kB
> > overcommit_memory.c:122: INFO: CommitLimit is 276632576 kB
> > mem.c:817: INFO: set overcommit_ratio to 0
> > mem.c:817: INFO: set overcommit_memory to 2
> > overcommit_memory.c:187: INFO: malloc 534667184 kB failed
> > overcommit_memory.c:208: PASS: alloc failed as expected
> > overcommit_memory.c:183: INFO: malloc 268435452 kB successfully
> > overcommit_memory.c:210: FAIL: alloc passed, expected to fail
> > overcommit_memory.c:183: INFO: malloc 133666730 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > mem.c:817: INFO: set overcommit_memory to 0
> > overcommit_memory.c:183: INFO: malloc 140770304 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:187: INFO: malloc 569659408 kB failed
> > overcommit_memory.c:208: PASS: alloc failed as expected
> > mem.c:817: INFO: set overcommit_memory to 1
> > overcommit_memory.c:183: INFO: malloc 142414852 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:183: INFO: malloc 284829704 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > overcommit_memory.c:183: INFO: malloc 569659408 kB successfully
> > overcommit_memory.c:202: PASS: alloc passed as expected
> > mem.c:817: INFO: set overcommit_memory to 0
> > mem.c:817: INFO: set overcommit_ratio to 50
> > 
>