How do I correct console output from a list of tasks?

Question

5.00/5 (1 vote)

See more:

I am playing in a new Console application in an attempt to finally get a proper understanding of Task and its various methods.

Below is my test program and the output from it. My question is: why do I get the 'Ending task' messages after the program reaches the statements after the Task.WhenAll() statement?

public static class Program
{
    private const int NumTasks = 10;
    private static int[] TaskDelays = { 1000, 1200, 1400, 1600, 1800, 2000, 2200, 2400, 2600, 2800 };
    private static List<Task> _tasks = new();

    static async Task Main( string[] args )
    {
        Console.WriteLine( "****** START ******" );

        await Run();

        Console.WriteLine( "****** END ******" );
        Console.WriteLine( "Press any key to end." );
        Console.ReadKey();
    }


    private static async Task Run()
    {
        Console.WriteLine( "Create tasks" );
        for( int i = 0; i < NumTasks; ++i )
            _tasks.Add( CreateNewTask( i ) );

        Console.WriteLine( "Start tasks" );
        Console.WriteLine( TaskStatusString() );
        for( int i = 0; i < NumTasks; ++i )
            _tasks[ i ].Start();

        Console.WriteLine( "Await tasks" );
        Console.WriteLine( TaskStatusString() );
        await Task.WhenAll( _tasks );

        Console.WriteLine( "After awaiting tasks" );
        Console.WriteLine( TaskStatusString() );
    }


    private static Task CreateNewTask( int index ) => new Task( async () =>
    {
        Console.WriteLine( $"Starting task {index}." );
        await Task.Delay( TaskDelays[ index ] );
        Console.WriteLine( $"Ending task {index}." );
    });


    private static string TaskStatusString()
    {
        StringBuilder sb = new StringBuilder( "Statuses: " );
        for( int i = 0; i < NumTasks; ++i )
            sb.Append( i.ToString() + "=" + _tasks[ i ].Status.ToString() + "; " );
        sb.Append( Environment.NewLine );
        return sb.ToString();
    }
}

Quote:
****** START ******
Create tasks
Start tasks
Statuses: 0=Created; 1=Created; 2=Created; 3=Created; 4=Created; 5=Created; 6=Created; 7=Created; 8=Created; 9=Created;

Await tasks
Statuses: 0=Running; 1=Running; 2=Running; 3=Running; 4=Running; 5=WaitingToRun; 6=WaitingToRun; 7=WaitingToRun; 8=WaitingToRun; 9=WaitingToRun;

Starting task 6.
Starting task 5.
Starting task 3.
Starting task 0.
Starting task 1.
Starting task 2.
Starting task 4.
Starting task 7.
Starting task 8.
Starting task 9.
After awaiting tasks
Statuses: 0=RanToCompletion; 1=RanToCompletion; 2=RanToCompletion; 3=RanToCompletion; 4=RanToCompletion; 5=RanToCompletion; 6=RanToCompletion; 7=RanToCompletion; 8=RanToCompletion; 9=RanToCompletion;

****** END ******
Press any key to end.
Ending task 0.
Ending task 1.
Ending task 2.
Ending task 3.
Ending task 4.
Ending task 5.
Ending task 6.
Ending task 7.
Ending task 8.
Ending task 9.

What I have tried:

Not sure what to try but I might take up knitting as an alternative to programming.

Changing the code to this gives the output below, which is exactly what I expect, though I am still not 100% clear on why this new version seems to operate differently to my original version.

    private const int NumTasks = 10;
    private readonly static int[] TaskDelays = { 5000, 6000, 6000, 6000, 8000, 6000, 10000, 12000, 1000, 28000 };
    private static List<Task> _tasks = new();

    static async Task Main( string[] args )
    {
        Debug.WriteLine( "****** START ******" );

        await Run();

        Debug.WriteLine( "****** END ******" );
        Debug.WriteLine( "Press any key to end." );
        Console.ReadKey();
    }


    private static async Task Run()
    {
        for( int i = 0; i < NumTasks; ++i )
            _tasks.Add( ReturnDelayedResultAsync( i ) );

        Debug.WriteLine( "Before awaiting tasks" + TaskStatusString() );
        await Task.WhenAll( _tasks );
        Debug.WriteLine( "After awaiting tasks" + TaskStatusString() );

        List<int> results = new();
        foreach( var task in _tasks )
        {
            int result = ((Task<int>)task).Result;
            results.Add( result );
        }

        for( int i = 0; i < NumTasks; ++i )
            Debug.WriteLine( $"Task[ {i} ] = {results[ i ]}" );
    }


    private static async Task<int> ReturnDelayedResultAsync( int index )
    {
        Debug.WriteLine( $"Starting task {index}." );
        await Task.Delay( TaskDelays[ index ] );
        Debug.WriteLine( $"Ending task {index}." );
        return index * 2;
    }


    private static string TaskStatusString()
    {
        StringBuilder sb = new StringBuilder( ": " );
        for( int i = 0; i < NumTasks; ++i )
            sb.Append( i.ToString() + "=" + _tasks[ i ].Status.ToString() + "; " );
        sb.Append( Environment.NewLine );
        return sb.ToString();
    }
}

Quote:
****** START ******
Starting task 0.
Starting task 1.
Starting task 2.
Starting task 3.
Starting task 4.
Starting task 5.
Starting task 6.
Starting task 7.
Starting task 8.
Starting task 9.
Before awaiting tasks: 0=WaitingForActivation; 1=WaitingForActivation; 2=WaitingForActivation; 3=WaitingForActivation; 4=WaitingForActivation; 5=WaitingForActivation; 6=WaitingForActivation; 7=WaitingForActivation; 8=WaitingForActivation; 9=WaitingForActivation;

Ending task 8.
Ending task 0.
Ending task 1.
Ending task 2.
Ending task 5.
Ending task 3.
Ending task 4.
Ending task 6.
Ending task 7.
Ending task 9.
After awaiting tasks: 0=RanToCompletion; 1=RanToCompletion; 2=RanToCompletion; 3=RanToCompletion; 4=RanToCompletion; 5=RanToCompletion; 6=RanToCompletion; 7=RanToCompletion; 8=RanToCompletion; 9=RanToCompletion;

Task[ 0 ] = 0
Task[ 1 ] = 2
Task[ 2 ] = 4
Task[ 3 ] = 6
Task[ 4 ] = 8
Task[ 5 ] = 10
Task[ 6 ] = 12
Task[ 7 ] = 14
Task[ 8 ] = 16
Task[ 9 ] = 18
****** END ******
Press any key to end.

Posted 8-Nov-21 21:52pm

Patrick Skelton

Updated 9-Nov-21 1:05am

v3

Add a Solution

Comments

Richard MacCutchan 9-Nov-21 4:03am

Because the tasks run independently the outputs to the console will come in random order.

Patrick Skelton 9-Nov-21 4:07am

Hi, Richard. I'm not sure I have phrased my question very well. What I don't understand is how any code can be running after the Task.WhenAll(). It seems to be doing nothing.

Richard MacCutchan 9-Nov-21 4:21am

The code has all finished, but the system still has to send the console messages out to the console, all of which are fairly low priority.

2 solutions

Add a Solution

Add your solution here

Treat my content as plain text, not as HTML

Preview 0

…

Existing Members

Sign in to your account

...or Join us

Download, Vote, Comment, Publish.

Your Email
Password
Forgot your password?

Your Email
This email is in use. Do you need your password?
Optional Password

I have read and agree to the Terms of Service and Privacy Policy
Please subscribe me to the CodeProject newsletters

When answering a question please:

Read the question carefully.
Understand that English isn't everyone's first language so be lenient of bad spelling and grammar.
If a question is poorly phrased then either ask for clarification, ignore it, or edit the question and fix the problem. Insults are not welcome.
Don't tell someone to read the manual. Chances are they have and don't get it. Provide an answer or move on to the next question.

Let's work to help developers, not make them feel stupid.

This content, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)

OriginalGriff · Accepted Answer · 2021-11-08T22:20:00

Because you are thinking in a linear way, instead of a multithreaded manner: each thread - each of your tasks and the main thread that started them - is an independant "runnable entity" which will execute on a core as one becomes available as and when the task is ready to run (i.e. not delayed or otherwise waiting).

But ... they all output to a common device: the console which is updated as and when data is available. Since you don't attempt to lock the console, the order in which data appears is pretty much random - though a quick perusal of the Reference Source does show that MS try to be "atomic" in the output by using block transfer instructions to make a "whole message" appear each time rather than "interlacing" outputs from different threads.

Since Windows threading model is preemptive, the order in which any thread execution happens is indeterminate, though if there is little actual code involved it's quite likely that it'll complete in single visit to the task scheduler. Which is probably what's happing with your main thread: it runs to completion before the other threads actually finish buffering data to the Console.

This is complicated, and you can twist your brain in strange ways if you "overthink it"!

Richard Deeming · Accepted Answer · 2021-11-09T01:05:00

Quote:

C#

private static Task CreateNewTask( int index ) => new Task( async () =>
{
    Console.WriteLine( $"Starting task {index}." );
    await Task.Delay( TaskDelays[ index ] );
    Console.WriteLine( $"Ending task {index}." );
});

This is the root of your problem.

The Task constructor you're calling[^] accepts an Action, not a Func<Task>. Your delegate returns after the first await call, at which point the parent Task has no idea that your delegate is still running. The parent Task completes immediately, but your delegate doesn't complete until after the specified delay.

Change your code to use the Task.Run method[^] instead, and remove the loop which starts the tasks. You will then get the expected output in (more-or-less) the right order - eg:

C#

private static Task CreateNewTask( int index ) => Task.Run( async () =>
{
    Console.WriteLine( $"Starting task {index}." );
    await Task.Delay( TaskDelays[ index ] );
    Console.WriteLine( $"Ending task {index}." );
});

C#

Console.WriteLine( "Create tasks" );
for( int i = 0; i < NumTasks; ++i )
    _tasks.Add( CreateNewTask( i ) );

/*
Console.WriteLine( "Start tasks" );
Console.WriteLine( TaskStatusString() );
for( int i = 0; i < NumTasks; ++i )
    // This line would throw an exception since the task has already started:
    _tasks[ i ].Start(); 
*/

Console.WriteLine( "Await tasks" );
Console.WriteLine( TaskStatusString() );
await Task.WhenAll( _tasks );

****** START ******
Create tasks
Await tasks
Starting task 6.
Starting task 4.
Starting task 5.
Starting task 3.
Starting task 7.
Statuses: 0=WaitingForActivation; 1=WaitingForActivation; 2=WaitingForActivation; 3=WaitingForActivation; 4=WaitingForActivation; 5=WaitingForActivation; 6=WaitingForActivation; 7=WaitingForActivation; 8=WaitingForActivation; 9=WaitingForActivation; 

Starting task 8.
Starting task 9.
Starting task 2.
Starting task 0.
Starting task 1.
Ending task 0.
Ending task 1.
Ending task 2.
Ending task 3.
Ending task 4.
Ending task 5.
Ending task 6.
Ending task 7.
Ending task 8.
Ending task 9.
After awaiting tasks
Statuses: 0=RanToCompletion; 1=RanToCompletion; 2=RanToCompletion; 3=RanToCompletion; 4=RanToCompletion; 5=RanToCompletion; 6=RanToCompletion; 7=RanToCompletion; 8=RanToCompletion; 9=RanToCompletion; 

****** END ******

It would probably be a good idea to install the Microsoft.VisualStudio.Threading.Analyzers NuGet package[^], which will add analyzers which would warn you about this pattern:
vs-threading/VSTHRD101.md at main · microsoft/vs-threading · GitHub[^]

How do I correct console output from a list of tasks?

2 solutions

Solution 1

Solution 2

Add your solution here

Preview 0