Welcome Guest! To enable all features please Login or Register.

Notification

Icon
Error

Tests that use await randomly time out
jnm236
#1 Posted : Thursday, June 25, 2015 4:55:23 PM(UTC)
Rank: Advanced Member

Groups: Registered
Joined: 6/25/2015(UTC)
Posts: 57
Location: United States of America

Thanks: 1 times
Was thanked: 4 time(s) in 4 post(s)
These tests are hitting the 60 second timeout randomly. All of them complete within milliseconds when run from Visual Studio or ReSharper.

In the large project I'm working on, it happens almost every time I type in a different project and cause a background rebuild.
I tried to put together a tiny demo solution, but I can't reproduce it in the demo solution. Any idea what might be going wrong?

I've boiled it down to some core scenarios. It happens consistently on only the tests that use `await` on a task that isn't already complete.

Code:

// These tests time out randomly. They seem to time out most frequently when I'm typing an another project in the solution and NCrunch builds projects and runs tests in the background.
// Doesn't tend to happen when I run them directly.
[TestMethod]
public async Task TaskCompletionSourceAwait()
{
    var tcs = new TaskCompletionSource<object>();
    Task.FromResult<object>(null).ContinueWith(_ => tcs.SetResult(null));
    await tcs.Task;
}

[TestMethod]
public async Task DelayAwait()
{
    await Task.Delay(10);
}
    
// These tests do not time out:
        
[TestMethod]
public Task TaskCompletionSource()
{
    var tcs = new TaskCompletionSource<object>();
    Task.FromResult<object>(null).ContinueWith(_ => tcs.SetResult(null));
    return tcs.Task;
}

[TestMethod]
public async Task TaskCompletionSourceImmediateAwait()
{
    var tcs = new TaskCompletionSource<object>();
    tcs.SetResult(null);
    await tcs.Task;
}

[TestMethod]
public Task Delay()
{
    return Task.Delay(10);
}
Remco
#2 Posted : Thursday, June 25, 2015 10:24:17 PM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 7,161

Thanks: 964 times
Was thanked: 1296 time(s) in 1202 post(s)
Hi,

Thanks for sharing this.

I've given this code a bit of a spin, but can't seem to get it to fail in the way that you've described. I think that probably the failure scenario requires a certain execution sequence that would be baked in through your cached NCrunch data. However, I did see something very interesting:

WARNING - UnitTest1.cs (16, 13): Because this call is not awaited, execution of the current method continues before the call is completed. Consider applying the 'await' operator to the result of the call.

This is a warning thrown up by the build, and I suspect it could be worth a look. This warning suggests that the code is kicking off a thread that isn't being waited for. This means that there is the possibility of a worker thread continuing to run in the background while NCrunch runs subsequent tests. The behaviour of the rest of the code in such a scenario could be very unpredictable, and I wouldn't rule out timeouts. The line of code showing this warning is: Task.FromResult<object>(null).ContinueWith(_ => tcs.SetResult(null));
jnm236
#3 Posted : Monday, June 29, 2015 2:53:03 PM(UTC)
Rank: Advanced Member

Groups: Registered
Joined: 6/25/2015(UTC)
Posts: 57
Location: United States of America

Thanks: 1 times
Was thanked: 4 time(s) in 4 post(s)
I did a little more digging. It seems like thread pool starvation. On a hunch, I turned off parallel execution for the solution. With parallel execution off, I'm still getting timeouts on similar tests but not for these particular tests. Also with parallel execution off, it takes an unbearably long time for all tests in the solution to time out. I'm going to leave it in parallel mode.

So you're saying after returning from TaskCompletionSourceAwait when tcs.SetResult(null) happens, the thread that called tcs.SetResult(null) is still hanging around in the background after the work is done? Isn't that common with any async API, and how would that impact the tests?
jnm236
#4 Posted : Monday, June 29, 2015 3:31:01 PM(UTC)
Rank: Advanced Member

Groups: Registered
Joined: 6/25/2015(UTC)
Posts: 57
Location: United States of America

Thanks: 1 times
Was thanked: 4 time(s) in 4 post(s)
I was successful in putting together a bare-bones demo. To repro, open the .sln and type a space in Program.cs and erase it, just to trigger a build. TaskCompletionSourceAwait fails every time. DelayAwait does not fail in the demo project, only in the full project.

In case it's relevant: NCrunch 2.15.0.9, VS2013 Professional (12.0.31101.00 Update 4), Windows 7 Professional x64, i5-3470, 16 GB RAM.



..okay, I don't have the ability to add an attachment to this post. Odd. 769 KB zip. I do have a dedicated link on this forum to create photo albums and upload photos (hello) but it obviously doesn't allow me to upload .zip. Just, saying, it's a little weird.

I have it temporarily uploaded offsite but it sure would be nice to upload it here for the sake of reference.

Edit: Await issue.zip
Remco
#5 Posted : Monday, June 29, 2015 10:41:30 PM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 7,161

Thanks: 964 times
Was thanked: 1296 time(s) in 1202 post(s)
Thanks for providing the sample code. I'm sorry that it was such a pain to submit it to the forum. Usually I try to recommend to send it through the contact form instead.

The problem, as I think you suspected, is caused by thread pool starvation. The TaskCompletionSourceAsync test is set to wait for a task to complete, of which the logic is dependent upon execution by the thread pool. The previous tests each are queuing up 100 sleep tasks inside the thread pool and this results in a total of 400 queued requests sitting in the pool at the time NCrunch starts to execute TaskCompletionSourceAsync.

The .NET thread pool has a limited scaling capacity and will only introduce new threads at a fixed speed once the pool has been exhausted. The 5 second timeout in this test just isn't fast enough for the pool to scale to meet the demand of the other tests. Thus the test is suspended by the await action until the timeout kicks in.

Parallel execution won't have any direct impact on this behaviour because it executes threads in parallel across separate processes. The .NET thread pool is local to each process and won't be aware of this execution, so the starvation should be no better or worse. However, parallel execution may indirectly affect the results you receive from NCrunch in this situation because it will run separate batches of tests in a new process, which reduces the risk of accumulated starvation through multiple tests.

The reason you're observing inconsistent results is because the above behaviour is sequence dependent. Where the TaskCompletionSourceAsync test is executed first (or on its own), it will immediately pass because the thread pool isn't starved. NCrunch will always batch tasks according to its knowledge of their normal execution time. If it notices that this test usually takes 5 seconds to run, it will execute it as part of a separate batch, thus changing the execution sequence. When the test passes immediately, NCrunch will then subsequently batch it with the other tests, so the next run fails.

In conclusion, the problem is in the code itself. It's important that when launching threads in test code (or code under test), you should always make sure the background threads are bounded to the foreground execution. Always wait until all tasks have been completed before returning from the test. Use whatever abstractions are necessary to make this happen. If you have no other option, there's always Thread.Sleep (messy, but it does work). Where you have background threads running beyond the length of the test, there's no telling how they can impact execution of later tests in the process. See here for more details - http://www.ncrunch.net/documentation/considerations-and-constraints_multi-threaded-tests.
Users browsing this topic
Guest
Forum Jump  
You cannot post new topics in this forum.
You cannot reply to topics in this forum.
You cannot delete your posts in this forum.
You cannot edit your posts in this forum.
You cannot create polls in this forum.
You cannot vote in polls in this forum.

YAF | YAF © 2003-2011, Yet Another Forum.NET
This page was generated in 0.041 seconds.
Trial NCrunch
Take NCrunch for a spin
Do your fingers a favour and supercharge your testing workflow
Free Download