stryker-mutator / stryker-net

Mutation testing for .NET core and .NET framework!
https://stryker-mutator.io
Apache License 2.0
1.75k stars 176 forks source link

Stryker fails to connect to vstest.console on Linux #1376

Closed Damarus999 closed 1 week ago

Damarus999 commented 3 years ago

Describe the bug When attempting to run Stryker on a .NET 5 app on Ubuntu 20.04, the process hangs and then errors out when trying to initialise test runners. Stryker runs successfully with this app when targeting .NET Core 3.1 on the same machine.

Logs log-20210120.txt

Expected behavior Stryker should successfully initialise the test runners and proceed to run the tests,

Desktop (please complete the following information):

Additional context A colleague ran into the same issues when running Stryker on macOS on the same project. I'll get the OS version details etc... and attach to the issue in due course.

I can run Stryker successfully under the following conditions:

Stryker fails to run (with the error above) under the following conditions:

rouke-broersma commented 3 years ago

Hi @Damarus999

On this buildserver, do you not have the dotnet core 3.1 runtime installed either? We try to start up vstest with forward compatibility (flag to allow running on a higher target runtime) but obviously this can fail. This is why stryker officially only supports running on a dotnet core 3.1 runtime.

Damarus999 commented 3 years ago

Hi @Mobrockers

If I try to run Stryker with .Net Core 3.1 when the project is targeting .NET 5 then Stryker believes the project is targeting .NET Framework and asks for the solution path: image log-20210121.txt

If there's anything else I can provide that could help, please let me know.

rouke-broersma commented 3 years ago

That is.. Interesting. Could you show me what your target framework looks like exactly?

Damarus999 commented 3 years ago

The main project's csproj file looks like this:

<Project Sdk="Microsoft.NET.Sdk.Web">

    <PropertyGroup>
        <TargetFramework>net5.0</TargetFramework>
        <GenerateDocumentationFile>true</GenerateDocumentationFile>
        <NoWarn>1591;</NoWarn>
    </PropertyGroup>

    <ItemGroup>
      <PackageReference Include="AspNetCore.HealthChecks.Publisher.ApplicationInsights" Version="3.1.1" />
      <PackageReference Include="AspNetCore.HealthChecks.SqlServer" Version="3.2.0" />
      <PackageReference Include="AutoMapper" Version="10.1.1" />
      <PackageReference Include="AutoMapper.Extensions.Microsoft.DependencyInjection" Version="8.1.0" />
      <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.16.0" />
      <PackageReference Include="Microsoft.AspNetCore.Authentication.JwtBearer" Version="3.1.10" />
      <PackageReference Include="Microsoft.AspNetCore.Authentication.OpenIdConnect" Version="3.1.10" />
      <PackageReference Include="Microsoft.EntityFrameworkCore.Design" Version="5.0.0" />
      <PackageReference Include="Microsoft.EntityFrameworkCore.InMemory" Version="5.0.0" />
      <PackageReference Include="Microsoft.EntityFrameworkCore.SqlServer" Version="5.0.0" />
      <PackageReference Include="Microsoft.EntityFrameworkCore.Tools" Version="5.0.0" />
      <PackageReference Include="Microsoft.Extensions.Diagnostics.HealthChecks.EntityFrameworkCore" Version="5.0.0" />
      <PackageReference Include="NWebsec.AspNetCore.Middleware" Version="3.0.0" />
      <PackageReference Include="Serilog.AspNetCore" Version="3.4.0" />
      <PackageReference Include="Serilog.Exceptions" Version="6.0.0" />
      <PackageReference Include="Serilog.Exceptions.EntityFrameworkCore" Version="6.0.0" />
      <PackageReference Include="Serilog.Exceptions.SqlServer" Version="6.0.0" />
      <PackageReference Include="Serilog.Settings.Configuration" Version="3.1.0" />
      <PackageReference Include="Serilog.Sinks.ApplicationInsights" Version="3.1.0" />
      <PackageReference Include="Serilog.Sinks.Console" Version="3.1.1" />
      <PackageReference Include="Swashbuckle.AspNetCore.ReDoc" Version="5.6.3" />
      <PackageReference Include="Swashbuckle.AspNetCore.SwaggerGen" Version="5.6.3" />
      <PackageReference Include="System.ComponentModel.Annotations" Version="5.0.0" />
    </ItemGroup>

    <ItemGroup>
      <Folder Include="Migrations" />
    </ItemGroup>

</Project>

and the test csproj:

<Project Sdk="Microsoft.NET.Sdk">

    <PropertyGroup>
        <TargetFramework>net5.0</TargetFramework>

        <IsPackable>false</IsPackable>
    </PropertyGroup>

    <ItemGroup>
        <PackageReference Include="AutoMapper" Version="10.1.1" />
        <PackageReference Include="FakeItEasy" Version="6.2.1" />
        <PackageReference Include="JUnitTestLogger" Version="1.1.0" />
        <PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.8.0" />
        <PackageReference Include="xunit" Version="2.4.1" />
        <PackageReference Include="xunit.runner.visualstudio" Version="2.4.3">
          <PrivateAssets>all</PrivateAssets>
          <IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
        </PackageReference>
    </ItemGroup>

    <ItemGroup>
      <ProjectReference Include="..\DecisionMomentsBackend\DecisionMomentsBackend.csproj" />
    </ItemGroup>

</Project>

Curiously, I also decided to retry running Stryker on the project, but this time using Microsoft's official .NET 5 SDK Docker image with the following command:

docker run -it --name dotnet-sdk5 -v '/home/paul/Development/Projects/decision-moments-backend:/var/opt/projects' mcr.microsoft.com/dotnet/sdk:5.0

and then with bash in the container:

cd /var/opt/projects/DecisionMomentsBackendTests/
dotnet tool restore
dotnet stryker

and it seems to run ok (with some errors apparently, but still - progress 😅): image

The output of dotnet --version in the container is 5.0.102 Here's the log file from another run in the container: log-20210121.txt

The fact that it runs inside the container leads me to believe there's some local environment issue preventing me from running Stryker. I originally neglected to mention that the dotnet-sdk was installed via Microsoft's official snap package for Ubuntu, so there may be an issue with that? I will try to do some digging on that at some point and post any findings to this thread.

rouke-broersma commented 3 years ago

The warnings are not a big issue. They simply mean that we introduced illegal syntax while mutating. Stryker automatically removes the illegal syntax so compilation is successful. We only ask users to create an issue for these kinds of problems so that we can improve our mutation engine and not place the illegal syntax in the first place.

Damarus999 commented 3 years ago

After further investigation I think you can probably close this issue. I have completely removed all the .NET SDKs from my system and installed the .NET 5 SDK from Microsoft's apt repository and Stryker now runs as expected in all cases, so I suspect this is an issue with Microsoft's .NET 5 Snap packaging rather than a problem with Stryker.

rouke-broersma commented 3 years ago

@Damarus999 thank you for the bug report anyways, it is useful information. And I'm glad you got stryker to work.

If you wish we would appreciate if you could create a new issue with details about the syntax we are mutating wrong (if you can provide a reproduction that would be great). I'll go ahead and close this one. If you run into this kinda issue again in the future feel free to create a new issue or ping me here to reopen this one.

nohwnd commented 3 years ago

@Mobrockers trying to figure out what is happening, I can repro. But would need to see logs (at least). Can I somehow pass parameters to vstest.console via stryker to enable it's logging? We unfortunately don't have env variables for that, just --diag parameter (and some app.config stuff I'd rather avoid).

rouke-broersma commented 3 years ago

Hi @nohwnd

We pass the stryker log level through to vstest.console and put the logfiles in \StrykerOutput\\logs

Example:

image

You will need the options --log-level to set the loglevel and --log-file to output the logging to file. I suggest log level trace.

So it would look like this dotnet stryker --log-level trace --log-file <other_params_specific_to_project>

For reference how we initiate the vstest.console wrapper with logging:

https://github.com/stryker-mutator/stryker-net/blob/master/src/Stryker.Core/Stryker.Core/TestRunners/VsTest/VsTestRunner.cs#L452-L456

Is that enough or are there other logs that could be output?

nohwnd commented 3 years ago

Thanks! 🙂 I tried that, but I see no output from vstest. Just the log from stryker, which is exactly the same as what I see on screen. I can execute the tests via vstest.console.dll that stryker uses directly as long as I provider the roll_forward_on_no_candidate_fx=2 env var.

nohwnd commented 3 years ago

I enabled COREHOST_TRACE=1, and in the log I can see where it runs vstest.console from, and by which dotnet executable, and with which parameters. Running that will start the process correctly, and it will log into the correct file a zillion of messages that it cannot connect to parent, which is expected because at that point no parent is running.

I have no idea why it does not work under stryker directly... It just says process exited with exit code 0x1.

rouke-broersma commented 3 years ago

@nohwnd VsTest is a big black box to me so as far as I'm concerned if we managed to kick off the correct process we've done our job 😆 I also have no idea what could be wrong here. It's also weird that it works with the 3.1 snap package and not 5.0 and that there is no problem at all using the sdk installed on the system directly.

The testhost must be crashing somewhere in startup specifically when started by the vstest console wrapper in the snap package right?

rouke-broersma commented 3 years ago

Actually we did implement a custom ITestHostLauncher but as far as I know we're not doing anything too special there: https://github.com/stryker-mutator/stryker-net/blob/master/src/Stryker.Core/Stryker.Core/TestRunners/VsTest/StrykerVstestHostLauncher.cs

Do you see anything there that could cause this issue in snap?

nohwnd commented 3 years ago

From the host log, and because there is no log output from vstest.console, I would guess vstest.console is not starting at all. vstest.console would then start testhost process, but since we are not getting any logs from vstest.console, I think it just dies on startup.

I don't see anything out of ordinary in your host launcher.

rouke-broersma commented 3 years ago

Mhm then I guess the only way to debug would be to run stryker from source with a vstest dll from source so you can debug into vstest or the wrapper itself, that's unfortunate. Please let me know if I can be of any assistance.

ociaw commented 1 year ago

I encountered this issue as well with a similar lack of debug output, and found that when I ran the extracted vstest.console.dll it immediately returned with this error:

FailFast: Couldn't find a valid ICU package installed on the system. Set the configuration flag System.Globalization.Invariant to true if you want to run with no globalization support.

at System.Environment.FailFast(System.String) at System.Globalization.GlobalizationMode.GetGlobalizationInvariantMode() at System.Globalization.GlobalizationMode..cctor() at System.Globalization.CultureData.CreateCultureWithInvariantData() at System.Globalization.CultureData.get_Invariant() at System.Globalization.CultureInfo..cctor() at System.StringComparer..cctor() at System.AppDomain.InitializeCompatibilityFlags() at System.AppDomain.Setup(System.Object)

Which led me to this issue. Running export DOTNET_SYSTEM_GLOBALIZATION_INVARIANT=1 before running Stryker solved the issue. I also tried installing the libicu package, but that hasn't resolved the issue. I'm not using dotnet from the package repositories, so perhaps that's why I'm was missing the dependency.

I'm unsure why the VS Test runner and/or Stryker failed to notice that the process immediately exited with a non-zero status code (134), so perhaps error handling could be improved there.

rouke-broersma commented 1 year ago

Interesting! Unfortunately I don't think we receive any information from vstest in this case. But perhaps there is a way for us to detect this scenario and let the user know. I don't think we can decide to set this env because the issues you linked mention that certain workloads don't work with invariant enabled.

dupdob commented 1 year ago

We can at least capture and report a non zero error code.