[corelib] dart:developer timeline flow events

This change adds an API to dart:developer Timeline for
adding flow events to the timeline. For details see the
changes in:

sdk/lib/developer/timeline.dart

R=rmacnak@google.com

Review-Url: https://codereview.chromium.org/2985253002 .
This commit is contained in:
Zachary Anderson 2017-07-31 07:46:50 -07:00
parent 33ab401cc7
commit 633ed4cf83
14 changed files with 330 additions and 5 deletions

View file

@ -31,6 +31,12 @@
* The `Uri` class now correctly handles paths while running on Node.js on
Windows.
* `dart:developer`
* `Timeline.startSync` and `Timeline.timeSync` now accept an optional
parameter `flow` of type `Flow`. The `flow` parameter is used to generate
flow timeline events that are enclosed by the slice described by
`Timeline.{start,finish}Sync` and `Timeline.timeSync`.
### Dart VM
* Support for MIPS has been remvoed.

View file

@ -74,6 +74,12 @@ void _reportCompleteEvent(int start, int startCpu, String category, String name,
// TODO.
}
@patch
void _reportFlowEvent(int start, int startCpu, String category, String name,
int type, int id, String argumentsAsJson) {
// TODO.
}
@patch
void _reportInstantEvent(
int start, String category, String name, String argumentsAsJson) {

View file

@ -110,6 +110,38 @@ DEFINE_NATIVE_ENTRY(Timeline_reportCompleteEvent, 5) {
return Object::null();
}
DEFINE_NATIVE_ENTRY(Timeline_reportFlowEvent, 7) {
#ifndef PRODUCT
if (!FLAG_support_timeline) {
return Object::null();
}
GET_NON_NULL_NATIVE_ARGUMENT(Integer, start, arguments->NativeArgAt(0));
GET_NON_NULL_NATIVE_ARGUMENT(Integer, start_cpu, arguments->NativeArgAt(1));
GET_NON_NULL_NATIVE_ARGUMENT(String, category, arguments->NativeArgAt(2));
GET_NON_NULL_NATIVE_ARGUMENT(String, name, arguments->NativeArgAt(3));
GET_NON_NULL_NATIVE_ARGUMENT(Integer, type, arguments->NativeArgAt(4));
GET_NON_NULL_NATIVE_ARGUMENT(Integer, flow_id, arguments->NativeArgAt(5));
GET_NON_NULL_NATIVE_ARGUMENT(String, args, arguments->NativeArgAt(6));
TimelineEventRecorder* recorder = Timeline::recorder();
if (recorder == NULL) {
return Object::null();
}
TimelineEvent* event = Timeline::GetDartStream()->StartEvent();
if (event == NULL) {
// Stream was turned off.
return Object::null();
}
DartTimelineEventHelpers::ReportFlowEvent(
thread, zone, event, start.AsInt64Value(), start_cpu.AsInt64Value(),
category.ToCString(), name.ToCString(), type.AsInt64Value(),
flow_id.AsInt64Value(), args.ToCString());
#endif // !defined(PRODUCT)
return Object::null();
}
DEFINE_NATIVE_ENTRY(Timeline_reportInstantEvent, 4) {
#ifndef PRODUCT
if (!FLAG_support_timeline) {

View file

@ -25,6 +25,10 @@ void _reportTaskEvent(int start, int taskId, String phase, String category,
void _reportCompleteEvent(int start, int startCpu, String category, String name,
String argumentsAsJson) native "Timeline_reportCompleteEvent";
@patch
void _reportFlowEvent(int start, int startCpu, String category, String name,
int type, int id, String argumentsAsJson) native "Timeline_reportFlowEvent";
@patch
void _reportInstantEvent(int start, String category, String name,
String argumentsAsJson) native "Timeline_reportInstantEvent";

View file

@ -17,6 +17,14 @@ primeTimeline() {
task.start('TASK1');
task.instant('ITASK');
task.finish();
Flow flow = Flow.begin();
Timeline.startSync('peach', flow: flow);
Timeline.finishSync();
Timeline.startSync('watermelon', flow: Flow.step(flow.id));
Timeline.finishSync();
Timeline.startSync('pear', flow: Flow.end(flow.id));
Timeline.finishSync();
}
List<Map> filterForDartEvents(List<Map> events) {
@ -92,7 +100,7 @@ var tests = [
expect(result['traceEvents'], new isInstanceOf<List>());
final int numEvents = result['traceEvents'].length;
List<Map> dartEvents = filterForDartEvents(result['traceEvents']);
expect(dartEvents.length, equals(5));
expect(dartEvents.length, equals(11));
allEventsHaveIsolateNumber(dartEvents);
allEventsHaveIsolateNumber(result['traceEvents']);
expect(eventsContains(dartEvents, 'I', 'ISYNC'), isTrue);
@ -101,6 +109,9 @@ var tests = [
expect(eventsContains(dartEvents, 'e', 'TASK1'), isTrue);
expect(eventsContains(dartEvents, 'n', 'ITASK'), isTrue);
expect(eventsContains(dartEvents, 'q', 'ITASK'), isFalse);
expect(eventsContains(dartEvents, 's', 'peach'), isTrue);
expect(eventsContains(dartEvents, 't', 'watermelon'), isTrue);
expect(eventsContains(dartEvents, 'f', 'pear'), isTrue);
// Calculate the time Window of Dart events.
int origin = timeOrigin(dartEvents);
int extent = timeDuration(dartEvents, origin);

View file

@ -172,6 +172,7 @@ namespace dart {
V(Timeline_getThreadCpuClock, 0) \
V(Timeline_isDartStreamEnabled, 0) \
V(Timeline_reportCompleteEvent, 5) \
V(Timeline_reportFlowEvent, 7) \
V(Timeline_reportInstantEvent, 4) \
V(Timeline_reportTaskEvent, 6) \
V(TypedData_Int8Array_new, 2) \

View file

@ -1696,6 +1696,57 @@ void DartCommonTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
event->CompleteWithPreSerializedJSON(json);
}
void DartCommonTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
const int64_t pid = OS::ProcessId();
OSThread* os_thread = thread->os_thread();
ASSERT(os_thread != NULL);
const int64_t tid = OSThread::ThreadIdToIntPtr(os_thread->trace_id());
TimelineEvent::EventType event_type =
static_cast<TimelineEvent::EventType>(type);
const char* typestr;
const char* bpstr = "";
switch (event_type) {
case TimelineEvent::kFlowBegin:
typestr = "s";
break;
case TimelineEvent::kFlowStep:
typestr = "t";
break;
case TimelineEvent::kFlowEnd:
typestr = "f";
bpstr = ", \"bp\":\"e\"";
break;
default:
UNREACHABLE();
break;
}
char* json = OS::SCreate(
zone,
"{\"name\":\"%s\",\"cat\":\"%s\",\"tid\":%" Pd64 ",\"pid\":%" Pd64
","
"\"ts\":%" Pd64 ",\"ph\":\"%s\", \"id\":%" Pd64 "%s, \"args\":%s}",
name, category, tid, pid, start, typestr, flow_id, bpstr, args);
ASSERT(json != NULL);
// Doesn't really matter what it is since it gets overriden by the
// preserialized json.
event->FlowBegin("", flow_id, start);
// json was allocated in the zone and a copy will be stored in event.
event->CompleteWithPreSerializedJSON(json);
}
void DartCommonTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -875,6 +875,17 @@ class DartTimelineEventHelpers : public AllStatic {
const char* name,
const char* args);
static void ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args);
static void ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
@ -907,6 +918,17 @@ class DartCommonTimelineEventHelpers : public AllStatic {
const char* name,
const char* args);
static void ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args);
static void ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -145,6 +145,21 @@ void DartTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
thread, zone, event, start, start_cpu, category, name, args);
}
void DartTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
DartCommonTimelineEventHelpers::ReportFlowEvent(thread, zone, event, start,
start_cpu, category, name,
type, flow_id, args);
}
void DartTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -188,6 +188,38 @@ void DartTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
event->Complete();
}
void DartTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
char* name_string = strdup(name);
ASSERT((type >= 0) && (type <= 2));
switch (type) {
case 0:
event->FlowBegin(name_string, flow_id, start);
break;
case 1:
event->FlowStep(name_string, flow_id, start);
break;
case 2:
event->FlowEnd(name_string, flow_id, start);
break;
default:
UNREACHABLE();
break;
}
event->set_owns_label(true);
event->SetNumArguments(1);
event->CopyArgument(0, "args", args);
event->Complete();
}
void DartTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -145,6 +145,21 @@ void DartTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
thread, zone, event, start, start_cpu, category, name, args);
}
void DartTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
DartCommonTimelineEventHelpers::ReportFlowEvent(thread, zone, event, start,
start_cpu, category, name,
type, flow_id, args);
}
void DartTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -71,6 +71,21 @@ void DartTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
thread, zone, event, start, start_cpu, category, name, args);
}
void DartTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
DartCommonTimelineEventHelpers::ReportFlowEvent(thread, zone, event, start,
start_cpu, category, name,
type, flow_id, args);
}
void DartTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -71,6 +71,21 @@ void DartTimelineEventHelpers::ReportCompleteEvent(Thread* thread,
thread, zone, event, start, start_cpu, category, name, args);
}
void DartTimelineEventHelpers::ReportFlowEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,
int64_t start,
int64_t start_cpu,
const char* category,
const char* name,
int64_t type,
int64_t flow_id,
const char* args) {
DartCommonTimelineEventHelpers::ReportFlowEvent(thread, zone, event, start,
start_cpu, category, name,
type, flow_id, args);
}
void DartTimelineEventHelpers::ReportInstantEvent(Thread* thread,
Zone* zone,
TimelineEvent* event,

View file

@ -9,12 +9,94 @@ const bool _isProduct = const bool.fromEnvironment("dart.vm.product");
typedef dynamic TimelineSyncFunction();
typedef Future TimelineAsyncFunction();
/// A class to represent Flow events.
///
/// [Flow] objects are used to thread flow events between timeline slices,
/// for example, those created with the [Timeline] class below. Adding
/// [Flow] objects cause arrows to be drawn between slices in Chrome's trace
/// viewer. The arrows start at e.g [Timeline] events that are passed a
/// [Flow.begin] object, go through [Timeline] events that are passed a
/// [Flow.step] object, and end at [Timeline] events that are passed a
/// [Flow.end] object, all having the same [Flow.id]. For example:
///
/// ```dart
/// var flow = Flow.begin();
/// Timeline.timeSync('flow_test', () {
/// doSomething();
/// }, flow: flow);
///
/// Timeline.timeSync('flow_test', () {
/// doSomething();
/// }, flow: Flow.step(flow.id));
///
/// Timeline.timeSync('flow_test', () {
/// doSomething();
/// }, flow: Flow.end(flow.id));
/// ```
class Flow {
// These values must be kept in sync with the enum "EventType" in
// runtime/vm/timeline.h.
static const int _begin = 9;
static const int _step = 10;
static const int _end = 11;
final int _type;
/// The flow id of the flow event.
final int id;
Flow._(this._type, this.id);
/// A "begin" Flow event.
///
/// When passed to a [Timeline] method, generates a "begin" Flow event.
/// If [id] is not provided, an id that conflicts with no other Dart-generated
/// flow id's will be generated.
static Flow begin({int id}) {
return new Flow._(_begin, id ?? _getNextAsyncId());
}
/// A "step" Flow event.
///
/// When passed to a [Timeline] method, generates a "step" Flow event.
/// The [id] argument is required. It can come either from another [Flow]
/// event, or some id that comes from the environment.
static Flow step(int id) => new Flow._(_step, id);
/// An "end" Flow event.
///
/// When passed to a [Timeline] method, generates a "end" Flow event.
/// The [id] argument is required. It can come either from another [Flow]
/// event, or some id that comes from the environment.
static Flow end(int id) => new Flow._(_end, id);
}
/// Add to the timeline.
///
/// [Timeline]'s methods add synchronous events to the timeline. When
/// generating a timeline in Chrome's tracing format, using [Timeline] generates
/// "Complete" events. [Timeline]'s [startSync] and [endSync] can be used
/// explicitly, or implicitly by wrapping a closure in [timeSync]. For exmaple:
///
/// ```dart
/// Timeline.startSync("Doing Something");
/// doSomething();
/// Timeline.finishSync();
/// ```
///
/// Or:
///
/// ```dart
/// Timeline.timeSync("Doing Something", () {
/// doSomething();
/// });
/// ```
class Timeline {
/// Start a synchronous operation labeled [name]. Optionally takes
/// a [Map] of [arguments]. This operation must be finished before
/// a [Map] of [arguments]. This slice may also optionally be associated with
/// a [Flow] event. This operation must be finished before
/// returning to the event queue.
static void startSync(String name, {Map arguments}) {
static void startSync(String name, {Map arguments, Flow flow}) {
if (_isProduct) {
return;
}
@ -30,6 +112,9 @@ class Timeline {
if (arguments is Map) {
block._appendArguments(arguments);
}
if (flow is Flow) {
block.flow = flow;
}
_stack.add(block);
}
@ -74,8 +159,8 @@ class Timeline {
/// A utility method to time a synchronous [function]. Internally calls
/// [function] bracketed by calls to [startSync] and [finishSync].
static dynamic timeSync(String name, TimelineSyncFunction function,
{Map arguments}) {
startSync(name, arguments: arguments);
{Map arguments, Flow flow}) {
startSync(name, arguments: arguments, flow: flow);
try {
return function();
} finally {
@ -225,6 +310,9 @@ class _SyncBlock {
// The start time stamp of the thread cpu clock.
final int _startCpu;
/// An (optional) flow event associated with this block.
Flow _flow;
_SyncBlock._(this.name, this._start, this._startCpu);
/// Finish this block of time. At this point, this block can no longer be
@ -233,6 +321,10 @@ class _SyncBlock {
// Report event to runtime.
_reportCompleteEvent(
_start, _startCpu, category, name, _argumentsAsJson(_arguments));
if (_flow != null) {
_reportFlowEvent(_start, _startCpu, category, name, _flow._type, _flow.id,
_argumentsAsJson(null));
}
}
void _appendArguments(Map arguments) {
@ -244,6 +336,10 @@ class _SyncBlock {
}
_arguments.addAll(arguments);
}
void set flow(Flow f) {
_flow = f;
}
}
String _fastPathArguments;
@ -283,6 +379,10 @@ external void _reportTaskEvent(int start, int taskId, String phase,
external void _reportCompleteEvent(int start, int startCpu, String category,
String name, String argumentsAsJson);
/// Reports a flow event.
external void _reportFlowEvent(int start, int startCpu, String category,
String name, int type, int id, String argumentsAsJson);
/// Reports an instant event.
external void _reportInstantEvent(
int start, String category, String name, String argumentsAsJson);