From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <SRS0=Usf8=5Z=kvack.org=owner-linux-mm@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
X-Spam-Level: 
X-Spam-Status: No, score=-7.4 required=3.0 tests=DKIMWL_WL_HIGH,DKIM_SIGNED,
	DKIM_VALID,DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,
	MENTIONS_GIT_HOSTING,SPF_HELO_NONE,SPF_PASS,USER_AGENT_SANE_1 autolearn=ham
	autolearn_force=no version=3.4.0
Received: from mail.kernel.org (mail.kernel.org [198.145.29.99])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 81395C2D0EA
	for <linux-mm@archiver.kernel.org>; Thu,  9 Apr 2020 06:38:15 +0000 (UTC)
Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17])
	by mail.kernel.org (Postfix) with ESMTP id 29AB520757
	for <linux-mm@archiver.kernel.org>; Thu,  9 Apr 2020 06:38:15 +0000 (UTC)
Authentication-Results: mail.kernel.org;
	dkim=pass (2048-bit key) header.d=nvidia.com header.i=@nvidia.com header.b="WYPAaDd4"
DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 29AB520757
Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=nvidia.com
Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org
Received: by kanga.kvack.org (Postfix)
	id B0E588E000D; Thu,  9 Apr 2020 02:38:14 -0400 (EDT)
Received: by kanga.kvack.org (Postfix, from userid 40)
	id ABFF98E0006; Thu,  9 Apr 2020 02:38:14 -0400 (EDT)
X-Delivered-To: int-list-linux-mm@kvack.org
Received: by kanga.kvack.org (Postfix, from userid 63042)
	id 9AE758E000D; Thu,  9 Apr 2020 02:38:14 -0400 (EDT)
X-Delivered-To: linux-mm@kvack.org
Received: from forelay.hostedemail.com (smtprelay0057.hostedemail.com [216.40.44.57])
	by kanga.kvack.org (Postfix) with ESMTP id 8C0BE8E0006
	for <linux-mm@kvack.org>; Thu,  9 Apr 2020 02:38:14 -0400 (EDT)
Received: from smtpin19.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251])
	by forelay01.hostedemail.com (Postfix) with ESMTP id 4F6DB180AD801
	for <linux-mm@kvack.org>; Thu,  9 Apr 2020 06:38:14 +0000 (UTC)
X-FDA: 76687362108.19.home80_2aac922158449
X-HE-Tag: home80_2aac922158449
X-Filterd-Recvd-Size: 11740
Received: from hqnvemgate24.nvidia.com (hqnvemgate24.nvidia.com [216.228.121.143])
	by imf23.hostedemail.com (Postfix) with ESMTP
	for <linux-mm@kvack.org>; Thu,  9 Apr 2020 06:38:13 +0000 (UTC)
Received: from hqpgpgate102.nvidia.com (Not Verified[216.228.121.13]) by hqnvemgate24.nvidia.com (using TLS: TLSv1.2, DES-CBC3-SHA)
	id <B5e8ec26c0000>; Wed, 08 Apr 2020 23:36:28 -0700
Received: from hqmail.nvidia.com ([172.20.161.6])
  by hqpgpgate102.nvidia.com (PGP Universal service);
  Wed, 08 Apr 2020 23:38:11 -0700
X-PGP-Universal: processed;
	by hqpgpgate102.nvidia.com on Wed, 08 Apr 2020 23:38:11 -0700
Received: from DRHQMAIL107.nvidia.com (10.27.9.16) by HQMAIL105.nvidia.com
 (172.20.187.12) with Microsoft SMTP Server (TLS) id 15.0.1473.3; Thu, 9 Apr
 2020 06:38:11 +0000
Received: from [10.2.50.223] (10.124.1.5) by DRHQMAIL107.nvidia.com
 (10.27.9.16) with Microsoft SMTP Server (TLS) id 15.0.1473.3; Thu, 9 Apr 2020
 06:38:10 +0000
Subject: Re: [patch 043/155] mm/gup: track FOLL_PIN pages
To: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>,
	<imbrenda@linux.ibm.com>, <jack@suse.cz>, <jglisse@redhat.com>
CC: Andrew Morton <akpm@linux-foundation.org>, <corbet@lwn.net>,
	<dan.j.williams@intel.com>, <david@fromorbit.com>, <hch@infradead.org>,
	<ira.weiny@intel.com>, <jgg@ziepe.ca>, <kirill.shutemov@linux.intel.com>,
	<linux-mm@kvack.org>, <mhocko@suse.com>, <mike.kravetz@oracle.com>,
	<shuah@kernel.org>, <torvalds@linux-foundation.org>, <vbabka@suse.cz>,
	<viro@zeniv.linux.org.uk>, <willy@infradead.org>
References: <20200402040529.wHKICHtvB%akpm@linux-foundation.org>
 <acb17a53-d6fa-170f-b69a-ea2c525b5e6a@I-love.SAKURA.ne.jp>
From: John Hubbard <jhubbard@nvidia.com>
X-Nvconfidentiality: public
Message-ID: <2d45b8b7-ecbc-298f-5124-cb635dd3928a@nvidia.com>
Date: Wed, 8 Apr 2020 23:38:10 -0700
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101
 Thunderbird/68.6.0
MIME-Version: 1.0
In-Reply-To: <acb17a53-d6fa-170f-b69a-ea2c525b5e6a@I-love.SAKURA.ne.jp>
X-Originating-IP: [10.124.1.5]
X-ClientProxiedBy: HQMAIL105.nvidia.com (172.20.187.12) To
 DRHQMAIL107.nvidia.com (10.27.9.16)
Content-Type: text/plain; charset="utf-8"; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 7bit
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=nvidia.com; s=n1;
	t=1586414188; bh=PVVCemy7l7NyFRujmAcdBFbeLOmPBfhxHvEqgxhKELU=;
	h=X-PGP-Universal:Subject:To:CC:References:From:X-Nvconfidentiality:
	 Message-ID:Date:User-Agent:MIME-Version:In-Reply-To:
	 X-Originating-IP:X-ClientProxiedBy:Content-Type:Content-Language:
	 Content-Transfer-Encoding;
	b=WYPAaDd4C77EWcfDYRByyrnyXxurlsUresjuc6P9HL4+jQVzF6hyTmT6tgta7gQ2P
	 J+n+C6CB4h0oC2LOPIgJkYE2SiClpmvDtY+bHGlC1C4eSt03txpptFkH5w8zNYlqHw
	 D4JpaJMz4K2jgFTlZjRdW1sYGCaokFJLqwc+cArW+A/+CSDhtOb7mn42oOHdjcm107
	 JL2jgcPuDbm/BzITKX4GllSQUZTt6WUfhozuIChJb4bcX0c3XmR/QX1cPEu2dRyzxh
	 ThZIh30/d6aP6N5zoGRJdA/zqpYTUtHNuH7NayIpEkc1YCyrFBpdWic9RgJbHQ5lLK
	 UDcmGrzHOf1lA==
X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4
Sender: owner-linux-mm@kvack.org
Precedence: bulk
X-Loop: owner-majordomo@kvack.org
List-ID: <linux-mm.kvack.org>

On 4/8/20 11:08 PM, Tetsuo Handa wrote:
> Hello.
> 
> I'm hitting WARN_ON() at try_get_page() from try_grab_page() due to page_ref_count(page) == -1021
> (which is "3 - GUP_PIN_COUNTING_BIAS") if I use loadable kernel module version of TOMOYO security
> module. Since I don't see recent changes in security/tomoyo regarding get_user_pages_remote(),
> I'm wondering what is happening.


Hi Tetsuo,

Yes, commit 3faa52c03f440d1b ("mm/gup: track FOLL_PIN pages") is the one that turns everything on,
so if any problems with the whole FOLL_PIN scheme are to be found, it's natural that git bisect
would point to that commit.

Thanks for all the details here. One of the first questions I normally have is: is anything in the
system even using FOLL_PIN? And the way to answer that is to monitor the two new *foll_pin* entries
in /proc/vmstat, approximately like this:

$ cat /proc/vmstat |grep foll_pin
nr_foll_pin_acquired 0
nr_foll_pin_released 0

If you could do that before, during and after (ideally...or whatever you can get) the problem, I'd
love to see that data.

Also, if you happen to know if anything is calling pin_user_page*() and/or unpin_user_page*(), that
is extra credit. :)

I don't see anything here that jumps out at me, yet. The call stack below is as expected, and the WARN
often picks up problems that happened in some other calling path (something else leaked a FOLL_PIN
page for example, etc).

quick question below:

> 
> [   10.427414][    T1] ------------[ cut here ]------------
> [   10.427425][    T1] WARNING: CPU: 3 PID: 1 at ./include/linux/mm.h:1009 try_grab_page+0x77/0x80
> [   10.427426][    T1] Modules linked in: caitsith(O) akari(O) xfs libcrc32c crc32c_generic sd_mod ata_generic pata_acpi mptspi scsi_transport_spi vmwgfx mptscsih drm_kms_helper mptbase cfbfillrect syscopyarea cfbimgblt sysfillrect sysimgblt fb_sys_fops cfbcopyarea fb ahci fbdev libahci ttm ata_piix nvme drm drm_panel_orientation_quirks libata nvme_core t10_pi agpgart e1000 i2c_core scsi_mod serio_raw atkbd libps2 i8042 serio unix
> [   10.427451][    T1] CPU: 3 PID: 1 Comm: akari-init Tainted: G           O      5.6.0-05654-g3faa52c03f44 #984
> [   10.427452][    T1] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/29/2019
> [   10.427454][    T1] RIP: 0010:try_grab_page+0x77/0x80
> [   10.427456][    T1] Code: 34 85 c0 7e 25 f0 ff 47 34 b8 01 00 00 00 5d c3 0f 0b eb b1 48 8d 78 ff eb c6 0f 0b 31 c0 5d 0f 1f 40 00 c3 48 8d 78 ff eb d4 <0f> 0b 31 c0 5d c3 0f 1f 00 55 48 89 e5 41 57 49 89 cf 41 56 49 89
> [   10.427457][    T1] RSP: 0018:ffffa859c0013ac0 EFLAGS: 00010286
> [   10.427459][    T1] RAX: 00000000fffffc03 RBX: ffffcb6208c71dc0 RCX: 8000000231c77067
> [   10.427460][    T1] RDX: 8000000231c77067 RSI: 0000000000002016 RDI: ffffcb6208c71dc0
> [   10.427461][    T1] RBP: ffffa859c0013ac0 R08: 0000000000000001 R09: 0000000000000000
> [   10.427462][    T1] R10: 0000000000000001 R11: ffff95d91c615340 R12: 0000000000002016
> [   10.427463][    T1] R13: ffff95d91c615328 R14: 0000000000000ff0 R15: ffff95d91e0c0ff0
> [   10.427465][    T1] FS:  00007fbfc3772740(0000) GS:ffff95d927a00000(0000) knlGS:0000000000000000
> [   10.427479][    T1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   10.427483][    T1] CR2: 0000000000ac5190 CR3: 000000022090a002 CR4: 00000000003606e0
> [   10.427491][    T1] Call Trace:
> [   10.427494][    T1]  follow_page_pte+0x329/0x443
> [   10.427503][    T1]  follow_p4d_mask+0x756/0x7c1
> [   10.427511][    T1]  follow_page_mask+0x6a/0x70
> [   10.427516][    T1]  __get_user_pages+0x110/0x880
> [   10.427518][    T1]  ? ___slab_alloc.constprop.95+0x929/0x980
> [   10.427532][    T1]  __get_user_pages_remote+0xce/0x230
> [   10.427540][    T1]  get_user_pages_remote+0x27/0x40
> [   10.427545][    T1]  ccs_dump_page+0x6a/0x140 [akari]
> [   10.427552][    T1]  ccs_start_execve+0x28c/0x490 [akari]
> [   10.427555][    T1]  ? ccs_start_execve+0x90/0x490 [akari]
> [   10.427561][    T1]  ? ccs_load_policy+0xee/0x150 [akari]
> [   10.427568][    T1]  ccs_bprm_check_security+0x4e/0x70 [akari]


...say, I can't find the ccs_*() routines in my tree, can you point me to them? Probably not
important but I'm curious now.

thanks,
-- 
John Hubbard
NVIDIA

> [   10.427572][    T1]  security_bprm_check+0x26/0x40
> [   10.427576][    T1]  search_binary_handler+0x22/0x1c0
> [   10.427580][    T1]  __do_execve_file.isra.41+0x723/0xac0
> [   10.427581][    T1]  ? __do_execve_file.isra.41+0x665/0xac0
> [   10.427590][    T1]  __x64_sys_execve+0x44/0x50
> [   10.427614][    T1]  do_syscall_64+0x4a/0x1e0
> [   10.427618][    T1]  entry_SYSCALL_64_after_hwframe+0x49/0xb3
> [   10.427649][    T1] RIP: 0033:0x7fbfc2e36c37
> [   10.427651][    T1] Code: ff ff 76 df 89 c6 f7 de 64 41 89 32 eb d5 89 c6 f7 de 64 41 89 32 eb db 66 2e 0f 1f 84 00 00 00 00 00 90 b8 3b 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 02 f3 c3 48 8b 15 08 12 30 00 f7 d8 64 89 02
> [   10.427652][    T1] RSP: 002b:00007fff25f9c0f8 EFLAGS: 00000202 ORIG_RAX: 000000000000003b
> [   10.427654][    T1] RAX: ffffffffffffffda RBX: 0000000000ac64f0 RCX: 00007fbfc2e36c37
> [   10.427672][    T1] RDX: 0000000000ac6be0 RSI: 0000000000ac6ac0 RDI: 0000000000ac64f0
> [   10.427673][    T1] RBP: 0000000000000000 R08: 00007fff25f9c0e0 R09: 0000000000000000
> [   10.427674][    T1] R10: 00007fff25f9bb60 R11: 0000000000000202 R12: 0000000000ac6be0
> [   10.427675][    T1] R13: 0000000000ac6ac0 R14: 0000000000ac6be0 R15: 0000000000ac6820
> [   10.427701][    T1] irq event stamp: 10135190
> [   10.427704][    T1] hardirqs last  enabled at (10135189): [<ffffffffb223092a>] __slab_alloc.constprop.94+0x48/0x5e
> [   10.427706][    T1] hardirqs last disabled at (10135190): [<ffffffffb2001eb7>] trace_hardirqs_off_thunk+0x1a/0x1c
> [   10.427707][    T1] softirqs last  enabled at (10135114): [<ffffffffb2a0032b>] __do_softirq+0x32b/0x455
> [   10.427710][    T1] softirqs last disabled at (10135107): [<ffffffffb2072985>] irq_exit+0xa5/0xb0
> [   10.427711][    T1] ---[ end trace 984e9bd0ce5a1e09 ]---
> 
> +bool __must_check try_grab_page(struct page *page, unsigned int flags)
> +{
> +       WARN_ON_ONCE((flags & (FOLL_GET | FOLL_PIN)) == (FOLL_GET | FOLL_PIN));
> +
> +       if (flags & FOLL_GET)
> +               return try_get_page(page);
> +       else if (flags & FOLL_PIN) {
> +               page = compound_head(page);
> +
> +               if (WARN_ON_ONCE(page_ref_count(page) <= 0))
> +                       return false;
> +
> +               page_ref_add(page, GUP_PIN_COUNTING_BIAS);
> +       }
> +
> +       return true;
> +}
> 
> Bisection says 3faa52c03f440d1b ("mm/gup: track FOLL_PIN pages") is the bad commit.
> 
> $ git bisect log
> # bad: [3faa52c03f440d1b9ddef18c4f189f4790d52d7e] mm/gup: track FOLL_PIN pages
> # good: [7111951b8d4973bda27ff663f2cf18b663d15b48] Linux 5.6
> # good: [d5226fa6dbae0569ee43ecfc08bdcd6770fc4755] Linux 5.5
> # good: [219d54332a09e8d8741c1e1982f5eae56099de85] Linux 5.4
> # good: [4d856f72c10ecb060868ed10ff1b1453943fc6c8] Linux 5.3
> # good: [0ecfebd2b52404ae0c54a878c872bb93363ada36] Linux 5.2
> # good: [e93c9c99a629c61837d5a7fc2120cd2b6c70dbdd] Linux 5.1
> # good: [1c163f4c7b3f621efff9b28a47abb36f7378d783] Linux 5.0
> # good: [86dfbed49f88fd87ce8a12d2314b1f93266da7a7] mm/gup: pass a flags arg to __gup_device_* functions
> # good: [83daf837884cc44c3cc0e4f8a096c5d1461cbcc2] mm/filemap.c: unexport find_get_entry
> # good: [cc7b8f6245f0042a232c7f6807dc130d87233164] mm/page-writeback.c: write_cache_pages(): deduplicate identical checks
> # good: [29d9f30d4ce6c7a38745a54a8cddface10013490] Merge git://git.kernel.org/pub/scm/linux/kernel/git/netdev/net-next
> # good: [4afdb733b1606c6cb86e7833f9335f4870cf7ddd] io-uring: drop completion when removing file
> git bisect start '3faa52c03f440d1b9ddef18c4f189f4790d52d7e' 'v5.6' 'v5.5' 'v5.4' 'v5.3' 'v5.2' 'v5.1' 'v5.0' '86dfbed49f88fd87ce8a12d2314b1f93266da7a7' '83daf837884cc44c3cc0e4f8a096c5d1461cbcc2' 'cc7b8f6245f0042a232c7f6807dc130d87233164' '29d9f30d4ce6c7a38745a54a8cddface10013490' '4afdb733b1606c6cb86e7833f9335f4870cf7ddd'
> # good: [3b78d8347d31a050bb4f378a5f42cf495d873796] mm/gup: pass gup flags to two more routines
> git bisect good 3b78d8347d31a050bb4f378a5f42cf495d873796
> # good: [94202f126f698691f8865906ad6a68203e5dde8c] mm/gup: require FOLL_GET for get_user_pages_fast()
> git bisect good 94202f126f698691f8865906ad6a68203e5dde8c
> # first bad commit: [3faa52c03f440d1b9ddef18c4f189f4790d52d7e] mm/gup: track FOLL_PIN pages
> 
>