From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: 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=-10.2 required=3.0 tests=BAYES_00, HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_PATCH,MAILING_LIST_MULTI,NICE_REPLY_A, SPF_HELO_NONE,SPF_PASS,UNPARSEABLE_RELAY,URIBL_BLOCKED,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 9F875C433C1 for ; Tue, 30 Mar 2021 04:56:18 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 9050161989 for ; Tue, 30 Mar 2021 04:56:17 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 9050161989 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=wanyeetech.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id E24586B007D; Tue, 30 Mar 2021 00:56:16 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id DD5DA6B007E; Tue, 30 Mar 2021 00:56:16 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id C75596B0080; Tue, 30 Mar 2021 00:56:16 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0009.hostedemail.com [216.40.44.9]) by kanga.kvack.org (Postfix) with ESMTP id AB46B6B007D for ; Tue, 30 Mar 2021 00:56:16 -0400 (EDT) Received: from smtpin04.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay03.hostedemail.com (Postfix) with ESMTP id 64CCA8249980 for ; Tue, 30 Mar 2021 04:56:16 +0000 (UTC) X-FDA: 77975329152.04.1774B6A Received: from out28-221.mail.aliyun.com (out28-221.mail.aliyun.com [115.124.28.221]) by imf20.hostedemail.com (Postfix) with ESMTP id 3A3B813A for ; Tue, 30 Mar 2021 04:56:09 +0000 (UTC) X-Alimail-AntiSpam:AC=CONTINUE;BC=0.07436377|-1;CH=green;DM=|CONTINUE|false|;DS=CONTINUE|ham_enroll_verification|0.00731599-0.000618088-0.992066;FP=0|0|0|0|0|-1|-1|-1;HT=ay29a033018047205;MF=zhouyanjie@wanyeetech.com;NM=1;PH=DS;RN=8;RT=8;SR=0;TI=SMTPD_---.JsMJqX2_1617080167; Received: from 192.168.123.38(mailfrom:zhouyanjie@wanyeetech.com fp:SMTPD_---.JsMJqX2_1617080167) by smtp.aliyun-inc.com(10.147.41.120); Tue, 30 Mar 2021 12:56:08 +0800 Subject: Re: exec error: BUG: Bad rss-counter To: Ilya Lipnitskiy Cc: "Eric W. Biederman" , Linux-MM , Linux Kernel Mailing List , linux-fsdevel , Kees Cook , Christoph Hellwig , Linus Torvalds References: From: Zhou Yanjie Message-ID: <05dc921e-da71-4e71-6132-736eccd35680@wanyeetech.com> Date: Tue, 30 Mar 2021 12:56:07 +0800 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Thunderbird/60.9.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US X-Rspamd-Server: rspam03 X-Rspamd-Queue-Id: 3A3B813A X-Stat-Signature: o81g4icte51kbnbpkxsz7j1tncqnt8a7 Received-SPF: none (wanyeetech.com>: No applicable sender policy available) receiver=imf20; identity=mailfrom; envelope-from=""; helo=out28-221.mail.aliyun.com; client-ip=115.124.28.221 X-HE-DKIM-Result: none/none X-HE-Tag: 1617080169-240864 Content-Transfer-Encoding: quoted-printable 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: Hi Ilya, On 2021/3/29 =E4=B8=8A=E5=8D=8810:48, Ilya Lipnitskiy wrote: > On Sat, Mar 20, 2021 at 8:59 AM Zhou Yanjie = wrote: >> Hi Ilya, >> >> On 2021/3/3 =E4=B8=8B=E5=8D=8811:55, Ilya Lipnitskiy wrote: >>> On Wed, Mar 3, 2021 at 7:50 AM Eric W. Biederman wrote: >>>> Ilya Lipnitskiy writes: >>>> >>>>> On Tue, Mar 2, 2021 at 11:37 AM Eric W. Biederman wrote: >>>>>> Ilya Lipnitskiy writes: >>>>>> >>>>>>> On Mon, Mar 1, 2021 at 12:43 PM Eric W. Biederman wrote: >>>>>>>> Ilya Lipnitskiy writes: >>>>>>>> >>>>>>>>> Eric, All, >>>>>>>>> >>>>>>>>> The following error appears when running Linux 5.10.18 on an em= bedded >>>>>>>>> MIPS mt7621 target: >>>>>>>>> [ 0.301219] BUG: Bad rss-counter state mm:(ptrval) type:MM_A= NONPAGES val:1 >>>>>>>>> >>>>>>>>> Being a very generic error, I started digging and added a stack= dump >>>>>>>>> before the BUG: >>>>>>>>> Call Trace: >>>>>>>>> [<80008094>] show_stack+0x30/0x100 >>>>>>>>> [<8033b238>] dump_stack+0xac/0xe8 >>>>>>>>> [<800285e8>] __mmdrop+0x98/0x1d0 >>>>>>>>> [<801a6de8>] free_bprm+0x44/0x118 >>>>>>>>> [<801a86a8>] kernel_execve+0x160/0x1d8 >>>>>>>>> [<800420f4>] call_usermodehelper_exec_async+0x114/0x194 >>>>>>>>> [<80003198>] ret_from_kernel_thread+0x14/0x1c >>>>>>>>> >>>>>>>>> So that's how I got to looking at fs/exec.c and noticed quite a= few >>>>>>>>> changes last year. Turns out this message only occurs once very= early >>>>>>>>> at boot during the very first call to kernel_execve. current->m= m is >>>>>>>>> NULL at this stage, so acct_arg_size() is effectively a no-op. >>>>>>>> If you believe this is a new error you could bisect the kernel >>>>>>>> to see which change introduced the behavior you are seeing. >>>>>>>> >>>>>>>>> More digging, and I traced the RSS counter increment to: >>>>>>>>> [<8015adb4>] add_mm_counter_fast+0xb4/0xc0 >>>>>>>>> [<80160d58>] handle_mm_fault+0x6e4/0xea0 >>>>>>>>> [<80158aa4>] __get_user_pages.part.78+0x190/0x37c >>>>>>>>> [<8015992c>] __get_user_pages_remote+0x128/0x360 >>>>>>>>> [<801a6d9c>] get_arg_page+0x34/0xa0 >>>>>>>>> [<801a7394>] copy_string_kernel+0x194/0x2a4 >>>>>>>>> [<801a880c>] kernel_execve+0x11c/0x298 >>>>>>>>> [<800420f4>] call_usermodehelper_exec_async+0x114/0x194 >>>>>>>>> [<80003198>] ret_from_kernel_thread+0x14/0x1c >>>>>>>>> >>>>>>>>> In fact, I also checked vma_pages(bprm->vma) and lo and behold = it is set to 1. >>>>>>>>> >>>>>>>>> How is fs/exec.c supposed to handle implied RSS increments that= happen >>>>>>>>> due to page faults when discarding the bprm structure? In this = case, >>>>>>>>> the bug-generating kernel_execve call never succeeded, it retur= ned -2, >>>>>>>>> but I didn't trace exactly what failed. >>>>>>>> Unless I am mistaken any left over pages should be purged by exi= t_mmap >>>>>>>> which is called by mmput before mmput calls mmdrop. >>>>>>> Good to know. Some more digging and I can say that we hit this er= ror >>>>>>> when trying to unmap PFN 0 (is_zero_pfn(pfn) returns TRUE, >>>>>>> vm_normal_page returns NULL, zap_pte_range does not decrement >>>>>>> MM_ANONPAGES RSS counter). Is my understanding correct that PFN 0= is >>>>>>> usable, but special? Or am I totally off the mark here? >>>>>> It would be good to know if that is the page that get_user_pages_r= emote >>>>>> returned to copy_string_kernel. The zero page that is always zero= , >>>>>> should never be returned when a writable mapping is desired. >>>>> Indeed, pfn 0 is returned from get_arg_page: (page is 0x809cf000, >>>>> page_to_pfn(page) is 0) and it is the same page that is being freed= and not >>>>> refcounted in mmput/zap_pte_range. Confirmed with good old printk. = Also, >>>>> ZERO_PAGE(0)=3D=3D0x809fc000 -> PFN 5120. >>>>> >>>>> I think I have found the problem though, after much digging and tha= nks to all >>>>> the information provided. init_zero_pfn() gets called too late (aft= er >>>>> the call to >>>>> is_zero_pfn(0) from mmput returns true), until then zero_pfn =3D=3D= 0, and after, >>>>> zero_pfn =3D=3D 5120. Boom. >>>>> >>>>> So PFN 0 is special, but only for a little bit, enough for somethin= g >>>>> on my system >>>>> to call kernel_execve :) >>>>> >>>>> Question: is my system not supposed to be calling kernel_execve thi= s >>>>> early or does >>>>> init_zero_pfn() need to happen earlier? init_zero_pfn is currently = a >>>>> core_initcall. >>>> Looking quickly it seems that init_zero_pfn() is in mm/memory.c and = is >>>> common for both mips and x86. Further it appears init_zero_pfn() ha= s >>>> been that was since 2009 a13ea5b75964 ("mm: reinstate ZERO_PAGE"). >>>> >>>> Given the testing that x86 gets and that nothing like this has been >>>> reported it looks like whatever driver is triggering the kernel_exec= ve >>>> is doing something wrong. >>>> Because honestly. If the zero page isn't working there is not a cha= nce >>>> that anything in userspace is working so it is clearly much too earl= y. >>>> >>>> I suspect there is some driver that is initialized very early that i= s >>>> doing something that looks innocuous (like triggering a hotplug even= t) >>>> and that happens to cause a call_usermode_helper which then calls >>>> kernel_execve. >>> I will investigate the offenders more closely. However, I do not >>> notice this behavior on the same system based on the 5.4 kernel. Is i= t >> >> I also encountered this problem on Ingenic X1000 and X1830. This is th= e >> printed information: >> >> [ 0.120715] BUG: Bad rss-counter state mm:(ptrval) >> type:MM_ANONPAGES val:1 >> >> I tested kernel 5.9, kernel 5.10, kernel 5.11, and kernel 5.12, only >> kernel 5.9 did not have this problem, so we can know that this problem >> was introduced in kernel 5.10, have you found any effective solution? > Try: > diff --git a/mm/memory.c b/mm/memory.c > index c8e357627318..1fd753245369 100644 > --- a/mm/memory.c > +++ b/mm/memory.c > @@ -166,7 +166,7 @@ static int __init init_zero_pfn(void) > zero_pfn =3D page_to_pfn(ZERO_PAGE(0)); > return 0; > } > -core_initcall(init_zero_pfn); > +early_initcall(init_zero_pfn); It works, thanks! Best regards! > void mm_trace_rss_stat(struct mm_struct *mm, int member, long count) > {