HangfireIO / Hangfire.InMemory

In-memory job storage for Hangfire with an efficient implementation
Other
74 stars 17 forks source link

Possible regression in 0.5.0 - recurring job keeps getting updated #10

Closed cearny closed 1 year ago

cearny commented 1 year ago

Hi, after updating to version 0.5.0, it seems that after running a recurring job the first time and about when hitting the second execution scheduled time, somehow it always is marked as being "updated", and so I am getting this log output (set to Trace):

Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       1 recurring job(s) processed by scheduler.
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mtrce#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       Recurring job 'AccessKeyRefresher' is being updated. RecurringJob: (Queue:default;Cron:* * * * *;TimeZoneId:UTC;Job:{"t":"RazorPagesWebApp.Web.Jobs.RefreshAnafAccessKeyJob, RazorPagesWebApp.Web","m":"Execute","p":["System.Threading.CancellationToken, mscorlib"],"a":[null]};CreatedAt:1687959765734;NextExecution:1687959900000;V:2;LastExecution:1687959841369;LastJobId:1b66945a-4fc0-4ca4-9164-a21e4ed60ccf), Changes: (), NextExecution: (06/28/2023 13:45:00)
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mdbug#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       1 recurring job(s) processed by scheduler.
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mtrce#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       Recurring job 'AccessKeyRefresher' is being updated. RecurringJob: (Queue:default;Cron:* * * * *;TimeZoneId:UTC;Job:{"t":"RazorPagesWebApp.Web.Jobs.RefreshAnafAccessKeyJob, RazorPagesWebApp.Web","m":"Execute","p":["System.Threading.CancellationToken, mscorlib"],"a":[null]};CreatedAt:1687959765734;NextExecution:1687959900000;V:2;LastExecution:1687959841369;LastJobId:1b66945a-4fc0-4ca4-9164-a21e4ed60ccf), Changes: (), NextExecution: (06/28/2023 13:45:00)
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mdbug#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       1 recurring job(s) processed by scheduler.
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mtrce#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       Recurring job 'AccessKeyRefresher' is being updated. RecurringJob: (Queue:default;Cron:* * * * *;TimeZoneId:UTC;Job:{"t":"RazorPagesWebApp.Web.Jobs.RefreshAnafAccessKeyJob, RazorPagesWebApp.Web","m":"Execute","p":["System.Threading.CancellationToken, mscorlib"],"a":[null]};CreatedAt:1687959765734;NextExecution:1687959900000;V:2;LastExecution:1687959841369;LastJobId:1b66945a-4fc0-4ca4-9164-a21e4ed60ccf), Changes: (), NextExecution: (06/28/2023 13:45:00)
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mdbug#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       1 recurring job(s) processed by scheduler.
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]: #033[40m#033[37mtrce#033[39m#033[22m#033[49m: Hangfire.Server.RecurringJobScheduler[0]
Jun 28 16:44:02 anaf-callback xconta-anaf-oauth2[1687]:       Recurring job 'AccessKeyRefresher' is being updated. RecurringJob: (Queue:default;Cron:* * * * *;TimeZoneId:UTC;Job:{"t":"RazorPagesWebApp.Web.Jobs.RefreshAnafAccessKeyJob, RazorPagesWebApp.Web","m":"Execute","p":["System.Threading.CancellationToken, mscorlib"],"a":[null]};CreatedAt:1687959765734;NextExecution:1687959900000;V:2;LastExecution:1687959841369;LastJobId:1b66945a-4fc0-4ca4-9164-a21e4ed60ccf), Changes: (), NextExecution: (06/28/2023 13:45:00)

The CPU spikes a lot and it seems the app ends up in an infinite loop. Downgrading to 0.4.1 fixes this.

This is the job definition (ASP.NET Core app):

using (var scope = app.Services.CreateScope())
{
    var services = scope.ServiceProvider;

    var recurringJob = services.GetRequiredService<IRecurringJobManager>();
    recurringJob.AddOrUpdate<RefreshAccessKeyJob>("AccessKeyRefresher", x => x.Execute(CancellationToken.None), Cron.Minutely);
}

I have checked and the job does not throw; as I mentioned, downgrading fixes this.

Let me know if you need more details.

odinserj commented 1 year ago

Thanks for reporting this, @cearny! I've just released the fix, please see https://github.com/HangfireIO/Hangfire.InMemory/releases/tag/v0.5.1. There was a problem with struct implementation that caused values in sets to be not updatable.

cearny commented 1 year ago

Actually, thank you! And this fix was also educative for me as I haven't gotten around to using readonly structs yet 😁

I'll give the new package version a try later today, but from just looking at the diff, I think that solves the issue.

odinserj commented 1 year ago

Yeah, immutable structs are like a mantra, and always should be used together 🥸.

No need to test it today – you did your job, I did my job, so let's celebrate 🍾🥳.