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=-5.0 required=3.0 tests=BAYES_00,DKIM_INVALID, DKIM_SIGNED,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE, SPF_PASS,URIBL_BLOCKED,USER_AGENT_SANE_1 autolearn=no 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 F1BF5C00A89 for ; Mon, 2 Nov 2020 14:30:49 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 2A7B82072C for ; Mon, 2 Nov 2020 14:30:48 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=fail reason="signature verification failed" (1024-bit key) header.d=redhat.com header.i=@redhat.com header.b="Ko+AhYUE" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 2A7B82072C Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=redhat.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id 307F76B0068; Mon, 2 Nov 2020 09:30:48 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id 2B8AD6B006C; Mon, 2 Nov 2020 09:30:48 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 180F06B006E; Mon, 2 Nov 2020 09:30:48 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0216.hostedemail.com [216.40.44.216]) by kanga.kvack.org (Postfix) with ESMTP id DFF0E6B0068 for ; Mon, 2 Nov 2020 09:30:47 -0500 (EST) Received: from smtpin04.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay03.hostedemail.com (Postfix) with ESMTP id 7A6EE8249980 for ; Mon, 2 Nov 2020 14:30:47 +0000 (UTC) X-FDA: 77439714534.04.grain87_0204441272b0 Received: from filter.hostedemail.com (10.5.16.251.rfc1918.com [10.5.16.251]) by smtpin04.hostedemail.com (Postfix) with ESMTP id 490FE800004D for ; Mon, 2 Nov 2020 14:30:47 +0000 (UTC) X-HE-Tag: grain87_0204441272b0 X-Filterd-Recvd-Size: 9891 Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [216.205.24.124]) by imf29.hostedemail.com (Postfix) with ESMTP for ; Mon, 2 Nov 2020 14:30:46 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1604327445; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=HgoHjvHTKD+aahDSfC3sk1RkQjJwPPtUoTUfQVXKlxE=; b=Ko+AhYUEsYS5Zd0T1kvLHq/F4bl1VPx3Jqf05206zXpt6TbYmVKkZzkWudR/S58Uhg9Oq5 6F0xlZVO6jHv0UQv4UcU4n9IwJg2W/r5cHQERed3aHQfcbDUqQZ+rciGAnrAwkY3lL33Ru ak1BilSCwz9EpSQBuNbCZhEsPnnMpS4= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) (Using TLS) by relay.mimecast.com with ESMTP id us-mta-25-1eFeWNgsO9erQluVajwL9A-1; Mon, 02 Nov 2020 09:30:41 -0500 X-MC-Unique: 1eFeWNgsO9erQluVajwL9A-1 Received: from smtp.corp.redhat.com (int-mx07.intmail.prod.int.phx2.redhat.com [10.5.11.22]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx01.redhat.com (Postfix) with ESMTPS id 77319801F99; Mon, 2 Nov 2020 14:30:39 +0000 (UTC) Received: from localhost (ovpn-13-83.pek2.redhat.com [10.72.13.83]) by smtp.corp.redhat.com (Postfix) with ESMTPS id 497FF10013BD; Mon, 2 Nov 2020 14:30:38 +0000 (UTC) Date: Mon, 2 Nov 2020 22:30:35 +0800 From: "bhe@redhat.com" To: Rahul Gopakumar Cc: "linux-mm@kvack.org" , "linux-kernel@vger.kernel.org" , "akpm@linux-foundation.org" , "natechancellor@gmail.com" , "ndesaulniers@google.com" , "clang-built-linux@googlegroups.com" , "rostedt@goodmis.org" , Rajender M , Yiu Cho Lau , Peter Jonasson , Venkatesh Rajaram Subject: Re: Performance regressions in "boot_time" tests in Linux 5.8 Kernel Message-ID: <20201102143035.GA3177@MiWiFi-R3L-srv> References: <20201010061124.GE25604@MiWiFi-R3L-srv> <20201013131735.GL25604@MiWiFi-R3L-srv> <20201020151814.GU25604@MiWiFi-R3L-srv> <20201022040440.GX25604@MiWiFi-R3L-srv> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.10.1 (2018-07-13) X-Scanned-By: MIMEDefang 2.84 on 10.5.11.22 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: On 11/02/20 at 02:15pm, Rahul Gopakumar wrote: > Hi Baoquan, >=20 > There could still be some memory initialization problem with > the draft patch. I see a lot of page corruption errors. >=20 > BUG: Bad page state in process swapper pfn:ab0803c >=20 > Here is the call trace >=20 > [ 0.262826] dump_stack+0x57/0x6a > [ 0.262827] bad_page.cold.119+0x63/0x93 > [ 0.262828] __free_pages_ok+0x31f/0x330 > [ 0.262829] memblock_free_all+0x153/0x1bf > [ 0.262830] mem_init+0x23/0x1f2 > [ 0.262831] start_kernel+0x299/0x57a > [ 0.262832] secondary_startup_64_no_verify+0xb8/0xbb >=20 > I don't see this in dmesg log with vanilla kernel. >=20 > It looks like the overhead due to this initialization problem > is around 3 secs. >=20 > [ 0.262831] start_kernel+0x299/0x57a > [ 0.262832] secondary_startup_64_no_verify+0xb8/0xbb > [ 3.758185] Memory: 3374072K/1073740756K available (12297K kernel co= de, 5778Krwdata, 4376K rodata, 2352K init, 6480K bss, 16999716K reserved,= 0K cma-reserved) >=20 > But the draft patch is fixing the initial problem > reported around 2 secs (log snippet below) hence the total > delay of 1 sec. >=20 > [ 0.024752] Normal zone: 1445888 pages used for memmap > [ 0.024753] Normal zone: 89391104 pages, LIFO batch:63 > [ 0.027379] ACPI: PM-Timer IO Port: 0x448 So, you mean with the draft patch applied, the initial performance regression goes away, just many page corruption errors with call trace are seen, right? And the performance regression is about 2sec delay in your system? Could you tell how you setup vmware VM so that I can ask our QA for help to create a vmware VM for me to test? I tested the draft patch on bare metal system with more than 1T memory, didn't see the page corruption call trace, need reproduce and have a look. >=20 >=20 > ________________________________________ > From: Rahul Gopakumar > Sent: 22 October 2020 10:51 PM > To: bhe@redhat.com > Cc: linux-mm@kvack.org; linux-kernel@vger.kernel.org; akpm@linux-founda= tion.org; natechancellor@gmail.com; ndesaulniers@google.com; clang-built-= linux@googlegroups.com; rostedt@goodmis.org; Rajender M; Yiu Cho Lau; Pet= er Jonasson; Venkatesh Rajaram > Subject: Re: Performance regressions in "boot_time" tests in Linux 5.8 = Kernel >=20 > Hi Baoquan, >=20 > >>=A0Can you tell how you measure the boot time? >=20 > Our test is actually boothalt, time reported by this test > includes both boot-up and shutdown time. >=20 > >> At above, you said "Patch on latest commit - 20.161 secs", > >> could you tell where this 20.161 secs comes from, >=20 > So this time is boot-up time + shutdown time. >=20 > From the dmesg.log it looks like during the memmap_init > it's taking less time in the patch. Let me take a closer look to > confirm this and also to find where the 1-sec delay in the patch > run is coming from. >=20 >=20 > From: bhe@redhat.com > Sent: 22 October 2020 9:34 AM > To: Rahul Gopakumar > Cc: linux-mm@kvack.org ; linux-kernel@vger.kernel.o= rg ; akpm@linux-foundation.org ; natechancellor@gmail.com ; nde= saulniers@google.com ; clang-built-linux@googleg= roups.com ; rostedt@goodmis.org ; Rajender M ; Yiu Cho Lau ; Peter Jonasson ; Venkatesh Rajaram > Subject: Re: Performance regressions in "boot_time" tests in Linux 5.8 = Kernel >=20 > Hi Rahul, >=20 > On 10/20/20 at 03:26pm, Rahul Gopakumar wrote: > > >> Here, do you mean it even cost more time with the patch applied? > > > > Yes, we ran it multiple times and it looks like there is a > > very minor increase with the patch. > > > ...... > > On 10/20/20 at 01:45pm, Rahul Gopakumar wrote: > > > Hi Baoquan, > > > > > > We had some trouble applying the patch to problem commit and the la= test upstream commit. Steven (CC'ed) helped us by providing the updated d= raft patch. We applied it on the latest commit (3e4fb4346c781068610d03c12= b16c0cfb0fd24a3), and it doesn't look like improving the performance numb= ers. > > > > Thanks for your feedback. From the code, I am sure what the problem i= s, > > but I didn't test it on system with huge memory. Forget mentioning my > > draft patch is based on akpm/master branch since it's a mm issue, it > > might be a little different with linus's mainline kernel, sorry for t= he > > inconvenience. > > > > I will test and debug this on a server with 4T memory in our lab, and > > update if any progress. > > > > > > > > Patch on latest commit - 20.161 secs > > > Vanilla latest commit - 19.50 secs > > >=20 > Can you tell how you measure the boot time? I checked the boot logs you > attached, E.g in below two logs, I saw patch_dmesg.log even has less > time during memmap init. Now I have got a machine with 1T memory for > testing, but didn't see obvious time cost increase. At above, you said > "Patch on latest commit - 20.161 secs", could you tell where this 20.16= 1 > secs comes from, so that I can investigate and reproduce on my system? >=20 > patch_dmesg.log: > [=A0=A0=A0 0.023126] Initmem setup node 1 [mem 0x0000005600000000-0x000= 000aaffffffff] > [=A0=A0=A0 0.023128] On node 1 totalpages: 89128960 > [=A0=A0=A0 0.023129]=A0=A0 Normal zone: 1392640 pages used for memmap > [=A0=A0=A0 0.023130]=A0=A0 Normal zone: 89128960 pages, LIFO batch:63 > [=A0=A0=A0 0.023893] Initmem setup node 2 [mem 0x000000ab00000000-0x000= 001033fffffff] > [=A0=A0=A0 0.023895] On node 2 totalpages: 89391104 > [=A0=A0=A0 0.023896]=A0=A0 Normal zone: 1445888 pages used for memmap > [=A0=A0=A0 0.023897]=A0=A0 Normal zone: 89391104 pages, LIFO batch:63 > [=A0=A0=A0 0.026744] ACPI: PM-Timer IO Port: 0x448 > [=A0=A0=A0 0.026747] ACPI: Local APIC address 0xfee00000 >=20 > vanilla_dmesg.log: > [=A0=A0=A0 0.024295] Initmem setup node 1 [mem 0x0000005600000000-0x000= 000aaffffffff] > [=A0=A0=A0 0.024298] On node 1 totalpages: 89128960 > [=A0=A0=A0 0.024299]=A0=A0 Normal zone: 1392640 pages used for memmap > [=A0=A0=A0 0.024299]=A0=A0 Normal zone: 89128960 pages, LIFO batch:63 > [=A0=A0=A0 0.025289] Initmem setup node 2 [mem 0x000000ab00000000-0x000= 001033fffffff] > [=A0=A0=A0 0.025291] On node 2 totalpages: 89391104 > [=A0=A0=A0 0.025292]=A0=A0 Normal zone: 1445888 pages used for memmap > [=A0=A0=A0 0.025293]=A0=A0 Normal zone: 89391104 pages, LIFO batch:63 > [=A0=A0=A0 2.096982] ACPI: PM-Timer IO Port: 0x448 > [=A0=A0=A0 2.096987] ACPI: Local APIC address 0xfee00000 >=20