Remember when an isolate was paused and subtly display it in Obseravatory

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

Committed: https://github.com/dart-lang/sdk/commit/d0882dd363d1010997a423d55a9991e3ba219f00

[Cutch, 2015-08-24 23:49:51]

johnmccutchan@google.com changed reviewers:
+ turnidge@google.com

[turnidge, 2015-08-25 18:25:31]

We create a Resume event in isolate.cc on line 1699.  This resume event will
have the wrong timestamp.  To fix this I recommend saving a
last_resume_timestamp_ perhaps in Isolate::Resume() and then playing the same
game you do with pause-on-start/exit.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/lib/src...
File runtime/observatory/lib/src/service/object.dart (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/lib/src...
runtime/observatory/lib/src/service/object.dart:1765: new
DateTime.fromMillisecondsSinceEpoch(map['timestamp'].toInt());
Here we are doing toInt(), but above for 'startTime' we are just passing it as
an int (e.g. line 1241).  Feels like these timestamps should be sent/processed
consistently.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
File runtime/observatory/tests/service/pause_on_start_and_exit_test.dart
(right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_and_exit_test.dart:44:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
Maybe save the pause time to pauseTime1?  See next comment.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_and_exit_test.dart:69:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
expect(pauseTime2, greaterThan(pauseTime1))

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
File runtime/observatory/tests/service/pause_on_start_then_step_test.dart
(right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_then_step_test.dart:73:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
Same comment as previous test.

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/debugger.h
File runtime/vm/debugger.h (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/debugger.h#newco...
runtime/vm/debugger.h:359: timestamp_(-1) {}
Let's not put this in DebuggerEvent.  Instead let's put it in ServiceEvent.

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/service_event.cc
File runtime/vm/service_event.cc (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/service_event.cc...
runtime/vm/service_event.cc:86: timestamp_ = debugger_event->timestamp();
Let's just use OS::GetCurrentTimeMillis() here too.

[turnidge, 2015-08-25 18:29:03]

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/debugger.h
File runtime/vm/debugger.h (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/debugger.h#newco...
runtime/vm/debugger.h:359: timestamp_(-1) {}
On 2015/08/25 18:25:31, turnidge wrote:
> Let's not put this in DebuggerEvent.  Instead let's put it in ServiceEvent.

Nevermind.

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/service_event.cc
File runtime/vm/service_event.cc (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/vm/service_event.cc...
runtime/vm/service_event.cc:86: timestamp_ = debugger_event->timestamp();
On 2015/08/25 18:25:31, turnidge wrote:
> Let's just use OS::GetCurrentTimeMillis() here too.

Nevermind

[Cutch, 2015-08-25 21:54:58]

PTAL

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/lib/src...
File runtime/observatory/lib/src/service/object.dart (right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/lib/src...
runtime/observatory/lib/src/service/object.dart:1765: new
DateTime.fromMillisecondsSinceEpoch(map['timestamp'].toInt());
On 2015/08/25 18:25:31, turnidge wrote:
> Here we are doing toInt(), but above for 'startTime' we are just passing it as
> an int (e.g. line 1241).  Feels like these timestamps should be sent/processed
> consistently.

We should be calling AddPropertyTimeMillis in C++ whenever we print a timestamp.
The Isolate::PrintJSON and GetVM was just adding it as an int.

I've fixed that and added the .toInt() call for all timestamps before passing to
DateTime.fromMillisecondsSinceEpoch.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
File runtime/observatory/tests/service/pause_on_start_and_exit_test.dart
(right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_and_exit_test.dart:44:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
On 2015/08/25 18:25:31, turnidge wrote:
> Maybe save the pause time to pauseTime1?  See next comment.

Done.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_and_exit_test.dart:69:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
On 2015/08/25 18:25:31, turnidge wrote:
> expect(pauseTime2, greaterThan(pauseTime1))

Done.

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
File runtime/observatory/tests/service/pause_on_start_then_step_test.dart
(right):

https://codereview.chromium.org/1311503004/diff/1/runtime/observatory/tests/s...
runtime/observatory/tests/service/pause_on_start_then_step_test.dart:73:
equals(isolate.pauseEvent.timestamp.millisecondsSinceEpoch));
On 2015/08/25 18:25:31, turnidge wrote:
> Same comment as previous test.

Done.

[turnidge, 2015-08-26 17:43:56]

lgtm

[Cutch, 2015-08-26 17:58:05]

Committed patchset #3 (id:40001) manually as
d0882dd363d1010997a423d55a9991e3ba219f00 (presubmit successful).

[nweiz, 2015-09-10 22:45:13]

nweiz@google.com changed reviewers:
+ nweiz@google.com

[nweiz, 2015-09-10 22:45:14]

DBC

https://codereview.chromium.org/1311503004/diff/40001/runtime/vm/service/serv...
File runtime/vm/service/service.md (right):

https://codereview.chromium.org/1311503004/diff/40001/runtime/vm/service/serv...
runtime/vm/service/service.md:964: // paused. For other events, the timestamp is
from when the event was created.
Which events are which?