Delayed progress reporting from async method

Question

I have a WinForms application containing Button and a RichTextBox controls. After user clicks on Button, an IO demanding operation is executed. To prevent blocking of the UI thread I have implemented the async/await pattern. I would also like to report progress of this operation into RichTextBox. This is how the simplified logic looks like:

private async void LoadData_Click(Object sender, EventArgs e)
{
    this.LoadDataBtn.Enabled = false;

    IProgress<String> progressHandler = new Progress<String>(p => this.Log(p));

    this.Log("Initiating work...");

    List<Int32> result = await this.HeavyIO(new List<Int32> { 1, 2, 3 }, progressHandler);

    this.Log("Done!");

    this.LoadDataBtn.Enabled = true;
}

private async Task<List<Int32>> HeavyIO(List<Int32> ids, IProgress<String> progress)
{
    List<Int32> result = new List<Int32>();

    foreach (Int32 id in ids)
    {
        progress?.Report("Downloading data for " + id);

        await Task.Delay(500); // Assume that data is downloaded from the web here.

        progress?.Report("Data loaded successfully for " + id);

        Int32 x = id + 1; // Assume some lightweight processing based on downloaded data.

        progress?.Report("Processing succeeded for " + id);

        result.Add(x);
    }

    return result;
}

private void Log(String message)
{
    message += Environment.NewLine;
    this.RichTextBox.AppendText(message);
    Console.Write(message);
}

After operation gets successfully completed, the RichTextBox contains following text:

Initiating work...
Downloading data for 1
Data loaded successfully for 1
Processing succeeded for 1
Downloading data for 2
Data loaded successfully for 2
Processing succeeded for 2
Downloading data for 3
Done!
Data loaded successfully for 3
Processing succeeded for 3

As you can see the progress for 3rd work item is reported after Done!.

My question is, what is causing the delayed progress reporting and how can I achieve that flow of LoadData_Click will continue only after all progress has been reported?

Answer 1

Progress class will capture current synchronization context when created and then will post callbacks to that context (this is stated in documentation of that class, or you can look at source code). In your case that means that WindowsFormsSynhronizationContext is captured, and posting to it is rougly the same as doing Control.BeginInvoke().

await also captures current context (unless you use ConfigureAwait(false)) and will post continuation of method to it. For iterations except last, UI thread is released on await Task.Delay(500); and so can process your report callbacks. But on last iteration of your foreach loop the following happens:

// context is captured
await Task.Delay(500); // Assume that data is downloaded from the web here.
// we are now back on UI thread
progress?.Report("Data loaded successfully for " + id);
// this is the same as BeginInvoke - this puts your callback in UI thread
// message queue
Int32 x = id + 1; // Assume some lightweight processing based on downloaded data.
// this also puts callback in UI thread queue and returns
progress?.Report("Processing succeeded for " + id);
result.Add(x);

So, in last iteration, your callbacks are put into UI thread message queue, but they cannot be executed right now, because you are executing code in UI thread at this same moment. When code reaches this.Log("done") - it's written to your log control (no BeginInvoke is used here). Then after your LoadData_Click method ends - only at this point UI thread is released from executing your code and message queue may be processed, so your 2 callbacks waiting there are resolved.

Given all that information - just Log directly as Enigmativity said in comment - there is no need to use Progress class here.