Skip to content
This repository has been archived by the owner on Jun 12, 2021. It is now read-only.

ReSharper treats all steps as a single test in SDK style projects #373

Closed
michael-wolfenden opened this issue Jul 19, 2017 · 22 comments
Closed

ReSharper treats all steps as a single test in SDK style projects #373

michael-wolfenden opened this issue Jul 19, 2017 · 22 comments
Assignees
@adamralph
Labels
question Further information is requested

Comments

@michael-wolfenden
Copy link

Given the following packages

<PackageReference Include="Microsoft.NET.Test.Sdk" Version="15.0.0" />
<PackageReference Include="Xbehave" Version="2.2.0-beta0003-build685" />
<PackageReference Include="xunit" Version="2.3.0-beta3-build3705" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.3.0-beta3-build3705" />

and Resharper version

JetBrains ReSharper Ultimate 2017.1.3  Build 108.0.20170613.154143

When running the follow test via resharper

[Scenario]
    public void Addition(int x, int y, Calculator calculator, int answer)
    {
        "Given the number 1"
            .x(() => x = 1);

        "And the number 2"
            .x(() =>
            {
                y = 2;

                //NOTE: An exception is throw during one of the steps
                throw new Exception();
            });

        "And a calculator"
            .x(() => calculator = new Calculator());

        "When I add the numbers together"
            .x(() => answer = calculator.Add(x, y));

        "Then the answer is 3"
            .x(() => Xunit.Assert.Equal(3, answer));
    }

Resharper's test runner is marking the test as inconclusive (not failed)

Resharper output

I have a repository that reproduces the issue at:
https://github.com/michael-wolfenden/xbehave-issue
@adamralph
Copy link
Owner

Thanks for reporting this @michael-wolfenden. I don't have R# to hand right now (I run it in a VM on another machine) but I'll look into this ASAP.

/cc @citizenmatt - any ideas?

@adamralph adamralph self-assigned this Jul 19, 2017
@citizenmatt
Copy link

Click on the "OK" in the top right of that window - it should show you a log file. It might provide some useful information. I'll try and take a look tomorrow, but I'm trying to get a lot done before vacation...

@michael-wolfenden
Copy link
Author

This was the info from the log file

2017.07.21 08:19:56.097   TRACE Processing message 'TestExecution.CustomTestHostLaunch'
2017.07.21 08:19:56.120   TRACE Processed message 'TestExecution.CustomTestHostLaunch'
2017.07.21 08:19:56.125    INFO Starting process: C:\Program Files\dotnet\dotnet.exe exec --runtimeconfig "D:\dev\spike\XBehaveIssue\XBehaveIssue\bin\Debug\netcoreapp1.1\XBehaveIssue.runtimeconfig.json" --depsfile "D:\dev\spike\XBehaveIssue\XBehaveIssue\bin\Debug\netcoreapp1.1\XBehaveIssue.deps.json" "C:\Users\michaelw\.nuget\packages\microsoft.testplatform.testhost/15.0.0\lib/netstandard1.5/testhost.dll" --port 58156 --parentprocessid 56600
2017.07.21 08:19:56.128    INFO Started process with pid 78780
2017.07.21 08:19:58.157   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.157    INFO [xUnit.net 00:00:01.2124467]   Starting:    XBehaveIssue
2017.07.21 08:19:58.157   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.508   TRACE Processing message 'TestExecution.StatsChange'
2017.07.21 08:19:58.534   TRACE Processed message 'TestExecution.StatsChange'
2017.07.21 08:19:58.613   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.613    INFO [xUnit.net 00:00:01.7379719]     XBehaveIssue.Test.Addition() [02] And the number 2 [FAIL]
2017.07.21 08:19:58.613   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.615   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.615    INFO [xUnit.net 00:00:01.7394212]       System.Exception : Exception of type 'System.Exception' was thrown.
2017.07.21 08:19:58.615   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.615   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.615    INFO [xUnit.net 00:00:01.7406016]       Stack Trace:
2017.07.21 08:19:58.615   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.618   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.618    INFO [xUnit.net 00:00:01.7424906]         D:\dev\spike\XBehaveIssue\XBehaveIssue\Test.cs(24,0): at XBehaveIssue.Test.<>c__DisplayClass1_0.<Addition>b__1()
2017.07.21 08:19:58.618   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.618   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.618    INFO [xUnit.net 00:00:01.7429537]         C:\projects\xbehave-net\src\Xbehave.Execution\StepInvoker.cs(75,0): at Xbehave.Execution.StepInvoker.<>c__DisplayClass8_1.<<InvokeBodyAsync>b__1>d.MoveNext()
2017.07.21 08:19:58.618   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.618   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.618    INFO [xUnit.net 00:00:01.7430518]         --- End of stack trace from previous location where exception was thrown ---
2017.07.21 08:19:58.618   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.618   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.618    INFO [xUnit.net 00:00:01.7430912]            at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
2017.07.21 08:19:58.618   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.619   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.619    INFO [xUnit.net 00:00:01.7431281]            at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
2017.07.21 08:19:58.619   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.619   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.619    INFO [xUnit.net 00:00:01.7431831]         --- End of stack trace from previous location where exception was thrown ---
2017.07.21 08:19:58.619   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.619   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.619    INFO [xUnit.net 00:00:01.7432353]            at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
2017.07.21 08:19:58.619   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.619   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.619    INFO [xUnit.net 00:00:01.7432863]            at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
2017.07.21 08:19:58.619   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.622   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.622    INFO [xUnit.net 00:00:01.7472350]     XBehaveIssue.Test.Addition() [03] And a calculator [SKIP]
2017.07.21 08:19:58.622   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.623   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.623    INFO [xUnit.net 00:00:01.7476562]       Failed to execute preceding step: XBehaveIssue.Test.Addition() [02] And the number 2
2017.07.21 08:19:58.623   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.624   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.624    INFO [xUnit.net 00:00:01.7496331]     XBehaveIssue.Test.Addition() [04] When I add the numbers together [SKIP]
2017.07.21 08:19:58.624   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.625   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.625    INFO [xUnit.net 00:00:01.7498154]       Failed to execute preceding step: XBehaveIssue.Test.Addition() [02] And the number 2
2017.07.21 08:19:58.625   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.625   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.625    INFO [xUnit.net 00:00:01.7502064]     XBehaveIssue.Test.Addition() [05] Then the answer is 3 [SKIP]
2017.07.21 08:19:58.625   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.625   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.625    INFO [xUnit.net 00:00:01.7502942]       Failed to execute preceding step: XBehaveIssue.Test.Addition() [02] And the number 2
2017.07.21 08:19:58.625   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.629   TRACE Processing message 'TestSession.Message'
2017.07.21 08:19:58.629    INFO [xUnit.net 00:00:01.7541346]   Finished:    XBehaveIssue
2017.07.21 08:19:58.629   TRACE Processed message 'TestSession.Message'
2017.07.21 08:19:58.711   TRACE Processing message 'TestExecution.StatsChange'
2017.07.21 08:19:58.746   TRACE Processed message 'TestExecution.StatsChange'
2017.07.21 08:19:58.746   TRACE Processing message 'TestExecution.Completed'
2017.07.21 08:19:58.764    INFO Process C:\Program Files\dotnet\dotnet.exe:78780 has exited
2017.07.21 08:19:58.765   TRACE Processed message 'TestExecution.Completed'
2017.07.21 08:19:58.770    INFO Run: a877ac75-d12a-4fe8-8776-6f7de79ca608 - Completed
2017.07.21 08:19:58.770    INFO RunTestsStage completed
2017.07.21 08:19:58.793    INFO Finishing run
2017.07.21 08:19:58.799    INFO Run is finished

@citizenmatt
Copy link

I'm not going to get a chance to look at this before vacation, sorry. You can raise an issue at youtrack.jetbrains.com if you'd like.

What do you get when you run it in the command line? I'm surprised it returns "ignored" - that means ReSharper has been directly told that it's been ignored/skipped. If a test is expected to run but doesn't, it usually gets "Inconclusive".

@michael-wolfenden
Copy link
Author

I have raised an issue with jetbrains

https://youtrack.jetbrains.com/issue/RSRP-465558

@michael-wolfenden
Copy link
Author

@adamralph just a quick update on this issue, I'm still waiting on a response from jetbrains.

@adamralph
Copy link
Owner

Thanks @michael-wolfenden!

@michael-wolfenden
Copy link
Author

@citizenmatt Have I logged the issue correctly? There doesn't appear to have been any activity on the issue.

@citizenmatt
Copy link

Yep, great issue, thanks. I've had a look and I think it's working as expected, surprisingly.

It looks like xbehave will run each step as a separate xunit test case. However, each step is being reported as the same test method, so ReSharper doesn't know that each step is different - it sees the same test being run 5 times. And when one step fails, the remaining steps are marked as skipped, but because the same test is being reported to ReSharper, the last write wins and ReSharper shows that test as having been skipped, even though one step passed, one failed and the rest were skipped.

To fix this, you can report each step like a theory row, and ReSharper will add the node into the tree. However, this will probably do weird things if someone selects step 3 in the tree and hits run, because xbehave won't support this. Alternatively, don't report steps as multiple tests, but as a single test, one for the scenario itself. If you only report one test result (passed, failed or skipped) then ReSharper will display it correctly.

@michael-wolfenden
Copy link
Author

Thanks for investigating @citizenmatt

Thoughts @adamralph?

@adamralph
Copy link
Owner

@michael-wolfenden I'm travelling currently but will chime in ASAP.

@adamralph adamralph added in-progress question Further information is requested labels Sep 2, 2017
@thomaslevesque
Copy link

Hey @adamralph, have you been able to look at this? I just noticed the issue too. At some point, R# showed each step of Xbehave scenarios, but now it doesn't; I suspect this is related to this problem. I don't know if the regression is in R# or in Xbehave. Did anything change in how Xbehave reports scenario steps?

@adamralph
Copy link
Owner

@thomaslevesque that problem was raised in #366. As far as I can tell, it's a bug in ReSharper.

In fact, I think this issue is the same problem. Because ReSharper is not treating each step separately, the result of the last step is used as the result of the entire scenario.

@adamralph
Copy link
Owner

This is the same issue as #366 so I'm going to merge them.

@adamralph
Copy link
Owner

On second thoughts - we'll use this issue and not #366, since #366 refers to project.json which is defunct, but this issue refers to SDK-style projects.

@adamralph adamralph reopened this Oct 14, 2017
@adamralph
Copy link
Owner

It looks like xbehave will run each step as a separate xunit test case. However, each step is being reported as the same test method, so ReSharper doesn't know that each step is different - it sees the same test being run 5 times. And when one step fails, the remaining steps are marked as skipped, but because the same test is being reported to ReSharper, the last write wins and ReSharper shows that test as having been skipped, even though one step passed, one failed and the rest were skipped.

@citizenmatt you are correct, but what xbehave is doing is no different to an xunit theory (in the case where the arguments do not serialize). More on that here.

To fix this, you can report each step like a theory row, and ReSharper will add the node into the tree.

Again, that is exactly what is happening. An xbehave scenario behaves just like an xunit theory which evaluates tests at execution time and not discovery time, which is a recognised behaviour in xunit that test runners should respect.

However, this will probably do weird things if someone selects step 3 in the tree and hits run, because xbehave won't support this.

I wouldn't worry about it. As you can see from the screenshot here, ReSharper is already reporting them separately for old-style csproj. If people see weird things happening when trying to run a single step then they'll soon learn to run the entire scenario instead. Or perhaps, that does indeed kick off the entire scenario already.

Alternatively, don't report steps as multiple tests, but as a single test, one for the scenario itself. If you only report one test result (passed, failed or skipped) then ReSharper will display it correctly.

The reporting of each step as a separate test (with a natural language description) is the whole idea behind xbehave. 😄

@adamralph adamralph mentioned this issue Oct 14, 2017
Closed
@adamralph adamralph changed the title Resharper reports test as ignored rather than failed if one of the steps in a scenario throws an exception ReSharper treats all steps as a single test in SDK style projects Oct 14, 2017
@adamralph
Copy link
Owner

adamralph commented Oct 14, 2017 •
edited

@citizenmatt I've pushed a repro to https://github.com/adamralph/resharper-xunit-theory-bug

Here you can see the problem in all its gory details:

image

For the "classic" csproj (bottom), everything works perfectly. xunit theories are reported with all tests as separate leaves in the tree, as are xbehave scenarios. For "SDK style" csproj, only the xunit theories which have tests evaluated at discovery time have the tests reported as separate leaves. xunit theories which have tests evaluated at execution time have all the tests collapsed into a single leaf, as do xbehave theories.

BTW - I checked to see what the behaviour is when a single xbehave step is executed from this UI and, indeed, the entire scenario is run, so we don't have to worry about any weird behaviour in that case.

@thomaslevesque
Copy link

Ah, so it stopped working in FakeItEasy when we migrated the specs to the new csproj... In this case, I agree that the problem is probably in ReSharper.

@Saisuryakattamuri Saisuryakattamuri mentioned this issue Oct 17, 2017
Closed
@citizenmatt
Copy link

The repro was very useful, thanks. Turns out this is a known issue - RSRP-464565, scheduled for a fix in 2017.3 (next release).

I've run the tests with tracing enabled, and from what I can tell the dotnet test API looks like it's sending the wrong information. The Feature.XunitTheoryWithTestsEvaluatedAtExecutionTime test case is being reported to ReSharper just like that - with no parameter information to indicate that it's a theory. The display name is the same. However, when the result comes in, the display name is correct. E.g. Feature.XunitTheoryWithTestsEvaluatedAtExecutionTime(x: Foo { Bar = 456 }). But I think it's too late at that point - we need this information in a "start" message, not just in the outcome.

I don't know if this is a fault of the vstest platform, the xunit test adapter, or if I'm reading the trace wrong...

@adamralph
Copy link
Owner

👍 thanks @citizenmatt.

I've added an entry for this in the known issues in the xBehave.net wiki.

Thank you @michael-wolfenden for opening this issue.

@michael-wolfenden
Copy link
Author

Appears to be working now after upgrading to JetBrains ReSharper Ultimate 2017.3 EAP 1

image

@adamralph
Copy link
Owner

@michael-wolfenden I've confirmed this from my end too. Great work @citizenmatt and team!

I've updated the FAQ.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@adamralph adamralph

Labels
question Further information is requested
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@citizenmatt @adamralph @michael-wolfenden @thomaslevesque