microsoft / vstest

Visual Studio Test Platform is the runner and engine that powers test explorer and vstest.console.
MIT License
897 stars 323 forks source link

MSTestv2 Discovery and Execution time regressed in TP V2. #245

Closed navin22 closed 7 years ago

navin22 commented 7 years ago

Description

Discovery and Execution time is slower using TP V2. TP V2 takes almost twice the time as TP V1 for Discovery. And Takes more time to execute also. See the numbers below.

Steps to reproduce

Open the UnitTestProject2.sln in \navbdevenv\share\TPV2Perf. Clean the solution and build. Note down the number in the Test output pane. Enable TP V2. Close and open the VS Now clean the solution and build

Expected behavior

Similar discovery and Execution experience across TP V1 and TP V2

Actual behavior

TP V2 is slower

Environment

d15rel/15.0.25914.0

Note

Same behaviour using vstest.console.exe also. Behaviour is same for 9K Tests also.

Data

Discovery Data: image

Execution Data: image

saikrishnav commented 7 years ago

@navin22 @codito @AbhitejJohn @sbaid

On a RC3 Machine, I am getting these numbers. There is practically no difference between MsTest-V1 and MsTest-V2. I am not seeing this as an MSTEST V2 issue.

But Xunit is an interesting one. I don't understand what's causing such a huge perf benefit.

MSTest V1: TPV1: First Time Discovery in IDE: ~4-5 sec for 9K Tests TPV2: First Time Discovery in IDE: ~8-9 sec for 9K Tests

MSTest V2: TPV1: First Time Discovery in IDE: ~4-5 sec for 9K Tests TPV2: First Time Discovery in IDE: ~8-9 sec for 9K Tests

Xunit (All Pre-release): TPV1: Discovery: 1 min 10 sec - 1 min 11 sec. TPV2: Discovery: 25-26 sec.

AbhitejJohn commented 7 years ago

Here is the time split for 9K tests for discovery: Adapter discovery : ~1 second Serializing test cases: ~2.5 seconds Sending them to vstest.console: ~1.5 seconds

This is only on the test host side though but accounts for most of the added time when compared to TPV1. The overhead of serialization and sending test cases alone is ~4 seconds.

Need to figure out how the same delta does not reflect for execution.

AbhitejJohn commented 7 years ago

Ok. More insight follows: Both discovery and execution follow the same pattern which is slightly different from what I reported above: Both of them spend around 3-4 seconds deserializing and sending the testcases/testresults across the wire. TP V1 takes a maximum of 2 seconds for these two operations.

Time(Sending data over the port) > Time(deserialization)

Execution numbers(CLI)

Platform Communication(a) Adapter time(b)(includes a) Total time(a+b+overhead - reported by the runner)
TP V2 3.463 12.048 12.477

Also I tried moving to sending data over the stream directly which netted around ~200-300 ms.(Not consistent though). Saw it being equal sometimes too. Also tried setting GC to server mode which regressed performance exponentially. This did not make much sense according to the documentation though. We can investigate this more.

AbhitejJohn commented 7 years ago

The RCA for this is similar to #129. Tracking it there and closing this one.