r347205 - [FileManager] getFile(open=true) after getFile(open=false) should open the file.
Sam McCall via cfe-commits
cfe-commits at lists.llvm.org
Thu Jan 24 08:05:14 PST 2019
Sure. Op counts and linux benchmarks are easy, I could try to get access to
mac/windows too...
Building clang's HeaderSearch.cpp (without PCH) yields:
master: fstat = 341, open = 1039, stat = 211
openFile=false: fstat = 9 (-332), open = 379 (-660), stat = 1203 (+992)
revert: fstat = 341 (+0), open = 1039 (+0), stat = 211 (+0)
(this is on linux, but that shouldn't matter to the counts)
Timings on my workstation (-fsyntax-only, disk caches flushed, warmed up by
running clang with no args):
master: 2.063
openFile=false patch: 1.953
revert: 1.946
(stdev is around 0.07)
So openFile=false a regression of 6% or so on linux, I don't think it's
worth testing anything else :-\
Best plan I have now is:
- revert r347205, disable tests that this breaks
- cherrypick the revert to 8.0 branch
- reapply r347205 + a version of this patch where the openFile value is
plumbed through, with false for the PCH case.
I'll send the revert out shortly. It should probably get reviewed since it
won't be clean.
The final patch is going to be ugly, but there's time to come up with a
better idea.
On Thu, Jan 24, 2019 at 3:26 PM Nico Weber <thakis at chromium.org> wrote:
> Can you measure on macOS and Windows too, and maybe with a larger program?
> The open+fstat (instead of stat+open) optimization was I think done with
> benchmarking on macOS.
>
> I can see why you say you think the new behavior is more consistent, but
> it's basically changing what information goes into the getFile() cache key.
> Previously, openFile didn't go in there, and from that perspective saying
> "the cache keeps the openFile passed the first time you call this for a
> file" makes sense to me too.
>
> I'm happy with either before your patch or with getFileAndSuggestModule()
> passing openFile=false if perf is comparable (which I expect it to be, to
> be honest).
>
> Since the openFile=false change might be a bit risky, maybe we should
> revert on 8.0 and do openFile=false only on trunk.
>
> On Thu, Jan 24, 2019 at 6:51 AM Sam McCall <sammccall at google.com> wrote:
>
>> So from my reading starting at getFileAndSuggestModule, changing to
>> openFile=false is correct there unless some code is relying on that side
>> effect.
>> All the tests pass, too.
>>
>> The most likely regression is where we previously did open+fstat we'll
>> now do stat+open+fstat.
>>
>> I tried running three commands using your repro, counting stat/open/fstat
>> by instrumenting Unix/Path.inc.
>> I used three versions of the code: old = before my patch, mid = with
>> r347205, new = with r347205 and openFile=false.
>>
>> Build PCH:
>> stat: 331 -> 331 -> 635
>> open: 316 -> 314 -> 316
>> fstat: 311 -> 311 -> 8
>>
>> Use PCH:
>> stat: 322 -> 322 -> 924
>> open: 910 -> 609 -> 308
>> fstat: 607 -> 607 -> 5
>>
>> No PCH:
>> stat: 16 -> 16 -> 617
>> open: 606 -> 606 -> 306
>> fstat: 604 -> 604 -> 3
>>
>> Summary:
>> - r347205 was neutral for stats and fstats. It caused fewer files to be
>> opened when building a PCH (though failed to close the ones it did). It
>> caused file handles to leak when using a PCH.
>> - openFile=false reduces the number of files opened when compiling (with
>> or without PCH). It also changes most fstats to stats, which is a loss.
>> - compared to the original state, having both patches seems like a small
>> loss when building a PCH, and a small win when using one or compiling
>> without one.
>>
>> So I'm tempted to check in the openFile=false.
>> It seems more internally consistent (passing openFile=true leaves the
>> file open), and avoids breaking clangd.
>> It seems uninvasive, though as we've seen side-effects are hard to
>> predict. Performance seems likely to be not-worse (vs reverting r347205).
>>
>> On Thu, Jan 24, 2019 at 10:49 AM Sam McCall <sammccall at google.com> wrote:
>>
>>> Thanks for all the digging!
>>> I can reproduce locally with your last example and ulimit -n 1000.
>>>
>>> So it sounds like:
>>> - this *is* actually the interaction/behavior I expected from
>>> FileManager (we call first with openFile=false then with openFile=true, and
>>> the file is opened the second time)
>>> - the problem manifests because the file is opened but never closed, so
>>> we leak file descriptors, but closing the file would'nt be the best fix -
>>> we shouldn't open it if we don't need its content
>>> - I would call this a bug in the caller of file manager (in the stack
>>> we saw where getFileAndSuggestModule calls getFile), because it calls with
>>> openFile=true, but doesn't use the file contents nor ensure the file is
>>> closed. This was previously masked by the bug (fixed in my patch) where
>>> openFile=true could result in not opening the file.
>>> - nevertheless if I can't find a fairly safe fix soon then we'll need
>>> to revert this patch.
>>>
>>> On Wed, Jan 23, 2019 at 10:27 PM Nico Weber <thakis at chromium.org> wrote:
>>>
>>>> For completeness, in case the construction isn't clear, here's a full
>>>> repro of the symptom.
>>>>
>>>> $ cat pch.cc
>>>> $ cat pch.h
>>>> #include "foo.h"
>>>> $ rm bar/foo.h
>>>> $ for i in {1..300}; do echo '#include "foo'$i'.h"' >> bar/foo.h; done
>>>> $ for i in {1..300}; do touch bar/foo$i.h; done
>>>> $ cat client.cc
>>>> #include "bar/foo.h"
>>>> $ for i in {1..300}; do echo '#include "bar/foo'$i'.h"' >> client.cc;
>>>> done
>>>>
>>>> With today's trunk, on macOS:
>>>>
>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h
>>>> /FIpch.h pch.cc /Ibar
>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h
>>>> /FIpch.h client.cc /Ibar
>>>> client.cc(253,10): fatal error: 'bar/foo252.h' file not found
>>>> #include "bar/foo252.h"
>>>> ^~~~~~~~~~~~~~
>>>> 1 error generated.
>>>>
>>>> This works fine with this patch undone.
>>>>
>>>> On Wed, Jan 23, 2019 at 2:55 PM Nico Weber <thakis at chromium.org> wrote:
>>>>
>>>>> This might finally be a repro!
>>>>>
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ ls bar
>>>>> foo.h foo2.h
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ type foo.h
>>>>> -bash: type: foo.h: not found
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ ls bar
>>>>> foo.h foo2.h
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat bar/foo.h
>>>>> #include "foo2.h"
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat bar/foo2.h
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.h
>>>>> #include "foo.h"
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.cc
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat client.cc
>>>>> #include "bar/foo.h"
>>>>> #include "bar/foo2.h"
>>>>>
>>>>> #include "foo3.h"
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h
>>>>> /FIpch.h pch.cc /Ibar
>>>>> stat pch.cc 1
>>>>> opened pch.cc
>>>>> closing pch.cc
>>>>> stat ./pch.h 1
>>>>> opened ./pch.h
>>>>> closing ./pch.h
>>>>> stat ./foo.h 1
>>>>> stat bar/foo.h 1
>>>>> opened bar/foo.h
>>>>> closing bar/foo.h
>>>>> stat bar/foo2.h 1
>>>>> opened bar/foo2.h
>>>>> closing bar/foo2.h
>>>>> stat pch.cc 1
>>>>> opened pch.cc
>>>>> stat pch.pch 1
>>>>> opened pch.pch
>>>>> closing pch.pch
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>> closing /Users/thakis/src/llvm-mono-2/pch.cc
>>>>> stat ./pch.h 1
>>>>> opened ./pch.h
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h
>>>>> /FIpch.h client.cc
>>>>> stat client.cc 1
>>>>> opened client.cc
>>>>> stat pch.pch 1
>>>>> opened pch.pch
>>>>> closing pch.pch
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>> closing client.cc
>>>>> stat ./pch.h 1
>>>>> opened ./pch.h
>>>>> stat ./bar/foo.h 1
>>>>> opened ./bar/foo.h
>>>>> closing ./bar/foo.h
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 1
>>>>> opened /Users/thakis/src/llvm-mono-2/bar/foo2.h
>>>>> closing /Users/thakis/src/llvm-mono-2/bar/foo2.h
>>>>> stat ./bar/foo2.h 1
>>>>> opened ./bar/foo2.h
>>>>> stat ./foo3.h 1
>>>>> opened ./foo3.h
>>>>> closing ./foo3.h
>>>>>
>>>>>
>>>>> Note how ./bar/foo2.h is opened in the 4th-to-last line but never
>>>>> closed. For comparision, with your patch reverted:
>>>>>
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h
>>>>> /FIpch.h pch.cc /Ibar
>>>>> stat pch.cc 1
>>>>> opened pch.cc
>>>>> closing pch.cc
>>>>> stat ./pch.h 1
>>>>> opened ./pch.h
>>>>> closing ./pch.h
>>>>> stat ./foo.h 1
>>>>> stat bar/foo.h 1
>>>>> opened bar/foo.h
>>>>> closing bar/foo.h
>>>>> stat bar/foo2.h 1
>>>>> opened bar/foo2.h
>>>>> closing bar/foo2.h
>>>>> stat pch.cc 1
>>>>> opened pch.cc
>>>>> stat pch.pch 1
>>>>> opened pch.pch
>>>>> closing pch.pch
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>> closing /Users/thakis/src/llvm-mono-2/pch.cc
>>>>> stat ./pch.h 1
>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h
>>>>> /FIpch.h client.cc
>>>>> stat client.cc 1
>>>>> opened client.cc
>>>>> stat pch.pch 1
>>>>> opened pch.pch
>>>>> closing pch.pch
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/bar/foo.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>> closing client.cc
>>>>> stat ./pch.h 1
>>>>> stat ./bar/foo.h 1
>>>>> stat ./bar/foo2.h 1
>>>>> stat ./foo3.h 1
>>>>> opened ./foo3.h
>>>>> closing ./foo3.h
>>>>>
>>>>> On Wed, Jan 23, 2019 at 2:21 PM Nico Weber <thakis at chromium.org>
>>>>> wrote:
>>>>>
>>>>>> On Wed, Jan 23, 2019 at 2:17 PM Nico Weber <thakis at chromium.org>
>>>>>> wrote:
>>>>>>
>>>>>>> Here's what I think is a repro:
>>>>>>>
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat foo.h
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat foo2.h
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.h
>>>>>>> #include "foo.h"
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.cc
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat client.cc
>>>>>>> #include "foo2.h"
>>>>>>> #include "foo.h"
>>>>>>>
>>>>>>> #include "foo2.h"
>>>>>>> #include "foo.h"
>>>>>>>
>>>>>>> Then just build pch.cc with a pch file, and then use it (you can do
>>>>>>> this on any OS; you could also use the gcc style driver if you prefer it).
>>>>>>>
>>>>>>> The following output is with your change reverted, I added
>>>>>>>
>>>>>>> fprintf(stderr, "stat %s %d\n", Filename.str().c_str(), openFile);
>>>>>>>
>>>>>>> right before the call to getStatValue() in getFile, and
>>>>>>>
>>>>>>> if (openFile) fprintf(stderr, "opened %s\n", Filename.str().c_str());
>>>>>>> UFE.File = std::move(F);
>>>>>>>
>>>>>>> at the very bottom of that function, and changed getBufferForFile()
>>>>>>> to have
>>>>>>>
>>>>>>> if (ShouldCloseOpenFile) {
>>>>>>> fprintf(stderr, "closing %s\n", Entry->getName().str().c_str());
>>>>>>> Entry->closeFile();
>>>>>>> }
>>>>>>>
>>>>>>>
>>>>>>> The output is:
>>>>>>>
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c
>>>>>>> /Ycpch.h /FIpch.h pch.cc
>>>>>>> stat pch.cc 1
>>>>>>> opened pch.cc
>>>>>>> closing pch.cc
>>>>>>> stat ./pch.h 1
>>>>>>> opened ./pch.h
>>>>>>> closing ./pch.h
>>>>>>> stat ./foo.h 1
>>>>>>> opened ./foo.h
>>>>>>> closing ./foo.h
>>>>>>> stat pch.cc 1
>>>>>>> opened pch.cc
>>>>>>> stat pch.pch 1
>>>>>>> opened pch.pch
>>>>>>> closing pch.pch
>>>>>>> stat /Users/thakis/src/llvm-mono-2/foo.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>>>> closing /Users/thakis/src/llvm-mono-2/pch.cc
>>>>>>> stat ./pch.h 1
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c
>>>>>>> /Yupch.h /FIpch.h client.cc
>>>>>>> stat client.cc 1
>>>>>>> opened client.cc
>>>>>>> stat pch.pch 1
>>>>>>> opened pch.pch
>>>>>>> closing pch.pch
>>>>>>> stat /Users/thakis/src/llvm-mono-2/foo.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>>>> closing client.cc
>>>>>>> stat ./pch.h 1
>>>>>>> stat ./foo2.h 1
>>>>>>> opened ./foo2.h
>>>>>>> closing ./foo2.h
>>>>>>> stat ./foo.h 1
>>>>>>>
>>>>>>>
>>>>>>> Note how foo.h at the end is stat'd with openFile = 1, but we don't
>>>>>>> keep that file handle around.
>>>>>>>
>>>>>>> Now with your patch applied, where put the
>>>>>>>
>>>>>>> if (openFile) fprintf(stderr, "opened %s\n", Filename.str().c_str());
>>>>>>> UFE.File = std::move(F);
>>>>>>>
>>>>>>> print in the block you moved up.
>>>>>>>
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c
>>>>>>> /Ycpch.h /FIpch.h pch.cc
>>>>>>> stat pch.cc 1
>>>>>>> opened pch.cc
>>>>>>> closing pch.cc
>>>>>>> stat ./pch.h 1
>>>>>>> opened ./pch.h
>>>>>>> closing ./pch.h
>>>>>>> stat ./foo.h 1
>>>>>>> opened ./foo.h
>>>>>>> closing ./foo.h
>>>>>>> stat pch.cc 1
>>>>>>> opened pch.cc
>>>>>>> stat pch.pch 1
>>>>>>> opened pch.pch
>>>>>>> closing pch.pch
>>>>>>> stat /Users/thakis/src/llvm-mono-2/foo.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>>>> closing /Users/thakis/src/llvm-mono-2/pch.cc
>>>>>>> stat ./pch.h 1
>>>>>>> opened ./pch.h
>>>>>>> Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c
>>>>>>> /Yupch.h /FIpch.h client.cc
>>>>>>> stat client.cc 1
>>>>>>> opened client.cc
>>>>>>> stat pch.pch 1
>>>>>>> opened pch.pch
>>>>>>> closing pch.pch
>>>>>>> stat /Users/thakis/src/llvm-mono-2/foo.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.h 0
>>>>>>> stat /Users/thakis/src/llvm-mono-2/pch.cc 0
>>>>>>> closing client.cc
>>>>>>> stat ./pch.h 1
>>>>>>> opened ./pch.h
>>>>>>> stat ./foo2.h 1
>>>>>>> opened ./foo2.h
>>>>>>> closing ./foo2.h
>>>>>>> stat ./foo.h 1
>>>>>>> opened ./foo.h
>>>>>>> closing ./foo.h
>>>>>>>
>>>>>>>
>>>>>>> Notice how pch.pch gets opened twice but never closed in the version
>>>>>>> with your patch.
>>>>>>>
>>>>>>
>>>>>> Sorry, I mean pch.h. But that's probably just from the /FI flag.
>>>>>> While this is an example of a file that's opened and not closed with your
>>>>>> patch, it'd be nice to have a repro that shows this from an #include line,
>>>>>> not from an /FI flag. Let me look at this a bit more. Sorry for the noise.
>>>>>>
>>>>>>
>>>>>>> I think this is enough to show that your patch is introducing
>>>>>>> assumptions made by clang's PCH code. Even though the issue isn't
>>>>>>> understood in detail, this is imho enough to revert and fix and debug
>>>>>>> async, unless you're able to fix very quickly.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On Wed, Jan 23, 2019 at 1:23 PM Nico Weber <thakis at chromium.org>
>>>>>>> wrote:
>>>>>>>
>>>>>>>> The way things worked before your patch is that getFile() calls for
>>>>>>>> headers that are loaded from a PCH file hit the early-ish return in
>>>>>>>>
>>>>>>>> if (UFE.isValid()) { // Already have an entry with this inode,
>>>>>>>> return it.
>>>>>>>>
>>>>>>>> The first stack I posted (with ReadControlBlock() in it) populates
>>>>>>>> this UniqueRealFiles cache, and then getFile() for includes in a pch when
>>>>>>>> called from the preprocessor just return "early", at least before the file
>>>>>>>> is opened. (Stack for that:
>>>>>>>>
>>>>>>>> (lldb) bt
>>>>>>>> * thread #1, queue = 'com.apple.main-thread', stop reason =
>>>>>>>> breakpoint 3.1
>>>>>>>> * frame #0: 0x000000010005a2cf
>>>>>>>> clang-cl`clang::FileManager::getFile(this=0x000000011200a190,
>>>>>>>> Filename=(Data =
>>>>>>>> "../../third_party/blink/renderer/core/layout/api/third_party/skia/include/core/SkPoint3.h/paint/third_party/skia/include/core/SkPoint3.hܲ?\x01",
>>>>>>>> Length = 89), openFile=true, CacheFailure=true) at FileManager.cpp:198
>>>>>>>> frame #1: 0x0000000102ca1cb2
>>>>>>>> clang-cl`clang::HeaderSearch::getFileAndSuggestModule(this=0x000000011282e600,
>>>>>>>> FileName=(Data =
>>>>>>>> "../../third_party/blink/renderer/core/layout/api/third_party/skia/include/core/SkPoint3.h/paint/third_party/skia/include/core/SkPoint3.hܲ?\x01",
>>>>>>>> Length = 89), IncludeLoc=(ID = 4980551), Dir=0x000000011071e500,
>>>>>>>> IsSystemHeaderDir=false, RequestingModule=0x0000000000000000,
>>>>>>>> SuggestedModule=0x00007fff5fbf9020) at HeaderSearch.cpp:313
>>>>>>>> frame #2: 0x0000000102ca37aa
>>>>>>>> clang-cl`clang::HeaderSearch::LookupFile(this=0x000000011282e600,
>>>>>>>> Filename=(Data = "third_party/skia/include/core/SkPoint3.h", Length = 40),
>>>>>>>> IncludeLoc=(ID = 4980551), isAngled=false, FromDir=0x0000000000000000,
>>>>>>>> CurDir=0x00007fff5fbf9848, Includers=ArrayRef<std::__1::pair<const
>>>>>>>> clang::FileEntry *, const clang::DirectoryEntry *> > @ 0x00007fff5fbf7c78,
>>>>>>>> SearchPath=0x00007fff5fbf9438, RelativePath=0x00007fff5fbf9028,
>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>> IsMapped=0x00007fff5fbf9857, SkipCache=false, BuildSystemModule=false) at
>>>>>>>> HeaderSearch.cpp:756
>>>>>>>> frame #3: 0x0000000102d01898
>>>>>>>> clang-cl`clang::Preprocessor::LookupFile(this=0x000000011282f618,
>>>>>>>> FilenameLoc=(ID = 4980551), Filename=(Data =
>>>>>>>> "third_party/skia/include/core/SkPoint3.h", Length = 40), isAngled=false,
>>>>>>>> FromDir=0x0000000000000000, FromFile=0x0000000000000000,
>>>>>>>> CurDir=0x00007fff5fbf9848, SearchPath=0x00007fff5fbf9438,
>>>>>>>> RelativePath=0x00007fff5fbf9028, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>> IsMapped=0x00007fff5fbf9857, SkipCache=false) at PPDirectives.cpp:740
>>>>>>>> frame #4: 0x0000000102d033c4
>>>>>>>> clang-cl`clang::Preprocessor::HandleIncludeDirective(this=0x000000011282f618,
>>>>>>>> HashLoc=(ID = 4980542), IncludeTok=0x000000011180a810,
>>>>>>>> LookupFrom=0x0000000000000000, LookupFromFile=0x0000000000000000,
>>>>>>>> isImport=false) at PPDirectives.cpp:1773
>>>>>>>> frame #5: 0x0000000102d05e3a
>>>>>>>> clang-cl`clang::Preprocessor::HandleDirective(this=0x000000011282f618,
>>>>>>>> Result=0x000000011180a810) at PPDirectives.cpp:942
>>>>>>>> frame #6: 0x0000000102cbff1f
>>>>>>>> clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011bc567a0,
>>>>>>>> Result=0x000000011180a810, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931
>>>>>>>> frame #7: 0x0000000102cbc1b8
>>>>>>>> clang-cl`clang::Lexer::Lex(this=0x000000011bc567a0,
>>>>>>>> Result=0x000000011180a810) at Lexer.cpp:3152
>>>>>>>> frame #8: 0x0000000102d54dcb
>>>>>>>> clang-cl`clang::Preprocessor::Lex(this=0x000000011282f618,
>>>>>>>> Result=0x000000011180a810) at Preprocessor.cpp:868
>>>>>>>> frame #9: 0x0000000102f235f9
>>>>>>>> clang-cl`clang::Parser::ConsumeBrace(this=0x000000011180a800) at
>>>>>>>> Parser.h:563
>>>>>>>> frame #10: 0x0000000102f2a21a
>>>>>>>> clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa560)
>>>>>>>> at RAIIObjectsForParser.h:429
>>>>>>>> frame #11: 0x0000000102e788e5
>>>>>>>> clang-cl`clang::Parser::ParseInnerNamespace(this=0x000000011180a800,
>>>>>>>> InnerNSs=0x00007fff5fbfa6e0, index=0, InlineLoc=0x00007fff5fbfa7a0,
>>>>>>>> attrs=0x00007fff5fbfa6b8, Tracker=0x00007fff5fbfa560) at
>>>>>>>> ParseDeclCXX.cpp:250
>>>>>>>> frame #12: 0x0000000102e77dd6
>>>>>>>> clang-cl`clang::Parser::ParseNamespace(this=0x000000011180a800,
>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa70, InlineLoc=(ID = 0)) at
>>>>>>>> ParseDeclCXX.cpp:223
>>>>>>>> frame #13: 0x0000000102e5af29
>>>>>>>> clang-cl`clang::Parser::ParseDeclaration(this=0x000000011180a800,
>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa70, attrs=0x00007fff5fbfac40)
>>>>>>>> at ParseDecl.cpp:1714
>>>>>>>> frame #14: 0x0000000102f25dc3
>>>>>>>> clang-cl`clang::Parser::ParseExternalDeclaration(this=0x000000011180a800,
>>>>>>>> attrs=0x00007fff5fbfac40, DS=0x0000000000000000) at Parser.cpp:788
>>>>>>>> frame #15: 0x0000000102f24f06
>>>>>>>> clang-cl`clang::Parser::ParseTopLevelDecl(this=0x000000011180a800,
>>>>>>>> Result=0x00007fff5fbfad78) at Parser.cpp:609
>>>>>>>> frame #16: 0x0000000102e4a076
>>>>>>>> clang-cl`clang::ParseAST(S=0x00000001118fb600, PrintStats=true,
>>>>>>>> SkipFunctionBodies=false) at ParseAST.cpp:156
>>>>>>>> frame #17: 0x0000000100add312
>>>>>>>> clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x0000000112007eb0)
>>>>>>>> at FrontendAction.cpp:1035
>>>>>>>> frame #18: 0x00000001004f6cbd
>>>>>>>> clang-cl`clang::CodeGenAction::ExecuteAction(this=0x0000000112007eb0) at
>>>>>>>> CodeGenAction.cpp:1047
>>>>>>>> frame #19: 0x0000000100adc920
>>>>>>>> clang-cl`clang::FrontendAction::Execute(this=0x0000000112007eb0) at
>>>>>>>> FrontendAction.cpp:934
>>>>>>>> frame #20: 0x0000000100a4ce4e
>>>>>>>> clang-cl`clang::CompilerInstance::ExecuteAction(this=0x0000000112005f70,
>>>>>>>> Act=0x0000000112007eb0) at CompilerInstance.cpp:954
>>>>>>>> frame #21: 0x0000000100b5c25f
>>>>>>>> clang-cl`clang::ExecuteCompilerInvocation(Clang=0x0000000112005f70) at
>>>>>>>> ExecuteCompilerInvocation.cpp:267
>>>>>>>> frame #22: 0x0000000100001ab9
>>>>>>>> clang-cl`cc1_main(Argv=ArrayRef<const char *> @ 0x00007fff5fbfb4c8,
>>>>>>>> Argv0="../../../../llvm-mono-2/out/gn/bin/clang-cl",
>>>>>>>> MainAddr=0x0000000100028100) at cc1_main.cpp:218
>>>>>>>> frame #23: 0x000000010002998f
>>>>>>>> clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78,
>>>>>>>> Tool=(Data = "", Length = 0)) at driver.cpp:309
>>>>>>>> frame #24: 0x0000000100028a71 clang-cl`main(argc_=409,
>>>>>>>> argv_=0x00007fff5fbfd170) at driver.cpp:381
>>>>>>>> frame #25: 0x00007fffb015c235 libdyld.dylib`start + 1
>>>>>>>>
>>>>>>>> ).
>>>>>>>>
>>>>>>>>
>>>>>>>> After your patch, we open the file before that cache check, and
>>>>>>>> then open way more files, and don't the ones from the PCH for some reason.
>>>>>>>> Closing is normally happening in through
>>>>>>>>
>>>>>>>> Preprocessor::HandleIncludeDirective() ->
>>>>>>>> Preprocessor::EnterSourceFile() -> SourceManager::getBuffer() ->
>>>>>>>> ContentCache::getBuffer()
>>>>>>>> -> FileManager::getBufferForFile(ShouldCloseOpenFile)
>>>>>>>>
>>>>>>>> but apparently that's not getting called for headers from PCH files.
>>>>>>>>
>>>>>>>> On Wed, Jan 23, 2019 at 12:38 PM Nico Weber <thakis at chromium.org>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>>> Stacks for getFile() from PCH files look like so:
>>>>>>>>>
>>>>>>>>> (lldb) bt
>>>>>>>>> * thread #1, queue = 'com.apple.main-thread', stop reason =
>>>>>>>>> breakpoint 1.1
>>>>>>>>> * frame #0: 0x000000010005a1fb
>>>>>>>>> clang-cl`clang::FileManager::getFile(this=0x00000001106111f0,
>>>>>>>>> Filename=(Data =
>>>>>>>>> "/Users/thakis/src/chrome/src/out/gnwin/../../third_party/skia/include/core/SkPoint3.h",
>>>>>>>>> Length = 85), openFile=false, CacheFailure=true) at FileManager.cpp:187
>>>>>>>>> frame #1: 0x0000000103c44b2e
>>>>>>>>> clang-cl`clang::ASTReader::getInputFile(this=0x000000011104c200,
>>>>>>>>> F=0x000000011104fc00, ID=3, Complain=true) at ASTReader.cpp:2120
>>>>>>>>> frame #2: 0x0000000103c5173b
>>>>>>>>> clang-cl`clang::ASTReader::ReadControlBlock(this=0x000000011104c200,
>>>>>>>>> F=0x000000011104fc00, Loaded=0x00007fff5fbfa130,
>>>>>>>>> ImportedBy=0x0000000000000000, ClientLoadCapabilities=0) at
>>>>>>>>> ASTReader.cpp:2398
>>>>>>>>> frame #3: 0x0000000103c5381b
>>>>>>>>> clang-cl`clang::ASTReader::ReadASTCore(this=0x000000011104c200,
>>>>>>>>> FileName=(Data =
>>>>>>>>> "obj/third_party/blink/renderer/core/layout/layout_cc.pch", Length = 56),
>>>>>>>>> Type=MK_PCH, ImportLoc=(ID = 0), ImportedBy=0x0000000000000000,
>>>>>>>>> Loaded=0x00007fff5fbfa130, ExpectedSize=0, ExpectedModTime=0,
>>>>>>>>> ExpectedSignature=ASTFileSignature @ 0x00007fff5fbf9d58,
>>>>>>>>> ClientLoadCapabilities=0) at ASTReader.cpp:4208
>>>>>>>>> frame #4: 0x0000000103c5fe95
>>>>>>>>> clang-cl`clang::ASTReader::ReadAST(this=0x000000011104c200, FileName=(Data
>>>>>>>>> = "obj/third_party/blink/renderer/core/layout/layout_cc.pch", Length = 56),
>>>>>>>>> Type=MK_PCH, ImportLoc=(ID = 0), ClientLoadCapabilities=0,
>>>>>>>>> Imported=0x0000000000000000) at ASTReader.cpp:3883
>>>>>>>>> frame #5: 0x0000000100a49542
>>>>>>>>> clang-cl`clang::CompilerInstance::createPCHExternalASTSource(Path=(Data =
>>>>>>>>> "obj/third_party/blink/renderer/core/layout/layout_cc.pch", Length = 56),
>>>>>>>>> Sysroot=(Data = "/", Length = 1), DisablePCHValidation=false,
>>>>>>>>> AllowPCHWithCompilerErrors=false, PP=0x0000000111037e18,
>>>>>>>>> Context=0x0000000111042200, PCHContainerRdr=0x000000011060d2b0,
>>>>>>>>> Extensions=ArrayRef<std::__1::shared_ptr<clang::ModuleFileExtension> > @
>>>>>>>>> 0x00007fff5fbfa430, DependencyFile=0x0000000000000000,
>>>>>>>>> DependencyCollectors=ArrayRef<std::__1::shared_ptr<clang::DependencyCollector>
>>>>>>>>> > @ 0x00007fff5fbfa448, DeserializationListener=0x0000000000000000,
>>>>>>>>> OwnDeserializationListener=false, Preamble=false,
>>>>>>>>> UseGlobalModuleIndex=true) at CompilerInstance.cpp:532
>>>>>>>>> frame #6: 0x0000000100a4909b
>>>>>>>>> clang-cl`clang::CompilerInstance::createPCHExternalASTSource(this=0x000000011060d000,
>>>>>>>>> Path=(Data = "obj/third_party/blink/renderer/core/layout/layout_cc.pch",
>>>>>>>>> Length = 56), DisablePCHValidation=false, AllowPCHWithCompilerErrors=false,
>>>>>>>>> DeserializationListener=0x0000000000000000,
>>>>>>>>> OwnDeserializationListener=false) at CompilerInstance.cpp:490
>>>>>>>>> frame #7: 0x0000000100ada301
>>>>>>>>> clang-cl`clang::FrontendAction::BeginSourceFile(this=0x000000011060eee0,
>>>>>>>>> CI=0x000000011060d000, RealInput=0x0000000110614a60) at
>>>>>>>>> FrontendAction.cpp:859
>>>>>>>>> frame #8: 0x0000000100a4cdf8
>>>>>>>>> clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d000,
>>>>>>>>> Act=0x000000011060eee0) at CompilerInstance.cpp:953
>>>>>>>>> frame #9: 0x0000000100b5c21f
>>>>>>>>> clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d000) at
>>>>>>>>> ExecuteCompilerInvocation.cpp:267
>>>>>>>>> frame #10: 0x0000000100001ac9
>>>>>>>>> clang-cl`cc1_main(Argv=ArrayRef<const char *> @ 0x00007fff5fbfb4c8,
>>>>>>>>> Argv0="../../../../llvm-mono-2/out/gn/bin/clang-cl",
>>>>>>>>> MainAddr=0x0000000100028110) at cc1_main.cpp:218
>>>>>>>>> frame #11: 0x000000010002999f
>>>>>>>>> clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78,
>>>>>>>>> Tool=(Data = "", Length = 0)) at driver.cpp:309
>>>>>>>>> frame #12: 0x0000000100028a81 clang-cl`main(argc_=409,
>>>>>>>>> argv_=0x00007fff5fbfd170) at driver.cpp:381
>>>>>>>>> frame #13: 0x00007fffb015c235 libdyld.dylib`start + 1
>>>>>>>>>
>>>>>>>>> (lldb) bt
>>>>>>>>> * thread #1, queue = 'com.apple.main-thread', stop reason =
>>>>>>>>> breakpoint 1.1
>>>>>>>>> * frame #0: 0x000000010005a1fb
>>>>>>>>> clang-cl`clang::FileManager::getFile(this=0x00000001106111f0,
>>>>>>>>> Filename=(Data =
>>>>>>>>> "/Users/thakis/src/chrome/src/out/gnwin/../../third_party/skia/include/core/SkPoint3.h",
>>>>>>>>> Length = 85), openFile=false, CacheFailure=true) at FileManager.cpp:187
>>>>>>>>> frame #1: 0x0000000103c476e3
>>>>>>>>> clang-cl`clang::serialization::reader::HeaderFileInfoTrait::EqualKey(this=0x00007fff5fbf5f80,
>>>>>>>>> Key=0x00007fff5fbf6068)::$_1::operator()(clang::serialization::reader::HeaderFileInfoTrait::internal_key_type
>>>>>>>>> const&) const at ASTReader.cpp:1723
>>>>>>>>> frame #2: 0x0000000103c4759f
>>>>>>>>> clang-cl`clang::serialization::reader::HeaderFileInfoTrait::EqualKey(this=0x0000000113a16c88,
>>>>>>>>> a=0x00007fff5fbf6068, b=0x00007fff5fbf6138) at ASTReader.cpp:1726
>>>>>>>>> frame #3: 0x0000000103cd5c1e
>>>>>>>>> clang-cl`llvm::OnDiskChainedHashTable<clang::serialization::reader::HeaderFileInfoTrait>::find_hashed(this=0x0000000113a16c70,
>>>>>>>>> IKey=0x00007fff5fbf6138, KeyHash=986574196, InfoPtr=0x0000000113a16c88) at
>>>>>>>>> OnDiskHashTable.h:390
>>>>>>>>> frame #4: 0x0000000103cd59b8
>>>>>>>>> clang-cl`llvm::OnDiskChainedHashTable<clang::serialization::reader::HeaderFileInfoTrait>::find(this=0x0000000113a16c70,
>>>>>>>>> EKey=0x00007fff5fbf6538, InfoPtr=0x0000000000000000) at
>>>>>>>>> OnDiskHashTable.h:345
>>>>>>>>> frame #5: 0x0000000103cd58b9 clang-cl`(anonymous
>>>>>>>>> namespace)::HeaderFileInfoVisitor::operator(this=0x00007fff5fbf6538,
>>>>>>>>> M=0x000000011104fc00)(clang::serialization::ModuleFile&) at
>>>>>>>>> ASTReader.cpp:5683
>>>>>>>>> frame #6: 0x0000000103cd5850 clang-cl`bool
>>>>>>>>> llvm::function_ref<bool
>>>>>>>>> (clang::serialization::ModuleFile&)>::callback_fn<(anonymous
>>>>>>>>> namespace)::HeaderFileInfoVisitor>(callable=140734799766840,
>>>>>>>>> params=0x000000011104fc00) at STLExtras.h:125
>>>>>>>>> frame #7: 0x0000000103e338cc clang-cl`llvm::function_ref<bool
>>>>>>>>> (clang::serialization::ModuleFile&)>::operator(this=0x00007fff5fbf64a0,
>>>>>>>>> params=0x000000011104fc00)(clang::serialization::ModuleFile&) const at
>>>>>>>>> STLExtras.h:142
>>>>>>>>> frame #8: 0x0000000103e33507
>>>>>>>>> clang-cl`clang::serialization::ModuleManager::visit(this=0x000000011104c298,
>>>>>>>>> Visitor=function_ref<bool (clang::serialization::ModuleFile &)> @
>>>>>>>>> 0x00007fff5fbf64a0, ModuleFilesHit=0x0000000000000000)>,
>>>>>>>>> llvm::SmallPtrSetImpl<clang::serialization::ModuleFile*>*) at
>>>>>>>>> ModuleManager.cpp:411
>>>>>>>>> frame #9: 0x0000000103c69ade
>>>>>>>>> clang-cl`clang::ASTReader::GetHeaderFileInfo(this=0x000000011104c200,
>>>>>>>>> FE=0x0000000113a00030) at ASTReader.cpp:5698
>>>>>>>>> frame #10: 0x0000000103c69d03 clang-cl`non-virtual thunk to
>>>>>>>>> clang::ASTReader::GetHeaderFileInfo(this=0x000000011104c200,
>>>>>>>>> FE=0x0000000113a00030) at ASTReader.cpp:0
>>>>>>>>> frame #11: 0x0000000102ca607c
>>>>>>>>> clang-cl`clang::HeaderSearch::getExistingFileInfo(this=0x0000000111036e00,
>>>>>>>>> FE=0x0000000113a00030, WantExternal=true) const at HeaderSearch.cpp:1140
>>>>>>>>> frame #12: 0x0000000102ca6faf
>>>>>>>>> clang-cl`clang::HeaderSearch::findModuleForHeader(this=0x0000000111036e00,
>>>>>>>>> File=0x0000000113a00030, AllowTextual=true) const at HeaderSearch.cpp:1334
>>>>>>>>> frame #13: 0x0000000102ca700a
>>>>>>>>> clang-cl`suggestModule(HS=0x0000000111036e00, File=0x0000000113a00030,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020) at
>>>>>>>>> HeaderSearch.cpp:1343
>>>>>>>>> frame #14: 0x0000000102ca1dd2
>>>>>>>>> clang-cl`clang::HeaderSearch::findUsableModuleForHeader(this=0x0000000111036e00,
>>>>>>>>> File=0x0000000113a00030, Root=0x00000001106126d0,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>>> IsSystemHeaderDir=false) at HeaderSearch.cpp:1367
>>>>>>>>> frame #15: 0x0000000102ca1cee
>>>>>>>>> clang-cl`clang::HeaderSearch::getFileAndSuggestModule(this=0x0000000111036e00,
>>>>>>>>> FileName=(Data = "../../third_party/skia/include/core/SkPoint3.h", Length =
>>>>>>>>> 46), IncludeLoc=(ID = 4980551), Dir=0x00000001106126d0,
>>>>>>>>> IsSystemHeaderDir=false, RequestingModule=0x0000000000000000,
>>>>>>>>> SuggestedModule=0x00007fff5fbf9020) at HeaderSearch.cpp:318
>>>>>>>>> frame #16: 0x0000000102ca20ad
>>>>>>>>> clang-cl`clang::DirectoryLookup::LookupFile(this=0x000000011060f1e0,
>>>>>>>>> Filename=0x00007fff5fbf7c20, HS=0x0000000111036e00, IncludeLoc=(ID =
>>>>>>>>> 4980551), SearchPath=0x00007fff5fbf9438, RelativePath=0x00007fff5fbf9028,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>>> InUserSpecifiedSystemFramework=0x00007fff5fbf763f,
>>>>>>>>> HasBeenMapped=0x00007fff5fbf763e, MappedName=0x00007fff5fbf7640) const at
>>>>>>>>> HeaderSearch.cpp:357
>>>>>>>>> frame #17: 0x0000000102ca3e15
>>>>>>>>> clang-cl`clang::HeaderSearch::LookupFile(this=0x0000000111036e00,
>>>>>>>>> Filename=(Data = "third_party/skia/include/core/SkPoint3.h", Length = 40),
>>>>>>>>> IncludeLoc=(ID = 4980551), isAngled=false, FromDir=0x0000000000000000,
>>>>>>>>> CurDir=0x00007fff5fbf9848, Includers=ArrayRef<std::__1::pair<const
>>>>>>>>> clang::FileEntry *, const clang::DirectoryEntry *> > @ 0x00007fff5fbf7c78,
>>>>>>>>> SearchPath=0x00007fff5fbf9438, RelativePath=0x00007fff5fbf9028,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>>> IsMapped=0x00007fff5fbf9857, SkipCache=false, BuildSystemModule=false) at
>>>>>>>>> HeaderSearch.cpp:854
>>>>>>>>> frame #18: 0x0000000102d01858
>>>>>>>>> clang-cl`clang::Preprocessor::LookupFile(this=0x0000000111037e18,
>>>>>>>>> FilenameLoc=(ID = 4980551), Filename=(Data =
>>>>>>>>> "third_party/skia/include/core/SkPoint3.h", Length = 40), isAngled=false,
>>>>>>>>> FromDir=0x0000000000000000, FromFile=0x0000000000000000,
>>>>>>>>> CurDir=0x00007fff5fbf9848, SearchPath=0x00007fff5fbf9438,
>>>>>>>>> RelativePath=0x00007fff5fbf9028, SuggestedModule=0x00007fff5fbf9020,
>>>>>>>>> IsMapped=0x00007fff5fbf9857, SkipCache=false) at PPDirectives.cpp:740
>>>>>>>>> frame #19: 0x0000000102d03384
>>>>>>>>> clang-cl`clang::Preprocessor::HandleIncludeDirective(this=0x0000000111037e18,
>>>>>>>>> HashLoc=(ID = 4980542), IncludeTok=0x000000011080ac10,
>>>>>>>>> LookupFrom=0x0000000000000000, LookupFromFile=0x0000000000000000,
>>>>>>>>> isImport=false) at PPDirectives.cpp:1773
>>>>>>>>> frame #20: 0x0000000102d05dfa
>>>>>>>>> clang-cl`clang::Preprocessor::HandleDirective(this=0x0000000111037e18,
>>>>>>>>> Result=0x000000011080ac10) at PPDirectives.cpp:942
>>>>>>>>> frame #21: 0x0000000102cbfedf
>>>>>>>>> clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011a6f1430,
>>>>>>>>> Result=0x000000011080ac10, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931
>>>>>>>>> frame #22: 0x0000000102cbc178
>>>>>>>>> clang-cl`clang::Lexer::Lex(this=0x000000011a6f1430,
>>>>>>>>> Result=0x000000011080ac10) at Lexer.cpp:3152
>>>>>>>>> frame #23: 0x0000000102d54d8b
>>>>>>>>> clang-cl`clang::Preprocessor::Lex(this=0x0000000111037e18,
>>>>>>>>> Result=0x000000011080ac10) at Preprocessor.cpp:868
>>>>>>>>> frame #24: 0x0000000102f235b9
>>>>>>>>> clang-cl`clang::Parser::ConsumeBrace(this=0x000000011080ac00) at
>>>>>>>>> Parser.h:563
>>>>>>>>> frame #25: 0x0000000102f2a1da
>>>>>>>>> clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa560)
>>>>>>>>> at RAIIObjectsForParser.h:429
>>>>>>>>> frame #26: 0x0000000102e788a5
>>>>>>>>> clang-cl`clang::Parser::ParseInnerNamespace(this=0x000000011080ac00,
>>>>>>>>> InnerNSs=0x00007fff5fbfa6e0, index=0, InlineLoc=0x00007fff5fbfa7a0,
>>>>>>>>> attrs=0x00007fff5fbfa6b8, Tracker=0x00007fff5fbfa560) at
>>>>>>>>> ParseDeclCXX.cpp:250
>>>>>>>>> frame #27: 0x0000000102e77d96
>>>>>>>>> clang-cl`clang::Parser::ParseNamespace(this=0x000000011080ac00,
>>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa70, InlineLoc=(ID = 0)) at
>>>>>>>>> ParseDeclCXX.cpp:223
>>>>>>>>> frame #28: 0x0000000102e5aee9
>>>>>>>>> clang-cl`clang::Parser::ParseDeclaration(this=0x000000011080ac00,
>>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa70, attrs=0x00007fff5fbfac40)
>>>>>>>>> at ParseDecl.cpp:1714
>>>>>>>>> frame #29: 0x0000000102f25d83
>>>>>>>>> clang-cl`clang::Parser::ParseExternalDeclaration(this=0x000000011080ac00,
>>>>>>>>> attrs=0x00007fff5fbfac40, DS=0x0000000000000000) at Parser.cpp:788
>>>>>>>>> frame #30: 0x0000000102f24ec6
>>>>>>>>> clang-cl`clang::Parser::ParseTopLevelDecl(this=0x000000011080ac00,
>>>>>>>>> Result=0x00007fff5fbfad78) at Parser.cpp:609
>>>>>>>>> frame #31: 0x0000000102e4a036
>>>>>>>>> clang-cl`clang::ParseAST(S=0x00000001108fba00, PrintStats=true,
>>>>>>>>> SkipFunctionBodies=false) at ParseAST.cpp:156
>>>>>>>>> frame #32: 0x0000000100add2d2
>>>>>>>>> clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x000000011060eee0)
>>>>>>>>> at FrontendAction.cpp:1035
>>>>>>>>> frame #33: 0x00000001004f6c7d
>>>>>>>>> clang-cl`clang::CodeGenAction::ExecuteAction(this=0x000000011060eee0) at
>>>>>>>>> CodeGenAction.cpp:1047
>>>>>>>>> frame #34: 0x0000000100adc8e0
>>>>>>>>> clang-cl`clang::FrontendAction::Execute(this=0x000000011060eee0) at
>>>>>>>>> FrontendAction.cpp:934
>>>>>>>>> frame #35: 0x0000000100a4ce0e
>>>>>>>>> clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d000,
>>>>>>>>> Act=0x000000011060eee0) at CompilerInstance.cpp:954
>>>>>>>>> frame #36: 0x0000000100b5c21f
>>>>>>>>> clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d000) at
>>>>>>>>> ExecuteCompilerInvocation.cpp:267
>>>>>>>>> frame #37: 0x0000000100001ac9
>>>>>>>>> clang-cl`cc1_main(Argv=ArrayRef<const char *> @ 0x00007fff5fbfb4c8,
>>>>>>>>> Argv0="../../../../llvm-mono-2/out/gn/bin/clang-cl",
>>>>>>>>> MainAddr=0x0000000100028110) at cc1_main.cpp:218
>>>>>>>>> frame #38: 0x000000010002999f
>>>>>>>>> clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78,
>>>>>>>>> Tool=(Data = "", Length = 0)) at driver.cpp:309
>>>>>>>>> frame #39: 0x0000000100028a81 clang-cl`main(argc_=409,
>>>>>>>>> argv_=0x00007fff5fbfd170) at driver.cpp:381
>>>>>>>>> frame #40: 0x00007fffb015c235 libdyld.dylib`start + 1
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> For regular includes they look like so:
>>>>>>>>>
>>>>>>>>> (lldb) bt
>>>>>>>>> * thread #1, queue = 'com.apple.main-thread', stop reason =
>>>>>>>>> breakpoint 1.1
>>>>>>>>> * frame #0: 0x0000000100059d29
>>>>>>>>> clang-cl`clang::FileManager::getStatValue(this=0x0000000110611270,
>>>>>>>>> Path=(Data =
>>>>>>>>> "../../third_party/blink/renderer/platform/scheduler/public/scheduling_lifecycle_state.h",
>>>>>>>>> Length = 87), Data=0x00007fff5fbf6640, isFile=true, F=0x00007fff5fbf6680)
>>>>>>>>> at FileManager.cpp:465
>>>>>>>>> frame #1: 0x000000010005a471
>>>>>>>>> clang-cl`clang::FileManager::getFile(this=0x0000000110611270,
>>>>>>>>> Filename=(Data =
>>>>>>>>> "../../third_party/blink/renderer/platform/scheduler/public/scheduling_lifecycle_state.h",
>>>>>>>>> Length = 87), openFile=true, CacheFailure=true) at FileManager.cpp:230
>>>>>>>>> frame #2: 0x0000000102ca1ca2
>>>>>>>>> clang-cl`clang::HeaderSearch::getFileAndSuggestModule(this=0x0000000111036e00,
>>>>>>>>> FileName=(Data =
>>>>>>>>> "../../third_party/blink/renderer/platform/scheduler/public/scheduling_lifecycle_state.h",
>>>>>>>>> Length = 87), IncludeLoc=(ID = 9004850), Dir=0x0000000110502730,
>>>>>>>>> IsSystemHeaderDir=false, RequestingModule=0x0000000000000000,
>>>>>>>>> SuggestedModule=0x00007fff5fbf9030) at HeaderSearch.cpp:313
>>>>>>>>> frame #3: 0x0000000102ca20dd
>>>>>>>>> clang-cl`clang::DirectoryLookup::LookupFile(this=0x0000000110503850,
>>>>>>>>> Filename=0x00007fff5fbf7c30, HS=0x0000000111036e00, IncludeLoc=(ID =
>>>>>>>>> 9004850), SearchPath=0x00007fff5fbf9448, RelativePath=0x00007fff5fbf9038,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9030,
>>>>>>>>> InUserSpecifiedSystemFramework=0x00007fff5fbf764f,
>>>>>>>>> HasBeenMapped=0x00007fff5fbf764e, MappedName=0x00007fff5fbf7650) const at
>>>>>>>>> HeaderSearch.cpp:357
>>>>>>>>> frame #4: 0x0000000102ca3e45
>>>>>>>>> clang-cl`clang::HeaderSearch::LookupFile(this=0x0000000111036e00,
>>>>>>>>> Filename=(Data =
>>>>>>>>> "third_party/blink/renderer/platform/scheduler/public/scheduling_lifecycle_state.h",
>>>>>>>>> Length = 81), IncludeLoc=(ID = 9004850), isAngled=false,
>>>>>>>>> FromDir=0x0000000000000000, CurDir=0x00007fff5fbf9858,
>>>>>>>>> Includers=ArrayRef<std::__1::pair<const clang::FileEntry *, const
>>>>>>>>> clang::DirectoryEntry *> > @ 0x00007fff5fbf7c88,
>>>>>>>>> SearchPath=0x00007fff5fbf9448, RelativePath=0x00007fff5fbf9038,
>>>>>>>>> RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9030,
>>>>>>>>> IsMapped=0x00007fff5fbf9867, SkipCache=false, BuildSystemModule=false) at
>>>>>>>>> HeaderSearch.cpp:854
>>>>>>>>> frame #5: 0x0000000102d01888
>>>>>>>>> clang-cl`clang::Preprocessor::LookupFile(this=0x0000000111037e18,
>>>>>>>>> FilenameLoc=(ID = 9004850), Filename=(Data =
>>>>>>>>> "third_party/blink/renderer/platform/scheduler/public/scheduling_lifecycle_state.h",
>>>>>>>>> Length = 81), isAngled=false, FromDir=0x0000000000000000,
>>>>>>>>> FromFile=0x0000000000000000, CurDir=0x00007fff5fbf9858,
>>>>>>>>> SearchPath=0x00007fff5fbf9448, RelativePath=0x00007fff5fbf9038,
>>>>>>>>> SuggestedModule=0x00007fff5fbf9030, IsMapped=0x00007fff5fbf9867,
>>>>>>>>> SkipCache=false) at PPDirectives.cpp:740
>>>>>>>>> frame #6: 0x0000000102d033b4
>>>>>>>>> clang-cl`clang::Preprocessor::HandleIncludeDirective(this=0x0000000111037e18,
>>>>>>>>> HashLoc=(ID = 9004841), IncludeTok=0x0000000115068810,
>>>>>>>>> LookupFrom=0x0000000000000000, LookupFromFile=0x0000000000000000,
>>>>>>>>> isImport=false) at PPDirectives.cpp:1773
>>>>>>>>> frame #7: 0x0000000102d05e2a
>>>>>>>>> clang-cl`clang::Preprocessor::HandleDirective(this=0x0000000111037e18,
>>>>>>>>> Result=0x0000000115068810) at PPDirectives.cpp:942
>>>>>>>>> frame #8: 0x0000000102cbff0f
>>>>>>>>> clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011d98b010,
>>>>>>>>> Result=0x0000000115068810, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931
>>>>>>>>> frame #9: 0x0000000102cbc1a8
>>>>>>>>> clang-cl`clang::Lexer::Lex(this=0x000000011d98b010,
>>>>>>>>> Result=0x0000000115068810) at Lexer.cpp:3152
>>>>>>>>> frame #10: 0x0000000102d54dbb
>>>>>>>>> clang-cl`clang::Preprocessor::Lex(this=0x0000000111037e18,
>>>>>>>>> Result=0x0000000115068810) at Preprocessor.cpp:868
>>>>>>>>> frame #11: 0x0000000102f235e9
>>>>>>>>> clang-cl`clang::Parser::ConsumeBrace(this=0x0000000115068800) at
>>>>>>>>> Parser.h:563
>>>>>>>>> frame #12: 0x0000000102f2a20a
>>>>>>>>> clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa570)
>>>>>>>>> at RAIIObjectsForParser.h:429
>>>>>>>>> frame #13: 0x0000000102e788d5
>>>>>>>>> clang-cl`clang::Parser::ParseInnerNamespace(this=0x0000000115068800,
>>>>>>>>> InnerNSs=0x00007fff5fbfa6f0, index=0, InlineLoc=0x00007fff5fbfa7b0,
>>>>>>>>> attrs=0x00007fff5fbfa6c8, Tracker=0x00007fff5fbfa570) at
>>>>>>>>> ParseDeclCXX.cpp:250
>>>>>>>>> frame #14: 0x0000000102e77dc6
>>>>>>>>> clang-cl`clang::Parser::ParseNamespace(this=0x0000000115068800,
>>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa80, InlineLoc=(ID = 0)) at
>>>>>>>>> ParseDeclCXX.cpp:223
>>>>>>>>> frame #15: 0x0000000102e5af19
>>>>>>>>> clang-cl`clang::Parser::ParseDeclaration(this=0x0000000115068800,
>>>>>>>>> Context=FileContext, DeclEnd=0x00007fff5fbfaa80, attrs=0x00007fff5fbfac50)
>>>>>>>>> at ParseDecl.cpp:1714
>>>>>>>>> frame #16: 0x0000000102f25db3
>>>>>>>>> clang-cl`clang::Parser::ParseExternalDeclaration(this=0x0000000115068800,
>>>>>>>>> attrs=0x00007fff5fbfac50, DS=0x0000000000000000) at Parser.cpp:788
>>>>>>>>> frame #17: 0x0000000102f24ef6
>>>>>>>>> clang-cl`clang::Parser::ParseTopLevelDecl(this=0x0000000115068800,
>>>>>>>>> Result=0x00007fff5fbfad88) at Parser.cpp:609
>>>>>>>>> frame #18: 0x0000000102e4a066
>>>>>>>>> clang-cl`clang::ParseAST(S=0x0000000115061a00, PrintStats=false,
>>>>>>>>> SkipFunctionBodies=false) at ParseAST.cpp:156
>>>>>>>>> frame #19: 0x0000000100add302
>>>>>>>>> clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x000000011060ef90)
>>>>>>>>> at FrontendAction.cpp:1035
>>>>>>>>> frame #20: 0x00000001004f6cad
>>>>>>>>> clang-cl`clang::CodeGenAction::ExecuteAction(this=0x000000011060ef90) at
>>>>>>>>> CodeGenAction.cpp:1047
>>>>>>>>> frame #21: 0x0000000100adc910
>>>>>>>>> clang-cl`clang::FrontendAction::Execute(this=0x000000011060ef90) at
>>>>>>>>> FrontendAction.cpp:934
>>>>>>>>> frame #22: 0x0000000100a4ce3e
>>>>>>>>> clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d050,
>>>>>>>>> Act=0x000000011060ef90) at CompilerInstance.cpp:954
>>>>>>>>> frame #23: 0x0000000100b5c24f
>>>>>>>>> clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d050) at
>>>>>>>>> ExecuteCompilerInvocation.cpp:267
>>>>>>>>> frame #24: 0x0000000100001b19
>>>>>>>>> clang-cl`cc1_main(Argv=ArrayRef<const char *> @ 0x00007fff5fbfb4d8,
>>>>>>>>> Argv0="../../../../llvm-mono-2/out/gn/bin/clang-cl",
>>>>>>>>> MainAddr=0x0000000100028160) at cc1_main.cpp:218
>>>>>>>>> frame #25: 0x00000001000299ef
>>>>>>>>> clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba88,
>>>>>>>>> Tool=(Data = "", Length = 0)) at driver.cpp:309
>>>>>>>>> frame #26: 0x0000000100028ad1 clang-cl`main(argc_=408,
>>>>>>>>> argv_=0x00007fff5fbfd188) at driver.cpp:381
>>>>>>>>> frame #27: 0x00007fffb015c235 libdyld.dylib`start + 1
>>>>>>>>> frame #28: 0x00007fffb015c235 libdyld.dylib`start + 1
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On Wed, Jan 23, 2019 at 12:10 PM Sam McCall <sammccall at google.com>
>>>>>>>>> wrote:
>>>>>>>>>
>>>>>>>>>> Thanks! given that we don't see an earlier stat, I guess these
>>>>>>>>>> files were being treated as virtual (file metadata deserialized from PCH).
>>>>>>>>>> Previously despite the open=true these never actually got opened, and that
>>>>>>>>>> worked fine.
>>>>>>>>>>
>>>>>>>>>> I'm away from my computer but will verify later tonight or in the
>>>>>>>>>> morning (CET) and try to find a fix. If it's not obvious, we should revert
>>>>>>>>>> the patch at least on the release branch.
>>>>>>>>>>
>>>>>>>>>> A stack trace at the relevant breakpoint might well be useful -
>>>>>>>>>> can't remember if there are lots of entry points here.
>>>>>>>>>>
>>>>>>>>>> Cheers, Sam
>>>>>>>>>>
>>>>>>>>>> On Wed, Jan 23, 2019, 16:38 Nico Weber <thakis at chromium.org
>>>>>>>>>> wrote:
>>>>>>>>>>
>>>>>>>>>>> With your patch reverted locally, at the same breakpoint I
>>>>>>>>>>> instead get
>>>>>>>>>>>
>>>>>>>>>>> $ lsof -p 95842 | wc -l
>>>>>>>>>>> 94
>>>>>>>>>>>
>>>>>>>>>>> So your patch seems to increase number of open file handles by
>>>>>>>>>>> ~260%.
>>>>>>>>>>>
>>>>>>>>>>> On Wed, Jan 23, 2019 at 10:27 AM Nico Weber <thakis at chromium.org>
>>>>>>>>>>> wrote:
>>>>>>>>>>>
>>>>>>>>>>>> On Wed, Jan 23, 2019 at 9:54 AM Sam McCall <
>>>>>>>>>>>> sammccall at google.com> wrote:
>>>>>>>>>>>>
>>>>>>>>>>>>> (Email is better than IRC if that's OK - I don't know this
>>>>>>>>>>>>> code that well so it takes me a while).
>>>>>>>>>>>>>
>>>>>>>>>>>>> Thanks, that's definitely interesting and not what I expected.
>>>>>>>>>>>>> I thought every call sequence r347205 changed the behavior of would have
>>>>>>>>>>>>> resulted in two calls to getStatValue().
>>>>>>>>>>>>> I guess the "pch"/"main" output is printed before the
>>>>>>>>>>>>> corresponding lines in run.sh?
>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> Correct.
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>> Weird that we don't get any output from building the PCH, but
>>>>>>>>>>>>> I don't know well how PCH builds work.
>>>>>>>>>>>>>
>>>>>>>>>>>>> > It looks like FS->getCurrentWorkingDirectory() is set
>>>>>>>>>>>>> yet FileSystemOpts.WorkingDir.empty() is also true. Is that expected?
>>>>>>>>>>>>> I think so. The FileManager and the VFS each have their own
>>>>>>>>>>>>> concept of working directory, I guess for historical reasons.
>>>>>>>>>>>>> Making use of the VFS one but not the FileManager one seems
>>>>>>>>>>>>> reasonable.
>>>>>>>>>>>>>
>>>>>>>>>>>>> So the weirdness is that FileSystemStatCache::get() is
>>>>>>>>>>>>> returning true (i.e. file doesn't exist), when the file does exist.
>>>>>>>>>>>>> Possibilities:
>>>>>>>>>>>>> 1) we're serving this result from the FileSystemStatCache (and
>>>>>>>>>>>>> maybe it's being poisoned in a PCH-related way somehow). Except as far as I
>>>>>>>>>>>>> can tell, FileSystemStatCache is always null (FileManager::setStateCache
>>>>>>>>>>>>> has no callers).
>>>>>>>>>>>>> 2) the FS.openFileForRead call failed (ultimately ::open, if
>>>>>>>>>>>>> FS is the real FS)
>>>>>>>>>>>>> 3) the OwnedFile->status() call failed (ultimately ::fstat)
>>>>>>>>>>>>> 4) I'm misreading the code somehow
>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> ::open() fails with errno == 24, EMFILE.
>>>>>>>>>>>>
>>>>>>>>>>>> This log statement here:
>>>>>>>>>>>>
>>>>>>>>>>>> diff --git a/clang/lib/Basic/FileSystemStatCache.cpp
>>>>>>>>>>>> b/clang/lib/Basic/FileSystemStatCache.cpp
>>>>>>>>>>>> index d29ebb750fc..63fc4780237 100644
>>>>>>>>>>>> --- a/clang/lib/Basic/FileSystemStatCache.cpp
>>>>>>>>>>>> +++ b/clang/lib/Basic/FileSystemStatCache.cpp
>>>>>>>>>>>> @@ -70,9 +70,13 @@ bool FileSystemStatCache::get(StringRef
>>>>>>>>>>>> Path, FileData &Data, bool isFile,
>>>>>>>>>>>> //
>>>>>>>>>>>> // Because of this, check to see if the file exists with
>>>>>>>>>>>> 'open'. If the
>>>>>>>>>>>> // open succeeds, use fstat to get the stat info.
>>>>>>>>>>>> - auto OwnedFile = FS.openFileForRead(Path);
>>>>>>>>>>>> + llvm::ErrorOr<std::unique_ptr<llvm::vfs::File>> OwnedFile =
>>>>>>>>>>>> + FS.openFileForRead(Path);
>>>>>>>>>>>>
>>>>>>>>>>>> if (!OwnedFile) {
>>>>>>>>>>>> +if (Path.endswith("scheduling_lifecycle_state.h")) {
>>>>>>>>>>>> +fprintf(stderr, "hmm failed %s\n",
>>>>>>>>>>>> OwnedFile.getError().message().c_str());
>>>>>>>>>>>> +}
>>>>>>>>>>>> // If the open fails, our "stat" fails.
>>>>>>>>>>>> R = CacheMissing;
>>>>>>>>>>>> } else {
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> causes clang to print "hmm failed Too many open files". That
>>>>>>>>>>>> path should maybe check if `OwnedFile.getError().value() == EMFILE &&
>>>>>>>>>>>> OwnedFile.getError().category() == std::generic_category()` on mac and
>>>>>>>>>>>> abort or diag or something more visible.
>>>>>>>>>>>>
>>>>>>>>>>>> `ulimit -n` on macOS is pretty small -- do you see how your
>>>>>>>>>>>> patch could cause clang to keep more file handles open?
>>>>>>>>>>>>
>>>>>>>>>>>> Here's how many files clang had open when I had a breakpoint in
>>>>>>>>>>>> that error path:
>>>>>>>>>>>>
>>>>>>>>>>>> $ lsof -p 91890 | wc -l
>>>>>>>>>>>> 343
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> Could you find out which of these is going on? Either running
>>>>>>>>>>>>> in a debugger or adding some similar printfs to FileSystemStatCache::get()
>>>>>>>>>>>>> should be doable.
>>>>>>>>>>>>> I'm also going to try to work out how the patch could have
>>>>>>>>>>>>> affected this, but new vs correct much easier for me to compare than new vs
>>>>>>>>>>>>> old...
>>>>>>>>>>>>>
>>>>>>>>>>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/cfe-commits/attachments/20190124/4a83d4da/attachment-0001.html>
More information about the cfe-commits
mailing list