cron-style jobs ActiveRecord::RecordNotUnique log level

[dup2]

Hi all

We use about 30 cron-style scheduled jobs and have multiple processes running, each in a separate docker container.

We now face the issue that we get a considerable amount of exceptions logged with level ERROR due to the locking feature for the enqueueing of the cron-style jobs, which is a good feature per se as it ensures only one job is enqueued at the specific time but on the other hand we get complaints from the monitoring that we have logs with severity ERROR all the time.

The errors are

lvl=ERROR
 event_name=enqueue_at.active_job
 adapter=GoodJob
 queue=default
 job_class=__our_job_class__
 job_id=__uuid__
 provider_job_id= 
 arguments=[]
 name=Rails
 msg="Failed enqueuing Reporting::SendQuotaReportJob (Job ID: __uuid__) to GoodJob(default)
(ActiveRecord::RecordNotUnique (PG::UniqueViolation: 
 ERROR:  duplicate key value violates unique constraint \"index_good_jobs_on_cron_key_and_cron_at_cond\"

Is there any way to treat these errors separately? Or is this not even within GoodJob?

Cheers,
-dup2

[bensheldon]

Forever I've thought that this was something unfortunate to live with... but looking at the error message you shared, it seems to me like the cause is bubbling an exception up though the AS Instrumentation for enqueue_at.active_job. If that truly has been the problem all along, I think I can fix that real quick 🤞🏻

[bensheldon]

Trying to do this, I'm now remembering the problem: There's no clean way to log "The adapter did not enqueue this, but it's ok/expected/don't worry about it."

Maybe there's a messier workaround...

[bensheldon]

🤞🏻 #1615

[dup2]

Great, thanks for the very fast reply!!

[bensheldon]

Released if you want to give it a try: https://github.com/bensheldon/good_job/releases/tag/v4.9.2

[dup2]

Thanks!

I do not get the ERROR log anymore, which is great. ActiveJob now logs an event about the callback:

lvl=INFO
event_name=enqueue_at.active_job
adapter=GoodJob
queue=default
job_class=__jobclass__
job_id=__uuid__
provider_job_id=
arguments=[]
name=Rails
msg="Failed enqueuing __jobclass__ (Job ID: __uuid__) to GoodJob(default), a before_enqueue callback halted the enqueuing execution.

This is much better than before, great!

[bensheldon]

YAY! 🙌🏻 Thanks for raising this problem!