Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

QueuedHostedService example is self-explanatory in Core 2.1, but complex in Core 3.0 #14746

Closed
huan086 opened this issue Oct 1, 2019 — with docs.microsoft.com · 11 comments · Fixed by #14765
Closed
Assignees
Labels
doc-enhancement Pri1 High priority, do before Pri2 and Pri3 Source - Docs.ms Docs Customer feedback via GitHub Issue

Comments

Copy link

huan086 commented Oct 1, 2019

Comparing the sample for Core 2.1

https://github.com/aspnet/AspNetCore.Docs/blob/master/aspnetcore/fundamentals/host/hosted-services/samples/2.x/BackgroundTasksSample/Services/QueuedHostedService.cs

with the sample for Core 3.0

https://github.com/aspnet/AspNetCore.Docs/blob/master/aspnetcore/fundamentals/host/hosted-services/samples/3.x/BackgroundTasksSample/Services/QueuedHostedService.cs

the Core 3.0 sample introduced a lot of additional code without explanation. For example, there is the addtion of _shutdown CancellationTokenSource, without explaining why it is used instead of passing stoppingToken into BackgroundProcessing as a parameter.

There is also no explanation why there needs to be a loop here

_backgroundTask = Task.Run(async () =>
                {
                    while (!stoppingToken.IsCancellationRequested)

especially when BackgroundProcessing already loops indefinitely until shutdown.

Furthermore, there is no explanation why StopAsync override does not call base.StopAsync(stoppingToken). Such a call is explicitly stated StopAsync(CancellationToken cancellationToken) – If this method is overridden, you must call (and await) the base class method to ensure the service shuts down properly.


Document Details

Do not edit this section. It is required for docs.microsoft.com ➟ GitHub issue linking.

@dotnet-bot dotnet-bot added the Source - Docs.ms Docs Customer feedback via GitHub Issue label Oct 1, 2019
@guardrex guardrex added the PU label Oct 1, 2019
@guardrex
Copy link
Collaborator

guardrex commented Oct 1, 2019

@huan086 ... yes ... we were going very fast (too fast) during the 3.0 updates.

@anurse, how about .......

public class QueuedHostedService : BackgroundService
{
    private Task _backgroundTask;
    private readonly ILogger<QueuedHostedService> _logger;

    public QueuedHostedService(IBackgroundTaskQueue taskQueue, 
        ILogger<QueuedHostedService> logger)
    {
        TaskQueue = taskQueue;
        _logger = logger;
    }

    public IBackgroundTaskQueue TaskQueue { get; }

    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
    {
        _logger.LogInformation(
            $"Queued Hosted Service is running.{Environment.NewLine}" +
            $"{Environment.NewLine}Tap W to add a work item to the " +
            $"background queue.{Environment.NewLine}");

        _backgroundTask = Task.Run(async () =>
            {
                await BackgroundProcessing(stoppingToken);
            }, stoppingToken);

        await _backgroundTask;
    }

    private async Task BackgroundProcessing(CancellationToken stoppingToken)
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            var workItem = 
                await TaskQueue.DequeueAsync(stoppingToken);

            try
            {
                await workItem(stoppingToken);
            }
            catch (Exception ex)
            {
                _logger.LogError(ex, 
                    "Error occurred executing {WorkItem}.", nameof(workItem));
            }
        }
    }

    public override async Task StopAsync(CancellationToken stoppingToken)
    {
        _logger.LogInformation("Queued Hosted Service is stopping.");

        await Task.WhenAny(_backgroundTask, 
                Task.Delay(Timeout.Infinite, stoppingToken));

        await base.StopAsync(stoppingToken);
    }
}

... and in the workItem perhaps recompose it a bit to ...

  • Combine a token check with the loop.
  • Trap the Delay so it doesn't log out the cancellation.
if (keyStroke.Key == ConsoleKey.W)
{
    // Enqueue a background work item
    _taskQueue.QueueBackgroundWorkItem(async token =>
    {
        // Simulate three 5-second tasks to complete

        int delayLoop = 0;
        var guid = Guid.NewGuid().ToString();

        _logger.LogInformation(
            "Queued Background Task {Guid} is starting.", guid);

        while (!token.IsCancellationRequested && delayLoop < 3)
        {
            try
            {
                await Task.Delay(TimeSpan.FromSeconds(5), token);
            }
            catch (OperationCanceledException)
            {
                // Prevent throwing if the Delay is cancelled.
            }

            delayLoop++;

            _logger.LogInformation(
                "Queued Background Task {Guid} is running. {DelayLoop}/3", guid, delayLoop);
        }

        if (delayLoop == 3)
        {
            _logger.LogInformation(
                "Queued Background Task {Guid} is complete.", guid);
        }
        else
        {
            _logger.LogInformation(
                "Queued Background Task {Guid} was cancelled.", guid);
        }
    });
}

... but it still isn't composed correctly. It throws on shutdown. It throws regardless of work items in the queue.

Unhandled exception. System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.Extensions.Hosting.Internal.Host.StopAsync(CancellationToken cancellationToken)
   at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.WaitForShutdownAsync(IHost host, CancellationToken token)
   at BackgroundTasksSample.Program.Main(String[] args) in C:\Users\guard\Desktop\BackgroundTasksSample\Program.cs:line 40
   at BackgroundTasksSample.Program.<Main>(String[] args)

@guardrex guardrex added the Pri1 High priority, do before Pri2 and Pri3 label Oct 1, 2019
@guardrex guardrex added this to To do in October 2019 via automation Oct 1, 2019
@guardrex guardrex added this to the 2019 Q4 ends Dec 31 milestone Oct 1, 2019
@guardrex guardrex moved this from To do to In progress in October 2019 Oct 1, 2019
@guardrex guardrex self-assigned this Oct 1, 2019
@guardrex
Copy link
Collaborator

guardrex commented Oct 1, 2019

Is it the slight delay is causing that throw? dotnet/extensions#1842 (comment)

Rubber 🦆 says that it doesn't seem so.

@huan086
Copy link
Author

huan086 commented Oct 2, 2019

Why not revert the code to the Core 2.1 version? The revised code above still has Task.WhenAny(_backgroundTask and Task.Run, which I think requires some explanation why they are needed instead of doing it the way in Core 2.1 sample.

The only useful addition I see is _logger.LogInformation("Queued Hosted Service is stopping.");. I'm not sure if the Core 2.1 sample can be extended just by adding this

    public override async Task StopAsync(CancellationToken stoppingToken)
    {
        _logger.LogInformation("Queued Hosted Service is stopping.");
        await base.StopAsync(stoppingToken);
    }

So the final code becomes

using System;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;

namespace BackgroundTasksSample.Services
{
    public class QueuedHostedService : BackgroundService
    {
        private readonly ILogger _logger;

        public QueuedHostedService(IBackgroundTaskQueue taskQueue, 
            ILoggerFactory loggerFactory)
        {
            TaskQueue = taskQueue;
            _logger = loggerFactory.CreateLogger<QueuedHostedService>();
        }

        public IBackgroundTaskQueue TaskQueue { get; }

        protected async override Task ExecuteAsync(
            CancellationToken cancellationToken)
        {
            _logger.LogInformation("Queued Hosted Service is starting.");

            while (!cancellationToken.IsCancellationRequested)
            {
                var workItem = await TaskQueue.DequeueAsync(cancellationToken);

                try
                {
                    await workItem(cancellationToken);
                }
                catch (Exception ex)
                {
                    _logger.LogError(ex, 
                       "Error occurred executing {WorkItem}.", nameof(workItem));
                }
            }

            _logger.LogInformation("Queued Hosted Service is stopping.");
        }

        public override async Task StopAsync(CancellationToken stoppingToken)
        {
            _logger.LogInformation("Queued Hosted Service is stopping.");
            await base.StopAsync(stoppingToken);
        }
    }
}

@huan086
Copy link
Author

huan086 commented Oct 2, 2019

With reference to the revised code, for trapping, let's avoid catching all exceptions. Wouldn't be good for documentation to spread bad practices CA1031

try
            {
                await Task.Delay(TimeSpan.FromSeconds(5), token);
            }
            catch (Exception) {}

Instead, just catching OperationCanceledException should be sufficient.

@guardrex
Copy link
Collaborator

guardrex commented Oct 2, 2019

IIRC, we're awaiting the queued tasks to finish. I yield to @anurse on these aspects.

avoid catching all exceptions

Sure ... I agree. I'll change my remark to show that. ☝️

@guardrex
Copy link
Collaborator

guardrex commented Oct 2, 2019

btw ... wrt "spread bad practices" ... engineering does catch all exceptions from time-to-time. They don't consider it to be a bad practice in all cases. In this case tho, I think it makes sense. I think we just want to avoid an ugly log entry ... but again ... I yield to Nurse. Unlike me, he actually knows how to write high quality code. Me ... I just get the commas in the right spots. 😄 lol

@analogrelay
Copy link
Contributor

Furthermore, there is no explanation why StopAsync override does not call base.StopAsync(stoppingToken). Such a call is explicitly stated StopAsync(CancellationToken cancellationToken) – If this method is overridden, you must call (and await) the base class method to ensure the service shuts down properly.

This was a recent addition to the docs and it was missed in the review of this sample. We should definitely add it.

With reference to the revised code, for trapping, let's avoid catching all exceptions.

Catching all exceptions may make some sense. There's no guarantee that the platform is catching exceptions ExecuteAsync throws so it's better to handle things ourselves. Plus, since this is processing items in a queue, a failure in a single queue work item shouldn't necessarily be fatal to the entire service.

I'll be perfectly honest. I'm of two minds about this sample. On the one hand, it's nice to provide a detailed and useful sample of a real-world scenario. On the other hand, there are a lot of application-specific decisions that need to be made to build a proper queue processor. Should a failure in a single work item cause the entire queue to be abandoned? Should only certain failures cause the queue to be abandoned? How should cancellation be handled? Should it stop allowing new items and drain the existing queue or should it stop processing new items? etc. etc.

@guardrex
Copy link
Collaborator

guardrex commented Oct 2, 2019

Catching all exceptions may make some sense. There's no guarantee that the platform is catching exceptions ExecuteAsync throws so it's better to handle things ourselves.

In this case, it was only a trap for a fake delay (Task.Delay) ... a simulation of a long-running task. I just didn't like that nasty looking log entry that appears without catching there.

@anurse I'll put up the changes thus far on a PR for you to review this afternoon. I'll keep the current don't abandon the queue approach because I like the idea of showing something that you reminded me of when we did the 3.0 update: It's turtles 🐢 all the way down! (i.e., It's async and tokens all the way down).

btw (and this may answer some of your, @huan086, asks on 'why is it like this?') ... it all started back here 👉 #3352 ... so you can see there the discussion and genesis of the topic+sample. The PR with additional discussion is here 👉 #6484.

One other thing tho @anurse ... any idea what's causing it to throw this? (with the code I show above) ...

Unhandled exception. System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.Extensions.Hosting.Internal.Host.StopAsync(CancellationToken cancellationToken)
   at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.WaitForShutdownAsync(IHost host, CancellationToken token)
   at BackgroundTasksSample.Program.Main(String[] args) in C:\Users\guard\Desktop\BackgroundTasksSample\Program.cs:line 40
   at BackgroundTasksSample.Program.<Main>(String[] args)

... I don't want to change it to something that 💥. lol

[EDIT] If you want me to put the whole revised sample up in a repo so that you can pull it down and fix it for me, let me know ... I'll do that when I put the PR up, and we can take it from there.

@guardrex
Copy link
Collaborator

guardrex commented Oct 2, 2019

Let's pick up further discussion on the PR ... #14765

@huan086
Copy link
Author

huan086 commented Oct 2, 2019

Let's trace the history

PR #6484, code was first written with IHostedService, because BackgroundService didn't exists back then.

dotnet/extensions@712c992 introduced BackgroundService, by extracting the _shutdown (renamed _stoppingCts) and _backgroundTask (renamed _executingTask) from QueuedHostedService into an abstract class.

PR #7640 changed QueuedHostedService sample to use BackgroundService, which simplifed the sample a lot. This is what I referred to as the Core 2.1 sample.

PR #14417 added documentation for Core 3.0, with QueuedHostedService code that looks like it's taken from way back in history of #6484, but changed to inherit from BackgroundService, and then loop added around BackgroundProcessing. And this PR did not justify why the code sample changed. This is what I referred to as the Core 3.0 sample.

I am thus very confused as to why QueuedHostedService Core 3.0 sample is doing the things (_stoppingCts, _backgroundTask, Task.WhenAny) that BackgroundService is already doing.

@guardrex
Copy link
Collaborator

guardrex commented Oct 2, 2019

@huan086 ... Move that whole remark over to the PR. We'll fix it up over there.

October 2019 automation moved this from In progress to Done Oct 14, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
doc-enhancement Pri1 High priority, do before Pri2 and Pri3 Source - Docs.ms Docs Customer feedback via GitHub Issue
Projects
No open projects
October 2019
  
Done
Development

Successfully merging a pull request may close this issue.

5 participants