Remember when an isolate was paused and subtly display it in Obseravatory
- Display paused time as tooltip over "paused" word.
- Send a timestamp with every ServiceEvent.
- Unit tests verifying that paused on start, exit, and breakpoint timestamps are stable.
- Remember the pause time in DebuggerEvent.
- Remember the pause time in MessageHandler.
- Updated service protocol documentation.
R=turnidge@google.com
Review URL: https://codereview.chromium.org//1311503004 .
diff --git a/runtime/observatory/lib/src/elements/isolate_summary.html b/runtime/observatory/lib/src/elements/isolate_summary.html
index 31dc45c..40b9eb2 100644
--- a/runtime/observatory/lib/src/elements/isolate_summary.html
+++ b/runtime/observatory/lib/src/elements/isolate_summary.html
@@ -45,7 +45,7 @@
<polymer-element name="isolate-run-state" extends="observatory-element">
<template>
<template if="{{ isolate.paused }}">
- <strong>paused</strong>
+ <strong title="{{ isolate.pauseEvent.timestamp.toString() }}">paused</strong>
</template>
<template if="{{ isolate.running }}">
diff --git a/runtime/observatory/lib/src/service/object.dart b/runtime/observatory/lib/src/service/object.dart
index d2dade6..8907a8e 100644
--- a/runtime/observatory/lib/src/service/object.dart
+++ b/runtime/observatory/lib/src/service/object.dart
@@ -767,7 +767,7 @@
version = map['version'];
targetCPU = map['targetCPU'];
architectureBits = map['architectureBits'];
- var startTimeMillis = map['startTime'];
+ var startTimeMillis = map['startTime'].toInt();
startTime = new DateTime.fromMillisecondsSinceEpoch(startTimeMillis);
refreshTime = new DateTime.now();
notifyPropertyChange(#upTime, 0, 1);
@@ -1238,7 +1238,7 @@
entry = map['entry'];
}
var savedStartTime = startTime;
- var startTimeInMillis = map['startTime'];
+ var startTimeInMillis = map['startTime'].toInt();
startTime = new DateTime.fromMillisecondsSinceEpoch(startTimeInMillis);
notifyPropertyChange(#upTime, 0, 1);
var countersMap = map['_tagCounters'];
@@ -1733,6 +1733,7 @@
}
@observable String kind;
+ @observable DateTime timestamp;
@observable Breakpoint breakpoint;
@observable Frame topFrame;
@observable Instance exception;
@@ -1745,6 +1746,7 @@
@observable String exceptions;
@observable String bytesAsString;
@observable Map logRecord;
+
int chunkIndex, chunkCount, nodeCount;
@observable bool get isPauseEvent {
@@ -1759,6 +1761,8 @@
_loaded = true;
_upgradeCollection(map, owner);
assert(map['isolate'] == null || owner == map['isolate']);
+ timestamp =
+ new DateTime.fromMillisecondsSinceEpoch(map['timestamp'].toInt());
kind = map['kind'];
notifyPropertyChange(#isPauseEvent, 0, 1);
name = 'ServiceEvent $kind';
diff --git a/runtime/observatory/tests/service/pause_on_start_and_exit_test.dart b/runtime/observatory/tests/service/pause_on_start_and_exit_test.dart
index b7f7935..7c63e9d 100644
--- a/runtime/observatory/tests/service/pause_on_start_and_exit_test.dart
+++ b/runtime/observatory/tests/service/pause_on_start_and_exit_test.dart
@@ -4,6 +4,7 @@
// VMOptions=--error_on_bad_type --error_on_bad_override
import 'package:observatory/service_io.dart';
+import 'package:unittest/unittest.dart';
import 'test_helper.dart';
import 'dart:async';
@@ -33,6 +34,15 @@
await completer.future;
}
+ // Grab the timestamp.
+ var pausetime1 = isolate.pauseEvent.timestamp;
+ expect(pausetime1, isNotNull);
+ // Reload the isolate.
+ await isolate.reload();
+ // Verify that it is the same.
+ expect(pausetime1.millisecondsSinceEpoch,
+ equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
+
completer = new Completer();
stream = await isolate.vm.getEventStream(VM.kDebugStream);
subscription = stream.listen((ServiceEvent event) {
@@ -48,6 +58,17 @@
// Wait for the isolate to hit PauseExit.
await completer.future;
+
+ // Grab the timestamp.
+ var pausetime2 = isolate.pauseEvent.timestamp;
+ expect(pausetime2, isNotNull);
+ // Reload the isolate.
+ await isolate.reload();
+ // Verify that it is the same.
+ expect(pausetime2.millisecondsSinceEpoch,
+ equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
+ expect(pausetime2.millisecondsSinceEpoch,
+ greaterThan(pausetime1.millisecondsSinceEpoch));
},
];
diff --git a/runtime/observatory/tests/service/pause_on_start_then_step_test.dart b/runtime/observatory/tests/service/pause_on_start_then_step_test.dart
index 316667f..0e6b5ee 100644
--- a/runtime/observatory/tests/service/pause_on_start_then_step_test.dart
+++ b/runtime/observatory/tests/service/pause_on_start_then_step_test.dart
@@ -4,6 +4,7 @@
// VMOptions=--error_on_bad_type --error_on_bad_override
import 'package:observatory/service_io.dart';
+import 'package:unittest/unittest.dart';
import 'test_helper.dart';
import 'dart:async';
@@ -35,6 +36,15 @@
await completer.future;
}
+ // Grab the timestamp.
+ var pausetime1 = isolate.pauseEvent.timestamp;
+ expect(pausetime1, isNotNull);
+ // Reload the isolate.
+ await isolate.reload();
+ // Verify that it is the same.
+ expect(pausetime1.millisecondsSinceEpoch,
+ equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
+
completer = new Completer();
stream = await isolate.vm.getEventStream(VM.kDebugStream);
subscription = stream.listen((ServiceEvent event) {
@@ -52,6 +62,18 @@
// Wait for the isolate to hit PauseBreakpoint.
print('Waiting for PauseBreakpoint');
await completer.future;
+
+ // Grab the timestamp.
+ var pausetime2 = isolate.pauseEvent.timestamp;
+ expect(pausetime2, isNotNull);
+ // Reload the isolate.
+ await isolate.reload();
+ // Verify that it is the same.
+ expect(pausetime2.millisecondsSinceEpoch,
+ equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
+
+ expect(pausetime2.millisecondsSinceEpoch,
+ greaterThan(pausetime1.millisecondsSinceEpoch));
},
];
diff --git a/runtime/vm/debugger.cc b/runtime/vm/debugger.cc
index 2855c18..0cd16d8 100644
--- a/runtime/vm/debugger.cc
+++ b/runtime/vm/debugger.cc
@@ -234,6 +234,11 @@
}
+void DebuggerEvent::UpdateTimestamp() {
+ timestamp_ = OS::GetCurrentTimeMillis();
+}
+
+
bool Debugger::HasEventHandler() {
return ((event_handler_ != NULL) ||
Service::isolate_stream.enabled() ||
@@ -2314,6 +2319,7 @@
ASSERT(obj_cache_ == NULL);
pause_event_ = event;
+ pause_event_->UpdateTimestamp();
obj_cache_ = new RemoteObjectCache(64);
InvokeEventHandler(event);
diff --git a/runtime/vm/debugger.h b/runtime/vm/debugger.h
index 15893d1..396e8b2 100644
--- a/runtime/vm/debugger.h
+++ b/runtime/vm/debugger.h
@@ -355,7 +355,8 @@
breakpoint_(NULL),
exception_(NULL),
async_continuation_(NULL),
- at_async_jump_(false) {}
+ at_async_jump_(false),
+ timestamp_(-1) {}
Isolate* isolate() const { return isolate_; }
@@ -414,6 +415,12 @@
return isolate_->main_port();
}
+ void UpdateTimestamp();
+
+ int64_t timestamp() const {
+ return timestamp_;
+ }
+
private:
Isolate* isolate_;
EventType type_;
@@ -422,6 +429,7 @@
const Object* exception_;
const Object* async_continuation_;
bool at_async_jump_;
+ int64_t timestamp_;
};
diff --git a/runtime/vm/isolate.cc b/runtime/vm/isolate.cc
index 0b8a1b0..853896d 100644
--- a/runtime/vm/isolate.cc
+++ b/runtime/vm/isolate.cc
@@ -661,6 +661,7 @@
debugger_(NULL),
single_step_(false),
resume_request_(false),
+ last_resume_timestamp_(OS::GetCurrentTimeMillis()),
has_compiled_(false),
flags_(),
random_(),
@@ -1674,7 +1675,7 @@
return;
}
int64_t start_time_millis = start_time() / kMicrosecondsPerMillisecond;
- jsobj.AddProperty64("startTime", start_time_millis);
+ jsobj.AddPropertyTimeMillis("startTime", start_time_millis);
IsolateSpawnState* state = spawn_state();
if (state != NULL) {
const Object& entry = Object::Handle(this, state->ResolveFunction());
diff --git a/runtime/vm/isolate.h b/runtime/vm/isolate.h
index 3a42366..cc07c1b 100644
--- a/runtime/vm/isolate.h
+++ b/runtime/vm/isolate.h
@@ -447,6 +447,11 @@
// Requests that the debugger resume execution.
void Resume() {
resume_request_ = true;
+ last_resume_timestamp_ = OS::GetCurrentTimeMillis();
+ }
+
+ int64_t last_resume_timestamp() const {
+ return last_resume_timestamp_;
}
// Returns whether the vm service has requested that the debugger
@@ -803,6 +808,7 @@
Debugger* debugger_;
bool single_step_;
bool resume_request_;
+ int64_t last_resume_timestamp_;
bool has_compiled_;
Flags flags_;
Random random_;
diff --git a/runtime/vm/message_handler.cc b/runtime/vm/message_handler.cc
index d330c0f..77604e8 100644
--- a/runtime/vm/message_handler.cc
+++ b/runtime/vm/message_handler.cc
@@ -6,9 +6,11 @@
#include "vm/dart.h"
#include "vm/lockers.h"
+#include "vm/os.h"
#include "vm/port.h"
#include "vm/thread_interrupter.h"
+
namespace dart {
DECLARE_FLAG(bool, trace_isolates);
@@ -42,6 +44,7 @@
pause_on_exit_(false),
paused_on_start_(false),
paused_on_exit_(false),
+ paused_timestamp_(-1),
pool_(NULL),
task_(NULL),
start_callback_(NULL),
@@ -250,6 +253,7 @@
NotifyPauseOnStart();
monitor_.Enter();
paused_on_start_ = true;
+ paused_timestamp_ = OS::GetCurrentTimeMillis();
}
HandleMessages(false, false);
if (pause_on_start()) {
@@ -258,6 +262,7 @@
return;
} else {
paused_on_start_ = false;
+ paused_timestamp_ = -1;
}
}
@@ -286,6 +291,7 @@
}
notify_paused_on_exit = true;
paused_on_exit_ = true;
+ paused_timestamp_ = OS::GetCurrentTimeMillis();
}
} else {
if (FLAG_trace_isolates) {
@@ -297,6 +303,7 @@
pool_ = NULL;
run_end_callback = true;
paused_on_exit_ = false;
+ paused_timestamp_ = -1;
}
}
}
diff --git a/runtime/vm/message_handler.h b/runtime/vm/message_handler.h
index 07fa5ab..78c5f6c 100644
--- a/runtime/vm/message_handler.h
+++ b/runtime/vm/message_handler.h
@@ -96,6 +96,11 @@
return paused_on_exit_;
}
+ // Timestamp of the paused on start or paused on exit.
+ int64_t paused_timestamp() const {
+ return paused_timestamp_;
+ }
+
class AcquiredQueues : public ValueObject {
public:
AcquiredQueues();
@@ -207,6 +212,7 @@
bool pause_on_exit_;
bool paused_on_start_;
bool paused_on_exit_;
+ int64_t paused_timestamp_;
ThreadPool* pool_;
ThreadPool::Task* task_;
StartCallback start_callback_;
diff --git a/runtime/vm/service.cc b/runtime/vm/service.cc
index a517f21..2da04ef 100644
--- a/runtime/vm/service.cc
+++ b/runtime/vm/service.cc
@@ -984,6 +984,7 @@
if (text != NULL) {
event.AddProperty("text", text);
}
+ event.AddPropertyTimeMillis("timestamp", OS::GetCurrentTimeMillis());
}
}
}
@@ -2543,6 +2544,7 @@
event.AddProperty("type", "Event");
event.AddProperty("kind", "_Graph");
event.AddProperty("isolate", isolate);
+ event.AddPropertyTimeMillis("timestamp", OS::GetCurrentTimeMillis());
event.AddProperty("chunkIndex", i);
event.AddProperty("chunkCount", num_chunks);
@@ -2875,7 +2877,7 @@
jsobj.AddProperty("_typeChecksEnabled", isolate->flags().type_checks());
int64_t start_time_millis = (Dart::vm_isolate()->start_time() /
kMicrosecondsPerMillisecond);
- jsobj.AddProperty64("startTime", start_time_millis);
+ jsobj.AddPropertyTimeMillis("startTime", start_time_millis);
// Construct the isolate list.
{
JSONArray jsarr(&jsobj, "isolates");
diff --git a/runtime/vm/service/service.md b/runtime/vm/service/service.md
index 17f46a8..3b24aee 100644
--- a/runtime/vm/service/service.md
+++ b/runtime/vm/service/service.md
@@ -959,6 +959,11 @@
// The isolate with which this event is associated.
@Isolate isolate;
+ // The timestamp (in milliseconds since the epoch) associated with this event.
+ // For some isolate pause events, the timestamp is from when the isolate was
+ // paused. For other events, the timestamp is from when the event was created.
+ int timestamp;
+
// The breakpoint which was added, removed, or resolved.
//
// This is provided for the event kinds:
diff --git a/runtime/vm/service_event.cc b/runtime/vm/service_event.cc
index 9c9868a9..42dd202 100644
--- a/runtime/vm/service_event.cc
+++ b/runtime/vm/service_event.cc
@@ -4,6 +4,8 @@
#include "vm/service_event.h"
+#include "vm/message_handler.h"
+
namespace dart {
// Translate from the legacy DebugEvent to a ServiceEvent.
@@ -30,6 +32,31 @@
}
}
+
+ServiceEvent::ServiceEvent(Isolate* isolate, EventKind event_kind)
+ : isolate_(isolate),
+ kind_(event_kind),
+ embedder_kind_(NULL),
+ embedder_stream_id_(NULL),
+ breakpoint_(NULL),
+ top_frame_(NULL),
+ exception_(NULL),
+ async_continuation_(NULL),
+ at_async_jump_(false),
+ inspectee_(NULL),
+ gc_stats_(NULL),
+ bytes_(NULL),
+ bytes_length_(0),
+ timestamp_(OS::GetCurrentTimeMillis()) {
+ if ((event_kind == ServiceEvent::kPauseStart) ||
+ (event_kind == ServiceEvent::kPauseExit)) {
+ timestamp_ = isolate->message_handler()->paused_timestamp();
+ } else if (event_kind == ServiceEvent::kResume) {
+ timestamp_ = isolate->last_resume_timestamp();
+ }
+}
+
+
ServiceEvent::ServiceEvent(const DebuggerEvent* debugger_event)
: isolate_(debugger_event->isolate()),
kind_(TranslateEventKind(debugger_event->type())),
@@ -40,7 +67,8 @@
inspectee_(NULL),
gc_stats_(NULL),
bytes_(NULL),
- bytes_length_(0) {
+ bytes_length_(0),
+ timestamp_(OS::GetCurrentTimeMillis()) {
DebuggerEvent::EventType type = debugger_event->type();
if (type == DebuggerEvent::kBreakpointReached) {
set_breakpoint(debugger_event->breakpoint());
@@ -55,6 +83,9 @@
type == DebuggerEvent::kExceptionThrown) {
set_top_frame(debugger_event->top_frame());
}
+ if (debugger_event->timestamp() != -1) {
+ timestamp_ = debugger_event->timestamp();
+ }
}
@@ -204,6 +235,8 @@
jsobj->AddProperty("type", "Event");
jsobj->AddProperty("kind", KindAsCString());
jsobj->AddProperty("isolate", isolate());
+ ASSERT(timestamp_ != -1);
+ jsobj->AddPropertyTimeMillis("timestamp", timestamp_);
}
} // namespace dart
diff --git a/runtime/vm/service_event.h b/runtime/vm/service_event.h
index 576e634..3268051 100644
--- a/runtime/vm/service_event.h
+++ b/runtime/vm/service_event.h
@@ -51,20 +51,7 @@
const Instance* stack_trace;
};
- ServiceEvent(Isolate* isolate, EventKind event_kind)
- : isolate_(isolate),
- kind_(event_kind),
- embedder_kind_(NULL),
- embedder_stream_id_(NULL),
- breakpoint_(NULL),
- top_frame_(NULL),
- exception_(NULL),
- async_continuation_(NULL),
- at_async_jump_(false),
- inspectee_(NULL),
- gc_stats_(NULL),
- bytes_(NULL),
- bytes_length_(0) {}
+ ServiceEvent(Isolate* isolate, EventKind event_kind);
explicit ServiceEvent(const DebuggerEvent* debugger_event);
@@ -164,6 +151,10 @@
log_record_ = log_record;
}
+ int64_t timestamp() const {
+ return timestamp_;
+ }
+
void PrintJSON(JSONStream* js) const;
void PrintJSONHeader(JSONObject* jsobj) const;
@@ -183,6 +174,7 @@
const uint8_t* bytes_;
intptr_t bytes_length_;
LogRecord log_record_;
+ int64_t timestamp_;
};
} // namespace dart
