test.py: Report timings by adding up the time of all commands

test.py: Report timings by adding up the time of all commands

BUT=http://dartbug.com/11847
R=ahe@google.com

Committed: https://code.google.com/p/dart/source/detail?r=25096

[kustermann, 2013-07-16 14:48:47]

https://codereview.chromium.org/19388002/diff/2001/tools/testing/dart/test_pr...
File tools/testing/dart/test_progress.dart (right):

https://codereview.chromium.org/19388002/diff/2001/tools/testing/dart/test_pr...
tools/testing/dart/test_progress.dart:222: }
This procedure will be called O(n*log n) which means that we call it quite a few
times per test. We could cache it, but looking through my performance glasses
this whole things should be changed:

We should use a MaxHeap data structure of 20 elements which would basically
reduce this to linear time. But that's for another CL I guess.

[ahe, 2013-07-16 14:50:11]

Adding up the times does not tell us which part is the problem. It would be
great if the individual steps were counted separately.

[kustermann, 2013-07-16 15:30:32]

On 2013/07/16 14:50:11, ahe wrote:
> Adding up the times does not tell us which part is the problem. It would be
> great if the individual steps were counted separately.

Just to clarify, do you want to sort the list as it is now and just print the
timing for every command, like this:

sum-of-all-command testname
  timing-of-command0 command0
  timing-of-command1 command1
...

Or do you only want to sort and print based on commands, like this:

timing-of-commandA-of-testcase-Y testcase nameY, commandA
timing-of-commandB-of-testcase-Z testcase nameZ, commandB
....

?

[kustermann, 2013-07-17 13:01:14]

PTAL

As discussed offline, we should sort/print only steps and not test cases.
Here's an example of the printed timing information:


--- Total time: 00:25 ---
0:00:04.141000 - dart2dart-vm release_ia32 - language/closure_cycles_test (vm)
0:00:01.903000 - dart2dart-vm release_ia32 -
language/instance_method2_negative_test (dart2dart)
0:00:01.849000 - dart2dart-vm release_ia32 - language/label8_negative_test
(dart2dart)
0:00:01.835000 - dart2dart-vm release_ia32 - language/field2_negative_test
(dart2dart)
0:00:01.813000 - dart2dart-vm release_ia32 -
language/type_variable_static_context_negative_test (dart2dart)
0:00:01.515000 - dart2dart-vm release_ia32 - language/issue4157508_test
(dart2dart)
0:00:01.515000 - dart2dart-vm release_ia32 - language/prefix22_test (dart2dart)
0:00:01.507000 - dart2dart-vm release_ia32 -
language/parameter_initializer2_test (dart2dart)
0:00:01.506000 - dart2dart-vm release_ia32 - language/issue11793_test
(dart2dart)
0:00:01.505000 - dart2dart-vm release_ia32 -
language/const_objects_are_immutable_test (dart2dart)
0:00:01.505000 - dart2dart-vm release_ia32 - language/super_operator_index4_test
(dart2dart)
0:00:01.504000 - dart2dart-vm release_ia32 - language/super_closure_test
(dart2dart)
0:00:01.503000 - dart2dart-vm release_ia32 -
language/closure_with_super_send_test (dart2dart)
0:00:01.502000 - dart2dart-vm release_ia32 -
language/named_parameters_passing_falsy_test (dart2dart)
0:00:01.502000 - dart2dart-vm release_ia32 -
language/interface_inherit_field_test (dart2dart)
0:00:01.502000 - dart2dart-vm release_ia32 - language/bailout_test (dart2dart)
0:00:01.501000 - dart2dart-vm release_ia32 -
language/string_interpolation3_negative_test (dart2dart)
0:00:01.501000 - dart2dart-vm release_ia32 - language/mixin_is_test (dart2dart)
0:00:01.500000 - dart2dart-vm release_ia32 - language/bootstrap_test (dart2dart)
0:00:01.499000 - dart2dart-vm release_ia32 - language/generic_instanceof2_test
(dart2dart)

844 compilations were skipped because the previous output was already up to date

[ahe, 2013-07-17 13:09:12]

Awesome, thank you!

LGTM

[kustermann, 2013-07-17 13:15:31]

Committed patchset #3 manually as r25096 (presubmit successful).