Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1760157AbcCDVUC (ORCPT ); Fri, 4 Mar 2016 16:20:02 -0500 Received: from g4t3428.houston.hp.com ([15.201.208.56]:46375 "EHLO g4t3428.houston.hp.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1758796AbcCDVUA (ORCPT ); Fri, 4 Mar 2016 16:20:00 -0500 Message-ID: <1457129560.15454.266.camel@hpe.com> Subject: Re: runtime regression with "x86/mm/pat: Emulate PAT when it is disabled" From: Toshi Kani To: Paul Gortmaker Cc: Borislav Petkov , Richard Purdie , Toshi Kani , Bruce Ashfield , openembedded-core , "Hart, Darren" , "saul.wold" , linux-kernel@vger.kernel.org Date: Fri, 04 Mar 2016 15:12:40 -0700 In-Reply-To: <20160304183713.GA26051@windriver.com> References: <20160303205924.GA25222@windriver.com> <1457067768.15454.181.camel@hpe.com> <20160304183713.GA26051@windriver.com> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.18.4 (3.18.4-1.fc23) Mime-Version: 1.0 Content-Transfer-Encoding: 8bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 7156 Lines: 159 On Fri, 2016-03-04 at 13:37 -0500, Paul Gortmaker wrote: > [Re: runtime regression with "x86/mm/pat: Emulate PAT when it is > disabled"] On 03/03/2016 (Thu 22:02) Toshi Kani wrote: > > > On Thu, 2016-03-03 at 15:59 -0500, Paul Gortmaker wrote:  : > > > > > > The stand alone reproducer is here; launched in 00-runme: > > > > > > http://openlinux.wrs.com/pat-splat/reproducer.tar.bz2   > > > > > > It is nothing fancy, just a generic yocto build of "sato" (gfx > > > enabled rootfs).  When it "works" it boots to a UI touchscreen > > > interface.  When > > > it fails, you get a black screen with a blinking cursor (as seen in > > > "vncviewer localhost:0"). > > > > Thanks for tracking down, and packaging the reproducer.  I simply > > untar'd and ran 00-runme, but was not able to connect with localhost:0. > >  I am not familiar with qemu, so I have not looked into why, though... > > Maybe it was localhost:1 in your case?  The qemu should have indicated > what vncserver sessions it started.  Can you paste in the output from > the 00-runme?   I tested the reproducer on a machine that was physically > distinct from the build, and that was a generic ubuntu install, but with > no qemu support installed at all and it worked there.  Plus I got Bruce > to test it worked on his machine, so I'm rather surprised it did not > work for you. I am not really sure what I am doing is correct. On one window: # ./00-runme Warning: vlan 0 is not connected to host network VNC server running on '::1:5900' And another window on the same system: # vncviewer localhost:1 TigerVNC Viewer 64-bit v1.6.0 Built on: 2016-01-04 15:09 Copyright (C) 1999-2015 TigerVNC Team and many others (see README.txt) See http://www.tigervnc.org for information on TigerVNC. Can't open display:  > > Anyway, with regarding the error message: > >   "x86/PAT: Xorg:705 map pfn expected mapping type uncached-minus for > > [mem > > 0xfd000000-0xfdffffff], got write-combining" > > > > Did it came from the following path during fork()? > >  copy_process > >   copy_mm > >    dup_mm > >     dup_mmap > >      copy_page_range > >       track_pfn_copy > >        reserve_pfn_range > > The trace is consistent, and was already captured by Richard, as per: > > http://lists.openembedded.org/pipermail/openembedded-core/2016-March/1183 > 97.html > > which is the link given earlier.  When I say consistent, I mean that I > get essentially the same thing when booting 4.5-rc6: There are two issues here.  1. copy_process() failed in the check in reserve_pfn_range()  2. error path in copy_process() then hit WARN_ON_ONCE in untrack_pfn(). We are currently looking into #1, which Richard referred as: | It appears that Xorg mmaps this from userspace, then later does a | fork() to execute a utility. At this point, when creating the vmas for | the new process, the pat code says "eeek!" as the protection mode for | the new vmas don't match the old one, returns -EINVAL, the process dies | and X goes with it. Since it seemed that Richard had some analysis on #1, I wanted to confirm that the failure path of #1 was the above stack trace. The stack trace below shows the failure path of #2. > [   30.098100] x86/PAT: Xorg:509 map pfn expected mapping type uncached- > minus for [mem 0xfd000000-0xfdffffff], got write-combining > [   30.106782] ------------[ cut here ]------------ > [   30.107093] WARNING: CPU: 0 PID: 509 at /home/paul/poky/build/tmp- > glibc/work-shared/qemux86/kernel-source/arch/x86/mm/pat.c:986 > untrack_pfn+0x9f/0xb0() > [   30.112553] Modules linked in: 8021q parport_pc parport floppy uvesafb > [   30.113766] CPU: 0 PID: 509 Comm: Xorg Not tainted 4.5.0-rc6-yocto- > standard #1 > [   30.113806] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), > BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014 > [   30.114078]  00000000 00003286 c0149d78 c13a6c7f 00000000 00000000 > c0149dac c1052bcb > [   30.114214]  c1ac7544 00000000 000001fd c1ac1ea4 000003da c104cbdf > 000003da c104cbdf > [   30.114214]  00000000 cdcf0528 00000000 c0149dbc c1052ca2 00000009 > 00000000 c0149de0 > [   30.114214] Call Trace: > [   30.114214]  [] dump_stack+0x58/0x79 > [   30.114214]  [] warn_slowpath_common+0x8b/0xc0 > [   30.114214]  [] ? untrack_pfn+0x9f/0xb0 > [   30.114214]  [] ? untrack_pfn+0x9f/0xb0 > [   30.114214]  [] warn_slowpath_null+0x22/0x30 > [   30.114214]  [] untrack_pfn+0x9f/0xb0 > [   30.114214]  [] ? __kunmap_atomic+0x54/0x110 > [   30.114214]  [] unmap_single_vma+0x56f/0x580 > [   30.114214]  [] ? pagevec_move_tail_fn+0xa0/0xa0 > [   30.114214]  [] unmap_vmas+0x43/0x60 > [   30.114214]  [] exit_mmap+0x5f/0xf0 > [   30.114214]  [] mmput+0x2d/0xa0 > [   30.114214]  [] copy_process.part.47+0x1229/0x1430 > [   30.114214]  [] _do_fork+0xb4/0x3b0 > [   30.114214]  [] SyS_clone+0x2c/0x30 > [   30.114214]  [] do_syscall_32_irqs_on+0x54/0xb0 > [   30.114214]  [] entry_INT80_32+0x2a/0x2a > [   30.124383] ---[ end trace f7c8a5d94542f94e ]--- > > > > > If so, track_pfn_copy() obtained pgprot from a PTE, and called > > reserve_pfn_range() with it.  So, the error message indicates that > > previous ioremap_wc() (i.e. pcm WC) resulted in creating UC- map (i.e. > > pgprot UC-).  pcm is a logical cache type and pgprot is a HW cache > > type.  They can be different when CPU does not have support for a given > > logical type.  This WC to UC- conversion happens when CPU does not > > support PAT. > > > > Richard's change, which compares with pgprot values in > > reserve_pfn_range() is a good one, but I do not understand how we get > > into this mess.  We do not have this check when PAT is disabled, and WC > > is supported when PAT is enabled. > > > > Commit 9cd25aac1 changed the initial values of the pcm<->pgrot > > conversion tables.  The tables should be initialized with the same > > values after pat_init() is called.  Is there any possibility that > > ioremap_wc() was called before pat_init()..? > > I don't think it is an initcall ordering thing; recall that I said the > problem seems to go away when built-in vs uvesafb as module.  So given > that, I think it is more related to where the code lands. >From the failure, it looks as if pat_init() was not called at all, but I cannot explain how built-in vs module can make such difference.  > > Also, can you send me a whole dmesg output?  I'd like to check how PAT > > is initialized. > > I'll send the full file off list vs. spamming everyone with it.  I'm open > to booting the pre-fail commit with PAT specific bootargs and the post- > fail with the same and diffing the two dmesg if there are bootargs you'd > like me to test.  I'd also like to ensure you have a working reproducer > locally so maybe we should look at how that failed 1st. Great.  Yes, two dmesg will be really helpful. Thanks, -Toshi