microsoft / azure-pipelines-tasks

Tasks for Azure Pipelines
https://aka.ms/tfbuild
MIT License
3.51k stars 2.62k forks source link

VSTest Build Task for UWP Unit Test Apps broken since Visual Studio 15.5 #6501

Closed DerGary closed 6 years ago

DerGary commented 6 years ago

Environment

Server: VSTS VSTS Account Name: dev-fg Team Project Name: App Development Build Definition Name: Reporting App UWP Pull Request Build ID: 2985 Build Number: 05203

Agent: Private OS: Windows 10 Build 15063.483 Agent version: 2.129.1

VSTest Version: 2.*

Issue Description

After updating Visual Studio from 15.3.x to 15.5.x the VSTest Build Task for testing UWP Unit Test Apps is always failing with an error message. It seems like it uses the vstest.console.exe from the folder C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\Extensions\TestPlatform instead of the folder C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\. When I try the vstest from the TestWindow folder locally everything works fine. When I try the vstest from the TestPlatform it fails with this error. I also tried specifying the path to the vstest.console.exe in the VSTest build task which did not work. Using a Command Line Build Task and opening vstest.console.exe works.

Settings: image image image

Error logs

2018-02-21T14:05:35.2912417Z [command]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @C:\Users\BUILDA~1\AppData\Local\Temp\49358541-1710-11e8-acfd-b367187f027b.txt
2018-02-21T14:05:35.6655935Z Microsoft (R) Test Execution Command Line Tool Version 15.5.0
2018-02-21T14:05:35.6660242Z Copyright (c) Microsoft Corporation.  All rights reserved.
2018-02-21T14:05:35.6660591Z 
2018-02-21T14:05:35.6706960Z vstest.console.exe 
2018-02-21T14:05:35.6707361Z "C:\Tools\agent\_work\71\a\AppxPackages\Freier.App.Reporting.Test_1.0.0.0_x86_Debug_Test\Freier.App.Reporting.Test_1.0.0.0_x86_Debug.appx"
2018-02-21T14:05:35.6707613Z /logger:"trx"
2018-02-21T14:05:35.6708085Z /diag:"C:\Users\BUILDA~1\AppData\Local\Temp\49358540-1710-11e8-acfd-b367187f027b.txt"
2018-02-21T14:05:36.1600044Z Starting test execution, please wait...
2018-02-21T14:05:36.1606707Z Logging Vstest Diagnostics in file: C:\Users\BuildAgent\AppData\Local\Temp\49358540-1710-11e8-acfd-b367187f027b.txt
2018-02-21T14:05:38.2483464Z Failed to launch testhost with error: System.AggregateException: One or more errors occurred. ---> Microsoft.Build.Exceptions.InvalidProjectFileException: The project file could not be loaded. Data at the root level is invalid. Line 1, position 1.  C:\Tools\agent\_work\71\a\AppxPackages\Freier.App.Reporting.Test_1.0.0.0_x86_Debug_Test\Freier.App.Reporting.Test_1.0.0.0_x86_Debug.appx ---> System.Xml.XmlException: Data at the root level is invalid. Line 1, position 1.
2018-02-21T14:05:38.2484192Z    at System.Xml.XmlTextReaderImpl.Throw(Exception e)
2018-02-21T14:05:38.2484780Z    at System.Xml.XmlTextReaderImpl.Throw(String res, String arg)
2018-02-21T14:05:38.2485270Z    at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
2018-02-21T14:05:38.2485531Z    at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
2018-02-21T14:05:38.2486119Z    at System.Xml.XmlTextReaderImpl.Read()
2018-02-21T14:05:38.2486357Z    at System.Xml.XmlTextReader.Read()
2018-02-21T14:05:38.2486613Z    at Microsoft.Build.Internal.XmlReaderExtension.GetXmlReader(StreamReader input, Encoding& encoding)
2018-02-21T14:05:38.2486865Z    at Microsoft.Build.Internal.XmlReaderExtension..ctor(String file)
2018-02-21T14:05:38.2487131Z    at Microsoft.Build.Construction.ProjectRootElement.LoadDocument(String fullPath, Boolean preserveFormatting)
2018-02-21T14:05:38.2487439Z    --- End of inner exception stack trace ---
2018-02-21T14:05:38.2487785Z    at Microsoft.Build.Shared.ProjectFileErrorUtilities.VerifyThrowInvalidProjectFile(Boolean condition, String errorSubCategoryResourceName, BuildEventFileInfo projectFile, Exception innerException, String resourceName, Object[] args)
2018-02-21T14:05:38.2488163Z    at Microsoft.Build.Construction.ProjectRootElement.LoadDocument(String fullPath, Boolean preserveFormatting)
2018-02-21T14:05:38.2488466Z    at Microsoft.Build.Construction.ProjectRootElement..ctor(String path, ProjectRootElementCache projectRootElementCache, Boolean preserveFormatting)
2018-02-21T14:05:38.2488849Z    at Microsoft.Build.Construction.ProjectRootElement.CreateProjectFromPath(String projectFile, IDictionary`2 globalProperties, String toolsVersion, ProjectRootElementCache projectRootElementCache, Boolean preserveFormatting)
2018-02-21T14:05:38.2489217Z    at Microsoft.Build.Construction.ProjectRootElement.<>c__DisplayClass200_0.<OpenProjectOrSolution>b__0(String path, ProjectRootElementCache cache)
2018-02-21T14:05:38.2489586Z    at Microsoft.Build.Evaluation.ProjectRootElementCache.Get(String projectFile, OpenProjectRootElement openProjectRootElement, Boolean isExplicitlyLoaded, Nullable`1 preserveFormatting)
2018-02-21T14:05:38.2489982Z    at Microsoft.Build.Construction.ProjectRootElement.OpenProjectOrSolution(String fullPath, IDictionary`2 globalProperties, String toolsVersion, ProjectRootElementCache projectRootElementCache, Boolean isExplicitlyLoaded)
2018-02-21T14:05:38.2490346Z    at Microsoft.Build.Evaluation.ProjectCollection.LoadProject(String fileName, IDictionary`2 globalProperties, String toolsVersion)
2018-02-21T14:05:38.2490636Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.RecipeFile.get_Project()
2018-02-21T14:05:38.2490878Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.RecipeFile.get_LayoutPath()
2018-02-21T14:05:38.2491163Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.Deployer.Microsoft.VisualStudio.UwpTestHostRuntimeProvider.IDeployer.Deploy()
2018-02-21T14:05:38.2491671Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.UwpTestHostManager.<LaunchHostAsync>d__35.MoveNext()
2018-02-21T14:05:38.2491942Z --- End of stack trace from previous location where exception was thrown ---
2018-02-21T14:05:38.2492301Z    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
2018-02-21T14:05:38.2492609Z    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
2018-02-21T14:05:38.2492926Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.UwpTestHostManager.<Microsoft-VisualStudio-TestPlatform-ObjectModel-Host-ITestRuntimeProvider-LaunchTestHostAsync>d__30.MoveNext()
2018-02-21T14:05:38.2493220Z    --- End of inner exception stack trace ---
2018-02-21T14:05:38.2493449Z    at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
2018-02-21T14:05:38.2493720Z    at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
2018-02-21T14:05:38.2493944Z    at System.Threading.Tasks.Task`1.get_Result()
2018-02-21T14:05:38.2494233Z    at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.Client.ProxyOperationManager.SetupChannel(IEnumerable`1 sources, CancellationToken cancellationToken)
2018-02-21T14:05:38.2494779Z ---> (Inner Exception #0) Microsoft.Build.Exceptions.InvalidProjectFileException: The project file could not be loaded. Data at the root level is invalid. Line 1, position 1.  C:\Tools\agent\_work\71\a\AppxPackages\Freier.App.Reporting.Test_1.0.0.0_x86_Debug_Test\Freier.App.Reporting.Test_1.0.0.0_x86_Debug.appx ---> System.Xml.XmlException: Data at the root level is invalid. Line 1, position 1.
2018-02-21T14:05:38.2495217Z    at System.Xml.XmlTextReaderImpl.Throw(Exception e)
2018-02-21T14:05:38.2495451Z    at System.Xml.XmlTextReaderImpl.Throw(String res, String arg)
2018-02-21T14:05:38.2495679Z    at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
2018-02-21T14:05:38.2495908Z    at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
2018-02-21T14:05:38.2496113Z    at System.Xml.XmlTextReaderImpl.Read()
2018-02-21T14:05:38.2496318Z    at System.Xml.XmlTextReader.Read()
2018-02-21T14:05:38.2496552Z    at Microsoft.Build.Internal.XmlReaderExtension.GetXmlReader(StreamReader input, Encoding& encoding)
2018-02-21T14:05:38.2496818Z    at Microsoft.Build.Internal.XmlReaderExtension..ctor(String file)
2018-02-21T14:05:38.2497074Z    at Microsoft.Build.Construction.ProjectRootElement.LoadDocument(String fullPath, Boolean preserveFormatting)
2018-02-21T14:05:38.2497354Z    --- End of inner exception stack trace ---
2018-02-21T14:05:38.2497681Z    at Microsoft.Build.Shared.ProjectFileErrorUtilities.VerifyThrowInvalidProjectFile(Boolean condition, String errorSubCategoryResourceName, BuildEventFileInfo projectFile, Exception innerException, String resourceName, Object[] args)
2018-02-21T14:05:38.2498059Z    at Microsoft.Build.Construction.ProjectRootElement.LoadDocument(String fullPath, Boolean preserveFormatting)
2018-02-21T14:05:38.2498381Z    at Microsoft.Build.Construction.ProjectRootElement..ctor(String path, ProjectRootElementCache projectRootElementCache, Boolean preserveFormatting)
2018-02-21T14:05:38.2498749Z    at Microsoft.Build.Construction.ProjectRootElement.CreateProjectFromPath(String projectFile, IDictionary`2 globalProperties, String toolsVersion, ProjectRootElementCache projectRootElementCache, Boolean preserveFormatting)
2018-02-21T14:05:38.2499141Z    at Microsoft.Build.Construction.ProjectRootElement.<>c__DisplayClass200_0.<OpenProjectOrSolution>b__0(String path, ProjectRootElementCache cache)
2018-02-21T14:05:38.2499505Z    at Microsoft.Build.Evaluation.ProjectRootElementCache.Get(String projectFile, OpenProjectRootElement openProjectRootElement, Boolean isExplicitlyLoaded, Nullable`1 preserveFormatting)
2018-02-21T14:05:38.2499902Z    at Microsoft.Build.Construction.ProjectRootElement.OpenProjectOrSolution(String fullPath, IDictionary`2 globalProperties, String toolsVersion, ProjectRootElementCache projectRootElementCache, Boolean isExplicitlyLoaded)
2018-02-21T14:05:38.2500345Z    at Microsoft.Build.Evaluation.ProjectCollection.LoadProject(String fileName, IDictionary`2 globalProperties, String toolsVersion)
2018-02-21T14:05:38.2500630Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.RecipeFile.get_Project()
2018-02-21T14:05:38.2500942Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.RecipeFile.get_LayoutPath()
2018-02-21T14:05:38.2501232Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.Deployer.Microsoft.VisualStudio.UwpTestHostRuntimeProvider.IDeployer.Deploy()
2018-02-21T14:05:38.2501535Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.UwpTestHostManager.<LaunchHostAsync>d__35.MoveNext()
2018-02-21T14:05:38.2501791Z --- End of stack trace from previous location where exception was thrown ---
2018-02-21T14:05:38.2502043Z    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
2018-02-21T14:05:38.2502318Z    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
2018-02-21T14:05:38.2502682Z    at Microsoft.VisualStudio.UwpTestHostRuntimeProvider.UwpTestHostManager.<Microsoft-VisualStudio-TestPlatform-ObjectModel-Host-ITestRuntimeProvider-LaunchTestHostAsync>d__30.MoveNext()<---
2018-02-21T14:05:38.2502897Z 
2018-02-21T14:05:38.2913346Z 
2018-02-21T14:05:38.2914167Z Test Run Aborted.

I uploaded the complete log of the VSTest build task to gist: https://gist.github.com/DerGary/6939cb6ac36e0e53a5edb9d1e053d074

Some Links to similar Problems: Link1 Link2 Link3

nigurr commented 6 years ago

@MireilleHanna Can you please share below info?

  1. Are you using Hosted Build Agents?
  2. If you are using private build agents, are they running under admin account?

UWP tests required to be run under admin account.

DerGary commented 6 years ago

@nigurr I already wrote that I'm using private Build Agents:

Environment

Server: VSTS VSTS Account Name: dev-fg Team Project Name: App Development Build Definition Name: Reporting App UWP Pull Request Build ID: 2985 Build Number: 05203

Agent: Private OS: Windows 10 Build 15063.483 Agent version: 2.129.1

VSTest Version: 2.*

  1. They are run under admin account. Since when does vstest.console.exe need to be run as admin? I can run vstest.console.exe on my local pc without admin privileges and it runs just like it should.

I never needed to run vstest.console.exe as admin before and until I updated Visual studio on the build agent everything run just fine. I really think that it has to do with the new version of vstest.console.exe from the TestPlatform folder. Like I already mentioned here:

When I try the vstest from the TestWindow folder locally everything works fine. When I try the vstest from the TestPlatform it fails with this error. I also tried specifying the path to the vstest.console.exe in the VSTest build task which did not work. Using a Command Line Build Task and opening vstest.console.exe works.

nigurr commented 6 years ago

Can you please mention the full path from which location it's working and from which location it's not working?

DerGary commented 6 years ago

I also already did this in my original post:

It seems like it uses the vstest.console.exe from the folder C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\Extensions\TestPlatform instead of the folder C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\

working: C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\

not working: C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\Extensions\TestPlatform\

mayankbansal018 commented 6 years ago

@DerGary we debugged this issue, & the reason it is failing is because in 15.5(2017 update 5) we brought our new Testplatform(C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\Extensions\TestPlatform) and made it as default for all scenarios except UWP

The reason it is passing in CLI from "C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\" is because our old testplatform contains an explicit check saying that if input is ".appx" do not redirect to newer testplatform. However in VSTS Test task, we create a response file as input to vstest.console, which does not end with ".appx", hence the request for UWP also goes to Tpv2 which fails to run it.

In 15.6 we have also made UWP to via our newer Testplatform, but the input for CLI has changed from ".appx" to ".appxrecipe", & also you need to pass the Framework switch. The support for ".appx" should come by 15.7 Current E.g. command vstest.consol.exe /Framework:FrameworkUap10

To run your UWP tests in CI/CD

This should work for you after above steps, please let us know if you still run into error.

DerGary commented 6 years ago

Thanks I will try your suggestion next week. Unfortunately this week I do not have time for it.

DerGary commented 6 years ago

@mayankbansal018 Using VS 15.6.1 with these settings does work:

image

What I don't understand is it says it's using the TestWindow Version of vstest but it is not using this version because it's using the TestPlatform Version which can be seen by the version string (15.6.0):

"C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @C:\Users\BUILDA~1\AppData\Local\Temp\e1233191-25f7-11e8-8f0b-c7c2802b7014.txt
Microsoft (R) Test Execution Command Line Tool Version 15.6.0
Copyright (c) Microsoft Corporation.  All rights reserved.
vstest.console.exe 
"C:\Tools\agent\_work\3\s\NUnitTestAPp\UnitTestProject1\bin\x86\Debug\UnitTestProject1.build.appxrecipe"
/logger:"trx"
/TestAdapterPath:"C:\Tools\agent\_work\3\s"
/Framework:FrameworkUap10
Starting test execution, please wait...

And if I try to supply a path to the TestWindow vstest it does not use the TestWindow version: image

and therefore fails with this error:

System.ArgumentException: File 'C:\Tools\agent\_work\3\s\NUnitTestAPp\UnitTestProject1\AppPackages\UnitTestProject1_1.0.0.0_x86_Debug_Test\UnitTestProject1_1.0.0.0_x86_Debug.appx' has an invalid extension, it must be '.appxrecipe'.

For now the suggested workaround does do the trick but I think when I supply a path to a specific exe it has to use this exe and not a totally different one from a different folder. This must have to do with the VSTest Build Task because it does not do this on the command line.

ShreyasRmsft commented 6 years ago

@DerGary can provide the full build logs with system.debug=true. I will if and why a different vstest.console.exe is being used when you explicitly provide the path.

DerGary commented 6 years ago

Build Definition:

image image image image image

logs: logs_3452.zip

ShreyasRmsft commented 6 years ago

@DerGary

2018-03-19T10:28:47.2598044Z [command]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @C:\Users\BUILDA~1\AppData\Local\Temp\4e8146b1-2b60-11e8-b0a7-43737c48c411.txt

from the logs it is clear that it is using the vstest.console.exe from the path you specified.

Since you are building with Vs 2017 update 6, tpv2 (newer testplatorm) dependencies get added to the appx itself, which cannot work with tpv1 (older testplatform) even though you pointed to its path.

We understand that this is a change in behavior for users currently, & we plan to bring the support of running tests via ".appx" in 15.7 RTM

Currently the way to go ahead right now is to change the extension to .appxrecipe

DerGary commented 6 years ago

@ShreyasRmsft

it is NOT using the vstest.console.exe from the path I specified. If I run the command on the CLI I do NOT get the error that is shown in the log files and it reports a different version number.

image

ShreyasRmsft commented 6 years ago

Hi @DerGary after looking into this a little more this is the conclusion:

This is indeed a bug/breaking change from our end and will indeed be fixed in 15.7 RTM.

For now you can either use an older version of VS or go ahead by changing the extension to .appxrecipe

The issue is not with the task but with the way vstest.console.exe handles redirects and also the lack of support for .appx files in tpv2 but this will be fixed.

Sorry for prematurely closing the issue. Lemme know if you need any more info or if I can close the issue now.

Thanks

DerGary commented 6 years ago

@ShreyasRmsft Thank you that explains this strange behavior. I already started to change all our build definitions to use .appxrecipe. I reckon .appxrecipe will stay supported after support for .appx files is added to tpv2? Yes you can close this issue now.

ShreyasRmsft commented 6 years ago

Yes .appxrecipe will be supported after .appx is added to tpv2. Tagging @mayankbansal018 to confirm this

mayankbansal018 commented 6 years ago

@DerGary , yes the support for ".appxrecipe" will continue to remain, but it seems reasonable to assume that users would want to use ".appx" for CLI, as it is self contained.

DerGary commented 6 years ago

ok thank you @mayankbansal018 @ShreyasRmsft you can close this issue Greetings