llvm.org GIT mirror llvm / b92b0b8
[XRay] Update XRayRecord to support Custom/Typed Events Summary: This change cuts across LLVM and compiler-rt to add support for rendering custom events in the XRayRecord type, to allow for including user-provided annotations in the output YAML (as raw bytes). This work enables us to add custom event and typed event records into the `llvm::xray::Trace` type for user-provided events. This can then be programmatically handled through the C++ API and can be included in some of the tooling as well. For now we support printing the raw data we encounter in the custom events in the converted output. Future work will allow us to start interpreting these custom and typed events through a yet-to-be-defined API for extending the trace analysis library. Reviewers: mboerger Subscribers: hiraditya, llvm-commits Differential Revision: https://reviews.llvm.org/D54139 git-svn-id: https://llvm.org/svn/llvm-project/llvm/trunk@346214 91177308-0d34-0410-b5e6-96231b3b80d8 Dean Michael Berris 11 months ago
23 changed file(s) with 173 addition(s) and 104 deletion(s). Raw diff Collapse all Expand all
2626 int32_t PID = 0;
2727 int32_t TID = 0;
2828 uint64_t BaseTSC = 0;
29 XRayRecord CurrentRecord{0, 0, RecordTypes::ENTER, 0, 0, 0, 0, {}};
29 XRayRecord CurrentRecord{0, 0, RecordTypes::ENTER, 0, 0, 0, 0, {}, {}};
3030 uint16_t CPUId = 0;
3131 uint16_t LogVersion = 0;
32 bool BuildingFunction = false;
32 bool BuildingRecord = false;
3333 bool IgnoringRecords = false;
3434
3535 void resetCurrentRecord();
1616
1717 #include
1818 #include
19 #include
1920
2021 namespace llvm {
2122 namespace xray {
5354 /// This may or may not correspond to actual record types in the raw trace (as
5455 /// the loader implementation may synthesize this information in the process of
5556 /// of loading).
56 enum class RecordTypes { ENTER, EXIT, TAIL_EXIT, ENTER_ARG };
57 enum class RecordTypes {
58 ENTER,
59 EXIT,
60 TAIL_EXIT,
61 ENTER_ARG,
62 CUSTOM_EVENT,
63 TYPED_EVENT
64 };
5765
66 /// An XRayRecord is the denormalized view of data associated in a trace. These
67 /// records may not correspond to actual entries in the raw traces, but they are
68 /// the logical representation of records in a higher-level event log.
5869 struct XRayRecord {
59 /// The type of record.
70 /// RecordType values are used as "sub-types" which have meaning in the
71 /// context of the `Type` below. For function call and custom event records,
72 /// the RecordType is always 0, while for typed events we store the type in
73 /// the RecordType field.
6074 uint16_t RecordType;
6175
6276 /// The CPU where the thread is running. We assume number of CPUs <= 65536.
6579 /// Identifies the type of record.
6680 RecordTypes Type;
6781
68 /// The function ID for the record.
82 /// The function ID for the record, if this is a function call record.
6983 int32_t FuncId;
7084
7185 /// Get the full 8 bytes of the TSC when we get the log record.
7993
8094 /// The function call arguments.
8195 std::vector CallArgs;
96
97 /// For custom and typed events, we provide the raw data from the trace.
98 std::string Data;
8299 };
83100
84101 } // namespace xray
3838 uint32_t TId;
3939 uint32_t PId;
4040 std::vector CallArgs;
41 std::string Data;
4142 };
4243
4344 struct YAMLXRayTrace {
5758 IO.enumCase(Type, "function-exit", xray::RecordTypes::EXIT);
5859 IO.enumCase(Type, "function-tail-exit", xray::RecordTypes::TAIL_EXIT);
5960 IO.enumCase(Type, "function-enter-arg", xray::RecordTypes::ENTER_ARG);
61 IO.enumCase(Type, "custom-event", xray::RecordTypes::CUSTOM_EVENT);
62 IO.enumCase(Type, "typed-event", xray::RecordTypes::TYPED_EVENT);
6063 }
6164 };
6265
7275
7376 template <> struct MappingTraits {
7477 static void mapping(IO &IO, xray::YAMLXRayRecord &Record) {
75 // FIXME: Make this type actually be descriptive
7678 IO.mapRequired("type", Record.RecordType);
77 IO.mapRequired("func-id", Record.FuncId);
79 IO.mapOptional("func-id", Record.FuncId);
7880 IO.mapOptional("function", Record.Function);
7981 IO.mapOptional("args", Record.CallArgs);
8082 IO.mapRequired("cpu", Record.CPU);
81 IO.mapRequired("thread", Record.TId);
83 IO.mapOptional("thread", Record.TId, 0U);
8284 IO.mapOptional("process", Record.PId, 0U);
8385 IO.mapRequired("kind", Record.Type);
8486 IO.mapRequired("tsc", Record.TSC);
87 IO.mapOptional("data", Record.Data);
8588 }
8689
8790 static constexpr bool flow = true;
1111 namespace xray {
1212
1313 void TraceExpander::resetCurrentRecord() {
14 if (BuildingFunction)
14 if (BuildingRecord)
1515 C(CurrentRecord);
16 BuildingFunction = false;
16 BuildingRecord = false;
1717 CurrentRecord.CallArgs.clear();
18 CurrentRecord.Data.clear();
1819 }
1920
2021 Error TraceExpander::visit(BufferExtents &) {
3536 return Error::success();
3637 }
3738
38 Error TraceExpander::visit(CustomEventRecord &) {
39 // TODO: Support custom event records in the future.
39 Error TraceExpander::visit(CustomEventRecord &R) {
4040 resetCurrentRecord();
41 if (!IgnoringRecords) {
42 CurrentRecord.TSC = R.tsc();
43 CurrentRecord.CPU = R.cpu();
44 CurrentRecord.PId = PID;
45 CurrentRecord.TId = TID;
46 CurrentRecord.Type = RecordTypes::CUSTOM_EVENT;
47 std::copy(R.data().begin(), R.data().end(),
48 std::back_inserter(CurrentRecord.Data));
49 BuildingRecord = true;
50 }
4151 return Error::success();
4252 }
4353
7787 CurrentRecord.PId = PID;
7888 CurrentRecord.TId = TID;
7989 CurrentRecord.CPU = CPUId;
80 BuildingFunction = true;
90 BuildingRecord = true;
8191 }
8292 return Error::success();
8393 }
373373 }
374374
375375 break;
376
377 case RecordTypes::CUSTOM_EVENT:
378 case RecordTypes::TYPED_EVENT:
379 // TODO: Support an extension point to allow handling of custom and typed
380 // events in profiles.
381 break;
376382 }
377383 }
378384
8080 OS << formatv("", R.functionId(),
8181 R.delta());
8282 break;
83 case RecordTypes::CUSTOM_EVENT:
84 case RecordTypes::TYPED_EVENT:
85 // TODO: Flag as a bug?
86 break;
8387 }
8488 OS << Delim;
8589 return Error::success();
351351 Records.clear();
352352 std::transform(Trace.Records.begin(), Trace.Records.end(),
353353 std::back_inserter(Records), [&](const YAMLXRayRecord &R) {
354 return XRayRecord{R.RecordType, R.CPU, R.Type, R.FuncId,
355 R.TSC, R.TId, R.PId, R.CallArgs};
354 return XRayRecord{R.RecordType, R.CPU, R.Type,
355 R.FuncId, R.TSC, R.TId,
356 R.PId, R.CallArgs, R.Data};
356357 });
357358 return Error::success();
358359 }
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3500000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-enter, tsc: 22555670288232728 }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288334784 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', args: [ 1 ], cpu: 17, thread: 8715, kind: function-enter-arg, tsc: 22555670288335768 }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288365224 }
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-enter, tsc: 22555670288232728, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288334784, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', args: [ 1 ], cpu: 17, thread: 8715, kind: function-enter-arg, tsc: 22555670288335768, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288365224, data: '' }
1414 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3900000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033303630902004 }
11 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033403115246844 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033490200702516 }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033504122687120 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 0, thread: 2590, process: 2590, kind: function-enter-arg, tsc: 2033505343905936 }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033505343936752 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033303630902004, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033403115246844, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033490200702516, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033504122687120, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 0, thread: 2590, process: 2590, kind: function-enter-arg, tsc: 2033505343905936, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033505343936752, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3900000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070767347414784 }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070767347496472 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768324320264 }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768324344100 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768921602152 }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768921625968 }
16 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070769627174140 }
17 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070769627197624 }
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070767347414784, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070767347496472, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768324320264, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768324344100, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768921602152, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768921625968, data: '' }
16 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070769627174140, data: '' }
17 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070769627197624, data: '' }
1818 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3500000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 1 ], cpu: 49, thread: 14648, kind: function-enter-arg, tsc: 18828908666543318 }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 49, thread: 14648, kind: function-exit, tsc: 18828908666595604 }
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 1 ], cpu: 49, thread: 14648, kind: function-enter-arg, tsc: 18828908666543318, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 49, thread: 14648, kind: function-exit, tsc: 18828908666595604, data: '' }
1212 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3900000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034042117104344 }
11 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034042117199088 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034043145686378 }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034043145762200 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 6, thread: 2631, process: 2631, kind: function-enter-arg, tsc: 2034049739853430 }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034049739878154 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034042117104344, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034042117199088, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034043145686378, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034043145762200, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 6, thread: 2631, process: 2631, kind: function-enter-arg, tsc: 2034049739853430, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034049739878154, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 3900000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069294857657498 }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069294857707502 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069295590705912 }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069295590734308 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069296377598128 }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069296377627032 }
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069294857657498, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069294857707502, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069295590705912, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069295590734308, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069296377598128, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069296377627032, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 5678
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407340 }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407346 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407347 }
13 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407387 }
14 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407437 }
15 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407467 }
16 ; CHECK-NEXT: - { type: 0, func-id: 4, function: '4', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407492 }
17 ; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407517 }
18 ; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-tail-exit, tsc: 7238225556407542 }
19 ; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407552 }
20 ; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407562 }
21 ; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-enter, tsc: 7238225556407682 }
22 ; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-exit, tsc: 7238225556407755 }
10 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407340, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407346, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407347, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407387, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407437, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407467, data: '' }
16 ; CHECK-NEXT: - { type: 0, func-id: 4, function: '4', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407492, data: '' }
17 ; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407517, data: '' }
18 ; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-tail-exit, tsc: 7238225556407542, data: '' }
19 ; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407552, data: '' }
20 ; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407562, data: '' }
21 ; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-enter, tsc: 7238225556407682, data: '' }
22 ; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-exit, tsc: 7238225556407755, data: '' }
2323 ; CHECK-NEXT: ...
1818 #CHECK-NEXT: nonstop-tsc: true
1919 #CHECK-NEXT: cycle-frequency: 2601000000
2020 #CHECK-NEXT: records:
21 #CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-enter, tsc: 10001 }
22 #CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-exit, tsc: 10100 }
21 #CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-enter, tsc: 10001, data: '' }
22 #CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-exit, tsc: 10100, data: '' }
2323 #CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 2601000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 2601000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 2601000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
1616 ; CHECK-NEXT: ...
77 ; CHECK-NEXT: nonstop-tsc: true
88 ; CHECK-NEXT: cycle-frequency: 2601000000
99 ; CHECK-NEXT: records:
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
10 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
11 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
12 ; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
13 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
14 ; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
15 ; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
1616 ; CHECK-NEXT: ...
145145
146146 auto &ThreadStack = PerThreadFunctionStack[Record.TId];
147147 switch (Record.Type) {
148 case RecordTypes::CUSTOM_EVENT:
149 case RecordTypes::TYPED_EVENT:
150 // TODO: Support custom and typed event accounting in the future.
151 return true;
148152 case RecordTypes::ENTER:
149153 case RecordTypes::ENTER_ARG: {
150154 ThreadStack.emplace_back(Record.FuncId, Record.TSC);
416420 template <> struct format_provider {
417421 static void format(const llvm::xray::RecordTypes &T, raw_ostream &Stream,
418422 StringRef Style) {
419 switch(T) {
420 case RecordTypes::ENTER:
421 Stream << "enter";
422 break;
423 case RecordTypes::ENTER_ARG:
424 Stream << "enter-arg";
425 break;
426 case RecordTypes::EXIT:
427 Stream << "exit";
428 break;
429 case RecordTypes::TAIL_EXIT:
430 Stream << "tail-exit";
431 break;
423 switch (T) {
424 case RecordTypes::ENTER:
425 Stream << "enter";
426 break;
427 case RecordTypes::ENTER_ARG:
428 Stream << "enter-arg";
429 break;
430 case RecordTypes::EXIT:
431 Stream << "exit";
432 break;
433 case RecordTypes::TAIL_EXIT:
434 Stream << "tail-exit";
435 break;
436 case RecordTypes::CUSTOM_EVENT:
437 Stream << "custom-event";
438 break;
439 case RecordTypes::TYPED_EVENT:
440 Stream << "typed-event";
441 break;
432442 }
433443 }
434444 };
9191 Trace.Records.push_back({R.RecordType, R.CPU, R.Type, R.FuncId,
9292 Symbolize ? FuncIdHelper.SymbolOrNumber(R.FuncId)
9393 : llvm::to_string(R.FuncId),
94 R.TSC, R.TId, R.PId, R.CallArgs});
94 R.TSC, R.TId, R.PId, R.CallArgs, R.Data});
9595 }
9696 Output Out(OS, nullptr, 0);
97 Out.setWriteDefaultValues(false);
9798 Out << Trace;
9899 }
99100
122123 // Then write out the rest of the records, still in an endian-appropriate
123124 // format.
124125 for (const auto &R : Records) {
125 Writer.write(R.RecordType);
126 // The on disk naive raw format uses 8 bit CPUs, but the record has 16.
127 // There's no choice but truncation.
128 Writer.write(static_cast(R.CPU));
129126 switch (R.Type) {
130127 case RecordTypes::ENTER:
131128 case RecordTypes::ENTER_ARG:
129 Writer.write(R.RecordType);
130 Writer.write(static_cast(R.CPU));
132131 Writer.write(uint8_t{0});
133132 break;
134133 case RecordTypes::EXIT:
134 Writer.write(R.RecordType);
135 Writer.write(static_cast(R.CPU));
135136 Writer.write(uint8_t{1});
136137 break;
137138 case RecordTypes::TAIL_EXIT:
139 Writer.write(R.RecordType);
140 Writer.write(static_cast(R.CPU));
138141 Writer.write(uint8_t{2});
139142 break;
143 case RecordTypes::CUSTOM_EVENT:
144 case RecordTypes::TYPED_EVENT:
145 // Skip custom and typed event records for v1 logs.
146 continue;
140147 }
141148 Writer.write(R.FuncId);
142149 Writer.write(R.TSC);
263270 double EventTimestampUs = double(1000000) / CycleFreq * double(R.TSC);
264271 StackTrieNode *&StackCursor = StackCursorByThreadId[R.TId];
265272 switch (R.Type) {
273 case RecordTypes::CUSTOM_EVENT:
274 case RecordTypes::TYPED_EVENT:
275 // TODO: Support typed and custom event rendering on Chrome Trace Viewer.
276 break;
266277 case RecordTypes::ENTER:
267278 case RecordTypes::ENTER_ARG:
268279 StackCursor = findOrCreateStackNode(StackCursor, R.FuncId, R.TId,
245245 updateStat(G[Record.FuncId].S, D);
246246 break;
247247 }
248 case RecordTypes::CUSTOM_EVENT:
249 case RecordTypes::TYPED_EVENT:
250 // TODO: Support custom and typed events in the graph processing?
251 break;
248252 }
249253
250254 return Error::success();
365365 AccountRecordState *state) {
366366 auto &TS = ThreadStackMap[R.TId];
367367 switch (R.Type) {
368 case RecordTypes::CUSTOM_EVENT:
369 case RecordTypes::TYPED_EVENT:
370 return AccountRecordStatus::OK;
368371 case RecordTypes::ENTER:
369372 case RecordTypes::ENTER_ARG: {
370373 state->wasLastRecordExit = false;