"Original project under test cannot be loaded" and "Unable to rollback mutation" when BuildOutputDir is changed relative to project dir

[derrickstolee]

Hello, I'm very new to using Stryker, and I'm having trouble that is likely related to the way my project puts build outputs outside of the source directory.

First, the error (and the request for me to create an issue):

[15:55:18 WRN] Original project under test C:\_git\VFSforGit\src\GVFS\BuildOutput\GVFS.Common\bin\AnyCPU\Debug\netcoreapp2.1\GVFS.Common.dll could not be loaded.
Embedded Resources might be missing.
System.IO.FileNotFoundException: Could not find file 'C:\_git\VFSforGit\src\GVFS\BuildOutput\GVFS.Common\bin\AnyCPU\Debug\netcoreapp2.1\GVFS.Common.dll'.
File name: 'C:\_git\VFSforGit\src\GVFS\BuildOutput\GVFS.Common\bin\AnyCPU\Debug\netcoreapp2.1\GVFS.Common.dll'
   at System.IO.FileStream.ValidateFileHandle(SafeFileHandle fileHandle)
   at System.IO.FileStream.CreateFileOpenHandle(FileMode mode, FileShare share, FileOptions options)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
   at Mono.Cecil.ModuleDefinition.ReadModule(String fileName, ReaderParameters parameters)
   at Stryker.Core.Initialisation.EmbeddedResourcesGenerator.LoadModule(String assemblyPath, ILogger logger) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\Initialisation\EmbeddedResourcesGenerator.cs:line 42
[15:55:19 ERR] Unable to rollback mutation for node FileAttributes with error: Ambiguity between 'FileProperties.FileAttributes' and 'FileProperties.FileAttributes' (at C:\_git\VFSforGit\src\GVFS\GVFS.Common\FileSystem\FileProperties.cs, line: 7, col: 80).
[15:55:19 ERR] This should not happen, please report this as an issue on github with the previous error message.

Note that we use build variables to specify that SolutionDir would be C:\_git\VFSforGit\src and the build outputs should go in C:\_git\VFSforGit\BuildOutput, but here a couple of levels are skipped. This is likely due to the following lines in our .csproj settings:

    <SolutionDir Condition="$(SolutionDir) == '' Or $(SolutionDir) == '*Undefined*'">..\..</SolutionDir>
    <BuildOutputDir>$(SolutionDir)\..\BuildOutput</BuildOutputDir>
    <PackagesDir>$(SolutionDir)\..\packages</PackagesDir>

This should make the SolutionDir be two levels above the project directory, and the build outputs go in ..\BuildOutputDir relative to that (which works during dotnet build). It appears that when Stryker mutates the code, something is going awry and causes some duplication of code.

My guess is that the mutated code is being placed in a deeper directory than normal, and hence the build outputs are being placed deeper in the source tree than usual. Alternatively, we are forcing the mutated outputs into the same spot as the non-mutated code and Stryker is trying to replace the mutation with the original binary. However, I'm not exactly sure how to resolve this issue.

I'd love to use Stryker to improve our test coverage, so I appreciate any pointers you can give.

[rouke-broersma]

Hey, thanks for reporting this issue! The warning about the original project not being loaded is only an issue if embedded resources such as language string resources are required, and will result in false positives in the test result due to exceptions about language strings being missing, but will not cause a failure to start the mutation testrun. We try to locate the original source binary so we can extract all embedded resources from it as it proved difficult to regenerate them from stryker.

As for the the placing of the mutated code, what we do is we place the mutated assembly directly in the test project build output dir. If this is the same directory as the source project build output dir then we will be overwriting the original source binary. This should not really be an issue, as we do not yet get to this stage. The error indicates that we are crashing before we place the mutated assembly on the filesystem:

Unable to rollback mutation for node FileAttributes with error: Ambiguity between 'FileProperties.FileAttributes' and 'FileProperties.FileAttributes' (at C:_git\VFSforGit\src\GVFS\GVFS.Common\FileSystem\FileProperties.cs, line: 7, col: 80)

All mutation placing and rollbacking (we roll back mutations that result in compile errors, as they are invalid) is done in-memory.

We will have to investigate why we were unable to rollback this mutation, and why our fallback rollback also failed to achieve the desired result.

Could you run stryker with options -f -l trace and attach the logs to the issue so we can see the exact mutation that was performed?

[derrickstolee]

Thanks for the quick response. Sorry I'm late in getting back to it.

Good to know these errors are not fatal. I never let the run finish because there are many many errors like this one filling the console. I'll let a run complete with the -f -l trace commands and share the logs when they complete (probably overnight).

[derrickstolee]

Here are the logs (zipped, due to size). It appears that it did not complete. I tried again with an Html reporter, but never saw an html report.

log-20190418.zip

[rouke-broersma]

Wow! We have not seen this many mutants in a single project before!

Looking at the logging it looks like we did never start with the actual mutation testrun, we are failing to compile the mutated assembly due to conflicts. I believe we might be hitting #18 again. Roslyn is not able to return all build errors to us within one compile cycle for larger projects so we rebuild twice currently. It could be that your project is so large that we need 3 or more compile cycles to remove all build errors. I will try to get your project running on my machine, and I will then see if increasing the amount of recompilations brings improvements.

[richardwerkman]

I think @Mobrockers is right about this. We initially thought that compiling 3 times would give us all compile errors. We might have been wrong 👎. Let's see if upping this to 20 or even 50 times would solve this issue.

[derrickstolee]

Thanks for the pointers. I did the (probably stupid) thing and made the recompile loop repeat indefinitely. It seems to be working.

[derrickstolee]

Ok, the run completed. Definitely hitting some interesting scaling issues here. I did see the same error messages again, just not as often. The run still did not produce a report, but instead ended with the following stack trace:

An error occurred during the mutation test run  (2ecaed66)
System.Collections.Generic.KeyNotFoundException: The given key '
    ***content of a .cs file***
}' was not present in the dictionary.
   at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
   at Stryker.Core.Compiling.RollbackProcess.Start(CSharpCompilation compiler, ImmutableArray`1 diagnostics, Boolean devMode) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\Compiling\RollbackProcess.cs:line 45
   at Stryker.Core.Compiling.CompilingProcess.RetryCompilation(MemoryStream ms, CSharpCompilation compilation, EmitResult previousEmitResult, Boolean devMode) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\Compiling\CompilingProcess.cs:line 96
   at Stryker.Core.Compiling.CompilingProcess.Compile(IEnumerable`1 syntaxTrees, MemoryStream ms, Boolean devMode) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\Compiling\CompilingProcess.cs:line 68
   at Stryker.Core.MutationTest.MutationTestProcess.Mutate(StrykerOptions options) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\MutationTest\MutationTestProcess.cs:line 91
   at Stryker.Core.StrykerRunner.RunMutationTest(StrykerOptions options) in C:\_git\stryker-net\src\Stryker.Core\Stryker.Core\StrykerRunner.cs:line 77

[derrickstolee]

And the logs are here: log-20190419.zip

[rouke-broersma]

It looks to me like some information about the syntaxtrees went missing somewhere due to the recompile loop, which causes the key not found in dictionary issue here:

https://github.com/stryker-mutator/stryker-net/blob/master/src/Stryker.Core/Stryker.Core/Compiling/RollbackProcess.cs#L45

Could you share how you implemented the recompile loop?

[derrickstolee]

@Mobrockers please see #473 for the details of how I changed the recompile logic.

[rouke-broersma]

Thank you!

https://github.com/stryker-mutator/stryker-net/blob/d8806082ccd6b89c231bd349b76510a74324bf23/src/Stryker.Core/Stryker.Core/Compiling/CompilingProcess.cs#L68

The error in your last run was most probably caused because of reusing the same compiler instance here, which contains syntaxes that were removed in a previous rollback.

Something like the following will resolve that error:

https://gist.github.com/Mobrockers/3e96886a045ebfa3c8ac293870153c9c

This still does not fix the compilation problems though, and it seems like we are failing to rollback the mutations completely as I am noticing no difference in errors between the rollback iterations. I have managed to get the project working locally though, so I am able to investigate now.

[rouke-broersma]

Hey @derrickstolee ,

We have identified the issues with compiling your project, and it turned out to be a problem in our logic of loading shared projects which resulted in loading the complete GVFS codebase instead only the project under test. We have fixed this, and have identified another issue in the process. We do not version the assembly we write to disk, which fails 4 of the unit tests in the project because they rely on an assembly version. We are going to try and copy the original assembly version number when compiling our mutated assembly.

We have also identified a problem with finding the solution directory when no solution file is passed to stryker, this resulted in the build output folder not being correctly identified. For now I suggest you pass the GVFS sln file to stryker so the solution dir and build output dir are correctly found.

[derrickstolee]

Thanks for the update! I was trying some other things, like excluding all .cs files in the solution other than a single file. I had not tried the solution file. Do I set that in the stryker-config.json file?

[rouke-broersma]

You can set it in the stryker-config with property "solution-path": "relative-or-absolute-path-to-sln.sln" or on the command line with -s "relative-or-absolute-path-to-sln.sln"

Ex:

-p "GVFS.Common" -r "['Html', 'ConsoleProgressBar']" -f -l trace -s "../../GVFS.sln"

Be advised that currently due to the assembly version problem, if you include the tests in GVFS.UnitTests\Common\TryCreateProductUpgraderTests.cs in the testrun you will have a 100% mutation test score because 4 tests in that file rely on a correct assemblyversion. We are working on including the assembly version in the mutated assembly.

[richardwerkman]

Should be fixed in stryker 0.11.0

[rouke-broersma]

Hey @derrickstolee

Could you confirm stryker properly runs on your project with version 0.11.0? I was able to get it working on my own checkout of GVFS with options -p "GVFS.Common" -r "['Html', 'Progress']" -f -s "../../GVFS.sln"

[derrickstolee]

Thanks for the ping @Mobrockers and for the detailed parameters. I ran the same thing and got a meaningful report! Of course, we need to do better with our unit tests, as very few mutations were killed.

Thanks so much for your help here!