Nunit-console: Remove -5 exit code on app domain unload failures

[wburgers]

Hi,

After updating from 3.7.0 to 3.8.0, NUnit gives an error exit code.
Below is the error output from both 3.7.0 and 3.8.0.
The way the NUnitEngineUnloadException is handled has changed, but I do believe it hasn't been for the better...
In 3.7.0 I didn't get an error exit code, but in 3.8.0 I do.

In 3.7 I get this as engine errors:
Unhandled Exception: NUnit.Engine.NUnitEngineException: Exception encountered unloading AppDomain Agent Process was terminated successfully after error. at NUnit.Engine.Runners.ProcessRunner.Dispose(Boolean disposing) at NUnit.Engine.Runners.AbstractTestRunner.Dispose() at NUnit.Engine.Runners.TestExecutionTask.Execute() at NUnit.Engine.Runners.ParallelTaskWorkerPool.ProcessTasksProc() at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state) at System.Threading.ThreadHelper.ThreadStart()
powershell gives True as output for this process

In 3.8 I get the following:
NUnit.Engine.NUnitEngineUnloadException : Multiple exceptions encountered. Retrieve AggregatedExceptions property for more information ----> NUnit.Engine.NUnitEngineUnloadException : Agent Process was terminated successfully after error. ----> NUnit.Engine.NUnitEngineUnloadException : Exception encountered unloading application domain ----> NUnit.Engine.NUnitEngineException : Exception encountered unloading application domain: Error while unloading ap pdomain. (Exception from HRESULT: 0x80131015) Application domain name: domain-f7378c0-*.dll Application domain BaseDirectory: Path
powershell gives False as output for this process

[ChrisMaddock]

This was an intentional change, rather than a regression.

An app domain failing to unload often represents a problem in the user's test code. Previous NUnit would swallow this exception - meaning it was easy for the user to not notice/realise the issue.

As of version 3.8 - this error returns a non-zero code, however returns the specific -5 error code. This leaves you two choices:

1. Fix the issues within your test code that are causing the app domain to fail to unload.

2. Decide that issues are not causing you any problems, and are not worth the time investment of fixing. You could then choose to accept the -5 code specifically as a success code along with zero - whilst not missing any other errors which may occur.

I will say that this should have been documented better than it was. I'll attempt to add something on that soon. I'll also close this issue - I hope that explains the decision, and I don't think there's any action we want to take - but please comment if you have more to add and we can always reopen. 🙂

[wburgers]

Ok, I get the choices made, but then my next question is: how is nunit-console versioned?
I thought it was semver, but apparently not. This change broke our build even though it is a minor version update.

[ChrisMaddock]

That's a big question, that I don't really have a good answer to. See: https://github.com/nunit/nunit/issues/2410. Your thoughts would be very welcome on that issue.

The issue we have is that NUnit has a much longer history than many other products and tools. Historically, there's been a major version with significant breaking changes every ~5-10 years or so, and we try and minimise the breaking changes in between. This, I agree is a breaking change, however we allowed it in as (in my opinion) - there is already an error in user code to trigger this - and this is just highlighting that error.

Sorry I don't have a better answer - versioning is definitely an issue we're aware of. We've got a long tradition of doing things one way - but whether we change that or not is an open issue. Like I said, your thoughts would be welcome on that issue.

[wburgers]

Ah got it, thanks for the answer.
I'll read up on the discussion and see if I have anything to add.
We also have an older product in which versioning is a problem, so I understand your concern very well.

Keep up the good work!
Cheers

[CharliePoole]

FWIW I've reached the conclusion that it makes no sense to say you use semver unless you also give a pretty precise definition of what you mean by a breaking change. We have not done that, I'm afraid, in part due to some disagreements in the team about what the definition should be.

[chillitom]

This is pretty frustrating, often you'll use third party libraries that will have long running threads that prevent AppDomains from being unloaded. I think a simple warning message would have sufficed.

[ChrisMaddock]

@chillitom This is why we chose to allocate these errors under a specific error code - so in such a case as yours, you can chose to consider -5 as a success code. The issue with warning messages is that they only work if the user is watching the console - something which isn't the case in something like CI.

Are you able to get around your issue by ignoring the -5 code, or is there a case we're not aware of yet?

[chillitom]

We can ignore the code but it's just more build cruft for something that should be straightforward. Most people don't give a toss about AppDomain unloading, AppDomains haven't made it into .Net Core so going forwards they are going to be of less and less relevance. As noble as the sentiments are to make sure people identify related issues I don't think it's the job of the test framework and if it is going to do it then it should be opt in. I've wasted an afternoon on this, hundreds of others will too.

[ChrisMaddock]

@nunit/engine-team Thoughts?

I'm fairly apathetic as to how we move forward - the previous issue we had was that we'd throw in certain circumstances and warn under others. This was an attempt to move towards consistency.

[jnm2]

I have the opposite view. If one of my tests left a stray thread running, that's not always something that there is an API to test for so it may be impossible to fail the proper test case, but it is something I consider highly critical.

[chillitom]

I completely agree, it is something you should be able to test for; it’s something I’d test for in cases where code unloading is important to me.

It is also perfectly valid to write code that can never be unloaded, a lot of code lives forever or until it is killed.

I think the job of deciding what is correct is up to the tester and not the framework. The framework can help the tester for sure, an optional switch or a assembly level attribute maybe but I don’t think it should decide that something is in error what it might not necessarily be so.

NUnit is used in all manner of different tests and in ways we can probably never imagine. It shouldn’t dictate what a correct test is or isn’t.

Il giorno 20 feb 2018, alle ore 19:02, Joseph Musser [e-mail] ha scritto:

I have the opposite view. If one of my tests left a stray thread running, that's not always something that there is an API to test for but it is something I consider highly critical.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[jnm2]

Sure! Seems like an opt-out setting would be safer so that you notice it the first time.
A non-zero exit code for success is not new though. For example, robocopy.

[CharliePoole]

I'm on the other side. I think we should report the problem but not throw or give a negative exit code. If users don't notice things that are reported but don't cause the run to fail, then there are a lot of other things they will miss. We should trust users to read the fine print.

[ChrisMaddock]

Different question: if we’re running in a separate process, as default, why do we unload the app domain, rather than just terminating the process?

[ChrisMaddock]

My default view would be to agree without a Joseph. But having some (inconsistent) history here is something we shouldn’t ignore.

That then got me thinking about why we’re actually doing this at all.

[CharliePoole]

We do it because the same code is used whether we are running in process or in a separate process. And of course, the default used to be to run in process.

Basically, we use the engine for two different purposes. In one role, it controls all tests. In another role, under an agent, it runs specific tests in an AppDomain. Using the engine for both purposes was expedient when we first went to NUnit 3. My idea was that the agent would eventually get it's own code rather than referencing the agent but that never came about.

It would be a bit messy to make the DomainManager work differently when run under the agent than when run in process, but it is possible.

The funny thing is, we often ask people to run in process in order to discover what's happening.

[jnm2]

My default view would be to agree without a Joseph.

This provided some amusement 😁

[ChrisMaddock]

Ha! Whoops sorry, autocorrect!

The fact that the unload is is many cases an unnecessary step does make me think we should worry alert to it less.

[chillitom]

Are you able to get around your issue by ignoring the -5 code, or is there a case we're not aware of yet?

On further reflection this isn't that straightforward, we use FAKE in our build scripts which abstracts the call to the console runner.

Now we either have to drop use of FAKE's helper and hand roll the calls or patch FAKE to support this return value. Other teams use CAKE which will also need updating.

In fact any library (both public and private) that helps with running NUnit will need updating to reflect this change.

[ChrisMaddock]

Cake will handle the error code gracefully as an unknown, until such a point someone chooses to update it. There’s no drawback to that - the change would be in the enhancement territory. (I wrote that bit of it to work like that! 😄)

Fake I know nothing about.

[chillitom]

@ChrisMaddock true that it will select an appropriate error string but my point was that Cake will throw an exception and fail where it wouldn't have previously, it provides no control over ignoring this code. If we add a switch to revert the behavior then libraries will need updating to be able to pass this option into the runner. I really think this should be reverted as soon as possible before more people upgrade and waste their time on it.

[jnm2]

I really think this should be reverted as soon as possible before more people upgrade and waste their time on it.

On the other hand, I've been in this exact situation and discovered a bug. What if we do what Cake does—add the new behavior but print out how to suppress the diagnostic, via command line or setting? That way no time is wasted, but people realize that something they are using is not well-behaved.

[chillitom]

@jnm2 cool, so can we have it as a warning so people who consider these issues important can still discover bugs? maybe with an option to upgrade the warning to an error via a different error code? This way there's no breaking change and no 3rd party library code changes required. Test suites that worked with 3.7 will still work with 3.8+ with no changes required.

[jnm2]

@chillitom Yeah! So long as the console flashes yellow or red when I'm running locally, and CI servers can report that the build completed with warnings, I'm happy. Wouldn't need the setting then. The only thing I'm afraid of is that stuff will happen in CI and I won't see it.

[CharliePoole]

@ChrisMaddock I think we made a mistake on this one. Reviewing the discussion, I think I had the impression that you were replacing a -100 code with -5, rather than causing a failure where we previously didn't have one.

I think it's important to separate this into its two constituent parts:

1. How the engine lets the runner know what happened. A -5 from the agent would be one way to do that. An assembly-level warning* would be another.

2. What the runner does about it the problem. I definitely don't think immediate termination should be the choice, in case there are still other assemblies running (or still to be run) in other processes. I did think that an __eventual__ return code (after all tests run) of -5 would be OK, but that was on the basis that we were already returning -100. I may have misunderstood the explanation, which was mixed in with a lot of discussion of other things.

• In the past, having the engine issue a warning was purely hypothetical. We didn't have a way to do it. Now, we actually have warnings. The engine could attach a warning-level AssertionResult to the assembly-level test. As it happens, the console would automatically report it. Users already get warnings, when they use the facility and have to examine the report to see them. They do not cause the test run to fail but give a 0 return code.

[ChrisMaddock]

Warnings sound good.

I also think we should look at only unloading the appdomain when necessary - as in when we’re running in process. That would mean in the default case, we wouldn’t even try to unload the appdomain, and only have that overhead when necessary.

I’m currently travelling with work - so don’t have the time to spend on this. @chillitom - would you be able to PR?

[ChrisMaddock]

(Although I think someone still needs to spec out an implementation with regards to how this is handled across different process and app domain models before diving into code - as I’m not sure we’re all on totally the same page yet!)

[ChrisMaddock]

In fact, if we don’t try and unload the app domain when not necessary - that would prevent us from needing to think about terminating early, right? As the only times we would try and unload the app domain are in cases which may cause an error - when we are running within the same process? That _should_ probably error, right, as improperly unloaded tests could affect the next test assembly running? Or am I missing something?

Apologies if so - I’m doing all this on my phone, so can’t see the code.

[ChrisMaddock]

Charlie - sorry I haven’t replied directly to your points - but I think the above is relevant. I don’t want to design a way for agents to report unload failures to the engine, if there’s never an actual need for an agent to unload an app domain, and therefore get an unload failure. Without looking at the code here, I’m not sure of the edge cases around this.

I am in agreement with you (both) now though that the current solution isn’t what we want.

[chillitom]

It could affect the next test that's true, though my preference would be
not to have the framework enforce this with a hard error if the framework
is capable of continuing its job. If switching to another process model
would solve peoples' problems though then I guess it isn't the end of the
world if it did.

On 21 February 2018 at 18:49, Chris Maddock [e-mail]
wrote:

In fact, if we don’t try and unload the app domain when not necessary -
that would prevent us from needing to think about terminating early, right?
As the only times we would try and unload the app domain are in cases which
may cause an error - when we are running within the same process? That
should probably error, right, as improperly unloaded tests could affect
the next test assembly running? Or am I missing something?

Apologies if so - I’m doing all this on my phone, so can’t see the code.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/nunit/nunit-console/issues/371#issuecomment-367430186,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAEiwd3_Yt0V2dimr3Puug8bbuW0d0jQks5tXGVGgaJpZM4SFVTY
.

[chillitom]

I’m currently travelling with work - so don’t have the time to spend on this. @chillitom - would you be able to PR?

I could have a go. I would be keen for the behavior to be agreed and well specified first though.

[ChrisMaddock]

@chillitom - to be clear here, the default option is to run each test assembly in a separate process, and therefore separate app domain. I imagine that’s how yours are running, unless you’re specifying anything special?

In that case - I’m not sure we should even be trying to unload the app domain - as it will go away with the process anyway.

However, in some cases the user may specify to run all tests in a single process, using different app domains. ~Here - if the unload fails, then Nunit theoretically can’t guarantee that the running of the next assembly will be clean, and therefore can’t guarantee that the test results are correct. That’s very much the test frameworks responsibility in my opinion - and something we should error on!~ The more I think about this, the more I think this bits wrong. Maybe it's _never_ an issue. I'd need to research more to know more.

As before - I’m currently travelling, so all this is from memory rather than code and documentation. There’s possibly things wrong with my memory! 😃

[ChrisMaddock]

(And great re: the PR - I agree, let’s get something firmly pinned down first!)

[ChrisMaddock]

Maybe the above is wrong, and you should always unload user-created app domains. I’m not sure from memory, and don’t have much time to dig into this right now, sorry.

[herebebeasties]

I also think we should look at only unloading the appdomain when necessary - as in when we’re running in process. That would mean in the default case, we wouldn’t even try to unload the appdomain, and only have that overhead when necessary.

FWIW, I think you should strive to behave the same way as much as possible, regardless of mode. More combinations to test, more subtleties when you swap over, etc. otherwise. @CharliePoole said above "The funny thing is, we often ask people to run in process in order to discover what's happening." - do you really want certain behavior to be wildly different when you do that?

[nealio42]

HI all, I'm trying to troubleshoot this warning message to improve my test framework. I've used --trace=Verbose as a command line arg. However, I'm only getting a basic warning with no details on how to fix. Are there logs or should it output to console?

NUnit.Engine.NUnitEngineUnloadException : Agent Process was terminated successfully after error.
----> NUnit.Engine.NUnitEngineUnloadException : Exception encountered unloading application domain
----> NUnit.Engine.NUnitEngineException : Exception encountered unloading application domain: Error while unloading appdomain. (Exception from HRESULT: 0x80131015)
Application domain name: domain-
Application domain BaseDirectory: C:\prizmdoc-installer-automation\server-automation\bin\Debug\

[mikkelbu]

Hi @nealio42
You'll probably need to provide some more information:

• Which version of the console are you using (perhaps also version of NUnit, but that should not matter)? the -5 result was removed in 3.9 as far as I can tell
• How are you invoking the console (which parameters etc.)
• When you invoke the tests with trace=Verbose you should get some trace files in the directory that perhaps will contain some more information

[nealio42]

Hi, thanks for the quick reply. I'm using version 3.9 using command line --trace=Verbose. I will look for trace files, thanks!

[nealio42]

I can't find any trace files ... Sorry I'm new to nunit. What is the file extension? Would the files be in the bin/Debug folder or the folder where I executed the script? I looked in both and I'm unable to see anything related to trace.

I'm using specflow 2.4 with nunit 3.9

cmd ... nunit3-console.exe --trace=Verbose --labels=All "--out=......\TestResults\serverTestResults.txt" "--result=......\TestResults\serverTestResults.xml;format=nunit2" "......\server-automation\bin\Debug\server-automation.dll" --params:app=%arg1% --params:pass=%arg2% --where "cat=full"

Test run perfectly in visual studio with no errors. Running from cmd line I frequently get the previously mentioned warning.

[mikkelbu]

If I run .\bin\Release\nunit3-console.exe .\bin\Release\nunit.engine.tests.dll --trace=Verbose from the commandline then when the console is completed I have the following in the current folder (not that the numbers are specific for the given run)

• InternalTrace.17344.log
• nunit-agent_2240.log
• InternalTrace.2240.nunit.engine.tests.dll.log

So one file for the engine, one for the agent, and one for the assembly. I don't know much about specflow, so how that affects the picture I don't know.

[nealio42]

found em, thanks!

I'm unable to see the issue. The logs show the following:

11:40:58.155 Info  [ 1] ProcessRunner: Done running 
11:40:58.172 Info  [ 1] ProcessRunner: Unloading 
11:41:09.009 Warning [ 1] ProcessRunner: Failed to unload the remote runner. Exception encountered unloading application domain
11:41:09.012 Error [ 1] ProcessRunner: NUnit.Engine.NUnitEngineUnloadException : Exception encountered unloading application domain
  ----> NUnit.Engine.NUnitEngineException : Exception encountered unloading application domain: Error while unloading appdomain. (Exception from HRESULT: 0x80131015)
Application domain name: domain-
Application domain BaseDirectory: C:\prizmdoc-installer-automation\server-automation\bin\Debug\

11:41:09.023 Error [ 1] ProcessRunner: --NUnitEngineUnloadException
Exception encountered unloading application domain

Server stack trace: 
   at NUnit.Engine.Services.DomainManager.DomainUnloader.Unload()
   at NUnit.Engine.Runners.TestDomainRunner.UnloadPackage()
   at NUnit.Engine.Runners.AbstractTestRunner.Unload()
   at NUnit.Engine.Agents.RemoteTestAgent.Unload()
   at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Object[]& outArgs)
   at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg)

Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at NUnit.Engine.ITestEngineRunner.Unload()
   at NUnit.Engine.Runners.ProcessRunner.UnloadPackage()
   at NUnit.Engine.Runners.ProcessRunner.Dispose(Boolean disposing)
--
NUnitEngineException
Exception encountered unloading application domain: Error while unloading appdomain. (Exception from HRESULT: 0x80131015)
Application domain name: domain-
Application domain BaseDirectory: C:\prizmdoc-installer-automation\server-automation\bin\Debug\



11:41:09.024 Debug [ 1] ProcessRunner: Stopping remote agent
11:41:09.100 Info  [ 1] ServiceManager: Stopping TestFilterService
11:41:09.100 Info  [ 1] ServiceManager: Stopping ResultService
11:41:09.100 Info  [ 1] ServiceManager: Stopping TestAgency
11:41:09.101 Info  [ 1] ServiceManager: Stopping DefaultTestRunnerFactory
11:41:09.101 Info  [ 1] ServiceManager: Stopping RuntimeFrameworkService
11:41:09.101 Info  [ 1] ServiceManager: Stopping ProjectService
11:41:09.101 Info  [ 1] ServiceManager: Stopping RecentFilesService
11:41:09.106 Info  [ 1] ServiceManager: Stopping DriverService
11:41:09.106 Info  [ 1] ServiceManager: Stopping ExtensionService
11:41:09.106 Info  [ 1] ServiceManager: Stopping DomainManager
11:41:09.106 Info  [ 1] ServiceManager: Stopping SettingsService

[nealio42]

Found the issue, It was related to my framework. Sorry for the trouble.

[mikkelbu]

No trouble at all 😄.