<div dir="ltr"><div dir="ltr">On Wed, Jan 23, 2019 at 2:17 PM Nico Weber <<a href="mailto:thakis@chromium.org">thakis@chromium.org</a>> wrote:<br></div><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr">Here's what I think is a repro:<div><br></div><div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat foo.h</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat foo2.h</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.h</div><div>#include "foo.h"</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat pch.cc</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat client.cc</div><div>#include "foo2.h"</div><div>#include "foo.h"</div><div><br></div><div>#include "foo2.h"</div><div>#include "foo.h"</div><div><br></div><div>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).</div><div><br>The following output is with your change reverted, I added </div><div><br></div><div><div>fprintf(stderr, "stat %s %d\n", Filename.str().c_str(), openFile);</div></div><div><br></div><div>right before the call to getStatValue() in getFile, and </div><div><br></div><div><div>if (openFile) fprintf(stderr, "opened %s\n", Filename.str().c_str());</div><div> UFE.File = std::move(F);</div></div><div><br></div><div>at the very bottom of that function, and changed getBufferForFile() to have</div><div><br><div> if (ShouldCloseOpenFile) {</div><div>fprintf(stderr, "closing %s\n", Entry->getName().str().c_str());</div><div> Entry->closeFile();</div><div>}</div></div><div><br></div><div><br></div><div>The output is:</div><div><br></div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h /FIpch.h pch.cc</div><div>stat pch.cc 1</div><div>opened pch.cc</div><div>closing pch.cc</div><div>stat ./pch.h 1</div><div>opened ./pch.h</div><div>closing ./pch.h</div><div>stat ./foo.h 1</div><div>opened ./foo.h</div><div>closing ./foo.h</div><div>stat pch.cc 1</div><div>opened pch.cc</div><div>stat pch.pch 1</div><div>opened pch.pch</div><div>closing pch.pch</div><div>stat /Users/thakis/src/llvm-mono-2/foo.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.cc 0</div><div>closing /Users/thakis/src/llvm-mono-2/pch.cc</div><div>stat ./pch.h 1</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h /FIpch.h client.cc </div><div>stat client.cc 1</div><div>opened client.cc</div><div>stat pch.pch 1</div><div>opened pch.pch</div><div>closing pch.pch</div><div>stat /Users/thakis/src/llvm-mono-2/foo.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.cc 0</div><div>closing client.cc</div><div>stat ./pch.h 1</div><div>stat ./foo2.h 1</div><div>opened ./foo2.h</div><div>closing ./foo2.h</div><div>stat ./foo.h 1</div></div><div><br></div><div><br></div><div>Note how foo.h at the end is stat'd with openFile = 1, but we don't keep that file handle around.</div><div><br></div><div>Now with your patch applied, where put the</div><div><br></div><div><div>if (openFile) fprintf(stderr, "opened %s\n", Filename.str().c_str());</div><div> UFE.File = std::move(F);</div></div><div><br></div><div>print in the block you moved up.</div><div><br></div><div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h /FIpch.h pch.cc</div><div>stat pch.cc 1</div><div>opened pch.cc</div><div>closing pch.cc</div><div>stat ./pch.h 1</div><div>opened ./pch.h</div><div>closing ./pch.h</div><div>stat ./foo.h 1</div><div>opened ./foo.h</div><div>closing ./foo.h</div><div>stat pch.cc 1</div><div>opened pch.cc</div><div>stat pch.pch 1</div><div>opened pch.pch</div><div>closing pch.pch</div><div>stat /Users/thakis/src/llvm-mono-2/foo.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.cc 0</div><div>closing /Users/thakis/src/llvm-mono-2/pch.cc</div><div>stat ./pch.h 1</div><div>opened ./pch.h</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h /FIpch.h client.cc </div><div>stat client.cc 1</div><div>opened client.cc</div><div>stat pch.pch 1</div><div>opened pch.pch</div><div>closing pch.pch</div><div>stat /Users/thakis/src/llvm-mono-2/foo.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/pch.cc 0</div><div>closing client.cc</div><div>stat ./pch.h 1</div><div>opened ./pch.h</div><div>stat ./foo2.h 1</div><div>opened ./foo2.h</div><div>closing ./foo2.h</div><div>stat ./foo.h 1</div><div>opened ./foo.h</div><div>closing ./foo.h</div></div><div><br></div><div><br></div><div>Notice how pch.pch gets opened twice but never closed in the version with your patch.</div></div></div></div></div></div></div></div></div></blockquote><div><br></div><div>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.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div>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.</div><div><br></div><div><br></div></div></div></div></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_6494235219790020627gmail_attr">On Wed, Jan 23, 2019 at 1:23 PM Nico Weber <<a href="mailto:thakis@chromium.org" target="_blank">thakis@chromium.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr">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<div><br></div><div><div> if (UFE.isValid()) { // Already have an entry with this inode, return it.</div></div><div><br></div><div>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:</div><div><br></div><div><div>(lldb) bt</div><div>* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 3.1</div><div> * 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</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> frame #5: 0x0000000102d05e3a clang-cl`clang::Preprocessor::HandleDirective(this=0x000000011282f618, Result=0x000000011180a810) at PPDirectives.cpp:942</div><div> frame #6: 0x0000000102cbff1f clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011bc567a0, Result=0x000000011180a810, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931</div><div> frame #7: 0x0000000102cbc1b8 clang-cl`clang::Lexer::Lex(this=0x000000011bc567a0, Result=0x000000011180a810) at Lexer.cpp:3152</div><div> frame #8: 0x0000000102d54dcb clang-cl`clang::Preprocessor::Lex(this=0x000000011282f618, Result=0x000000011180a810) at Preprocessor.cpp:868</div><div> frame #9: 0x0000000102f235f9 clang-cl`clang::Parser::ConsumeBrace(this=0x000000011180a800) at Parser.h:563</div><div> frame #10: 0x0000000102f2a21a clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa560) at RAIIObjectsForParser.h:429</div><div> frame #11: 0x0000000102e788e5 clang-cl`clang::Parser::ParseInnerNamespace(this=0x000000011180a800, InnerNSs=0x00007fff5fbfa6e0, index=0, InlineLoc=0x00007fff5fbfa7a0, attrs=0x00007fff5fbfa6b8, Tracker=0x00007fff5fbfa560) at ParseDeclCXX.cpp:250</div><div> frame #12: 0x0000000102e77dd6 clang-cl`clang::Parser::ParseNamespace(this=0x000000011180a800, Context=FileContext, DeclEnd=0x00007fff5fbfaa70, InlineLoc=(ID = 0)) at ParseDeclCXX.cpp:223</div><div> frame #13: 0x0000000102e5af29 clang-cl`clang::Parser::ParseDeclaration(this=0x000000011180a800, Context=FileContext, DeclEnd=0x00007fff5fbfaa70, attrs=0x00007fff5fbfac40) at ParseDecl.cpp:1714</div><div> frame #14: 0x0000000102f25dc3 clang-cl`clang::Parser::ParseExternalDeclaration(this=0x000000011180a800, attrs=0x00007fff5fbfac40, DS=0x0000000000000000) at Parser.cpp:788</div><div> frame #15: 0x0000000102f24f06 clang-cl`clang::Parser::ParseTopLevelDecl(this=0x000000011180a800, Result=0x00007fff5fbfad78) at Parser.cpp:609</div><div> frame #16: 0x0000000102e4a076 clang-cl`clang::ParseAST(S=0x00000001118fb600, PrintStats=true, SkipFunctionBodies=false) at ParseAST.cpp:156</div><div> frame #17: 0x0000000100add312 clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x0000000112007eb0) at FrontendAction.cpp:1035</div><div> frame #18: 0x00000001004f6cbd clang-cl`clang::CodeGenAction::ExecuteAction(this=0x0000000112007eb0) at CodeGenAction.cpp:1047</div><div> frame #19: 0x0000000100adc920 clang-cl`clang::FrontendAction::Execute(this=0x0000000112007eb0) at FrontendAction.cpp:934</div><div> frame #20: 0x0000000100a4ce4e clang-cl`clang::CompilerInstance::ExecuteAction(this=0x0000000112005f70, Act=0x0000000112007eb0) at CompilerInstance.cpp:954</div><div> frame #21: 0x0000000100b5c25f clang-cl`clang::ExecuteCompilerInvocation(Clang=0x0000000112005f70) at ExecuteCompilerInvocation.cpp:267</div><div> 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</div><div> frame #23: 0x000000010002998f clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78, Tool=(Data = "", Length = 0)) at driver.cpp:309</div><div> frame #24: 0x0000000100028a71 clang-cl`main(argc_=409, argv_=0x00007fff5fbfd170) at driver.cpp:381</div><div> frame #25: 0x00007fffb015c235 libdyld.dylib`start + 1</div></div><div><br></div><div>).</div><div><br></div><div><br></div><div>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</div><div><br></div><div>Preprocessor::HandleIncludeDirective() -> Preprocessor::EnterSourceFile() -> SourceManager::getBuffer() -> ContentCache::getBuffer() -> FileManager::getBufferForFile(ShouldCloseOpenFile)<br></div><div><br></div><div>but apparently that's not getting called for headers from PCH files.</div></div></div></div></div></div></div></div></div></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_6494235219790020627gmail-m_-2357291524176352923gmail_attr">On Wed, Jan 23, 2019 at 12:38 PM Nico Weber <<a href="mailto:thakis@chromium.org" target="_blank">thakis@chromium.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr">Stacks for getFile() from PCH files look like so:<div><br></div><div><div>(lldb) bt</div><div>* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1</div><div> * 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</div><div> frame #1: 0x0000000103c44b2e clang-cl`clang::ASTReader::getInputFile(this=0x000000011104c200, F=0x000000011104fc00, ID=3, Complain=true) at ASTReader.cpp:2120</div><div> frame #2: 0x0000000103c5173b clang-cl`clang::ASTReader::ReadControlBlock(this=0x000000011104c200, F=0x000000011104fc00, Loaded=0x00007fff5fbfa130, ImportedBy=0x0000000000000000, ClientLoadCapabilities=0) at ASTReader.cpp:2398</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> frame #7: 0x0000000100ada301 clang-cl`clang::FrontendAction::BeginSourceFile(this=0x000000011060eee0, CI=0x000000011060d000, RealInput=0x0000000110614a60) at FrontendAction.cpp:859</div><div> frame #8: 0x0000000100a4cdf8 clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d000, Act=0x000000011060eee0) at CompilerInstance.cpp:953</div><div> frame #9: 0x0000000100b5c21f clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d000) at ExecuteCompilerInvocation.cpp:267</div><div> 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</div><div> frame #11: 0x000000010002999f clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78, Tool=(Data = "", Length = 0)) at driver.cpp:309</div><div> frame #12: 0x0000000100028a81 clang-cl`main(argc_=409, argv_=0x00007fff5fbfd170) at driver.cpp:381</div><div> frame #13: 0x00007fffb015c235 libdyld.dylib`start + 1</div></div><div><br></div><div><div>(lldb) bt</div><div>* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1</div><div> * 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</div><div> 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</div><div> frame #2: 0x0000000103c4759f clang-cl`clang::serialization::reader::HeaderFileInfoTrait::EqualKey(this=0x0000000113a16c88, a=0x00007fff5fbf6068, b=0x00007fff5fbf6138) at ASTReader.cpp:1726</div><div> 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</div><div> frame #4: 0x0000000103cd59b8 clang-cl`llvm::OnDiskChainedHashTable<clang::serialization::reader::HeaderFileInfoTrait>::find(this=0x0000000113a16c70, EKey=0x00007fff5fbf6538, InfoPtr=0x0000000000000000) at OnDiskHashTable.h:345</div><div> frame #5: 0x0000000103cd58b9 clang-cl`(anonymous namespace)::HeaderFileInfoVisitor::operator(this=0x00007fff5fbf6538, M=0x000000011104fc00)(clang::serialization::ModuleFile&) at ASTReader.cpp:5683</div><div> 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</div><div> 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</div><div> 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</div><div> frame #9: 0x0000000103c69ade clang-cl`clang::ASTReader::GetHeaderFileInfo(this=0x000000011104c200, FE=0x0000000113a00030) at ASTReader.cpp:5698</div><div> frame #10: 0x0000000103c69d03 clang-cl`non-virtual thunk to clang::ASTReader::GetHeaderFileInfo(this=0x000000011104c200, FE=0x0000000113a00030) at ASTReader.cpp:0</div><div> frame #11: 0x0000000102ca607c clang-cl`clang::HeaderSearch::getExistingFileInfo(this=0x0000000111036e00, FE=0x0000000113a00030, WantExternal=true) const at HeaderSearch.cpp:1140</div><div> frame #12: 0x0000000102ca6faf clang-cl`clang::HeaderSearch::findModuleForHeader(this=0x0000000111036e00, File=0x0000000113a00030, AllowTextual=true) const at HeaderSearch.cpp:1334</div><div> frame #13: 0x0000000102ca700a clang-cl`suggestModule(HS=0x0000000111036e00, File=0x0000000113a00030, RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020) at HeaderSearch.cpp:1343</div><div> frame #14: 0x0000000102ca1dd2 clang-cl`clang::HeaderSearch::findUsableModuleForHeader(this=0x0000000111036e00, File=0x0000000113a00030, Root=0x00000001106126d0, RequestingModule=0x0000000000000000, SuggestedModule=0x00007fff5fbf9020, IsSystemHeaderDir=false) at HeaderSearch.cpp:1367</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> frame #20: 0x0000000102d05dfa clang-cl`clang::Preprocessor::HandleDirective(this=0x0000000111037e18, Result=0x000000011080ac10) at PPDirectives.cpp:942</div><div> frame #21: 0x0000000102cbfedf clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011a6f1430, Result=0x000000011080ac10, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931</div><div> frame #22: 0x0000000102cbc178 clang-cl`clang::Lexer::Lex(this=0x000000011a6f1430, Result=0x000000011080ac10) at Lexer.cpp:3152</div><div> frame #23: 0x0000000102d54d8b clang-cl`clang::Preprocessor::Lex(this=0x0000000111037e18, Result=0x000000011080ac10) at Preprocessor.cpp:868</div><div> frame #24: 0x0000000102f235b9 clang-cl`clang::Parser::ConsumeBrace(this=0x000000011080ac00) at Parser.h:563</div><div> frame #25: 0x0000000102f2a1da clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa560) at RAIIObjectsForParser.h:429</div><div> frame #26: 0x0000000102e788a5 clang-cl`clang::Parser::ParseInnerNamespace(this=0x000000011080ac00, InnerNSs=0x00007fff5fbfa6e0, index=0, InlineLoc=0x00007fff5fbfa7a0, attrs=0x00007fff5fbfa6b8, Tracker=0x00007fff5fbfa560) at ParseDeclCXX.cpp:250</div><div> frame #27: 0x0000000102e77d96 clang-cl`clang::Parser::ParseNamespace(this=0x000000011080ac00, Context=FileContext, DeclEnd=0x00007fff5fbfaa70, InlineLoc=(ID = 0)) at ParseDeclCXX.cpp:223</div><div> frame #28: 0x0000000102e5aee9 clang-cl`clang::Parser::ParseDeclaration(this=0x000000011080ac00, Context=FileContext, DeclEnd=0x00007fff5fbfaa70, attrs=0x00007fff5fbfac40) at ParseDecl.cpp:1714</div><div> frame #29: 0x0000000102f25d83 clang-cl`clang::Parser::ParseExternalDeclaration(this=0x000000011080ac00, attrs=0x00007fff5fbfac40, DS=0x0000000000000000) at Parser.cpp:788</div><div> frame #30: 0x0000000102f24ec6 clang-cl`clang::Parser::ParseTopLevelDecl(this=0x000000011080ac00, Result=0x00007fff5fbfad78) at Parser.cpp:609</div><div> frame #31: 0x0000000102e4a036 clang-cl`clang::ParseAST(S=0x00000001108fba00, PrintStats=true, SkipFunctionBodies=false) at ParseAST.cpp:156</div><div> frame #32: 0x0000000100add2d2 clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x000000011060eee0) at FrontendAction.cpp:1035</div><div> frame #33: 0x00000001004f6c7d clang-cl`clang::CodeGenAction::ExecuteAction(this=0x000000011060eee0) at CodeGenAction.cpp:1047</div><div> frame #34: 0x0000000100adc8e0 clang-cl`clang::FrontendAction::Execute(this=0x000000011060eee0) at FrontendAction.cpp:934</div><div> frame #35: 0x0000000100a4ce0e clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d000, Act=0x000000011060eee0) at CompilerInstance.cpp:954</div><div> frame #36: 0x0000000100b5c21f clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d000) at ExecuteCompilerInvocation.cpp:267</div><div> 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</div><div> frame #38: 0x000000010002999f clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba78, Tool=(Data = "", Length = 0)) at driver.cpp:309</div><div> frame #39: 0x0000000100028a81 clang-cl`main(argc_=409, argv_=0x00007fff5fbfd170) at driver.cpp:381</div><div> frame #40: 0x00007fffb015c235 libdyld.dylib`start + 1</div></div><div><br></div><div><br></div><div>For regular includes they look like so:</div><div><br></div><div><div>(lldb) bt</div><div>* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1</div><div> * 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</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> 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</div><div> frame #7: 0x0000000102d05e2a clang-cl`clang::Preprocessor::HandleDirective(this=0x0000000111037e18, Result=0x0000000115068810) at PPDirectives.cpp:942</div><div> frame #8: 0x0000000102cbff0f clang-cl`clang::Lexer::LexTokenInternal(this=0x000000011d98b010, Result=0x0000000115068810, TokAtPhysicalStartOfLine=true) at Lexer.cpp:3931</div><div> frame #9: 0x0000000102cbc1a8 clang-cl`clang::Lexer::Lex(this=0x000000011d98b010, Result=0x0000000115068810) at Lexer.cpp:3152</div><div> frame #10: 0x0000000102d54dbb clang-cl`clang::Preprocessor::Lex(this=0x0000000111037e18, Result=0x0000000115068810) at Preprocessor.cpp:868</div><div> frame #11: 0x0000000102f235e9 clang-cl`clang::Parser::ConsumeBrace(this=0x0000000115068800) at Parser.h:563</div><div> frame #12: 0x0000000102f2a20a clang-cl`clang::BalancedDelimiterTracker::consumeClose(this=0x00007fff5fbfa570) at RAIIObjectsForParser.h:429</div><div> frame #13: 0x0000000102e788d5 clang-cl`clang::Parser::ParseInnerNamespace(this=0x0000000115068800, InnerNSs=0x00007fff5fbfa6f0, index=0, InlineLoc=0x00007fff5fbfa7b0, attrs=0x00007fff5fbfa6c8, Tracker=0x00007fff5fbfa570) at ParseDeclCXX.cpp:250</div><div> frame #14: 0x0000000102e77dc6 clang-cl`clang::Parser::ParseNamespace(this=0x0000000115068800, Context=FileContext, DeclEnd=0x00007fff5fbfaa80, InlineLoc=(ID = 0)) at ParseDeclCXX.cpp:223</div><div> frame #15: 0x0000000102e5af19 clang-cl`clang::Parser::ParseDeclaration(this=0x0000000115068800, Context=FileContext, DeclEnd=0x00007fff5fbfaa80, attrs=0x00007fff5fbfac50) at ParseDecl.cpp:1714</div><div> frame #16: 0x0000000102f25db3 clang-cl`clang::Parser::ParseExternalDeclaration(this=0x0000000115068800, attrs=0x00007fff5fbfac50, DS=0x0000000000000000) at Parser.cpp:788</div><div> frame #17: 0x0000000102f24ef6 clang-cl`clang::Parser::ParseTopLevelDecl(this=0x0000000115068800, Result=0x00007fff5fbfad88) at Parser.cpp:609</div><div> frame #18: 0x0000000102e4a066 clang-cl`clang::ParseAST(S=0x0000000115061a00, PrintStats=false, SkipFunctionBodies=false) at ParseAST.cpp:156</div><div> frame #19: 0x0000000100add302 clang-cl`clang::ASTFrontendAction::ExecuteAction(this=0x000000011060ef90) at FrontendAction.cpp:1035</div><div> frame #20: 0x00000001004f6cad clang-cl`clang::CodeGenAction::ExecuteAction(this=0x000000011060ef90) at CodeGenAction.cpp:1047</div><div> frame #21: 0x0000000100adc910 clang-cl`clang::FrontendAction::Execute(this=0x000000011060ef90) at FrontendAction.cpp:934</div><div> frame #22: 0x0000000100a4ce3e clang-cl`clang::CompilerInstance::ExecuteAction(this=0x000000011060d050, Act=0x000000011060ef90) at CompilerInstance.cpp:954</div><div> frame #23: 0x0000000100b5c24f clang-cl`clang::ExecuteCompilerInvocation(Clang=0x000000011060d050) at ExecuteCompilerInvocation.cpp:267</div><div> 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</div><div> frame #25: 0x00000001000299ef clang-cl`ExecuteCC1Tool(argv=ArrayRef<const char *> @ 0x00007fff5fbfba88, Tool=(Data = "", Length = 0)) at driver.cpp:309</div><div> frame #26: 0x0000000100028ad1 clang-cl`main(argc_=408, argv_=0x00007fff5fbfd188) at driver.cpp:381</div><div> frame #27: 0x00007fffb015c235 libdyld.dylib`start + 1</div><div> frame #28: 0x00007fffb015c235 libdyld.dylib`start + 1</div></div><div><br></div><div><br></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_6494235219790020627gmail-m_-2357291524176352923gmail-m_-8713845311852917488gmail_attr">On Wed, Jan 23, 2019 at 12:10 PM Sam McCall <<a href="mailto:sammccall@google.com" target="_blank">sammccall@google.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="auto">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.<div dir="auto"><br></div><div dir="auto">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.</div><div dir="auto"><br></div><div dir="auto">A stack trace at the relevant breakpoint might well be useful - can't remember if there are lots of entry points here.</div><div dir="auto"><br></div><div dir="auto">Cheers, Sam</div></div><br><div class="gmail_quote"><div dir="ltr">On Wed, Jan 23, 2019, 16:38 Nico Weber <<a href="mailto:thakis@chromium.org" target="_blank">thakis@chromium.org</a> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr">With your patch reverted locally, at the same breakpoint I instead get<div><br></div><div><div>$ lsof -p 95842 | wc -l</div><div> 94</div></div><div><br></div><div>So your patch seems to increase number of open file handles by ~260%.</div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_6494235219790020627gmail-m_-2357291524176352923gmail-m_-8713845311852917488gmail-m_4107432976352932795m_3334640080678745290gmail_attr">On Wed, Jan 23, 2019 at 10:27 AM Nico Weber <<a href="mailto:thakis@chromium.org" rel="noreferrer" target="_blank">thakis@chromium.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr">On Wed, Jan 23, 2019 at 9:54 AM Sam McCall <<a href="mailto:sammccall@google.com" rel="noreferrer" target="_blank">sammccall@google.com</a>> wrote:<br></div><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div>(Email is better than IRC if that's OK - I don't know this code that well so it takes me a while).</div><div><br></div><div>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().</div><div>I guess the "pch"/"main" output is printed before the corresponding lines in run.sh?</div></div></div></div></blockquote><div><br></div><div>Correct.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div>Weird that we don't get any output from building the PCH, but I don't know well how PCH builds work.</div><div><br></div><div>> It looks like FS->getCurrentWorkingDirectory() is set yet FileSystemOpts.WorkingDir.empty() is also true. Is that expected?</div><div>I think so. The FileManager and the VFS each have their own concept of working directory, I guess for historical reasons.</div><div>Making use of the VFS one but not the FileManager one seems reasonable.</div><div><br></div><div>So the weirdness is that FileSystemStatCache::get() is returning true (i.e. file doesn't exist), when the file does exist.</div><div>Possibilities:</div><div>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).</div><div>2) the FS.openFileForRead call failed (ultimately ::open, if FS is the real FS)</div><div>3) the OwnedFile->status() call failed (ultimately ::fstat)</div><div>4) I'm misreading the code somehow</div></div></div></div></blockquote><div><br></div><div>::open() fails with errno == 24, EMFILE. </div><div><br></div><div>This log statement here:</div><div><br></div><div><div>diff --git a/clang/lib/Basic/FileSystemStatCache.cpp b/clang/lib/Basic/FileSystemStatCache.cpp</div><div>index d29ebb750fc..63fc4780237 100644</div><div>--- a/clang/lib/Basic/FileSystemStatCache.cpp</div><div>+++ b/clang/lib/Basic/FileSystemStatCache.cpp</div><div>@@ -70,9 +70,13 @@ bool FileSystemStatCache::get(StringRef Path, FileData &Data, bool isFile,</div><div> //</div><div> // Because of this, check to see if the file exists with 'open'. If the</div><div> // open succeeds, use fstat to get the stat info.</div><div>- auto OwnedFile = FS.openFileForRead(Path);</div><div>+ llvm::ErrorOr<std::unique_ptr<llvm::vfs::File>> OwnedFile =</div><div>+ FS.openFileForRead(Path);</div><div> </div><div> if (!OwnedFile) {</div><div>+if (Path.endswith("scheduling_lifecycle_state.h")) {</div><div>+fprintf(stderr, "hmm failed %s\n", OwnedFile.getError().message().c_str());</div><div>+}</div><div> // If the open fails, our "stat" fails.</div><div> R = CacheMissing;</div><div> } else {</div></div><div><br></div><div><br></div><div>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.</div><div><br></div><div>`ulimit -n` on macOS is pretty small -- do you see how your patch could cause clang to keep more file handles open?</div><div><br></div><div>Here's how many files clang had open when I had a breakpoint in that error path:</div><div><br></div><div><div>$ lsof -p 91890 | wc -l</div><div> 343</div></div><div><br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div><br></div><div>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.</div><div>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...</div></div></div></div>
</blockquote></div></div></div></div></div></div></div></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div></div>