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 <sammcc...@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 <tha...@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 <tha...@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 <tha...@chromium.org> wrote:
>>>
>>>> On Wed, Jan 23, 2019 at 2:17 PM Nico Weber <tha...@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 <tha...@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 <tha...@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 <sammcc...@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 <tha...@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 <tha...@chromium.org>
>>>>>>>>> wrote:
>>>>>>>>>
>>>>>>>>>> On Wed, Jan 23, 2019 at 9:54 AM Sam McCall <sammcc...@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...
>>>>>>>>>>>
>>>>>>>>>>
_______________________________________________
cfe-commits mailing list
cfe-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
