Problem with Delayed Job - I am in big trouble

Hello,

It feels that we have a bug with delayed job.

I am adding a job to be executed after 15 mins. I expect this job to be enqueued after 15 minutes so that some worker process can take care of it. I understand that it is hard to say that when an enqueued job will be processed but as per documentation the delayed jobs are enqueued after the defined delay time, which is simply not happening in my case. I am adding a delayed job to be executed after 15 mins but It is showing that job will be enqueued after 12 hours :frowning:

Below is related data from the table HangFire.State.

CreatedAt : 2014-12-03 10:49:59.770
Data : {“EnqueueAt”:“2014-12-03T22:54:58.6514824Z”,“ScheduledAt”:“2014-12-03T10:49:59.3257412Z”}

Problems:

1. CreatedAt time is not the correct one, I added the job at 2014-12-03 11:49:59.770 which means the database is showing one hour less.

2. Enqueued and Scheduled times are showing values after the 12 hours.

I am not sure why it is happening, but i suspect that since the createdat time is less than the DateTime.Now on the machine HangFire thinks that the execution time has passed so it just reschedules the job to be executed in 12 hours.

It seems that the HangFire is not taking care of the local machine time, instead it is using time from somewhere else!! I hope I am clear enough to explain the problem, I have created some discussion earlier as well but no one replied, perhaps I had not added the enough description. I hope to get some suggestion this time, please ask me if you dont understand my problem completely. I am adding the image which shows the job schedule in the UI

Can any one help me??

Thanks.

Can you post here the line of code where you create a delayed background job like the following:

BackgroundJob.Schedule(() => Method, TimeSpan.FromMinutes(XXX));
1 Like
Dim ExecuteOn As DateTime = DateTime.Now.AddMinutes(MinGapForThisJob)
JobId = Hangfire.BackgroundJob.Schedule(Sub() EmailUtilityNew.SendNewsletter(newsletterID), ExecuteOn.TimeOfDay)

Just change it with the following:

Dim ExecuteOn As TimeSpan = TimeSpan.FromMinutes(MinGapForThisJob)
JobId = Hangfire.BackgroundJob.Schedule(Sub() EmailUtilityNew.SendNewsletter(newsletterID), ExecuteOn)
1 Like

It is working boss. I am so sorry I made such an idiotic mistake. I want to remove the tag “Bug” form this post but dont know how!

Your code helped me a lot, I just used your code

Hangfire.BackgroundJob.Schedule(Sub() EmailUtilityNew.SendNewsletter(newsletterID), TimeSpan.FromMinutes(MinGapForThisJob))

and it worked perfectly.

Thank you so much.

There is a bug in Discouse – you can’t unset a category. Regarding to the Schedule method, it works with UTC, and I don’t wanted to introduce the overload with DateTime parameter, because it is very simple to pass DateTime.Now (instead of DateTime.UtcNow) here and get wrong results.

However, I’ve discovered that the TimeSpan class is not very popular and sometimes confuses people, so it worth to introduce the DateTimeOffset class support that works fine with both DateTimeOffset.Now and DateTimeOffset.UtcNowhttps://github.com/HangfireIO/Hangfire/issues/237

Humm, seems logical to me.

I have more problem, after the above fixes there comes a new situation, Job was added to be executed at 1:16 PM and that time has passed a long ago it is now almost 2 hours but the job is still appearing in the scheduled list. Any idea why it has not be processed??

Is BackgroundJobServer instance is active (please see the Servers page)? Maybe it is failing to execute, what shows the job details page?

Hm. Do you have any logs? Looks like SchedulePoller class have some issues.

I have no idea about logs, where can I get them?

Currently here – http://docs.hangfire.io/en/latest/deployment-to-production/adding-logging.html

It is very confusing, which versions to use to configure the logger as per the above help article. I am using the Hangfire (.net4) which uses the Common.Logging (2.2.0) which Nlog and Nlog adapters should i use?

We are using the Log4Net and it would be nice if I know which version of Log4Net are compatible. Log4Net adapters are using the Common.Logging > = 2.3 and getting compile error…

Answered you in another thread:

Can you downgrade the Common.Logging to 2.2.0 at least temporary to see the logs?

Hi
I am using Hangfire 1.3.4, and cant get schedule working. What mistake could you spot? tq

Remark: WriteX is a static method.

var jobid = BackgroundJob.Schedule(() => WriteX(“GGG”,
DerivedHangfireToken.Null), TimeSpan.FromSeconds(6));

{“EnqueueAt”:“2015-02-25T04:14:05.1189185Z”,“ScheduledAt”:“2015-02-25T04:13:59.1189185Z”}

Do you have any logs? What displays the dashboard?

2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker Manager’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker Manager’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Server Heartbeat’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Server Heartbeat’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Schedule Poller’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Schedule Poller’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Server Watchdog’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Server Watchdog’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Recurring Job Scheduler’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Recurring Job Scheduler’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘SQL Records Expiration Manager’…
.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘SQL Records Expiration Manager’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker Manager’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Server Heartbeat’…
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker Manager’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Schedule Poller’…
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Server Heartbeat’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Server Watchdog’…
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Schedule Poller’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Recurring Job Scheduler’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #1’…
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Server Watchdog’ started.
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Recurring Job Scheduler’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘SQL Records Expiration Manager’…
.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #1’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #2’…
2015-02-25 08:50:26 [INFO] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘SQL Records Expiration Manager’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #2’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #3’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.SqlServer.ExpirationManager) Removing outd
ated records from table ‘Counter’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #3’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #4’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #4’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #5’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #6’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #5’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #6’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #7’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #7’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #8’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #8’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #9’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #9’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #10’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #10’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #11’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #11’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #12’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #12’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #13’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #14’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #13’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #15’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #14’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #16’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #15’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #16’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #17’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #17’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #18’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #19’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #18’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #19’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting a new thread for server component ‘Worker #20’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Starting server component ‘Worker #20’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #1’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #2’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #1’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #3’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #2’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #4’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #3’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #5’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #4’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #6’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #5’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #7’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #6’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #8’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #7’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #8’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #9’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #10’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #9’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #11’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #10’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #12’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #11’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #13’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #12’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #14’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #13’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #15’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #16’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #17’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #18’…
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #19’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #16’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #17’ started.
2015-02-25 08:50:26 [INFO] (Hangfire.Server.ServerWatchdog) 1 servers were remo
ved due to timeout
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #19’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.SqlServer.ExpirationManager) Removing outd
ated records from table ‘Job’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #18’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #14’ started.
2015-02-25 08:50:26 [TRACE] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Sending start request for server component ‘Worker #20’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #15’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.Server.AutomaticRetryServerComponentWrappe
r) Server component ‘Worker #20’ started.
2015-02-25 08:50:26 [DEBUG] (Hangfire.SqlServer.ExpirationManager) Removing outd
ated records from table ‘List’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.SqlServer.ExpirationManager) Removing outd
ated records from table ‘Set’…
2015-02-25 08:50:26 [DEBUG] (Hangfire.SqlServer.ExpirationManager) Removing outd
ated records from table ‘Hash’…