Slow display of SUnitBrowser

> Jeff, and anyone else with an interest:
>
> There is definitely still an issue with SUnitBrowser slowing down the
> running of tests due to its updating of the display.
>
> Sorry about the length of this post, but I felt I needed to present some
> of the details of what I found in my investigation. Something more
> resembling conclusions can be found at the bottom.
>
> (For reference, this was done on a Win2K 667MHz machine).
>
> Starting with a single suite that has 33 TestCases in it:
>     [DateAndTimeTest suite run] millisecondsToRun  ---> 24
> So it takes about 0.7ms each to run them. Actually, running a test takes
> about 0.2ms. The rest of the time is building the suite, half of which
> (at least in larger groups of suites) is in sorting the selectors.
>
> Running the same in SUnitBrowser (which displays it as 33 separate lines
> with 1 TestCase each)
>     [SUnitBrowser allInstances first runAll] millisecondsToRun  ---> 307
>
> or more than 12 times as long! And it only gets worse with more tests or
> larger suites. :-(
>
> I temporarily replicated 10 copies of that suite with 33 tests in each.
> Running without the UI took 232ms. In SUnitBrowser it took 9.4 seconds,
> or 40 times longer!!
>
> For the rest of my investigation I used my current full suite of tests.
> They are quite a mixed bag, with many of them being more like
> integration or acceptance tests rather than simple unit tests. To focus
> just on the UI slowdown on otherwise fast tests, I made them all fast
> <g> by commenting out TestCase>>runCase.
>
> With that I was able to check out 1017 tests in 155 suites. That
> averages 6.5 tests per suite with the largest having 57. "Running" the
> tests without the UI took 2.3 seconds, of which 97% was in #buildSuite,
> with 51% in sorting the selectors.
>
> Running the tests in SUnitBrowser took 54 seconds. Even assuming say 1ms
> per test to actually run a typical unit test, once one has the suite
> built, it's something like a factor of 50 slowdown to update the UI.
>
> Doing a profile of it using Ian's profiler does point out pretty clearly
> what's going on:
>     Profiler profile: [SUnitBrowser allInstances first runAll]
>
> One is struck that 56% of the time is spent doing
> Collection>>inject:into: for one reason or another. That 50% of the time
> is in ListViewColumn>>textFromRow:. And a whopping 47% of the time is in
> SUnitBrowserResult>>numberCorrectFor:.
>
> As quick confirmation of this, I made #numberCorrectFor: simply return a
> constant, and the time to run dropped from 54s to 28.6s.
>
> So the biggest problem is, as others have pointed out, that of
> repeatedly scanning collections to determine the current status of a
> test suite. It's at least O(n-squared), with the number of tests in the
> current suite against the total number of tests that have been run so
> far. You can see a definite slow-down on large suites, and also over
> time on equally sized suites. Seems that the model change you spoke of
> is definitely in order -- where the model incrementally updates the
> status of a suite. That should knock 1/2 the time off.
>
> The second hotspot was with 19% spent in ListModel>>findFirst:. Given a
> testCase, it's looking for what index in the list should be updated.
> Given that we're running the tests for each line of the list
> sequentially, there should be a way to completely dispense with this
> time.
>
> But even with all those time wasters eliminated, still seems like a high
> overhead for the UI update when running a bunch of quick tests.
>
> The real question is how much of a slowdown is it worth to get the "eye
> candy" of continually updated status while all of the tests are run. I'm
> starting to think not very much. It seems the real value of the detail
> list comes in selecting which tests to run, and in reviewing the status
> after running some or all of them.
>
> Ah, just tried an experiment - if the "display all results" is off (and
> the bug fixed), then it runs in 4.3 seconds rather than 54. Now were
> talking. That's just updating the status bar at the bottom. Even there,
> there's not really a need to update that status 250 times a second.
>
> As far as displaying the details while running, perhaps the ideal
> solution would be to update at most a few times per second, plus when
> moving on to a new suite. Seems like we should be able to get it down to
> a reasonable overhead for fast running tests, while still providing
> progress feedback even on slower running tests.
>
> This last is something I'll try to explore when I get some more time, as
> it's actually independent of changing the model since the overhead can
> be reduced by doing fewer updates as well as speeding up each one.
>
> Regards,
> -Bill
>
> -------------------------------------------
> Bill Dargel            [hidden email]
> Shoshana Technologies
> 100 West Joy Road, Ann Arbor, MI 48105  USA
>
>

> detail list while the tests are running.
>
> Regards,
> -Bill
>
> -------------------------------------------
> Bill Dargel            [hidden email]
> Shoshana Technologies
> 100 West Joy Road, Ann Arbor, MI 48105  USA
>
>