Background jobs not processing. #10627

5 Answer(s)

• 

  0

  maliming created 4 months ago

  Support Team Fullstack Developer

  Hi,

  Sorry to hear about the trouble. To narrow this down on 8.3.0 we'll need a bit more info from your side:

  1. Which background job provider are you using? The default Volo.Abp.BackgroundJobs store, Hangfire, Quartz, or RabbitMQ?
  2. Deployment topology — single instance or multi-instance? Hosted in IIS / Docker / Kubernetes / Azure App Service / etc.? Any recent infra changes around April 22 (database failover, Redis restart, scaling, network changes)?
  3. BackgroundJobOptions configuration — anything you've customized (e.g. IsJobExecutionEnabled, custom JobExecutionTimeout, DefaultTimeout)?
  4. State of the AbpBackgroundJobs table — a snapshot of a few stuck rows showing IsAbandoned, NextTryTime, TryCount, LastTryTime would help a lot.
  5. Application logs around April 22 — especially anything at Error / Warning level from Volo.Abp.BackgroundJobs.* or Volo.Abp.DistributedLocking.*.
  6. Debug logs — please enable Debug level logging for the background job namespaces and capture a few minutes of output while jobs are sitting in the queue. Steps here: https://abp.io/support/questions/8622/How-to-enable-Debug-logs-for-troubleshoot-problemse

  A few common causes we've seen for this exact symptom:

  • The worker host process is up but the background job worker isn't actually running (e.g. IsJobExecutionEnabled = false got set, or only the API host is running and the job host isn't).
  • A distributed lock (IAbpDistributedLock) is stuck — leftover lock row in DB / Redis that never expires, blocking the periodic queue poller.
  • Long-running DB transaction / blocking on the AbpBackgroundJobs table preventing the poller from reading the queue.
  • Job records all marked IsAbandoned = true after exceeding MaxTryCount (default 3), which is why "previously failing" jobs stopped retrying.

  If you can share the logs and a sample of the AbpBackgroundJobs rows, we can dig in from there.

  Thanks

  Markdown supported.

  Copy, paste, or drag & drop images and files (max 100 MB per file, 100 MB total per post)

  Save Cancel
• 

  0

  stevefisher created 4 months ago

  Hi,

  Sorry for the somewhat delayed response. The issue has resolved itself now, but it would be good to try and get an idea of what happened and how we can look to prevent the issue in the future. The only things I did during the day on the 28th was to set the IsAbandoned flag on the last jobs that had been retrying before it stopped working and restarted the application. On restart I noticed high CPU usage of the app, but nothing changed. It then seems to have jumped back into life during the early hours on 29th.

  In response to your questions:

  1. We are using Volo.Abp.BackgroundJobs
  2. Single instance in Azure App Service - we had a change deployed on the 15/16th but everything had been functioning after that.
  3. No IsJobExecutionEnabled, custom JobExecutionTimeout, DefaultTimeout haven't been customised
  4. I’ve included a sample of some of the jobs that were hung prior to me changing the IsAbandoned flag in the linked investigation files (the flag is set in the results I’m sending)
  5. Application logs from the point we saw the last mention of Volo.Abp.BackgroundJobs are included in the linked investigation files - after that there is nothing and if I look at the log for 23rd there is nothing at all despite there still being non abandoned jobs in the queue.
  6. I’m not sure this one is going to help us now the jobs are processing again. A lock sounds plausible though. We don’t use Redis so everything would be in the SQL database. Is there any locking the application does itself or would it just be a case of SQL locks?

  Investigation Files: https://1drv.ms/u/c/f973c8721a5019ff/IQA66z9bj6KkTL0VtwF_LD1yAYMFJUIF6V4roYH347pEPc4?e=NVo0RM Password: DELETED

  Hopefully this answers everything but please let me know if I can provide anything else.

  Thanks.

  Markdown supported.

  Copy, paste, or drag & drop images and files (max 100 MB per file, 100 MB total per post)

  Save Cancel
• 

  0

  maliming created 4 months ago

  Support Team Fullstack Developer

  Hi,

  Thanks for the logs and CSV — they made the picture pretty clear. Here's what happened:

  The default BackgroundJobWorker in ABP processes jobs sequentially in a single foreach, and the whole polling cycle is wrapped in a distributed lock (AbpBackgroundJobWorker). When you don't use Redis, that lock lives in process memory (LocalAbpDistributedLock). The implication: if any single job gets stuck on an await (e.g. an HTTP call that never returns), the worker thread holds the lock forever, every subsequent 5-second polling cycle silently fails to acquire it, and no further jobs are processed and no log lines are produced — exactly what you saw after 12:19:14 on April 22.

  In your case, VacancyDataSendingJob / ApplicantDataSendingJob call EzekiaCRM. The default HttpClient.Timeout is 100 seconds, but it only applies to the response headers — once a response starts trickling back slowly (or a TCP socket gets half-open), the call can hang indefinitely. Most likely Ezekia had a hiccup that day, one of those calls never returned, the worker thread parked there, and the lock stayed held. Restarting the app on the 28th cleared the in-memory lock, but the same jobs immediately ran into the same external behavior, which is why CPU went up but the queue still didn't drain. By early on the 29th the upstream connection finally died and the worker resumed.

  The other IdentitySessionCleanupBackgroundWorker / TokenCleanupBackgroundWorker entries you can see throughout the log confirm the worker host itself was alive — only the background job worker was wedged.

  Fix — give the EzekiaCRM HttpClient an explicit timeout

  This is the smallest change that actually prevents the deadlock. Wherever you register the Ezekia client, set a hard Timeout:

  context.Services.AddHttpClient<EzekiaCRM.Client>(client =>
  {
      client.BaseAddress = new Uri("https://api.ezekiacrm.com/");
      client.Timeout = TimeSpan.FromSeconds(30);
  });
  

  Pick a value that's comfortably above your normal Ezekia response time but well under "forever" (30–60s is usually fine). Once that's in place, the worst case is the job throws TaskCanceledException, the executor catches it as a normal failure, increments TryCount, and moves on — the worker is never wedged again.

  If you also want belt-and-braces, you can wrap the call in a CancellationTokenSource inside the job itself, but the HttpClient.Timeout alone is enough to prevent the symptom you ran into.

  We'll also look into adding a per-job timeout in the default worker on our side so this kind of upstream hang can't silently freeze the whole queue.

  Thanks

  Markdown supported.

  Copy, paste, or drag & drop images and files (max 100 MB per file, 100 MB total per post)

  Save Cancel
• 

  0

  stevefisher created 4 months ago

  Thanks for this. I've fed this back to the team and it appears we already have a 25 second timeout configured.

   context.Services.AddHttpClient<EzekiaCRM.IClient, EzekiaCRM.Client>(client =>
          {
              var apiKey = configuration.GetValue<string>("EzekiaConfiguration:ApiKey");
              var apiUrl = configuration.GetSection("EzekiaConfiguration:BaseApiUrl").Value;
   
              client.BaseAddress = new Uri(apiUrl);
              client.DefaultRequestHeaders.Authorization = new System.Net.Http.Headers.AuthenticationHeaderValue("Bearer", apiKey);
              client.Timeout = TimeSpan.FromSeconds(CompanyConsts.ExternalRequestTimeoutInSec);
          }
  

  We don't have the call wrapped in CancellationTokenSource inside the job itself so we could add that but thought it was worth mentioning in case you had any other ideas or that changed anything.

  Markdown supported.

  Copy, paste, or drag & drop images and files (max 100 MB per file, 100 MB total per post)

  Save Cancel
• 

  0

  maliming created 4 months ago

  Support Team Fullstack Developer

  Hi,

  Thanks for confirming — that's actually really useful information, because it tells us the wedge wasn't the EzekiaCRM HTTP call itself. Looking again at the log around the same window, there's a lot more going on that day:

  • 14:13 — Azure Blob Storage RetriableStream.ReadAsync cancelled (a profile-picture call)
  • 14:57 — IdentityUserManager.GetByIdAsync cancelled
  • 19:13 — EF Core SaveChanges cancelled mid-ConsumeResultSetAsync
  • 12:57 → 17:35 — repeated String or binary data would be truncated ... AbpSessions.IpAddresses errors

  So Azure SQL and Azure Blob were both flaky for a long stretch on the 22nd. Since HttpClient.Timeout only protects the EzekiaCRM call, any other await inside the job (EF Core SaveChangesAsync, a blob read, a SQL connection open, even a downstream IdentityUserManager lookup) has no per-job timeout — BackgroundJobWorker only passes the application's StoppingToken, which never fires. That's almost certainly what kept the worker pinned: one of the other awaits in SendVacancyDataAsync / ApplicantDataSendingJob got stuck on Azure SQL or Blob, not on Ezekia.

  What I'd add now

  You can do all of this on your side — no ABP changes needed.

  1) Wrap the job body in a CancellationTokenSource. Yes, please add it — this is the only catch-all that bounds everything inside the job, not just the HTTP call. ABP's IAsyncBackgroundJob<TArgs>.ExecuteAsync doesn't take a CancellationToken parameter, so you create one yourself:

  public class VacancyDataSendingJob : AsyncBackgroundJob<VacancySendingArgs>, ITransientDependency
  {
      private readonly ExternalCompanyService _service;
  
      public override async Task ExecuteAsync(VacancySendingArgs args)
      {
          using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(2));
          await _service.SendVacancyDataAsync(args.vacancyId, cts.Token);
      }
  }
  

  Make sure SendVacancyDataAsync actually flows the token down to the EzekiaCRM call and to any SaveChangesAsync / blob read it does. Whatever you pick (we usually suggest 1–2 min) just needs to be longer than a healthy job and shorter than "forever."

  2) Set an EF Core CommandTimeout. This protects you against Azure SQL hangs specifically. In your DbContextOptions configuration:

  options.UseSqlServer(connectionString, sql =>
  {
      sql.CommandTimeout(60);
  });
  

  3) Separately, you'll want to fix the AbpSessions.IpAddresses truncation. It's unrelated to the jobs but it was throwing all afternoon on the 22nd and is masking other things in your logs. The column is nvarchar(64) by default and your Cloudflare-fronted requests pile up multiple X-Forwarded-For IPs that exceed it. Either widen the column with a custom EF migration, or override the session-recording behaviour to keep only the leftmost client IP.

  With (1) in place you'll never see this exact lockup again — even if Azure SQL or Blob has a bad day, the worst case is the job throws after 2 minutes, gets retried later, and the worker keeps moving.

  On our side, we'll look at adding a built-in DefaultJobTimeout option to AbpBackgroundJobOptions so future versions wrap each job in a timeout automatically — but you don't need to wait for that, the snippet above is enough.

  Thanks

  Markdown supported.

  Copy, paste, or drag & drop images and files (max 100 MB per file, 100 MB total per post)

  Save Cancel