Skip to content

Commit 11c876b

Browse files
authored
[Proton] Fix global time trace precision (#8309)
The current approach that converts global init time to `double` will introduce precision problem. Note that the global time read from the timer is a very larger `uint64` number, we should be very careful about the bits handling here. This PR carefully handles the bits to make output trace accurate with global time offset (like the figure). <img width="1650" height="602" alt="fine-grained-accurate" src="https://github.com/user-attachments/assets/ea752f3d-09d4-48a5-9264-9d6328da1736" />
1 parent c6ad34f commit 11c876b

File tree

3 files changed

+40
-20
lines changed

3 files changed

+40
-20
lines changed

third_party/proton/common/include/TraceDataIO/TraceWriter.h

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -50,7 +50,8 @@ class StreamChromeTraceWriter : public StreamTraceWriter {
5050
void write(std::ostream &outfile) override final;
5151

5252
private:
53-
void writeKernel(nlohmann::json &object, const KernelTrace &kernelTrace);
53+
void writeKernel(nlohmann::json &object, const KernelTrace &kernelTrace,
54+
const uint64_t minInitTime);
5455

5556
const std::vector<std::string> kChromeColor = {"cq_build_passed",
5657
"cq_build_failed",

third_party/proton/common/lib/TraceDataIO/TraceWriter.cpp

Lines changed: 32 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,21 @@
88
using namespace proton;
99
using json = nlohmann::json;
1010

11+
namespace {
12+
13+
uint64_t getMinInitTime(const std::vector<KernelTrace> &streamTrace) {
14+
uint64_t minInitTime = std::numeric_limits<uint64_t>::max();
15+
for (const auto &kernelTrace : streamTrace)
16+
for (const auto &bt : kernelTrace.first->blockTraces) {
17+
if (bt.initTime < minInitTime) {
18+
minInitTime = bt.initTime;
19+
}
20+
}
21+
return minInitTime;
22+
}
23+
24+
} // namespace
25+
1126
StreamTraceWriter::StreamTraceWriter(
1227
const std::vector<KernelTrace> &streamTrace, const std::string &path)
1328
: streamTrace(streamTrace), path(path) {}
@@ -43,8 +58,10 @@ void StreamChromeTraceWriter::write(std::ostream &outfile) {
4358

4459
json object = {{"displayTimeUnit", "ns"}, {"traceEvents", json::array()}};
4560

61+
const auto minInitTime = getMinInitTime(streamTrace);
62+
4663
for (const auto &kernelTrace : streamTrace) {
47-
writeKernel(object, kernelTrace);
64+
writeKernel(object, kernelTrace, minInitTime);
4865
}
4966
outfile << object.dump() << "\n";
5067
}
@@ -144,7 +161,8 @@ std::vector<int> assignLineIds(
144161
} // namespace
145162

146163
void StreamChromeTraceWriter::writeKernel(json &object,
147-
const KernelTrace &kernelTrace) {
164+
const KernelTrace &kernelTrace,
165+
const uint64_t minInitTime) {
148166
auto result = kernelTrace.first;
149167
auto metadata = kernelTrace.second;
150168

@@ -192,16 +210,17 @@ void StreamChromeTraceWriter::writeKernel(json &object,
192210
else
193211
name = metadata->scopeName.at(scopeId);
194212

195-
double freq = 1000; // Unit: MHz
196-
197-
double startCycle = event.first->cycle; // Unit: cycle
198-
double endCycle = event.second->cycle; // Unit: cycle
199-
double dur = (endCycle - startCycle) / freq; // Unit: us
213+
// Unit: MHz, we assume freq is 1000MHz (1GHz)
214+
double freq = 1000.0;
200215

201-
double startCycleRel =
202-
startCycle - blockToMinCycle[ctaId]; // Unit: cycle
203-
double startTimeRel = startCycleRel / freq; // Unit: us
204-
double ts = bt->initTime / 1e3 + startTimeRel; // Unit: us
216+
// Global time is in `ns` unit. With 1GHz assumption, we
217+
// could subtract with blockToMInCycle: (ns - ns) / 1GHz - cycle
218+
int64_t cycleAdjust =
219+
static_cast<int64_t>(bt->initTime - minInitTime) -
220+
static_cast<int64_t>(blockToMinCycle[ctaId]);
221+
int64_t ts = static_cast<int64_t>(event.first->cycle) + cycleAdjust;
222+
int64_t dur =
223+
static_cast<int64_t>(event.second->cycle) - event.first->cycle;
205224

206225
json element;
207226
element["cname"] = color;
@@ -210,8 +229,8 @@ void StreamChromeTraceWriter::writeKernel(json &object,
210229
element["ph"] = "X";
211230
element["pid"] = pid;
212231
element["tid"] = tid;
213-
element["ts"] = ts;
214-
element["dur"] = dur;
232+
element["ts"] = static_cast<double>(ts) / freq;
233+
element["dur"] = static_cast<double>(dur) / freq;
215234
json args;
216235
args["Finalization Time (ns)"] = bt->postFinalTime - bt->preFinalTime;
217236
args["Frequency (MHz)"] = freq;

third_party/proton/test/unittest/TraceDataIO/ChromeTraceWriterTest.cpp

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -97,8 +97,8 @@ TEST_F(ChromeTraceWriterTest, SingleBlock) {
9797
EXPECT_EQ(data["traceEvents"].size(), 2);
9898
EXPECT_EQ(data["traceEvents"][0]["name"], "s1");
9999
EXPECT_EQ(data["traceEvents"][1]["name"], "scope_7");
100-
EXPECT_EQ(data["traceEvents"][0]["ts"], 0.0);
101-
EXPECT_EQ(data["traceEvents"][1]["ts"], 0.1);
100+
EXPECT_DOUBLE_EQ(data["traceEvents"][0]["ts"], 0.0);
101+
EXPECT_DOUBLE_EQ(data["traceEvents"][1]["ts"], 0.1);
102102
}
103103

104104
TEST_F(ChromeTraceWriterTest, MultiBlockMultiWarp) {
@@ -202,10 +202,10 @@ TEST_F(ChromeTraceWriterTest, MultiKernel) {
202202

203203
EXPECT_EQ(data.empty(), false);
204204
EXPECT_EQ(data["traceEvents"][0]["cat"], "kernel1");
205-
EXPECT_EQ(data["traceEvents"][0]["ts"], 0.0);
206-
EXPECT_EQ(data["traceEvents"][0]["dur"], 400.0);
205+
EXPECT_DOUBLE_EQ(data["traceEvents"][0]["ts"], 0.0);
206+
EXPECT_DOUBLE_EQ(data["traceEvents"][0]["dur"], 400.0);
207207
EXPECT_EQ(data["traceEvents"][1]["cat"], "kernel1");
208208
EXPECT_EQ(data["traceEvents"][2]["cat"], "kernel2");
209-
EXPECT_EQ(data["traceEvents"][2]["ts"], 10000.0);
210-
EXPECT_EQ(data["traceEvents"][2]["dur"], 400.0);
209+
EXPECT_DOUBLE_EQ(data["traceEvents"][2]["ts"], 10000.0);
210+
EXPECT_DOUBLE_EQ(data["traceEvents"][2]["dur"], 400.0);
211211
}

0 commit comments

Comments
 (0)