<div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr">Sure. Op counts and linux benchmarks are easy, I could try to get access to mac/windows too...<div><br></div><div>Building clang's HeaderSearch.cpp (without PCH) yields:</div><div>master: fstat = 341, open = 1039, stat = 211</div><div>openFile=false: fstat = 9 (-332), open = 379 (-660), stat = 1203 (+992)</div><div>revert: fstat = 341 (+0), open = 1039 (+0), stat = 211 (+0)</div><div>(this is on linux, but that shouldn't matter to the counts)</div><div><br></div><div>Timings on my workstation (-fsyntax-only, disk caches flushed, warmed up by running clang with no args):</div><div><div>master: 2.063</div><div>openFile=false patch: 1.953</div><div>revert: 1.946</div></div><div>(stdev is around 0.07)</div><div>So openFile=false a regression of 6% or so on linux, I don't think it's worth testing anything else :-\</div><div><br></div><div>Best plan I have now is:</div><div> - revert r347205, disable tests that this breaks</div><div> - cherrypick the revert to 8.0 branch</div><div> - reapply r347205 + a version of this patch where the openFile value is plumbed through, with false for the PCH case.</div><div>I'll send the revert out shortly. It should probably get reviewed since it won't be clean.</div><div>The final patch is going to be ugly, but there's time to come up with a better idea.</div></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, Jan 24, 2019 at 3:26 PM Nico Weber <<a href="mailto:thakis@chromium.org">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">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.<div><br></div><div>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.</div><div><br>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).</div><div><br>Since the openFile=false change might be a bit risky, maybe we should revert on 8.0 and do openFile=false only on trunk.</div></div></div><br><div class="gmail_quote"><div dir="ltr">On Thu, Jan 24, 2019 at 6:51 AM 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="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">So from my reading starting at getFileAndSuggestModule, changing to openFile=false is correct there unless some code is relying on that side effect.<div>All the tests pass, too.</div><div><br></div><div>The most likely regression is where we previously did open+fstat we'll now do stat+open+fstat.</div><div><br></div><div>I tried running three commands using your repro, counting stat/open/fstat by instrumenting Unix/Path.inc.</div><div>I used three versions of the code: old = before my patch, mid = with r347205, new = with r347205 and openFile=false.</div><div><br></div><div>Build PCH:</div><div> stat: 331 -> 331 -> 635</div><div> open: 316 -> 314 -> 316</div><div> fstat: 311 -> 311 -> 8</div><div><br></div><div>Use PCH:</div><div> stat: 322 -> 322 -> 924</div><div> open: 910 -> 609 -> 308</div><div> fstat: 607 -> 607 -> 5</div><div><br></div><div>No PCH:</div><div> stat: 16 -> 16 -> 617</div><div> open: 606 -> 606 -> 306</div><div> fstat: 604 -> 604 -> 3</div><div><br></div><div>Summary:</div><div> - 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.</div><div> - 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.</div><div> - 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.</div><div><br></div><div>So I'm tempted to check in the openFile=false.</div><div>It seems more internally consistent (passing openFile=true leaves the file open), and avoids breaking clangd.</div><div>It seems uninvasive, though as we've seen side-effects are hard to predict. Performance seems likely to be not-worse (vs reverting r347205).</div></div></div></div></div></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail_attr">On Thu, Jan 24, 2019 at 10:49 AM 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="ltr">Thanks for all the digging!<div>I can reproduce locally with your last example and ulimit -n 1000.<div><br><div>So it sounds like:<div> - 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)</div><div> - 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</div><div> - 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.</div><div> - nevertheless if I can't find a fairly safe fix soon then we'll need to revert this patch.</div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail_attr">On Wed, Jan 23, 2019 at 10:27 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>For completeness, in case the construction isn't clear, here's a full repro of the symptom.</div><div><br></div><div>$ cat pch.cc</div><div>$ cat pch.h</div><div>#include "foo.h"</div><div>$ rm bar/foo.h</div><div>$ for i in {1..300}; do echo '#include "foo'$i'.h"' >> bar/foo.h; done</div><div>$ for i in {1..300}; do touch bar/foo$i.h; done</div><div>$ cat client.cc</div><div>#include "bar/foo.h"</div><div>$ for i in {1..300}; do echo '#include "bar/foo'$i'.h"' >> client.cc; done</div><div><br></div><div>With today's trunk, on macOS:</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 /Ibar</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Yupch.h /FIpch.h client.cc /Ibar</div><div>client.cc(253,10): fatal error: 'bar/foo252.h' file not found</div><div>#include "bar/foo252.h"</div><div> ^~~~~~~~~~~~~~</div><div>1 error generated.</div></div><div><br></div><div>This works fine with this patch undone.</div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail_attr">On Wed, Jan 23, 2019 at 2:55 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">This might finally be a repro!<div><br></div><div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ ls bar</div><div>foo.h<span style="white-space:pre-wrap"> </span>foo2.h</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ type foo.h</div><div>-bash: type: foo.h: not found</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ ls bar</div><div>foo.h<span style="white-space:pre-wrap"> </span>foo2.h</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat bar/foo.h</div><div>#include "foo2.h"</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ cat bar/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 "bar/foo.h"</div><div>#include "bar/foo2.h"</div><div><br></div><div>#include "foo3.h"</div><div>Nicos-MacBook-Pro:llvm-mono-2 thakis$ out/gn/bin/clang-cl /c /Ycpch.h /FIpch.h pch.cc /Ibar</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>stat bar/foo.h 1</div><div>opened bar/foo.h</div><div>closing bar/foo.h</div><div>stat bar/foo2.h 1</div><div>opened bar/foo2.h</div><div>closing bar/foo2.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/bar/foo2.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/bar/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/bar/foo2.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/bar/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 ./bar/foo.h 1</div><div>opened ./bar/foo.h</div><div>closing ./bar/foo.h</div><div>stat /Users/thakis/src/llvm-mono-2/bar/foo2.h 1</div><div>opened /Users/thakis/src/llvm-mono-2/bar/foo2.h</div><div>closing /Users/thakis/src/llvm-mono-2/bar/foo2.h</div><div>stat ./bar/foo2.h 1</div><div>opened ./bar/foo2.h</div><div>stat ./foo3.h 1</div><div>opened ./foo3.h</div><div>closing ./foo3.h</div></div><div><br></div><div><br></div><div>Note how ./bar/foo2.h is opened in the 4th-to-last line but never closed. For comparision, with your patch reverted:</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 /Ibar</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>stat bar/foo.h 1</div><div>opened bar/foo.h</div><div>closing bar/foo.h</div><div>stat bar/foo2.h 1</div><div>opened bar/foo2.h</div><div>closing bar/foo2.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/bar/foo2.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/bar/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/bar/foo2.h 0</div><div>stat /Users/thakis/src/llvm-mono-2/bar/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 ./bar/foo.h 1</div><div>stat ./bar/foo2.h 1</div><div>stat ./foo3.h 1</div><div>opened ./foo3.h</div><div>closing ./foo3.h</div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail-m_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail-m_8817731855394060055gmail_attr">On Wed, Jan 23, 2019 at 2:21 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">On Wed, Jan 23, 2019 at 2:17 PM Nico Weber <<a href="mailto:thakis@chromium.org" target="_blank">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_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail-m_8817731855394060055gmail-m_-6452600705638845562gmail-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_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail-m_8817731855394060055gmail-m_-6452600705638845562gmail-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_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail-m_8817731855394060055gmail-m_-6452600705638845562gmail-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_399200357660786776gmail-m_6888106547505906819gmail-m_-6595287925759262957gmail-m_3791107178215721321gmail-m_-2241666347075897189gmail-m_8817731855394060055gmail-m_-6452600705638845562gmail-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>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>