Bug 17585 - System.InvalidOperationException: The task has already completed
Summary: System.InvalidOperationException: The task has already completed
Status: RESOLVED NORESPONSE
Alias: None
Product: iOS
Classification: Xamarin
Component: BCL Class Libraries ()
Version: 7.0.6.x
Hardware: PC Mac OS
: Normal normal
Target Milestone: Untriaged
Assignee: Marek Safar
URL:
Depends on:
Blocks:
 
Reported: 2014-02-04 01:42 UTC by Prashant Cholachagudda
Modified: 2016-07-08 14:43 UTC (History)
7 users (show)

Tags:
Is this bug a regression?: ---
Last known good build:


Attachments
SampleTest (9.67 KB, application/zip)
2014-03-03 05:18 UTC, Sadik Ali
Details


Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report on Developer Community or GitHub with your current version information, steps to reproduce, and relevant error messages or log files if you are hitting an issue that looks similar to this resolved bug and you do not yet see a matching new report.

Related Links:
Status:
RESOLVED NORESPONSE

Description Prashant Cholachagudda 2014-02-04 01:42:13 UTC
System.InvalidOperationException when using Async stream operations

System.InvalidOperationException: The task has already completed
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[Elevenworks.Drawing.Core.Figure].SetResult (Elevenworks.Drawing.Core.Figure result) [0x00000] in <filename unknown>:0
at Elevenworks.Drawing.Persistence.StreamingXmlPersistenceInput+<ReadAsync>c__async17.MoveNext () [0x00000] in <filename unknown>:0
at System.Threading.Tasks.SynchronizationContextContinuation.<Execute>m__0 (System.Object l) [0x00000] in <filename unknown>:0
at MonoTouch.UIKit.UIKitSynchronizationContext+<Post>c__AnonStorey89.<>m__A8 () [0x00000] in <filename unknown>:0
at MonoTouch.Foundation.NSAsyncActionDispatcher.Apply () [0x00000] in <filename unknown>:0
at (wrapper managed-to-native) MonoTouch.UIKit.UIApplication:UIApplicationMain (int,string[],intptr,intptr)
at MonoTouch.UIKit.UIApplication.Main (System.String[] args, System.String principalClassName, System.String delegateClassName) [0x00000] in <filename unknown>:0
at Elevenworks.TouchDraw.Application.Main (System.String[] args) [0x00000] in <filename unknown>:0
Comment 2 Marek Safar 2014-02-04 02:16:09 UTC
Without any test case I cannot verify that 7.0.6 TPL hotfix resolves the issue but the changes are quite hight that it does.
Comment 3 Sadik Ali 2014-03-03 05:18:22 UTC
Created attachment 6197 [details]
SampleTest

I have created test project with some Asynchronous methods and checked this issue but unable to reproduce this.

Checked with below environments:

All Mac
XS 4.2.3 (build 59)
Xamarin.iOS : 7.0.6.168 

I have attached Test project, let me know if I am missing any thing. Also can you please provide me some inputs to verify this issue.
Comment 4 Sebastien Pouliot 2016-05-24 21:14:05 UTC
The information was provided.
Comment 5 Vyacheslav Napadovsky 2016-07-08 14:19:20 UTC
Same exception here. Below is the possible reason:

Unhandled Exception:
System.InvalidOperationException: The task has already completed
  at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[System.String].SetException (System.Exception exception) [0x00000] in <filename unknown>:0
  at System.IO.StreamReader+<ReadToEndAsyncCore>c__async2.MoveNext () [0x00000] in <filename unknown>:0
  at (wrapper unbox) System.IO.StreamReader/<ReadToEndAsyncCore>c__async2:MoveNext ()
  at System.Threading.Tasks.AwaiterActionContinuation.Execute () [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.ProcessCompleteDelegates () [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.HandleGenericException (System.AggregateException e) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.TrySetException (System.AggregateException aggregate, Boolean cancellation, Boolean observed) [0x00000] in <filename unknown>:0
  at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[System.Int32].SetException (System.Exception exception) [0x00000] in <filename unknown>:0
  at System.IO.StreamReader+<ReadBufferAsync>c__async3.MoveNext () [0x00000] in <filename unknown>:0
  at (wrapper unbox) System.IO.StreamReader/<ReadBufferAsync>c__async3:MoveNext ()
  at System.Threading.Tasks.AwaiterActionContinuation.Execute () [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.ProcessCompleteDelegates () [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.HandleGenericException (System.AggregateException e) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.Task.TrySetException (System.AggregateException aggregate, Boolean cancellation, Boolean observed) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.TaskCompletionSource`1[System.Int32].TrySetException (IEnumerable`1 exceptions) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.TaskCompletionSource`1[System.Int32].SetException (IEnumerable`1 exceptions) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.TaskCompletionSource`1[System.Int32].SetException (System.Exception exception) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.TaskFactory`1[System.Int32].InnerInvoke (System.Threading.Tasks.TaskCompletionSource`1 tcs, System.Func`2 endMethod, IAsyncResult l) [0x00000] in <filename unknown>:0
  at System.Threading.Tasks.TaskFactory`1+<FromAsyncBeginEnd>c__AnonStorey5`3[System.Int32,System.Byte[],System.Int32,System.Int32].<>m__0 (IAsyncResult l) [0x00000] in <filename unknown>:0
  at System.Net.WebAsyncResult.CB (System.Object unused) [0x00000] in <filename unknown>:0


The app creates a lot of connections during it's run. The issue happens after 7 hours of running (about 80000 connections was created-closed already).
The fault is happening while executing following code:

async Task<string> RequestGet(Uri uri) {
    var request = WebRequest.Create(uri) as HttpWebRequest;
    request.CookieContainer = _cookies;
    request.UserAgent = _userAgent;
    using (var response = await request.GetResponseTimeout())
    using (var stream = response.GetResponseStream())
    using (var reader = new StreamReader(stream, Encoding.UTF8))
        return await reader.ReadToEndAsync();
}

// GetRequestTimeout method:
public static Task<WebResponse> GetResponseTimeout(this WebRequest request, int timeout = 30000) {
    request.Timeout = timeout;
    return Task.FromResult(request.GetResponse());
}

Note, there are no more than one instance of RequestGet running at the same time (I await on all of the its calls), and _cookies container got accessed only via this method (+ its construction).
Comment 6 Vyacheslav Napadovsky 2016-07-08 14:22:59 UTC
Forgot to mention, 
$ mono --version
Mono JIT compiler version 3.2.8 (Debian 3.2.8+dfsg-10)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
        TLS:           __thread
        SIGSEGV:       normal
        Notifications: epoll
        Architecture:  armel,vfp+hard
        Disabled:      none
        Misc:          softdebug
        LLVM:          supported, not enabled.
        GC:            sgen
Comment 7 Vyacheslav Napadovsky 2016-07-08 14:43:59 UTC
Additionally, periodically this message below appears on console (0x8 is just a sample there are other numbers):

_wapi_connect: error looking up socket handle 0x8

This message appears usually after connection timeout reached.
For example: among 30998 connections there were 10262 timed out. And only 25 such messages appear on console. The code that creates so much connections is below:

async Task<bool> CheckUrl(string url, CancellationToken ct) {
    bool ret = true;
    try {
        var request = (HttpWebRequest)WebRequest.Create(url);
        using (var response = await request.GetResponseTimeout(12000))
        using (var reader = new BinaryReader(response.GetResponseStream())) {
            ct.ThrowIfCancellationRequested();
            const int kilobyte = 1024;
            byte[] buffer = new byte[40 * kilobyte];
            int idx = 0;
            while (ret && (idx > 10 * kilobyte)) {
                int read = reader.Read(buffer, idx, buffer.Length - idx);
                idx += read;
                ret = read > 0;
            }
        }
    }
    catch (OperationCanceledException) {
        throw;
    }
    catch (Exception) {
        ret = false;
    }
    return ret;
}

Exceptions in this method does not get logged unfortunately; and I'm gonna add logging now.
CheckUrl method runs in heavy parallel (45 instances max), but sequentially with the RequestGet method mentioned above:
RequestGet -> ... -> RequestGet -> {CheckAvailability: 45 paralled instances of CheckUrl created -> all instances finished} -> loop for RequestGet -> ...
The issue happens on 8th of this loop iteration.
CheckAvailability function code below:

public async Task CheckAvailability(CancellationToken ct) {
    lock (_logger) {
        _logger.WriteLine();
        _logger.WriteLine("CheckAvailability: started", DateTime.Now);
    }
    Dictionary<string, List<Item>> split;   // channel url host -> list of channels
    CheckProgress cp;
    lock (_listLock) {
        split = _list
            .GroupBy(k => (new Uri(k.Value.Url)).Host, e => e.Value)
            .ToDictionary(k => k.Key, e => e.ToList());
        cp = new CheckProgress {
            Processed = 0,
            FailsCount = 0,
            Count = _list.Count,
        };
    }
    const int ConcurrentChecksMax = 45;
    var tasks = new List<Task>();
    foreach (var slice in split.Values) {
        tasks.Add(CheckSequence(slice, cp, ct));
        if (tasks.Count >= ConcurrentChecksMax)
            tasks.Remove(await Task.WhenAny(tasks));
    }
    await Task.WhenAll(tasks);
    lock (_listLock)
        _list = split.SelectMany(d => d.Value).ToDictionary(c => c.Url);
    lock (_logger) {
        _logger.WriteLine();
        _logger.WriteLine("CheckAvailability: finished");
        _logger.WriteLine("CheckAvailability: {0} fails out of {1} channels", cp.FailsCount, cp.Count);
    }
}

async Task CheckSequence(ICollection<Item> sequence, CheckProgress progress, CancellationToken ct) {
    var random = new Random();
    foreach (var item in new List<Item>(sequence)) {
        bool success = await CheckUrl(item.Url, ct);
        ct.ThrowIfCancellationRequested();
        if (!success) {
            await Task.Delay(random.Next(1000, 2000), ct);
            success = await CheckUrl(item.Url, ct);
        }
        lock (Console.Out) {
            int fails = success ? progress.FailsCount : Interlocked.Increment(ref progress.FailsCount);
            int processed = Interlocked.Increment(ref progress.Processed);
            var status = string.Format(" {3:###}% completed ({0}/{1}, {2} fails)",
                processed, progress.Count, fails, processed * 100 / progress.Count);
            Console.Out.Write(ConsoleFillString(status));
            Console.Out.Write("\r");
        }
        if (!success)
            sequence.Remove(item);
        await Task.Delay(random.Next(4000, 10000), ct);
    }
}

class ConsoleLogger {
    public void WriteLine(string format = "", params object[] args) {
        lock (Console.Out)
            Console.Out.WriteLine("[{0:G}] {1}", DateTime.Now, string.Format(format, args));
    }
}

class Item {
    public string Header { get; set; }
    public string Title { get; set; }
    public string Url { get; set; }
    public int Index { get; set; }
}

class CheckProgress {
    public int Processed;
    public int FailsCount;
    public int Count;
}

all other code I can send via mail request (just don't want to make it fully public).