Azure-pipelines-tasks: Exception : Index was out of range. Must be non-negative and less than the size of the collection. on VSTest\2.0.17\TestSelector\TestSelector.exe UpdateTestResults

[wouterroos]

Hi,

Today I was playing with the 'Run only impacted tests' feature of the 'Run Tests using Visual Studio task'. My test run succeeds, but I get the following error when VSTest\2.0.17\TestSelector\TestSelector.exe UpdateTestResults is executed (see below).

2017-03-07T15:55:38.0425386Z Total tests: 1206. Passed: 1200. Failed: 0. Skipped: 6.
2017-03-07T15:55:38.0425386Z Test Run Successful.
2017-03-07T15:55:38.0425386Z Test execution time: 11.8204 Minutes
2017-03-07T15:55:38.9516587Z Results File: C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13.trx
2017-03-07T15:55:39.1116416Z ##[debug]rc:0
2017-03-07T15:55:39.1116416Z ##[debug]success:true
2017-03-07T15:55:39.1116416Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bbaf38b0-034c-11e7-a552-4390675c08db.runsettings
2017-03-07T15:55:39.1116416Z ##[debug]removing file
2017-03-07T15:55:39.1116416Z ##[debug]defaultRoot: 'C:\tfsagent\_work\19\s\TestResults'
2017-03-07T15:55:39.1116416Z ##[debug]findOptions.followSpecifiedSymbolicLink: 'true'
2017-03-07T15:55:39.1195144Z ##[debug]findOptions.followSymbolicLinks: 'true'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.debug: 'false'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.nobrace: 'true'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.noglobstar: 'false'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.dot: 'true'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.noext: 'false'
2017-03-07T15:55:39.1195144Z ##[debug]matchOptions.nocase: 'true'
2017-03-07T15:55:39.1216417Z ##[debug]matchOptions.nonull: 'false'
2017-03-07T15:55:39.1216417Z ##[debug]matchOptions.matchBase: 'false'
2017-03-07T15:55:39.1216417Z ##[debug]matchOptions.nocomment: 'false'
2017-03-07T15:55:39.1216417Z ##[debug]matchOptions.nonegate: 'false'
2017-03-07T15:55:39.1216417Z ##[debug]matchOptions.flipNegate: 'false'
2017-03-07T15:55:39.1288242Z ##[debug]pattern: 'C:\tfsagent\_work\19\s\TestResults\*.trx'
2017-03-07T15:55:39.1288242Z ##[debug]findPath: 'C:\tfsagent\_work\19\s\TestResults'
2017-03-07T15:55:39.1288242Z ##[debug]statOnly: 'false'
2017-03-07T15:55:39.1288242Z ##[debug]findPath: 'C:\tfsagent\_work\19\s\TestResults'
2017-03-07T15:55:39.1288242Z ##[debug]findOptions.followSpecifiedSymbolicLink: 'true'
2017-03-07T15:55:39.1288242Z ##[debug]findOptions.followSymbolicLinks: 'true'
2017-03-07T15:55:39.1288242Z ##[debug]  C:\tfsagent\_work\19\s\TestResults (directory)
2017-03-07T15:55:39.1316419Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\e8ca5e74-0e5e-4b9a-9669-ae42f540193d (directory)
2017-03-07T15:55:39.1316419Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\e8ca5e74-0e5e-4b9a-9669-ae42f540193d\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_43_51.coverage (file)
2017-03-07T15:55:39.1316419Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\f82cb885-fd7f-461c-a1ec-97ade1afe849 (directory)
2017-03-07T15:55:39.1316419Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13 (directory)
2017-03-07T15:55:39.1316419Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13\In (directory)
2017-03-07T15:55:39.1384786Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13\In\VTFS-DBS02 (directory)
2017-03-07T15:55:39.1384786Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13\In\VTFS-DBS02\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_43_51.coverage (file)
2017-03-07T15:55:39.1384786Z ##[debug]  C:\tfsagent\_work\19\s\TestResults\tfsonlinebuild_VTFS-DBS02 2017-03-07 15_44_13.trx (file)
2017-03-07T15:55:39.1384786Z ##[debug]9 results
2017-03-07T15:55:39.1384786Z ##[debug]found 9 paths
2017-03-07T15:55:39.1384786Z ##[debug]applying include pattern
2017-03-07T15:55:39.1384786Z ##[debug]1 matches
2017-03-07T15:55:39.1384786Z ##[debug]1 final results
2017-03-07T15:55:39.1384786Z ##[debug]C:\tfsagent\tasks\VSTest\2.0.17\TestSelector\TestSelector.exe arg: UpdateTestResults
2017-03-07T15:55:39.1384786Z ##[debug]Build.BuildId=22122
2017-03-07T15:55:39.1416422Z ##[debug]System.TeamFoundationCollectionUri=https://xxx.visualstudio.com/
2017-03-07T15:55:39.1416422Z ##[debug]System.TeamProject=MFS
2017-03-07T15:55:39.1416422Z ##[debug]SystemVssConnection auth param AccessToken = ********
2017-03-07T15:55:39.1478419Z ##[debug]exec tool: C:\tfsagent\tasks\VSTest\2.0.17\TestSelector\TestSelector.exe
2017-03-07T15:55:39.1478419Z ##[debug]Arguments:
2017-03-07T15:55:39.1478419Z ##[debug]   UpdateTestResults
2017-03-07T15:55:39.1478419Z [command]C:\tfsagent\tasks\VSTest\2.0.17\TestSelector\TestSelector.exe UpdateTestResults
2017-03-07T15:55:39.1478419Z ##[debug]Deleting the response file C:\Users\TFSONL~1\AppData\Local\Temp\d847ee40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1478419Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\d847ee40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1478419Z ##[debug]Deleting the discovered tests file C:\Users\TFSONL~1\AppData\Local\Temp\bd966f40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1478419Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bd966f40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1478419Z ##[debug]removing file
2017-03-07T15:55:39.1478419Z ##[debug]Deleting the baseline build id file C:\Users\TFSONL~1\AppData\Local\Temp\bb56b871-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1516430Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bb56b871-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:39.1516430Z ##[debug]removing file
2017-03-07T15:55:41.4382356Z PERF: GetTestCaseResults: took 1738.5298 ms
2017-03-07T15:55:41.6221835Z PERF: ReadResultsFromFile: took 173.4023 ms
2017-03-07T15:55:42.2365842Z PERF: UpdateResultsAndSignatures: took 623.0815 ms
2017-03-07T15:55:42.2614184Z Exception : Index was out of range. Must be non-negative and less than the size of the collection.
2017-03-07T15:55:42.2614184Z Parameter name: index
2017-03-07T15:55:42.2614184Z  Stack :    at System.ThrowHelper.ThrowArgumentOutOfRangeException(ExceptionArgument argument, ExceptionResource resource)
2017-03-07T15:55:42.2614184Z    at System.Collections.Generic.List`1.get_Item(Int32 index)
2017-03-07T15:55:42.2614184Z    at Microsoft.TeamFoundation.DistributedTask.Task.TestResults.TestRunPublisher.UpdateResults(TestCaseResultData[] testResults, List`1 tcmTestCaseResults, TestHttpClientBase testImpactClient, Int32 runId, Int32 definitionRunId, DefinitionType definitionType) in D:\v2.0\A1\_work\4\s\DistributedTask\Agent\Task.TestResults\TestRunPublisher.cs:line 152
2017-03-07T15:55:42.2614184Z    at Microsoft.TestFoundation.TestImpact.TestSelector.CommandUpdateTestResults.Run() in D:\v2.0\A1\_work\4\s\Ta\Tasks\TestImpact\TestSelector\Commands\Command\CommandUpdateTestResults.cs:line 133
2017-03-07T15:55:42.2614184Z    at Microsoft.TestFoundation.TestImpact.TestSelector.Program.RunCommand(String commandName, String[] args) in D:\v2.0\A1\_work\4\s\Ta\Tasks\TestImpact\TestSelector\Program.cs:line 41
2017-03-07T15:55:42.2964179Z ##[debug]rc:4294967295
2017-03-07T15:55:42.2964179Z ##[debug]success:false
2017-03-07T15:55:42.2964179Z ##[debug]Test Run Updation failed!
2017-03-07T15:55:42.2964179Z ##[debug]task result: Failed
2017-03-07T15:55:42.3064182Z ##[error]Vstest exited with return code: 1.
2017-03-07T15:55:42.3364192Z ##[debug]Deleting the response file C:\Users\TFSONL~1\AppData\Local\Temp\d847ee40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\d847ee40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]Deleting the discovered tests file C:\Users\TFSONL~1\AppData\Local\Temp\bd966f40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bd966f40-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]Deleting the baseline build id file C:\Users\TFSONL~1\AppData\Local\Temp\bb56b871-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bb56b871-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]Deleting the run id fileC:\Users\TFSONL~1\AppData\Local\Temp\bb56b870-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]rm -rf C:\Users\TFSONL~1\AppData\Local\Temp\bb56b870-034c-11e7-a552-4390675c08db.txt
2017-03-07T15:55:42.3364192Z ##[debug]removing file

Am I missing something?

[prawalagarwal]

Hi @wouterroos,

Answer to a few questions will help us:

1) Did you see this error only in your first run or are you seeing this in every run? Are you able to see only impacted tests running? Please share the logs with us after setting system.debug to true in the build variables.

2) The error log says "Test Run Updation Failed". Can you verify if you are not able to see run information in "Summary" tab in the build details or Runs tab under the Test tab?

Thanks

[wouterroos]

Hi,

1. I saw the error multiple times, but sometimes the run finished with some 'not impacted' tests in the results. I'm currently trying to reproduce the issue at the moment, but I'm having some issues with the 'Path to custom test adapters' field (set to 'packages' for our repo, since we're using xunit) which causes the test run to fail with errors similar to: The test source file "(187a4a28b02d5c896372aaea0625e2440ffa3315),<<InsertSensitiveTestNameHere>>" provided was not found. Any ideas on that?

2. For this run, the 'Summary' tab looks like this:

[acesiddhu]

@wouterroos can you share the build logs (after enabling system.debug = true) for "test source file ..." issue

[acesiddhu]

For "Index was out of range. Must be non-negative and less than the size of the collection" issue let me check the code to see where the problem could be

[wouterroos]

@acesiddhu see the attachment for the logs, I've anonymized them so there could by 'duplicate' file references which can be disregarded. If you need anything else just ask.

log.txt

[wouterroos]

@acesiddhu @prawalagarwal I tried to reproduce the issue on my own machine based on the logging I sent you and it seems that the tests will run fine when the (187a4a28b02d5c896372aaea0625e2440ffa3315) part of the test names are not appended. It seems to only append that part for xunit tests but I'm unable to trace where these test names are coming from (my guess is from the Test Impact Analysis feature). Is there anything else I can do to help? We're really exited to start using this feature!

[acesiddhu]

@wouterroos we got a repro today at our end using xunit tests. in the mean time can you tell if you are using VS 2015?
187a4a28b02d5c896372aaea0625e2440ffa3315 should not come from Test Impact Analysis feature. Did this test case name come when you disable test impact analysis?
Also can you ping me ur account name? you can mail me at devops_tools AT Microsoft DOT com. you might get mail delivery failure but I will get the mail

[wouterroos]

@acesiddhu we use Visual Studio 2015 Update 3 on our build server. If I look at older, successful logs I don't see these kind of numbers in the test execution logs. Which account name do you mean exactly?

[acesiddhu]

@wouterroos your vsts accountname. .visualstudio.com

[wouterroos]

@acesiddhu Great, I sent it to the email address provided earlier.

[acesiddhu]

@wouterroos I got a repro and I am working on a fix. Will keep you posted

[acesiddhu]

Hi @wouterroos
Just to update. I saw that test name while using xunit.runner.visualstudio version 2.2.0 comes as fullyqualified name of the test where as in older version of adapter I saw test name was coming as just name (which is correct behavior)

Due to this there is a mis match while uploading test results to TFS. Can you confirm if you are also using 2.2.0?

[wouterroos]

@acesiddhu Yes, we indeed use xunit 2.2.0.

[wouterroos]

@acesiddhu Do you have any update on this or is there something else I can do to help?

[acesiddhu]

@wouterroos we know the root cause of the issue. we can have a temporary fix on our side but we are looking at long term and correct fix. I am discussing this internally on this. Will post back on this. in the mean time is it possible for you to use xunit .99 till we roll out a fix or may be disable run only impacted tests? I will keep this thread posted as we get a fix out

[wouterroos]

@acesiddhu we have currently disabled the feature in order to pass our builds and we will wait until you guys come up with a fix. Thanks for all the help so far!

[acesiddhu]

@wouterroos just an update. one part of the fix (the fix is ensure we publish results properly to server and get rid of the exception you reported) is fixed in this PR https://github.com/Microsoft/vsts-tasks/pull/4002. the fix will roll out in next deployment.

The next issue we are investigating is about test impact meta data that is used to run only impacted test wasn't working for me if I use xunit 2. so essentially if you check run only impacted tests we will always be running all the test now after the above fix. Will let you know about that investigation.

[wouterroos]

@acesiddhu good to hear, when will the next deployment take place? We could then enable the feature again to see of the first part is fixed.

[acesiddhu]

It will start next week. But it depends on which scale unit your account is in. Will keep you updated

[wouterroos]

@acesiddhu Any updates on when either one of the issues will be fixed on our VSTS environment?

[acesiddhu]

@wouterroos can you give it a try now? the deployment happened on Friday. you should not see a crash.
Let me know whats the outcome.

[wouterroos]

@acesiddhu running a build now, will post back the results when finished.

[wouterroos]

@acesiddhu just tried running our tests twice, but I'm still getting the same error message as before.

[acesiddhu]

Can u share build logs to me on email address i shared before in the thread. Also r u using theories by any chance?

Sent from my Windows 10 phone

From: Wouter [e-mail]
Sent: 01 May 2017 23:47
To: Microsoft/[e-mail]
Cc: Siddhartha [e-mail]; [e-mail]
Subject: Re: [Microsoft/vsts-tasks] Exception : Index was out of range. Must be non-negative and less than the size of the collection. on VSTest\2.0.17\TestSelector\TestSelector.exe UpdateTestResults (#3744)

@acesiddhuhttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Facesiddhu&data=02%7C01%7Csiddhartha.pandey%40microsoft.com%7C2591b982a29f4e5ba5d108d490be5de6%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636292594666920615&sdata=BGzefKsY4uzuwCm2SZUHm%2FxxuRDMfcl9emTOE47r51s%3D&reserved=0 just tried running our tests twice, but I'm still getting the same error message as before.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHubhttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FMicrosoft%2Fvsts-tasks%2Fissues%2F3744%23issuecomment-298392553&data=02%7C01%7Csiddhartha.pandey%40microsoft.com%7C2591b982a29f4e5ba5d108d490be5de6%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636292594666920615&sdata=lXw%2Flx7Ysou9HAmERnm%2F9lZ%2FpOBX8CJItYGqpRGDpGg%3D&reserved=0, or mute the threadhttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FABHVt-81i22ZTxCavLTl8qM-pMx707zyks5r1iHIgaJpZM4MVxq8&data=02%7C01%7Csiddhartha.pandey%40microsoft.com%7C2591b982a29f4e5ba5d108d490be5de6%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636292594666920615&sdata=qZMmBMiOcvaeokaaDGVFTuza%2FrYAUGyLye%2FNq0N22Ko%3D&reserved=0.

[wouterroos]

@acesiddhu I sent you the logs as requested. If you need any more information, just let me know. Regarding your question about the xunit Theory tests, we do use them, but as far as I can see from the logs, both Fact and Theory tests are causing errors.

[acesiddhu]

@wouterroos we got the logs. we will look into this.

[wouterroos]

@acesiddhu Any update on this issue?

[acesiddhu]

@wouterroos
Sorry for the delay. we were checking with xunit folks on this one.

There are overall two issues
1) Looks like you are using theories. Theories or data driven test cases wont work with run only impacted test cases. We should make a fix to atleast run all theories and not fail like this. This will ensure that if the test task is running mix of theories and facts we should atleast apply this feature in facts and run all theories.

2) Xunit 2 by default enables parallelism. we rely on certain events from xunit for this functionality. To make this feature work you need to have a runsettings file with this content. This is for Facts

<RunSettings>
  <RunConfiguration>
    <DisableParallelization>true</DisableParallelization>
  </RunConfiguration>
</RunSettings>

We can have a quick call on this and see how we can unblock you on this one?

[acesiddhu]

@wouterroos I have added support for theories and data driven test cases for this feature to work in our backlog. I am closing this issue. Let me know and we can have a call to see if we can unblock you in the mean time

[wouterroos]

@acesiddhu It's not blocking for us at the moment, but we would love to have this functionality to improve our build times. I will look into disabling parallelism and see if that improves our build times with the added benefit of running only impacted Facts.

[acesiddhu]

@wouterroos do let us know if Facts works by disabling parallelism.

[wouterroos]

@acesiddhu I tried running our tests again with DisableParallelization set to true but I still get the same error as before. Are you sure the latest version has been deployed to our VSTS instance?

[acesiddhu]

Does it have theories? Whats the full log saying? If the log has 187a4a28b02d5c896372aaea0625e2440ffa3315 (some random number )they do have theories

[wouterroos]

@acesiddhu Yes it does, I was under the impression that you already created a fix that excludes [Theory] tests from the Impacted Test feature and always runs them, but that doesn't seem to be the case. At the moment I have no easy way to skip all [Theory] tests in our solution so I can't really test if it would work for just [Fact] tests.

[acesiddhu]

@wouterroos hmm. yes it wont work if you have theories. Let me see what can be done to atleast enable a fix scenario like urs before we have solution for theories

[tmmueller]

We are experiencing what seems to be the same issue: checking the "Run only impacted tests" box causes our build to fail with lots of "The test source file ... provided was not found" errors. We are also using theories in xUnit, although we are on v2.3.0 beta 1. Please let me know if there is anything we can do to help with testing or a fix. Since this issue is closed, is there somewhere we can track progress for always running theories or for handling them fully?

In the meantime, I just uncheck that box, and it works fine. It would be very nice to skip some of our tests -- it takes about half an hour for around 3000 tests to run.

[acesiddhu]

Next deployment will atleast get rid of this exception we see ("The test source file ... provided was not found")

Note that there isn't a way to associate the original discovered test with test case that were eventually executed because of data rows and hence you will end up seeing duplicates tests (one whos results are marked properly and one which will be marked not impacted. For instance assume there is a single test case named "Foo" with three data rows 1 2 and 3

The results will show these test with their outcomes eventually

Foo 187a4a28b02d5c896372aaea0625e2440ffa3315 NotImpacted
Foo kqjhjkefjgkhsdgfiuernbkhfea0625e2440ffa3315 NotImpacted
Foo 575a4a28b02d5c896372aaea0625e2440ffa3315 NotImpacted
Foo 1 Passed
Foo 2 Passed
Foo 3 Passed

Supporting data driven test cases fully (by fully I mean select that are impacted properly and have proper test results) is in backlog. we just ensured folks are not blocked in cases there is a mix of data driven test cases/theories and normal test cases and they have Run only impacted tests is switched on.