-
Notifications
You must be signed in to change notification settings - Fork 159
/
output_json.cpp
451 lines (406 loc) · 12 KB
/
output_json.cpp
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
/*
* Copyright (c) Facebook, Inc. and its affiliates.
* All rights reserved.
* This source code is licensed under the BSD-style license found in the
* LICENSE file in the root directory of this source tree.
*/
#include "output_json.h"
#include <fmt/format.h>
#include <fstream>
#include <time.h>
#include <map>
#include <unistd.h>
#include "Config.h"
#ifdef HAS_CUPTI
#include "CuptiActivity.h"
#include "CuptiActivity.tpp"
#include "CuptiActivityInterface.h"
#endif // HAS_CUPTI
#include "Demangle.h"
#include "TraceSpan.h"
#include "Logger.h"
using std::endl;
using namespace libkineto;
namespace KINETO_NAMESPACE {
static constexpr int kSchemaVersion = 1;
static void writeHeader(std::ofstream& stream) {
stream << fmt::format(R"JSON(
{{
"schemaVersion": {},
"traceEvents": [
)JSON", kSchemaVersion);
}
static void openTraceFile(std::string& name, std::ofstream& stream) {
stream.open(name, std::ofstream::out | std::ofstream::trunc);
if (!stream) {
PLOG(ERROR) << "Failed to open '" << name << "'";
} else {
LOG(INFO) << "Tracing to " << name;
writeHeader(stream);
}
}
ChromeTraceLogger::ChromeTraceLogger(const std::string& traceFileName)
: fileName_(traceFileName), pid_(getpid()) {
traceOf_.clear(std::ios_base::badbit);
openTraceFile(fileName_, traceOf_);
#ifdef HAS_CUPTI
smCount_ = CuptiActivityInterface::singleton().smCount();
#endif
}
int ChromeTraceLogger::renameThreadID(uint32_t tid) {
// the tid here is the thread ID that schedules the operator
static int curr_tid = 0;
// Note this function is not thread safe; The user of this ChromeTraceLogger
// need to maintain thread safety
if (tidMap_.count(tid)) {
return tidMap_[tid];
} else {
return tidMap_[tid] = curr_tid++;
}
}
static int64_t us(int64_t timestamp) {
// It's important that this conversion is the same here and in the CPU trace.
// No rounding!
return timestamp / 1000;
}
void ChromeTraceLogger::handleProcessInfo(
const ProcessInfo& processInfo,
uint64_t time) {
if (!traceOf_) {
return;
}
// M is for metadata
// process_name needs a pid and a name arg
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"name": "process_name", "ph": "M", "ts": {}, "pid": {}, "tid": 0,
"args": {{
"name": "{}"
}}
}},
{{
"name": "process_labels", "ph": "M", "ts": {}, "pid": {}, "tid": 0,
"args": {{
"labels": "{}"
}}
}},)JSON",
time, processInfo.pid,
processInfo.name,
time, processInfo.pid,
processInfo.label);
// clang-format on
}
void ChromeTraceLogger::handleThreadInfo(
const ThreadInfo& threadInfo,
int64_t time) {
if (!traceOf_) {
return;
}
// M is for metadata
// thread_name needs a pid and a name arg
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"name": "thread_name", "ph": "M", "ts": {}, "pid": {}, "tid": "{}",
"args": {{
"name": "thread {} ({})"
}}
}},)JSON",
time, pid_, (uint32_t)threadInfo.tid,
renameThreadID((uint32_t)threadInfo.tid), threadInfo.name);
// clang-format on
}
void ChromeTraceLogger::handleTraceSpan(const TraceSpan& span) {
if (!traceOf_) {
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Trace", "ts": {}, "dur": {},
"pid": "Traces", "tid": "{}",
"name": "{}{} ({})",
"args": {{
"Op count": {}
}}
}},)JSON",
span.startTime, span.endTime - span.startTime,
span.name,
span.prefix, span.name, span.iteration,
span.opCount);
// clang-format on
}
void ChromeTraceLogger::handleIterationStart(const TraceSpan& span) {
if (!traceOf_) {
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"name": "Iteration Start: {}", "ph": "i", "s": "g",
"pid": "Traces", "tid": "Trace {}", "ts": {}
}},)JSON",
span.name,
span.name, span.startTime);
// clang-format on
}
static std::string traceActivityJson(const TraceActivity& activity, std::string tidPrefix) {
// clang-format off
return fmt::format(R"JSON(
"name": "{}", "pid": {}, "tid": "{}{}",
"ts": {}, "dur": {})JSON",
activity.name(), activity.deviceId(), tidPrefix, (uint32_t)activity.resourceId(),
activity.timestamp(), activity.duration());
// clang-format on
}
void ChromeTraceLogger::handleCpuActivity(
const libkineto::ClientTraceActivity& op,
const TraceSpan& span) {
if (!traceOf_) {
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Operator", {},
"args": {{
"Input dims": {}, "Input type": {}, "Input names": {},
"Output dims": {}, "Output type": {}, "Output names": {},
"Device": {}, "External id": {}, "Extra arguments": {},
"Call stack": "{}",
"Trace name": "{}", "Trace iteration": {}
}}
}},)JSON",
traceActivityJson(op, ""),
// args
op.inputDims, op.inputTypes, op.inputNames,
op.outputDims, op.outputTypes, op.outputNames,
op.device, op.correlation, op.arguments,
op.callStack,
span.name, span.iteration);
// clang-format on
}
void ChromeTraceLogger::handleGenericActivity(
const GenericTraceActivity& op) {
if (!traceOf_) {
return;
}
// FIXME: Make cat and tid customizable
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "User", "name": "{}",
"pid": {}, "tid": "stream {} user",
"ts": {}, "dur": {},
"args": {{
"External id": {}
}}
}},)JSON",
op.name(), op.deviceId(), op.resourceId(),
op.timestamp(), op.duration(),
op.correlationId());
// clang-format on
}
#ifdef HAS_CUPTI
void ChromeTraceLogger::handleLinkStart(const RuntimeActivity& s) {
if (!traceOf_) {
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "s", "id": {}, "pid": {}, "tid": {}, "ts": {},
"cat": "async", "name": "launch"
}},)JSON",
s.correlationId(), pid_, s.resourceId(), s.timestamp());
// clang-format on
}
void ChromeTraceLogger::handleLinkEnd(const TraceActivity& e) {
if (!traceOf_) {
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "f", "id": {}, "pid": {}, "tid": "stream {}", "ts": {},
"cat": "async", "name": "launch", "bp": "e"
}},)JSON",
e.correlationId(), e.deviceId(), e.resourceId(), e.timestamp());
// clang-format on
}
void ChromeTraceLogger::handleRuntimeActivity(
const RuntimeActivity& activity) {
if (!traceOf_) {
return;
}
const CUpti_CallbackId cbid = activity.raw().cbid;
const TraceActivity& ext = *activity.linkedActivity();
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Runtime", {},
"args": {{
"cbid": {}, "correlation": {},
"external id": {}, "external ts": {}
}}
}},)JSON",
traceActivityJson(activity, ""),
// args
cbid, activity.raw().correlationId,
ext.correlationId(), ext.timestamp());
// clang-format on
// FIXME: This is pretty hacky and it's likely that we miss some links.
// May need to maintain a map instead.
if (cbid == CUPTI_RUNTIME_TRACE_CBID_cudaLaunchKernel_v7000 ||
(cbid >= CUPTI_RUNTIME_TRACE_CBID_cudaMemcpy_v3020 &&
cbid <= CUPTI_RUNTIME_TRACE_CBID_cudaMemset2DAsync_v3020) ||
cbid ==
CUPTI_RUNTIME_TRACE_CBID_cudaLaunchCooperativeKernel_v9000 ||
cbid ==
CUPTI_RUNTIME_TRACE_CBID_cudaLaunchCooperativeKernelMultiDevice_v9000) {
handleLinkStart(activity);
}
}
// GPU side kernel activity
void ChromeTraceLogger::handleGpuActivity(
const GpuActivity<CUpti_ActivityKernel4>& activity) {
if (!traceOf_) {
return;
}
const CUpti_ActivityKernel4* kernel = &activity.raw();
const TraceActivity& ext = *activity.linkedActivity();
constexpr int threads_per_warp = 32;
float warps_per_sm = -1.0;
if (smCount_) {
warps_per_sm = (kernel->gridX * kernel->gridY * kernel->gridZ) *
(kernel->blockX * kernel->blockY * kernel->blockZ) /
(float) threads_per_warp / smCount_;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Kernel", {},
"args": {{
"queued": {}, "device": {}, "context": {},
"stream": {}, "correlation": {}, "external id": {},
"registers per thread": {},
"shared memory": {},
"warps per SM": {},
"grid": [{}, {}, {}],
"block": [{}, {}, {}]
}}
}},)JSON",
traceActivityJson(activity, "stream "),
// args
us(kernel->queued), kernel->deviceId, kernel->contextId,
kernel->streamId, kernel->correlationId, ext.correlationId(),
kernel->registersPerThread,
kernel->staticSharedMemory + kernel->dynamicSharedMemory,
warps_per_sm,
kernel->gridX, kernel->gridY, kernel->gridZ,
kernel->blockX, kernel->blockY, kernel->blockZ);
// clang-format on
handleLinkEnd(activity);
}
// GPU side memcpy activity
void ChromeTraceLogger::handleGpuActivity(
const GpuActivity<CUpti_ActivityMemcpy>& activity) {
if (!traceOf_) {
return;
}
const CUpti_ActivityMemcpy& memcpy = activity.raw();
const TraceActivity& ext = *activity.linkedActivity();
VLOG(2) << memcpy.correlationId << ": MEMCPY";
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Memcpy", {},
"args": {{
"device": {}, "context": {},
"stream": {}, "correlation": {}, "external id": {},
"bytes": {}, "memory bandwidth (GB/s)": {}
}}
}},)JSON",
traceActivityJson(activity, "stream "),
// args
memcpy.deviceId, memcpy.contextId,
memcpy.streamId, memcpy.correlationId, ext.correlationId(),
memcpy.bytes, memcpy.bytes * 1.0 / (memcpy.end - memcpy.start));
// clang-format on
handleLinkEnd(activity);
}
// GPU side memcpy activity
void ChromeTraceLogger::handleGpuActivity(
const GpuActivity<CUpti_ActivityMemcpy2>& activity) {
if (!traceOf_) {
return;
}
const CUpti_ActivityMemcpy2& memcpy = activity.raw();
const TraceActivity& ext = *activity.linkedActivity();
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Memcpy", {},
"args": {{
"fromDevice": {}, "inDevice": {}, "toDevice": {},
"fromContext": {}, "inContext": {}, "toContext": {},
"stream": {}, "correlation": {}, "external id": {},
"bytes": {}, "memory bandwidth (GB/s)": {}
}}
}},)JSON",
traceActivityJson(activity, "stream "),
// args
memcpy.srcDeviceId, memcpy.deviceId, memcpy.dstDeviceId,
memcpy.srcContextId, memcpy.contextId, memcpy.dstContextId,
memcpy.streamId, memcpy.correlationId, ext.correlationId(),
memcpy.bytes, memcpy.bytes * 1.0 / (memcpy.end - memcpy.start));
// clang-format on
handleLinkEnd(activity);
}
void ChromeTraceLogger::handleGpuActivity(
const GpuActivity<CUpti_ActivityMemset>& activity) {
if (!traceOf_) {
return;
}
const CUpti_ActivityMemset& memset = activity.raw();
const TraceActivity& ext = *activity.linkedActivity();
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"ph": "X", "cat": "Memset", {},
"args": {{
"device": {}, "context": {},
"stream": {}, "correlation": {}, "external id": {},
"bytes": {}, "memory bandwidth (GB/s)": {}
}}
}},)JSON",
traceActivityJson(activity, "stream "),
// args
memset.deviceId, memset.contextId,
memset.streamId, memset.correlationId, ext.correlationId(),
memset.bytes, memset.bytes * 1.0 / (memset.end - memset.start));
// clang-format on
handleLinkEnd(activity);
}
#endif // HAS_CUPTI
void ChromeTraceLogger::finalizeTrace(
const Config& /*unused*/,
std::unique_ptr<ActivityBuffers> /*unused*/,
int64_t endTime) {
if (!traceOf_) {
LOG(ERROR) << "Failed to write to log file!";
return;
}
// clang-format off
traceOf_ << fmt::format(R"JSON(
{{
"name": "Record Window End", "ph": "i", "s": "g",
"pid": "", "tid": "", "ts": {}
}}
]}})JSON",
endTime);
// clang-format on
traceOf_.close();
LOG(INFO) << "Chrome Trace written to " << fileName_;
}
} // namespace KINETO_NAMESPACE