-ftime-trace incorrect header hierarchy when a header contains a template function for his last symbol

[galop1n]

Using the repro case below, you will observe in the traces that 2.h shows up as an inclusion under 1.h instead of being an inclusion of main/cpp. The addition of a dummy forward declaration at the end of 1.h is a workaround to the problem and will yield the correct result with 2.h being under main.cpp. In both case, 3.h remains under 2.h accordingly.

• main.cpp

#include "1.h"
#include "2.h"
int foo();

• 1.h

#pragma once
#include <vector>
struct LARGE {};
template <typename T> auto Zero() -> T { return T{}; }
#if defined GUARD
struct guard;
#endif

• 2.h

#pragma once
#include "3.h"
#include <map>
struct Bla {};

• 3.h

#pragma once
#include <algorithm>
struct Foo {};

To produce the incorrect time trace : clang -ftime-trace main.cpp -c -o main-wrong.o
To produce the correct time trace : clang -DGUARD -ftime-trace main.cpp -c -o main-right.o

[MaggieYingYi]

Trimmed the test:

% cat main.cpp
#include "1.h"
#include "2.h"
int foo();

% cat 1.h
template <typename T> auto Zero() -> T { return T{}; }

%cat 2.h
struct Bla {};

Compile the code with -ftime-trace-granularity=0 -ftime-trace to show the issue:

prospero-clang -ftime-trace-granularity=0 -ftime-trace main.cpp -c -o main.o 

[MaggieYingYi]

Created D147520 for code review.

[llvmbot]

@llvm/issue-subscribers-clang-frontend

[MaskRay]

Compile the code with -ftime-trace-granularity=0 -ftime-trace to show the issue:

Hi, @MaggieYingYi Please can you edit the comment to elaborate what the issue is? I created a trace file with clang -ftime-trace-granularity=0 -ftime-trace and loaded it on ui.perfetto.dev, but I didn't find anything strange...

[MaskRay]

clang -c -ftime-trace -ftime-trace-granularity=0 main.cpp

Open the trace file main.json with https://ui.perfetto.dev/.
The "Source" 1.h interval ([ts,ts+dur)) contains "Source" 2.h's. This causes the two "Source" elements to be incorrectly nested.

In clang::Parser::ParseSingleDeclarationAfterTemplate, we have a RAII object llvm::TimeTraceScope TimeScope("ParseTemplate", ...).
When parsing the the end r_brace token of templated function definition (return ParseFunctionDefinition(DeclaratorInfo, TemplateInfo, &LateParsedAttrs);),
we consume the token and lex the next one. This action makes us reach the end of a file (clang/lib/Lex/Lexer.cpp return LexEndOfFile(Result, CurPtr-1);) and call llvm::timeTraceProfilerEnd();.
The call pops the back element, which is normally a "Source".
But in this case, the back element is actually a "ParseTemplate".
After 2.h is fully parsed, the llvm::TimeTraceScope TimeScope("ParseTemplate", ...) object for 1.h finally destructs and causes "Source" 1.h to be ended.

https://reviews.llvm.org/D147520 attempts to solve this bug by adding a workaround at the llvm/lib/Support/TimeProfiler.cpp level.
This feels wrong to me. I think we should fix it in clangParse or remove the ParseTemplate TimeTraceScope if this cannot be easily fixed.

[MaggieYingYi]

The issue came back again after the commit 33b85867e (PR-65268).

Failure is cause by the same reason as before, which is also mentioned in D148410.

Previously, we just removed the "ParseTemplate" TimeTraceScope to fix the issue.

I agree with @MaskRay, a proper fix requires complex codes.