Job being executed twice using Rails, Active Job, Sidekiq, Clockwork, Heroku

119 Views Asked by At

Using the stack outlined, my jobs are running twice and I can't figure out why. Everything seems to work as planned when testing locally. I'm using a separate process to run bundle exec clockwork clock.rb

clock.rb

require 'clockwork'
require './config/boot'
require './config/environment'

module Clockwork

    configure do |config|
        # set timezone to central time
        config[:tz] = 'America/Chicago'
    end

    every(1.day, "SendInvoiceOverdueRemindersJob", at: '08:00') do
        SendInvoiceOverdueRemindersJob.perform_later
    end 

    every(1.day, "CreateWarehouseInvoicesForCustomersJob", at: '20:00', if: lambda { |t| t.day == 1 }) do
        CreateWarehouseInvoicesForCustomersJob.perform_later
    end

end

Example Job:

class SendInvoiceOverdueRemindersJob < ApplicationJob
  queue_as :default
  DAYS_OVERDUE_TRIGGER = 3

  def perform(*args)
        overdue_invoices = Invoice.overdue.where(overdue_reminder_sent: false)

        overdue_invoices.each do |inv|
            days_overdue = (Date.today() - inv.due_date.to_date).to_i

            if (days_overdue > DAYS_OVERDUE_TRIGGER)
                finance_contacts = inv.manufacturing_order.contacts.joins(:document_types).where("contacts.is_active": true, "document_types.code": :invoice)

                emails_string = finance_contacts.collect(&:email).join(",")

                if emails_string.present?
                    inv.overdue_reminder_sent = true;
                    if inv.save
                        InvoiceMailer.send_overdue_reminder(emails_string, inv.id).deliver_later
                    end
                else # send notification that contacts are missing from projects
                    InvoiceMailer.send_missing_contacts_notification(inv.id).deliver_later
                end
            end
        end
  end
end

I was previously using Heroku Scheduler, then removed the addon. Here is the result of heroku ps:

 ›   Warning: heroku update available from 7.60.1 to 8.1.3.
=== scheduler (Basic): bundle exec clockwork clock.rb (1)
scheduler.1: up 2023/05/25 11:00:36 -0500 (~ 2h ago)

=== sidekiqworker (Basic): bundle exec sidekiq -c 2 -q default -q mailers (1)
sidekiqworker.1: up 2023/05/25 11:00:44 -0500 (~ 2h ago)

=== web (Basic): bin/rails server -p $PORT -e $RAILS_ENV (1)
web.1: up 2023/05/25 11:00:47 -0500 (~ 2h ago)

Heroku Logs

May 30 06:00:01 app app/sidekiqworker.1 D, [2023-05-30T13:00:01.314428 #2] DEBUG -- : [ActiveJob] [SendInvoiceOverdueRemindersJob] [5478e192-3f00-4808-a6c6-9770feffc7a6]   TRANSACTION (2.7ms)  COMMIT
May 30 06:00:01 app app/sidekiqworker.1 I, [2023-05-30T13:00:01.327844 #2]  INFO -- : [ActiveJob] [SendInvoiceOverdueRemindersJob] [5478e192-3f00-4808-a6c6-9770feffc7a6] Enqueued ActionMailer::MailDeliveryJob (Job ID: 1d9e1441-fcec-465b-a942-94ef4e1fbaef) to Sidekiq(default) with arguments: "InvoiceMailer", "send_overdue_reminder", "deliver_now", {:args=>["[email protected],[email protected],[email protected]", 12204]}
May 30 06:00:01 app app/sidekiqworker.1 I, [2023-05-30T13:00:01.328481 #2]  INFO -- : [ActiveJob] [SendInvoiceOverdueRemindersJob] [5478e192-3f00-4808-a6c6-9770feffc7a6] Performed SendInvoiceOverdueRemindersJob (Job ID: 5478e192-3f00-4808-a6c6-9770feffc7a6) from Sidekiq(default) in 690.84ms
May 30 06:00:01 app app/sidekiqworker.1 2 TID-10kq SendInvoiceOverdueRemindersJob JID-880ee11a0fb55b07c7cbd300 INFO: done: 0.732 sec
May 30 06:00:01 app app/sidekiqworker.1 I, [2023-05-30T13:00:01.328268 #2]  INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef] Performing ActionMailer::MailDeliveryJob (Job ID: 1d9e1441-fcec-465b-a942-94ef4e1fbaef) from Sidekiq(default) enqueued at 2023-05-30T13:00:01Z with arguments: "InvoiceMailer", "send_overdue_reminder", "deliver_now", {:args=>["[email protected],[email protected],[email protected]", 12204]}
May 30 06:00:03 app app/sidekiqworker.1 D, [2023-05-30T13:00:03.385487 #2] DEBUG -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef]   Rendering invoice_mailer/send_overdue_reminder.html.erb within layouts/mailer
May 30 06:00:03 app app/sidekiqworker.1 I, [2023-05-30T13:00:03.386305 #2]  INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef]   Rendered invoice_mailer/send_overdue_reminder.html.erb within layouts/mailer (Duration: 0.8ms | Allocations: 81)
May 30 06:00:03 app app/sidekiqworker.1 D, [2023-05-30T13:00:03.388852 #2] DEBUG -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef]   Rendering invoice_mailer/send_overdue_reminder.text.erb within layouts/mailer
May 30 06:00:03 app app/sidekiqworker.1 I, [2023-05-30T13:00:03.389753 #2]  INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef]   Rendered invoice_mailer/send_overdue_reminder.text.erb within layouts/mailer (Duration: 0.9ms | Allocations: 78)
May 30 06:00:03 app app/sidekiqworker.1 D, [2023-05-30T13:00:03.394141 #2] DEBUG -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [1d9e1441-fcec-465b-a942-94ef4e1fbaef] InvoiceMailer#send_overdue_reminder: processed outbound mail in 2064.7ms
May 30 06:00:09 app app/sidekiqworker.1     We're just giving you a friendly reminder that the attached invoice is overdue. 

Logs - Action Mailer Exception

{
  "context": "Job raised exception",
  "job": {
    "class": "ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper",
    "wrapped": "ActionMailer::MailDeliveryJob",
    "queue": "default",
    "args": [
      {
        "job_class": "ActionMailer::MailDeliveryJob",
        "job_id": "d34397b9-0f74-4894-980c-dccc783b0f40",
        "provider_job_id": null,
        "queue_name": "default",
        "priority": null,
        "arguments": [
          "InvoiceMailer",
          "send_overdue_reminder",
          "deliver_now",
          {
            "args": [
              "[email protected]",
              12199
            ],
            "_aj_ruby2_keywords": [
              "args"
            ]
          }
        ],
        "executions": 0,
        "exception_executions": {},
        "locale": "en",
        "timezone": "Central Time (US & Canada)",
        "enqueued_at": "2023-05-29T13:00:00Z"
      }
    ],
    "retry": true,
    "jid": "05324bdf6fd2aedb9e65c480",
    "created_at": 1685365200.5488749,
    "enqueued_at": 1685365200.5489137
  },
  "jobstr": "{\"class\":\"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper\",\"wrapped\":\"ActionMailer::MailDeliveryJob\",\"queue\":\"default\",\"args\":[{\"job_class\":\"ActionMailer::MailDeliveryJob\",\"job_id\":\"d34397b9-0f74-4894-980c-dccc783b0f40\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[\"InvoiceMailer\",\"send_overdue_reminder\",\"deliver_now\",{\"args\":[\"[email protected]\",12199],\"_aj_ruby2_keywords\":[\"args\"]}],\"executions\":0,\"exception_executions\":{},\"locale\":\"en\",\"timezone\":\"Central Time (US & Canada)\",\"enqueued_at\":\"2023-05-29T13:00:00Z\"}],\"retry\":true,\"jid\":\"05324bdf6fd2aedb9e65c480\",\"created_at\":1685365200.5488749,\"enqueued_at\":1685365200.5489137}"
}

Why might the job be executing twice?

0

There are 0 best solutions below