【发布时间】:2020-07-29 23:26:10
【问题描述】:
我继承了一个使用 Hangfire 和 sql server 作业存储的系统。通常,当一个作业计划立即运行时,我们会注意到它需要几秒钟才能被触发。
在我的开发环境中运行时查看 SQL Profiler,针对 Hangfire db 运行的 SQL 看起来像这样 -
exec sp_executesql N'delete top (1) JQ
output DELETED.Id, DELETED.JobId, DELETED.Queue
from [HangFire].JobQueue JQ with (readpast, updlock, rowlock, forceseek)
where Queue in (@queues1) and (FetchedAt is null or FetchedAt < DATEADD(second, @timeout, GETUTCDATE()))',N'@queues1 nvarchar(4000),@timeout float',@queues1=N'MYQUEUENAME_master',@timeout=-1800
-- Exactly the same SQL as above is executed about 6 times/second for about 3-4 seconds,
-- then nothing for about 2 seconds, then:
exec sp_getapplock @Resource=N'HangFire:recurring-jobs:lock',@DbPrincipal=N'public',@LockMode=N'Exclusive',@LockOwner=N'Session',@LockTimeout=5000
exec sp_getapplock @Resource=N'HangFire:locks:schedulepoller',@DbPrincipal=N'public',@LockMode=N'Exclusive',@LockOwner=N'Session',@LockTimeout=5000
exec sp_executesql N'select top (@count) Value from [HangFire].[Set] with (readcommittedlock, forceseek) where [Key] = @key and Score between @from and @to order by Score',N'@count int,@key nvarchar(4000),@from float,@to float',@count=1000,@key=N'recurring-jobs',@from=0,@to=1596053348
exec sp_executesql N'select top (@count) Value from [HangFire].[Set] with (readcommittedlock, forceseek) where [Key] = @key and Score between @from and @to order by Score',N'@count int,@key nvarchar(4000),@from float,@to float',@count=1000,@key=N'schedule',@from=0,@to=1596053348
exec sp_releaseapplock @Resource=N'HangFire:recurring-jobs:lock',@LockOwner=N'Session'
exec sp_releaseapplock @Resource=N'HangFire:locks:schedulepoller',@LockOwner=N'Session'
-- Then nothing is executed for about 8-10 seconds, then:
exec sp_executesql N'update [HangFire].Server set LastHeartbeat = @now where Id = @id',N'@now datetime,@id nvarchar(4000)',@now='2020-07-29 20:09:19.097',@id=N'ps12345:19764:fe362d1a-5ee4-4d97-b70d-134fdfab2b87'
-- Then about 500ms-2s later I get
exec sp_executesql N'delete top (1) JQ ... -- i.e. Same as first query
The update LastHeartbeat query is only there every second time (from just a brief inspection, maybe that’s not exactly right).
看起来至少有 3 个线程在对 JQ 运行 DELETE 查询,因为我可以看到几个 RPC:Starting 在 RPC:Completed 之前,这表明它们是并行执行的,而不是顺序执行的。 我不知道这是否正常,但看起来很奇怪,因为我认为我们只有一个“消费者”的工作。
我的开发环境中只有一个队列,虽然我猜在现场我们会有 20-50 个。
关于我应该在哪里寻找导致的配置的任何建议: a) 检查作业之间的 8-10 秒停顿 b)正在检查作业的线程数 - 似乎我有太多
写完后,我意识到我们使用的是旧版本,所以我从 1.5.x 升级到 1.7.12,升级了数据库,并将启动配置更改为:
app.UseHangfireDashboard();
GlobalConfiguration.Configuration
.UseSqlServerStorage(connstring, new SqlServerStorageOptions
{
CommandBatchMaxTimeout = TimeSpan.FromMinutes(5),
QueuePollInterval = TimeSpan.Zero,
SlidingInvisibilityTimeout = TimeSpan.FromMinutes(5),
UseRecommendedIsolationLevel = true,
PrepareSchemaIfNecessary = true, // Default value: true
EnableHeavyMigrations = true // Default value: false
})
.UseAutofacActivator(_container);
JobActivator.Current = new AutofacJobActivator(_container);
但如果有的话,问题现在更糟了。或者相同但更快:现在大约 1 秒内发生了对 delete top (1) JQ... 的 20 次调用,然后是其他查询,然后等待 15 秒,然后重新开始。
需要明确的是,主要问题是,如果在 15 秒延迟期间添加了任何作业,那么在执行我的作业之前将需要 15 秒的剩余时间。我认为第二个问题是它对 SQL Server 的影响超出了需要:至少对我的需要而言,每秒 20 次有点多。
(交叉发布到hangfire forums)
【问题讨论】:
-
根据来源中的这一行,将 QueuePollInterval 设置为 0 会使系统切换到长轮询。我建议选择一个严格高于 1s 的值,比如 2s,来更改等待策略,看看它是否有所作为(除了删除转换为更新)github.com/HangfireIO/Hangfire/blob/…
-
谢谢,我试试。仍然没有解释为什么它会经常等待 10 秒,显然无论它使用什么策略都是不好的。但也许战略的改变将意味着它无论如何都会停止这样做。