1use std::{collections::HashMap, error::Error, future::Future, pin::Pin, time::Duration};
2
3use chrono::Utc;
4use chrono_tz::Tz;
5
6use crate::app_state::AppState as AS;
7#[cfg(feature = "jobs")]
8use crate::jobs::Job;
9#[cfg(feature = "jobs")]
10use crate::jobs::{
11 EnqueueError, enqueue_failure, enqueue_on_connection, enqueue_receipt, enqueue_span,
12};
13#[cfg(feature = "jobs")]
14use tracing::Instrument;
15
16pub struct CronRegistry<AppState: AS> {
17 pub(super) jobs: HashMap<&'static str, CronJob<AppState>>,
18}
19
20#[async_trait::async_trait]
21pub trait CronFn<AppState: AS> {
22 async fn run(&self, app_state: AppState, context: String) -> Result<(), String>;
26}
27
28pub struct CronFnClosure<
29 AppState: AS,
30 FnError: Error + Send + Sync + 'static,
31 F: Fn(AppState, String) -> Pin<Box<dyn Future<Output = Result<(), FnError>> + Send>>
32 + Send
33 + Sync
34 + 'static,
35> {
36 pub(super) func: F,
37 _marker: std::marker::PhantomData<AppState>,
38}
39
40#[async_trait::async_trait]
41impl<
42 AppState: AS,
43 FnError: Error + Send + Sync + 'static,
44 F: Fn(AppState, String) -> Pin<Box<dyn Future<Output = Result<(), FnError>> + Send>>
45 + Send
46 + Sync
47 + 'static,
48> CronFn<AppState> for CronFnClosure<AppState, FnError, F>
49{
50 async fn run(&self, app_state: AppState, context: String) -> Result<(), String> {
51 (self.func)(app_state, context)
52 .await
53 .map_err(|err| format!("{err:?}"))
54 }
55}
56
57#[derive(Clone, Debug)]
58pub struct IntervalSchedule(pub Duration);
59
60impl IntervalSchedule {
61 fn should_run(
62 &self,
63 last_run: Option<&chrono::DateTime<Utc>>,
64 now: chrono::DateTime<Utc>,
65 _worker_started_at: chrono::DateTime<Utc>,
66 _timezone: Tz,
67 ) -> bool {
68 if let Some(last_run) = last_run {
69 let elapsed = now - last_run;
70 if elapsed < chrono::Duration::zero() {
72 return false;
73 }
74 let elapsed = elapsed.to_std().unwrap_or(Duration::ZERO);
76 elapsed > self.0
77 } else {
78 true
79 }
80 }
81
82 pub fn next_run(
83 &self,
84 last_run: Option<&chrono::DateTime<Utc>>,
85 now: chrono::DateTime<Utc>,
86 timezone: Tz,
87 ) -> chrono::DateTime<Tz> {
88 let last_run = last_run.unwrap_or(&now);
89 let last_run_tz = last_run.with_timezone(&timezone);
90 let duration: chrono::Duration = chrono::Duration::from_std(self.0).unwrap();
91 let next_run = last_run_tz.checked_add_signed(duration).unwrap();
92 next_run.with_timezone(&timezone)
93 }
94}
95
96#[derive(Clone, Debug)]
97pub struct CronSchedule(pub Box<cron::Schedule>);
98
99impl CronSchedule {
100 fn should_run(
101 &self,
102 last_run: Option<&chrono::DateTime<Utc>>,
103 now: chrono::DateTime<Utc>,
104 worker_started_at: chrono::DateTime<Utc>,
105 timezone: Tz,
106 ) -> bool {
107 let last_run = last_run.unwrap_or(&worker_started_at);
109 let last_run_tz = last_run.with_timezone(&timezone);
110
111 if let Some(next_run) = self.0.after(&last_run_tz).next() {
112 let now_tz = now.with_timezone(&timezone);
113 now_tz >= next_run
114 } else {
115 false
116 }
117 }
118
119 pub fn next_run(
120 &self,
121 last_run: Option<&chrono::DateTime<Utc>>,
122 now: chrono::DateTime<Utc>,
123 timezone: Tz,
124 ) -> chrono::DateTime<Tz> {
125 let last_run = last_run.unwrap_or(&now);
126 let last_run_tz = last_run.with_timezone(&timezone);
127 self.0.after(&last_run_tz).next().unwrap()
128 }
129}
130
131#[derive(Clone, Debug)]
132pub enum Schedule {
133 Interval(IntervalSchedule),
134 Cron(CronSchedule),
135}
136
137impl Schedule {
138 pub fn should_run(
139 &self,
140 last_run: Option<&chrono::DateTime<Utc>>,
141 now: chrono::DateTime<Utc>,
142 worker_started_at: chrono::DateTime<Utc>,
143 timezone: Tz,
144 ) -> bool {
145 match self {
146 Schedule::Interval(interval) => {
147 interval.should_run(last_run, now, worker_started_at, timezone)
148 }
149 Schedule::Cron(cron) => cron.should_run(last_run, now, worker_started_at, timezone),
150 }
151 }
152
153 pub fn next_run(
154 &self,
155 last_run: Option<&chrono::DateTime<Utc>>,
156 now: chrono::DateTime<Utc>,
157 timezone: Tz,
158 ) -> chrono::DateTime<Tz> {
159 match self {
160 Schedule::Interval(interval) => interval.next_run(last_run, now, timezone),
161 Schedule::Cron(cron) => cron.next_run(last_run, now, timezone),
162 }
163 }
164}
165
166#[allow(clippy::type_complexity)]
167pub struct CronJob<AppState: AS> {
168 pub name: &'static str,
169 pub description: Option<&'static str>,
170 action: CronAction<AppState>,
171 pub schedule: Schedule,
172 #[cfg(all(test, feature = "jobs"))]
173 pause_after_claim: Option<std::sync::Arc<ClaimPause>>,
174 #[cfg(all(test, feature = "jobs"))]
175 pause_after_commit: Option<std::sync::Arc<CallbackPause>>,
176}
177
178#[cfg(all(test, feature = "jobs"))]
179struct ClaimPause {
180 claimed: tokio::sync::mpsc::Sender<i32>,
181 release: tokio::sync::Notify,
182}
183
184#[cfg(all(test, feature = "jobs"))]
185struct CallbackPause {
186 committed: tokio::sync::mpsc::Sender<chrono::DateTime<Utc>>,
187 release: tokio::sync::Notify,
188}
189
190enum CronAction<AppState: AS> {
191 Callback(Box<dyn CronFn<AppState> + Send + Sync + 'static>),
192 #[cfg(feature = "jobs")]
193 Job(Box<dyn CronEnqueueJob<AppState> + Send + Sync + 'static>),
194}
195
196#[cfg(feature = "jobs")]
197#[async_trait::async_trait]
198trait CronEnqueueJob<AppState: AS>: Send + Sync {
199 async fn insert(
200 &self,
201 conn: &mut sqlx::PgConnection,
202 context: &str,
203 at: chrono::DateTime<Utc>,
204 id: uuid::Uuid,
205 ) -> Result<uuid::Uuid, EnqueueError>;
206 fn span(&self, context: &str, at: chrono::DateTime<Utc>, id: uuid::Uuid) -> tracing::Span;
207 fn name(&self) -> &'static str;
208 async fn enqueue_direct(&self, app_state: AppState, context: String) -> Result<(), String>;
209}
210
211#[cfg(feature = "jobs")]
212#[async_trait::async_trait]
213impl<AppState: AS, J: Job<AppState>> CronEnqueueJob<AppState> for J {
214 async fn insert(
215 &self,
216 conn: &mut sqlx::PgConnection,
217 context: &str,
218 at: chrono::DateTime<Utc>,
219 id: uuid::Uuid,
220 ) -> Result<uuid::Uuid, EnqueueError> {
221 enqueue_on_connection::<AppState, J>(conn, self.clone(), context, None, at, id).await
222 }
223 fn span(&self, context: &str, at: chrono::DateTime<Utc>, id: uuid::Uuid) -> tracing::Span {
224 enqueue_span::<AppState, J>(self, context, None, at, id)
225 }
226 fn name(&self) -> &'static str {
227 J::NAME
228 }
229 async fn enqueue_direct(&self, app_state: AppState, context: String) -> Result<(), String> {
230 self.clone()
231 .enqueue(app_state, context, None)
232 .await
233 .map_err(|err| err.to_string())
234 }
235}
236
237#[derive(Debug, thiserror::Error)]
238#[error("TickError: {0}")]
239pub enum TickError {
240 JobError(String),
241 SqlxError(sqlx::Error),
242}
243
244#[cfg(feature = "jobs")]
245fn recoverable_sqlstate(code: &str) -> bool {
246 matches!(code, "55P03" | "57014" | "25P03" | "57P01") || code.starts_with("08")
247}
248
249#[cfg(feature = "jobs")]
250fn recoverable(error: &sqlx::Error) -> bool {
251 match error {
252 sqlx::Error::Database(db) => db.code().is_some_and(|code| recoverable_sqlstate(&code)),
253 sqlx::Error::Io(_) | sqlx::Error::PoolClosed => true,
254 _ => false,
255 }
256}
257
258#[cfg(feature = "jobs")]
261struct Claim<'c> {
262 tx: sqlx::Transaction<'c, sqlx::Postgres>,
263 at: chrono::DateTime<Utc>,
265 last_run: Option<chrono::DateTime<Utc>>,
267}
268
269#[cfg(feature = "jobs")]
270fn skip_recoverable(name: &str, operation: &str, error: &sqlx::Error) -> bool {
271 if recoverable(error) {
272 tracing::warn!(cron.name = name, operation, sqlstate = ?error.as_database_error().and_then(sqlx::error::DatabaseError::code), cause = %error, "Cron claim skipped");
273 true
274 } else {
275 false
276 }
277}
278
279impl<AppState: AS> CronJob<AppState> {
280 #[tracing::instrument(
281 name = "cron_job.tick",
282 level = "trace",
283 skip_all,
284 fields(
285 cron_job.name = self.name,
286 cron_job.schedule = ?self.schedule
287 )
288 )]
289 pub(crate) async fn tick(
290 &self,
291 app_state: AppState,
292 last_enqueue_map: &HashMap<String, chrono::DateTime<Utc>>,
293 worker_started_at: chrono::DateTime<Utc>,
294 timezone: Tz,
295 ) -> Result<(), TickError> {
296 let last_enqueue = last_enqueue_map.get(self.name);
297 let context = format!("Cron@{}", app_state.version());
298 let now = Utc::now();
299
300 let should_run = self
301 .schedule
302 .should_run(last_enqueue, now, worker_started_at, timezone);
303
304 if should_run {
305 return self
306 .tick_claimed(&app_state, &context, worker_started_at, timezone)
307 .await;
308 }
309
310 Ok(())
311 }
312
313 pub async fn run(&self, app_state: AppState, context: String) -> Result<(), String> {
314 match &self.action {
315 CronAction::Callback(func) => func.run(app_state, context).await,
316 #[cfg(feature = "jobs")]
317 CronAction::Job(job) => job.enqueue_direct(app_state, context).await,
318 }
319 }
320
321 #[cfg(feature = "jobs")]
335 fn fire_receipt(&self, last_run: Option<chrono::DateTime<Utc>>) {
336 tracing::info!(task_name = self.name, last_run = ?last_run, "Enqueuing Task");
337 }
338
339 #[cfg(feature = "jobs")]
340 async fn claim_due(
341 &self,
342 app_state: &AppState,
343 worker_started_at: chrono::DateTime<Utc>,
344 timezone: Tz,
345 ) -> Result<Option<Claim<'_>>, TickError> {
346 let mut tx = match app_state.db().begin().await {
347 Ok(tx) => tx,
348 Err(err) if skip_recoverable(self.name, "begin", &err) => return Ok(None),
349 Err(err) => return Err(TickError::SqlxError(err)),
350 };
351 for (setting, value) in [
352 ("lock_timeout", "1s"),
353 ("statement_timeout", "5s"),
354 ("idle_in_transaction_session_timeout", "15s"),
355 ] {
356 let sql = format!("SET LOCAL {setting} = '{value}'");
357 if let Err(err) = sqlx::query(&sql).execute(&mut *tx).await {
358 if skip_recoverable(self.name, "timeout setup", &err) {
359 return Ok(None);
360 }
361 return Err(TickError::SqlxError(err));
362 }
363 }
364 let existing = sqlx::query_as::<_, (chrono::DateTime<Utc>,)>(
365 "SELECT last_run_at FROM crons WHERE name = $1 FOR UPDATE NOWAIT",
366 )
367 .bind(self.name)
368 .fetch_optional(&mut *tx)
369 .await;
370 let last_run = match existing {
371 Ok(Some((at,))) => Some(at),
372 Ok(None) => {
373 let inserted = sqlx::query(
374 "INSERT INTO crons (cron_id, name, last_run_at, created_at, updated_at)
375 VALUES ($1, $2, clock_timestamp(), clock_timestamp(), clock_timestamp())
376 ON CONFLICT (name) DO NOTHING RETURNING cron_id",
377 )
378 .bind(uuid::Uuid::new_v4())
379 .bind(self.name)
380 .fetch_optional(&mut *tx)
381 .await;
382 match inserted {
383 Ok(Some(_)) => None,
384 Ok(None) => match sqlx::query_as::<_, (chrono::DateTime<Utc>,)>(
385 "SELECT last_run_at FROM crons WHERE name = $1 FOR UPDATE NOWAIT",
386 )
387 .bind(self.name)
388 .fetch_one(&mut *tx)
389 .await
390 {
391 Ok((at,)) => Some(at),
392 Err(err) if skip_recoverable(self.name, "reselect", &err) => {
393 return Ok(None);
394 }
395 Err(err) => return Err(TickError::SqlxError(err)),
396 },
397 Err(err) if skip_recoverable(self.name, "first-row insert", &err) => {
398 return Ok(None);
399 }
400 Err(err) => return Err(TickError::SqlxError(err)),
401 }
402 }
403 Err(err) if skip_recoverable(self.name, "row claim", &err) => return Ok(None),
404 Err(err) => return Err(TickError::SqlxError(err)),
405 };
406 let claim_time =
407 match sqlx::query_scalar::<_, chrono::DateTime<Utc>>("SELECT clock_timestamp()")
408 .fetch_one(&mut *tx)
409 .await
410 {
411 Ok(at) => at,
412 Err(err) if skip_recoverable(self.name, "database time", &err) => return Ok(None),
413 Err(err) => return Err(TickError::SqlxError(err)),
414 };
415 if !self
416 .schedule
417 .should_run(last_run.as_ref(), claim_time, worker_started_at, timezone)
418 {
419 return Ok(None);
420 }
421 Ok(Some(Claim {
422 tx,
423 at: claim_time,
424 last_run,
425 }))
426 }
427
428 #[cfg(feature = "jobs")]
429 async fn tick_claimed(
430 &self,
431 app_state: &AppState,
432 context: &str,
433 worker_started_at: chrono::DateTime<Utc>,
434 timezone: Tz,
435 ) -> Result<(), TickError> {
436 let Some(Claim {
437 tx,
438 at: claim_time,
439 last_run,
440 }) = self
441 .claim_due(app_state, worker_started_at, timezone)
442 .await?
443 else {
444 return Ok(());
445 };
446 #[cfg(test)]
447 let mut tx = tx;
448 #[cfg(test)]
449 if let Some(pause) = &self.pause_after_claim {
450 let pid = sqlx::query_scalar::<_, i32>("SELECT pg_backend_pid()")
451 .fetch_one(&mut *tx)
452 .await
453 .map_err(TickError::SqlxError)?;
454 pause.claimed.send(pid).await.expect("claim test receiver");
455 pause.release.notified().await;
456 }
457 match &self.action {
458 CronAction::Job(job) => {
459 self.fire(tx, claim_time, last_run, job.as_ref(), context)
460 .await
461 }
462 CronAction::Callback(callback) => {
463 if !self.commit_claim(tx, claim_time).await? {
464 return Ok(());
465 }
466 self.fire_receipt(last_run);
467 #[cfg(test)]
468 if let Some(pause) = &self.pause_after_commit {
469 pause
470 .committed
471 .send(claim_time)
472 .await
473 .expect("callback test receiver");
474 pause.release.notified().await;
475 }
476 callback
477 .run(app_state.clone(), context.to_owned())
478 .await
479 .map_err(TickError::JobError)
480 }
481 }
482 }
483
484 #[cfg(feature = "jobs")]
485 async fn commit_claim(
486 &self,
487 mut tx: sqlx::Transaction<'_, sqlx::Postgres>,
488 claim_time: chrono::DateTime<Utc>,
489 ) -> Result<bool, TickError> {
490 if let Err(err) =
491 sqlx::query("UPDATE crons SET last_run_at = $1, updated_at = $1 WHERE name = $2")
492 .bind(claim_time)
493 .bind(self.name)
494 .execute(&mut *tx)
495 .await
496 {
497 if skip_recoverable(self.name, "cron update", &err) {
498 return Ok(false);
499 }
500 return Err(TickError::SqlxError(err));
501 }
502 if let Err(err) = tx.commit().await {
503 if skip_recoverable(self.name, "commit", &err) {
504 return Ok(false);
505 }
506 return Err(TickError::SqlxError(err));
507 }
508 Ok(true)
509 }
510
511 #[cfg(feature = "jobs")]
512 async fn fire(
513 &self,
514 mut tx: sqlx::Transaction<'_, sqlx::Postgres>,
515 claim_time: chrono::DateTime<Utc>,
516 last_run: Option<chrono::DateTime<Utc>>,
517 job: &dyn CronEnqueueJob<AppState>,
518 context: &str,
519 ) -> Result<(), TickError> {
520 let id = uuid::Uuid::new_v4();
521 let span = job.span(context, claim_time, id);
522 async {
523 if let Err(err) = job.insert(&mut tx, context, claim_time, id).await {
524 enqueue_failure(id, &err);
525 match err {
526 EnqueueError::SqlxError(sqlx_err)
527 if skip_recoverable(self.name, "queue insert", &sqlx_err) =>
528 {
529 return Ok(());
530 }
531 EnqueueError::SqlxError(sqlx_err) => {
532 return Err(TickError::SqlxError(sqlx_err));
533 }
534 EnqueueError::SerdeJsonError(serde_err) => {
535 return Err(TickError::JobError(serde_err.to_string()));
536 }
537 }
538 }
539 if self.commit_claim(tx, claim_time).await? {
540 self.fire_receipt(last_run);
542 enqueue_receipt(id, job.name());
543 }
544 Ok(())
545 }
546 .instrument(span)
547 .await
548 }
549}
550
551impl<AppState: AS> CronRegistry<AppState> {
552 pub fn new() -> Self {
553 Self {
554 jobs: HashMap::new(),
555 }
556 }
557
558 #[tracing::instrument(name = "cron.register", skip_all, fields(cron_job.name = name, cron_job.interval = ?interval))]
559 pub fn register<FnError: Error + Send + Sync + 'static>(
560 &mut self,
561 name: &'static str,
562 description: Option<&'static str>,
563 interval: Duration,
564 job: impl Fn(AppState, String) -> Pin<Box<dyn Future<Output = Result<(), FnError>> + Send>>
565 + Send
566 + Sync
567 + 'static,
568 ) {
569 let cron_job = CronJob {
570 name,
571 description,
572 action: CronAction::Callback(Box::new(CronFnClosure {
573 func: job,
574 _marker: std::marker::PhantomData,
575 })),
576 schedule: Schedule::Interval(IntervalSchedule(interval)),
577 #[cfg(all(test, feature = "jobs"))]
578 pause_after_claim: None,
579 #[cfg(all(test, feature = "jobs"))]
580 pause_after_commit: None,
581 };
582 self.jobs.insert(name, cron_job);
583 }
584
585 #[tracing::instrument(name = "cron.register_with_cron", skip_all, fields(cron_job.name = name, cron_job.cron = cron_expr))]
586 pub fn register_with_cron<FnError: Error + Send + Sync + 'static>(
587 &mut self,
588 name: &'static str,
589 description: Option<&'static str>,
590 cron_expr: &str,
591 job: impl Fn(AppState, String) -> Pin<Box<dyn Future<Output = Result<(), FnError>> + Send>>
592 + Send
593 + Sync
594 + 'static,
595 ) -> Result<(), cron::error::Error> {
596 let cron_schedule = cron_expr.parse::<cron::Schedule>()?;
597 let cron_job = CronJob {
598 name,
599 description,
600 action: CronAction::Callback(Box::new(CronFnClosure {
601 func: job,
602 _marker: std::marker::PhantomData,
603 })),
604 schedule: Schedule::Cron(CronSchedule(Box::new(cron_schedule))),
605 #[cfg(all(test, feature = "jobs"))]
606 pause_after_claim: None,
607 #[cfg(all(test, feature = "jobs"))]
608 pause_after_commit: None,
609 };
610 self.jobs.insert(name, cron_job);
611 Ok(())
612 }
613
614 #[cfg(feature = "jobs")]
615 #[tracing::instrument(name = "cron.register_job", skip_all, fields(cron_job.name = J::NAME, cron_job.interval = ?interval))]
616 pub fn register_job<J: Job<AppState>>(
617 &mut self,
618 job: J,
619 description: Option<&'static str>,
620 interval: Duration,
621 ) {
622 self.jobs.insert(
623 J::NAME,
624 CronJob {
625 name: J::NAME,
626 description,
627 action: CronAction::Job(Box::new(job)),
628 schedule: Schedule::Interval(IntervalSchedule(interval)),
629 #[cfg(all(test, feature = "jobs"))]
630 pause_after_claim: None,
631 #[cfg(all(test, feature = "jobs"))]
632 pause_after_commit: None,
633 },
634 );
635 }
636
637 #[cfg(feature = "jobs")]
638 #[tracing::instrument(name = "cron.register_job_with_cron", skip_all, fields(cron_job.name = J::NAME, cron_job.cron = cron_expr))]
639 pub fn register_job_with_cron<J: Job<AppState>>(
640 &mut self,
641 job: J,
642 description: Option<&'static str>,
643 cron_expr: &str,
644 ) -> Result<(), cron::error::Error> {
645 let schedule = cron_expr.parse::<cron::Schedule>()?;
646 self.jobs.insert(
647 J::NAME,
648 CronJob {
649 name: J::NAME,
650 description,
651 action: CronAction::Job(Box::new(job)),
652 schedule: Schedule::Cron(CronSchedule(Box::new(schedule))),
653 #[cfg(all(test, feature = "jobs"))]
654 pause_after_claim: None,
655 #[cfg(all(test, feature = "jobs"))]
656 pause_after_commit: None,
657 },
658 );
659 Ok(())
660 }
661
662 #[cfg(feature = "jobs")]
663 #[tracing::instrument(name = "cron.get", skip_all, fields(cron_job.name = name))]
664 pub fn get(&self, name: &str) -> Option<&CronJob<AppState>> {
665 self.jobs.get(name)
666 }
667
668 pub fn jobs(&self) -> &HashMap<&'static str, CronJob<AppState>> {
670 &self.jobs
671 }
672
673 #[must_use]
679 pub fn entries(&self) -> Vec<(&'static str, String)> {
680 let mut entries: Vec<(&'static str, String)> = self
681 .jobs
682 .values()
683 .map(|job| {
684 let schedule = match &job.schedule {
685 Schedule::Interval(IntervalSchedule(duration)) => format!("{duration:?}"),
686 Schedule::Cron(CronSchedule(schedule)) => schedule.to_string(),
687 };
688 (job.name, schedule)
689 })
690 .collect();
691 entries.sort_unstable_by_key(|(name, _)| *name);
692 entries
693 }
694}
695
696impl<AppState: AS> Default for CronRegistry<AppState> {
697 fn default() -> Self {
698 Self::new()
699 }
700}
701
702#[cfg(test)]
703mod test {
704 use crate::app_state::AppState;
705 use crate::server::cookies::CookieKey;
706 use std::fmt::Write;
707 use std::sync::{Arc, Mutex, OnceLock};
708 use tracing::{
709 Event, Id, Subscriber,
710 field::{Field, Visit},
711 instrument::WithSubscriber,
712 span::Attributes,
713 };
714 use tracing_subscriber::{Layer, layer::Context, prelude::*, registry::LookupSpan};
715
716 use super::*;
717
718 #[derive(Default)]
719 struct Fields(String);
720
721 impl Visit for Fields {
722 fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
723 let _ = write!(self.0, " {}={value:?}", field.name());
724 }
725 }
726
727 struct TraceCapture(Arc<Mutex<Vec<String>>>);
728
729 fn trace_capture() -> &'static Arc<Mutex<Vec<String>>> {
730 static CAPTURE: OnceLock<Arc<Mutex<Vec<String>>>> = OnceLock::new();
731 CAPTURE.get_or_init(|| {
732 let lines = Arc::new(Mutex::new(Vec::new()));
733 tracing::subscriber::set_global_default(
734 tracing_subscriber::registry()
735 .with(TraceCapture(lines.clone()))
736 .with(tracing_subscriber::filter::LevelFilter::TRACE),
737 )
738 .expect("install one test tracing subscriber");
739 lines
740 })
741 }
742
743 impl<S> Layer<S> for TraceCapture
744 where
745 S: Subscriber + for<'a> LookupSpan<'a>,
746 {
747 fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
748 let mut fields = Fields::default();
749 attrs.record(&mut fields);
750 let parent = ctx
751 .span(id)
752 .and_then(|span| span.parent().map(|parent| parent.name().to_owned()));
753 self.0.lock().unwrap().push(format!(
754 "span:{} parent:{parent:?}{}",
755 attrs.metadata().name(),
756 fields.0
757 ));
758 }
759
760 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
761 let mut fields = Fields::default();
762 event.record(&mut fields);
763 let parent = ctx.event_span(event).map(|span| span.name().to_owned());
764 self.0
765 .lock()
766 .unwrap()
767 .push(format!("event parent:{parent:?}{}", fields.0));
768 }
769 }
770
771 #[derive(Clone, Debug)]
773 struct CapturedEvent {
774 target: String,
775 level: tracing::Level,
776 parent: Option<String>,
777 fields: std::collections::BTreeMap<String, String>,
778 }
779
780 #[derive(Default)]
781 struct FieldMap(std::collections::BTreeMap<String, String>);
782
783 impl Visit for FieldMap {
784 fn record_str(&mut self, field: &Field, value: &str) {
785 self.0.insert(field.name().to_owned(), value.to_owned());
786 }
787
788 fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
789 self.0.insert(field.name().to_owned(), format!("{value:?}"));
790 }
791 }
792
793 #[derive(Clone, Default)]
797 struct EventCapture(Arc<Mutex<Vec<CapturedEvent>>>);
798
799 impl<S> Layer<S> for EventCapture
800 where
801 S: Subscriber + for<'a> LookupSpan<'a>,
802 {
803 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
804 let mut fields = FieldMap::default();
805 event.record(&mut fields);
806 self.0.lock().unwrap().push(CapturedEvent {
807 target: event.metadata().target().to_owned(),
808 level: *event.metadata().level(),
809 parent: ctx.event_span(event).map(|span| span.name().to_owned()),
810 fields: fields.0,
811 });
812 }
813 }
814
815 impl EventCapture {
816 fn dispatch(&self) -> tracing::Dispatch {
817 trace_capture();
824 tracing::Dispatch::new(tracing_subscriber::registry().with(self.clone()))
825 }
826
827 fn messages(&self) -> Vec<String> {
828 self.0
829 .lock()
830 .unwrap()
831 .iter()
832 .filter_map(|event| event.fields.get("message").cloned())
833 .collect()
834 }
835
836 fn fire_receipts(&self, name: &str) -> Vec<CapturedEvent> {
840 self.0
841 .lock()
842 .unwrap()
843 .iter()
844 .filter(|event| {
845 event
846 .fields
847 .get("message")
848 .is_some_and(|message| message.starts_with("Enqueuing Task"))
849 && event.fields.get("task_name").map(String::as_str) == Some(name)
850 })
851 .cloned()
852 .collect()
853 }
854 }
855
856 fn assert_fire_receipt(
858 receipt: &CapturedEvent,
859 name: &str,
860 last_run: Option<chrono::DateTime<Utc>>,
861 ) {
862 assert_eq!(receipt.target, "cja::cron::registry", "{receipt:?}");
863 assert_eq!(receipt.level, tracing::Level::INFO, "{receipt:?}");
864 let field = |key: &str| receipt.fields.get(key).map(String::as_str);
865 assert_eq!(field("message"), Some("Enqueuing Task"), "{receipt:?}");
866 assert_eq!(field("task_name"), Some(name), "{receipt:?}");
867 let last_run = format!("{last_run:?}");
868 assert_eq!(field("last_run"), Some(last_run.as_str()), "{receipt:?}");
869 }
870
871 async fn backdate(db: &sqlx::PgPool, name: &str, by: &str) -> chrono::DateTime<Utc> {
874 sqlx::query_scalar(
875 "UPDATE crons SET last_run_at = clock_timestamp() - $2::text::interval
876 WHERE name = $1 RETURNING last_run_at",
877 )
878 .bind(name)
879 .bind(by)
880 .fetch_one(db)
881 .await
882 .unwrap()
883 }
884
885 const RECEIPT_CALLBACK: &str = "receipt_callback";
886
887 fn receipt_registry() -> CronRegistry<TestAppState> {
890 let mut registry = CronRegistry::new();
891 registry.register_job(TestJob, None, Duration::from_mins(1));
892 registry.register(RECEIPT_CALLBACK, None, Duration::from_mins(1), |_, _| {
893 Box::pin(async {
894 tracing::info!("callback body ran");
895 Ok::<(), std::io::Error>(())
896 })
897 });
898 registry
899 }
900
901 #[derive(Clone)]
902 struct TestAppState {
903 db: sqlx::PgPool,
904 cookie_key: CookieKey,
905 }
906
907 impl AppState for TestAppState {
908 fn db(&self) -> &sqlx::PgPool {
909 &self.db
910 }
911
912 fn version(&self) -> &'static str {
913 "test"
914 }
915
916 fn cookie_key(&self) -> &CookieKey {
917 &self.cookie_key
918 }
919 }
920
921 #[derive(Clone, Debug, serde::Deserialize, serde::Serialize)]
922 struct TestJob;
923
924 #[async_trait::async_trait]
925 impl Job<TestAppState> for TestJob {
926 const NAME: &'static str = "test_job";
927
928 async fn run(&self, _app_state: TestAppState) -> color_eyre::Result<()> {
929 Ok(())
930 }
931 }
932
933 #[derive(Clone, Debug, serde::Deserialize, serde::Serialize)]
934 struct FailingJob;
935
936 #[async_trait::async_trait]
937 impl Job<TestAppState> for FailingJob {
938 const NAME: &'static str = "failing_job";
939
940 async fn run(&self, _app_state: TestAppState) -> color_eyre::Result<()> {
941 Err(color_eyre::eyre::eyre!("Test error"))
942 }
943 }
944
945 #[derive(Clone, Debug, serde::Deserialize, serde::Serialize)]
946 struct SecondTestJob;
947
948 #[async_trait::async_trait]
949 impl Job<TestAppState> for SecondTestJob {
950 const NAME: &'static str = "second_test_job";
951
952 async fn run(&self, _app_state: TestAppState) -> color_eyre::Result<()> {
953 Ok(())
954 }
955 }
956
957 #[derive(Clone, Debug, serde::Deserialize, serde::Serialize)]
958 struct TelemetryJob;
959
960 #[async_trait::async_trait]
961 impl Job<TestAppState> for TelemetryJob {
962 const NAME: &'static str = "atomic_telemetry_job";
963
964 async fn run(&self, _app_state: TestAppState) -> color_eyre::Result<()> {
965 Ok(())
966 }
967 }
968
969 fn job_worker(db: sqlx::PgPool) -> crate::cron::Worker<TestAppState> {
970 let state = TestAppState {
971 db,
972 cookie_key: CookieKey::generate(),
973 };
974 let mut registry = CronRegistry::new();
975 registry.register_job(TestJob, None, Duration::from_mins(1));
976 crate::cron::Worker::new(state, registry)
977 }
978
979 #[sqlx::test]
980 async fn two_pools_commit_one_enqueue_per_interval(db: sqlx::PgPool) {
981 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
982 .await
983 .unwrap();
984 let first = job_worker(db.clone());
985 let second = job_worker(other);
986 let count = || async {
987 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE name = $1")
988 .bind(TestJob::NAME)
989 .fetch_one(&db)
990 .await
991 .unwrap()
992 };
993 let pair = || async {
994 let barrier = Arc::new(tokio::sync::Barrier::new(3));
995 let (a, b, _) = tokio::join!(
996 async {
997 barrier.wait().await;
998 first.tick().await
999 },
1000 async {
1001 barrier.wait().await;
1002 second.tick().await
1003 },
1004 barrier.wait(),
1005 );
1006 a.unwrap();
1007 b.unwrap();
1008 };
1009 pair().await;
1010 assert_eq!(count().await, 1);
1011 assert_eq!(
1012 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM crons WHERE name = $1")
1013 .bind(TestJob::NAME)
1014 .fetch_one(&db)
1015 .await
1016 .unwrap(),
1017 1
1018 );
1019 pair().await;
1020 assert_eq!(count().await, 1);
1021 for expected in 2..=4 {
1022 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '2 minutes' WHERE name = $1")
1023 .bind(TestJob::NAME).execute(&db).await.unwrap();
1024 pair().await;
1025 assert_eq!(count().await, expected);
1026 println!("job interval {expected}: {} enqueue(s)", count().await);
1027 pair().await;
1028 assert_eq!(count().await, expected);
1029 }
1030 }
1031
1032 #[sqlx::test]
1033 async fn two_pools_commit_one_enqueue_per_cron_slot(db: sqlx::PgPool) {
1034 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1035 .await
1036 .unwrap();
1037 let make_worker = |pool| {
1038 let mut registry = CronRegistry::new();
1039 registry
1040 .register_job_with_cron(TestJob, None, "* * * * * * *")
1041 .unwrap();
1042 crate::cron::Worker::new(
1043 TestAppState {
1044 db: pool,
1045 cookie_key: CookieKey::generate(),
1046 },
1047 registry,
1048 )
1049 };
1050 let first = make_worker(db.clone());
1051 let second = make_worker(other);
1052 for expected in 1..=4 {
1053 let db_now = sqlx::query_scalar::<_, chrono::DateTime<Utc>>("SELECT clock_timestamp()")
1056 .fetch_one(&db)
1057 .await
1058 .unwrap();
1059 tokio::time::sleep(Duration::from_millis(
1060 1100 - u64::from(db_now.timestamp_subsec_millis()),
1061 ))
1062 .await;
1063 if expected > 1 {
1064 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '2 seconds' WHERE name = $1")
1065 .bind(TestJob::NAME).execute(&db).await.unwrap();
1066 }
1067 let barrier = Arc::new(tokio::sync::Barrier::new(3));
1068 let (a, b, _) = tokio::join!(
1069 async {
1070 barrier.wait().await;
1071 first.tick().await
1072 },
1073 async {
1074 barrier.wait().await;
1075 second.tick().await
1076 },
1077 barrier.wait(),
1078 );
1079 a.unwrap();
1080 b.unwrap();
1081 let actual = sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE name = $1")
1082 .bind(TestJob::NAME)
1083 .fetch_one(&db)
1084 .await
1085 .unwrap();
1086 assert_eq!(actual, expected);
1087 println!("cron expression slot {expected}: {actual} enqueue(s)");
1088 }
1089 }
1090
1091 #[sqlx::test]
1092 async fn two_pools_claim_callback_once_per_interval(db: sqlx::PgPool) {
1093 use std::sync::atomic::{AtomicUsize, Ordering};
1094 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1095 .await
1096 .unwrap();
1097 let calls = Arc::new(AtomicUsize::new(0));
1098 let make_worker = |pool, calls: Arc<AtomicUsize>| {
1099 let mut registry = CronRegistry::new();
1100 registry.register("callback", None, Duration::from_mins(1), move |_, _| {
1101 let calls = calls.clone();
1102 Box::pin(async move {
1103 calls.fetch_add(1, Ordering::SeqCst);
1104 Ok::<(), std::io::Error>(())
1105 })
1106 });
1107 crate::cron::Worker::new(
1108 TestAppState {
1109 db: pool,
1110 cookie_key: CookieKey::generate(),
1111 },
1112 registry,
1113 )
1114 };
1115 let first = make_worker(db.clone(), calls.clone());
1116 let second = make_worker(other, calls.clone());
1117 for expected in 1..=4 {
1118 if expected > 1 {
1119 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '2 minutes' WHERE name = 'callback'")
1120 .execute(&db).await.unwrap();
1121 }
1122 let (a, b) = tokio::join!(first.tick(), second.tick());
1123 a.unwrap();
1124 b.unwrap();
1125 assert_eq!(calls.load(Ordering::SeqCst), expected);
1126 println!(
1127 "callback interval {expected}: {} invocation(s)",
1128 calls.load(Ordering::SeqCst)
1129 );
1130 }
1131 }
1132
1133 #[sqlx::test]
1134 async fn callback_aborted_after_commit_waits_for_next_interval(db: sqlx::PgPool) {
1135 use std::sync::atomic::{AtomicUsize, Ordering};
1136 let calls = Arc::new(AtomicUsize::new(0));
1137 let mut registry = CronRegistry::new();
1138 let observed = calls.clone();
1139 registry.register("callback", None, Duration::from_secs(30), move |_, _| {
1140 let observed = observed.clone();
1141 Box::pin(async move {
1142 observed.fetch_add(1, Ordering::SeqCst);
1143 Ok::<(), std::io::Error>(())
1144 })
1145 });
1146 let (sender, mut receiver) = tokio::sync::mpsc::channel(1);
1147 let pause = Arc::new(CallbackPause {
1148 committed: sender,
1149 release: tokio::sync::Notify::new(),
1150 });
1151 registry
1152 .jobs
1153 .get_mut("callback")
1154 .unwrap()
1155 .pause_after_commit = Some(pause.clone());
1156 let state = TestAppState {
1157 db: db.clone(),
1158 cookie_key: CookieKey::generate(),
1159 };
1160 let worker = crate::cron::Worker::new(state.clone(), registry);
1161 let task = tokio::spawn(async move { worker.tick().await });
1162 let claim_time = tokio::time::timeout(Duration::from_secs(3), receiver.recv())
1163 .await
1164 .unwrap()
1165 .unwrap();
1166 task.abort();
1167 assert!(task.await.unwrap_err().is_cancelled());
1168 assert_eq!(calls.load(Ordering::SeqCst), 0);
1169 let stored = sqlx::query_scalar::<_, chrono::DateTime<Utc>>(
1170 "SELECT last_run_at FROM crons WHERE name = 'callback'",
1171 )
1172 .fetch_one(&db)
1173 .await
1174 .unwrap();
1175 assert_eq!(stored, claim_time);
1176 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '31 seconds' WHERE name = 'callback'")
1177 .execute(&db).await.unwrap();
1178 let remaining = calls.clone();
1179 let mut retry = CronRegistry::new();
1180 retry.register("callback", None, Duration::from_secs(30), move |_, _| {
1181 let calls = calls.clone();
1182 Box::pin(async move {
1183 calls.fetch_add(1, Ordering::SeqCst);
1184 Ok::<(), std::io::Error>(())
1185 })
1186 });
1187 crate::cron::Worker::new(state, retry).tick().await.unwrap();
1188 assert_eq!(remaining.load(Ordering::SeqCst), 1);
1189 println!("aborted callback: first interval skipped; next interval invoked once");
1190 }
1191
1192 #[sqlx::test]
1193 async fn dropped_claim_rolls_back_and_next_tick_fires(db: sqlx::PgPool) {
1194 let state = TestAppState {
1195 db: db.clone(),
1196 cookie_key: CookieKey::generate(),
1197 };
1198 let mut registry = CronRegistry::new();
1199 registry.register_job(TestJob, None, Duration::from_secs(864));
1200 let cron = registry.get(TestJob::NAME).unwrap();
1201 let claim = cron
1202 .claim_due(&state, Utc::now(), chrono_tz::UTC)
1203 .await
1204 .unwrap()
1205 .unwrap();
1206 drop(claim);
1207 assert_eq!(
1208 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM crons")
1209 .fetch_one(&db)
1210 .await
1211 .unwrap(),
1212 0
1213 );
1214 let worker = crate::cron::Worker::new(state.clone(), registry);
1215 worker.tick().await.unwrap();
1216 assert_eq!(
1217 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1218 .fetch_one(&db)
1219 .await
1220 .unwrap(),
1221 1
1222 );
1223 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '866 seconds' WHERE name = $1")
1224 .bind(TestJob::NAME).execute(&db).await.unwrap();
1225 let mut registry = CronRegistry::new();
1226 registry.register_job(TestJob, None, Duration::from_secs(864));
1227 let cron = registry.get(TestJob::NAME).unwrap();
1228 let claim = cron
1229 .claim_due(&state, Utc::now(), chrono_tz::UTC)
1230 .await
1231 .unwrap()
1232 .unwrap();
1233 drop(claim);
1234 crate::cron::Worker::new(state, registry)
1235 .tick()
1236 .await
1237 .unwrap();
1238 assert_eq!(
1239 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1240 .fetch_one(&db)
1241 .await
1242 .unwrap(),
1243 2
1244 );
1245 }
1246
1247 #[sqlx::test]
1248 async fn cadence_864_seconds_and_database_stamp(db: sqlx::PgPool) {
1249 let state = TestAppState {
1250 db: db.clone(),
1251 cookie_key: CookieKey::generate(),
1252 };
1253 let mut registry = CronRegistry::new();
1254 registry.register_job(TestJob, None, Duration::from_secs(864));
1255 let worker = crate::cron::Worker::new(state, registry);
1256 worker.tick().await.unwrap();
1257 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '862 seconds' WHERE name = $1")
1258 .bind(TestJob::NAME).execute(&db).await.unwrap();
1259 worker.tick().await.unwrap();
1260 assert_eq!(
1261 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1262 .fetch_one(&db)
1263 .await
1264 .unwrap(),
1265 1
1266 );
1267 sqlx::query("UPDATE crons SET last_run_at = clock_timestamp() - interval '866 seconds' WHERE name = $1")
1268 .bind(TestJob::NAME).execute(&db).await.unwrap();
1269 let before = sqlx::query_scalar::<_, chrono::DateTime<Utc>>("SELECT clock_timestamp()")
1270 .fetch_one(&db)
1271 .await
1272 .unwrap();
1273 worker.tick().await.unwrap();
1274 let after = sqlx::query_scalar::<_, chrono::DateTime<Utc>>("SELECT clock_timestamp()")
1275 .fetch_one(&db)
1276 .await
1277 .unwrap();
1278 let stamp = sqlx::query_scalar::<_, chrono::DateTime<Utc>>(
1279 "SELECT last_run_at FROM crons WHERE name = $1",
1280 )
1281 .bind(TestJob::NAME)
1282 .fetch_one(&db)
1283 .await
1284 .unwrap();
1285 assert!(stamp >= before && stamp <= after);
1286 assert_eq!(
1287 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1288 .fetch_one(&db)
1289 .await
1290 .unwrap(),
1291 2
1292 );
1293 }
1294
1295 #[sqlx::test]
1296 async fn locked_cron_does_not_block_other_crons(db: sqlx::PgPool) {
1297 let state = TestAppState {
1298 db: db.clone(),
1299 cookie_key: CookieKey::generate(),
1300 };
1301 let mut registry = CronRegistry::new();
1302 registry.register_job(TestJob, None, Duration::from_secs(30));
1303 registry.register_job(SecondTestJob, None, Duration::from_secs(30));
1304 let worker = crate::cron::Worker::new(state, registry);
1305 sqlx::query("INSERT INTO crons (cron_id, name, last_run_at, created_at, updated_at) VALUES ($1, $2, clock_timestamp() - interval '60 seconds', clock_timestamp(), clock_timestamp())")
1306 .bind(uuid::Uuid::new_v4()).bind(TestJob::NAME).execute(&db).await.unwrap();
1307 let mut blocker = db.begin().await.unwrap();
1308 sqlx::query("SELECT last_run_at FROM crons WHERE name = $1 FOR UPDATE")
1309 .bind(TestJob::NAME)
1310 .fetch_one(&mut *blocker)
1311 .await
1312 .unwrap();
1313 tokio::time::timeout(Duration::from_secs(3), worker.tick())
1314 .await
1315 .unwrap()
1316 .unwrap();
1317 assert_eq!(
1318 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE name = $1")
1319 .bind(SecondTestJob::NAME)
1320 .fetch_one(&db)
1321 .await
1322 .unwrap(),
1323 1
1324 );
1325 assert_eq!(
1326 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE name = $1")
1327 .bind(TestJob::NAME)
1328 .fetch_one(&db)
1329 .await
1330 .unwrap(),
1331 0
1332 );
1333 blocker.rollback().await.unwrap();
1334 worker.tick().await.unwrap();
1335 assert_eq!(
1336 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE name = $1")
1337 .bind(TestJob::NAME)
1338 .fetch_one(&db)
1339 .await
1340 .unwrap(),
1341 1
1342 );
1343 }
1344
1345 #[sqlx::test]
1346 async fn uncommitted_first_row_is_bounded_and_retried(db: sqlx::PgPool) {
1347 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1348 .await
1349 .unwrap();
1350 let worker = job_worker(other);
1351 let mut blocker = db.begin().await.unwrap();
1352 sqlx::query("INSERT INTO crons (cron_id, name, last_run_at, created_at, updated_at) VALUES ($1, $2, clock_timestamp(), clock_timestamp(), clock_timestamp())")
1353 .bind(uuid::Uuid::new_v4()).bind(TestJob::NAME).execute(&mut *blocker).await.unwrap();
1354 tokio::time::timeout(Duration::from_secs(3), worker.tick())
1355 .await
1356 .unwrap()
1357 .unwrap();
1358 assert_eq!(
1359 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1360 .fetch_one(&db)
1361 .await
1362 .unwrap(),
1363 0
1364 );
1365 blocker.rollback().await.unwrap();
1366 worker.tick().await.unwrap();
1367 assert_eq!(
1368 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1369 .fetch_one(&db)
1370 .await
1371 .unwrap(),
1372 1
1373 );
1374 }
1375
1376 #[sqlx::test]
1377 async fn terminated_claimer_rolls_back_and_retries(db: sqlx::PgPool) {
1378 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1379 .await
1380 .unwrap();
1381 let state = TestAppState {
1382 db: db.clone(),
1383 cookie_key: CookieKey::generate(),
1384 };
1385 let mut registry = CronRegistry::new();
1386 registry.register_job(TestJob, None, Duration::from_mins(1));
1387 let (sender, mut receiver) = tokio::sync::mpsc::channel(1);
1388 let pause = std::sync::Arc::new(ClaimPause {
1389 claimed: sender,
1390 release: tokio::sync::Notify::new(),
1391 });
1392 registry
1393 .jobs
1394 .get_mut(TestJob::NAME)
1395 .unwrap()
1396 .pause_after_claim = Some(pause.clone());
1397 let worker = crate::cron::Worker::new(state.clone(), registry);
1398 let task = tokio::spawn(async move { worker.tick().await });
1399 let pid = tokio::time::timeout(Duration::from_secs(3), receiver.recv())
1400 .await
1401 .unwrap()
1402 .unwrap();
1403 assert!(
1404 sqlx::query_scalar::<_, bool>("SELECT pg_terminate_backend($1)")
1405 .bind(pid)
1406 .fetch_one(&other)
1407 .await
1408 .unwrap()
1409 );
1410 pause.release.notify_one();
1411 tokio::time::timeout(Duration::from_secs(3), task)
1412 .await
1413 .unwrap()
1414 .unwrap()
1415 .unwrap();
1416 assert_eq!(
1417 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1418 .fetch_one(&db)
1419 .await
1420 .unwrap(),
1421 0
1422 );
1423 assert_eq!(
1424 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM crons")
1425 .fetch_one(&db)
1426 .await
1427 .unwrap(),
1428 0
1429 );
1430 let mut retry_registry = CronRegistry::new();
1431 retry_registry.register_job(TestJob, None, Duration::from_mins(1));
1432 crate::cron::Worker::new(state, retry_registry)
1433 .tick()
1434 .await
1435 .unwrap();
1436 assert_eq!(
1437 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1438 .fetch_one(&db)
1439 .await
1440 .unwrap(),
1441 1
1442 );
1443 }
1444
1445 #[sqlx::test]
1446 async fn statement_timeout_is_recoverable(db: sqlx::PgPool) {
1447 let state = TestAppState {
1448 db,
1449 cookie_key: CookieKey::generate(),
1450 };
1451 let mut registry = CronRegistry::new();
1452 registry.register_job(TestJob, None, Duration::from_mins(1));
1453 let cron = registry.get(TestJob::NAME).unwrap();
1454 let Claim { mut tx, .. } = cron
1455 .claim_due(&state, Utc::now(), chrono_tz::UTC)
1456 .await
1457 .unwrap()
1458 .unwrap();
1459 sqlx::query("SET LOCAL statement_timeout = '10ms'")
1460 .execute(&mut *tx)
1461 .await
1462 .unwrap();
1463 let error = sqlx::query("SELECT pg_sleep(0.1)")
1464 .execute(&mut *tx)
1465 .await
1466 .unwrap_err();
1467 assert_eq!(
1468 error.as_database_error().unwrap().code().as_deref(),
1469 Some("57014")
1470 );
1471 assert!(recoverable(&error));
1472 }
1473
1474 #[test]
1475 fn termination_sqlstates_are_recoverable() {
1476 for code in ["55P03", "57014", "25P03", "57P01", "08006", "08003"] {
1477 assert!(recoverable_sqlstate(code), "{code}");
1478 }
1479 for code in ["23505", "42P01", "25P02"] {
1480 assert!(!recoverable_sqlstate(code), "{code}");
1481 }
1482 }
1483
1484 #[derive(Clone, Debug, serde::Deserialize, serde::Serialize)]
1485 struct CronContextJob;
1486
1487 #[async_trait::async_trait]
1488 impl Job<TestAppState> for CronContextJob {
1489 const NAME: &'static str = "cron_context_job";
1490
1491 async fn run(&self, _app_state: TestAppState) -> color_eyre::Result<()> {
1492 Ok(())
1493 }
1494 }
1495
1496 mod cron_context_jobs {
1497 use super::{CronContextJob, TestAppState};
1498 crate::impl_job_registry!(TestAppState, CronContextJob);
1499 }
1500
1501 #[sqlx::test]
1502 async fn cron_triggered_run_span_carries_cron_context(db: sqlx::PgPool) {
1503 let lines = trace_capture();
1506 let state = TestAppState {
1507 db: db.clone(),
1508 cookie_key: CookieKey::generate(),
1509 };
1510 let mut registry = CronRegistry::new();
1511 registry.register_job(CronContextJob, None, Duration::from_mins(1));
1512 crate::cron::Worker::new(state.clone(), registry)
1513 .tick()
1514 .await
1515 .unwrap();
1516 let job_id: uuid::Uuid = sqlx::query_scalar("SELECT job_id FROM jobs WHERE name = $1")
1517 .bind(CronContextJob::NAME)
1518 .fetch_one(&db)
1519 .await
1520 .unwrap();
1521
1522 let token = crate::jobs::CancellationToken::new();
1523 let worker = tokio::spawn(crate::jobs::worker::job_worker(
1524 state,
1525 cron_context_jobs::Jobs,
1526 Duration::from_millis(20),
1527 3,
1528 token.clone(),
1529 crate::jobs::JobWorkerConfig::default(),
1530 ));
1531 tokio::time::timeout(Duration::from_secs(10), async {
1532 while sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs WHERE job_id = $1")
1533 .bind(job_id)
1534 .fetch_one(&db)
1535 .await
1536 .unwrap()
1537 > 0
1538 {
1539 tokio::time::sleep(Duration::from_millis(20)).await;
1540 }
1541 })
1542 .await
1543 .expect("cron-enqueued job runs");
1544 token.cancel();
1545 worker.await.unwrap().unwrap();
1546
1547 let captured = lines.lock().unwrap().clone();
1548 let span = captured
1549 .iter()
1550 .find(|line| {
1551 line.starts_with("span:worker.run_job") && line.contains(&job_id.to_string())
1552 })
1553 .expect("run span for the cron-enqueued job");
1554 assert!(span.contains("job.context=\"Cron@test\""), "{span}");
1555 for field in [
1556 "job.name",
1557 "job.priority",
1558 "job.run_at",
1559 "job.created_at",
1560 "job.error_count",
1561 ] {
1562 assert!(span.contains(field), "missing {field}: {span}");
1563 }
1564 }
1565
1566 #[sqlx::test]
1567 async fn enqueue_receipt_follows_commit_and_has_parent_span(db: sqlx::PgPool) {
1568 let lines = trace_capture();
1569 let state = TestAppState {
1570 db: db.clone(),
1571 cookie_key: CookieKey::generate(),
1572 };
1573 let mut registry = CronRegistry::new();
1574 registry.register_job(TelemetryJob, None, Duration::from_mins(1));
1575 let worker = crate::cron::Worker::new(state.clone(), registry);
1576 worker.tick().await.unwrap();
1577 let captured = lines.lock().unwrap().clone();
1578 let span = captured
1579 .iter()
1580 .find(|line| line.starts_with("span:jobs.enqueue") && line.contains(TelemetryJob::NAME))
1581 .expect("enqueue span");
1582 assert!(span.contains("parent:Some(\"cron_job.tick\")"), "{span}");
1583 for field in [
1584 "job.id",
1585 "job.name",
1586 "job.context",
1587 "job.priority",
1588 "job.created_at",
1589 "job.run_at",
1590 ] {
1591 assert!(span.contains(field), "missing {field}: {span}");
1592 }
1593 let receipt = captured
1594 .iter()
1595 .find(|line| line.contains("job_enqueued") && line.contains(TelemetryJob::NAME))
1596 .expect("enqueue receipt");
1597 assert!(receipt.contains("jobs.enqueue"), "{receipt}");
1598 let fire =
1599 |line: &&String| line.contains("Enqueuing Task") && line.contains(TelemetryJob::NAME);
1600 let fire_receipt = captured.iter().find(fire).expect("cron fire receipt");
1601 assert!(
1602 fire_receipt.contains("parent:Some(\"jobs.enqueue\")"),
1603 "{fire_receipt}"
1604 );
1605 assert_eq!(
1606 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1607 .fetch_one(&db)
1608 .await
1609 .unwrap(),
1610 1
1611 );
1612
1613 sqlx::query("DELETE FROM jobs").execute(&db).await.unwrap();
1614 sqlx::query("DELETE FROM crons").execute(&db).await.unwrap();
1615 sqlx::query("ALTER TABLE jobs ADD CONSTRAINT test_reject_job CHECK (name <> 'atomic_telemetry_job')")
1616 .execute(&db)
1617 .await
1618 .unwrap();
1619 let start = lines.lock().unwrap().len();
1622 assert!(worker.tick().await.is_err());
1623 let rejected = lines.lock().unwrap()[start..].to_vec();
1624 assert!(
1625 !rejected
1626 .iter()
1627 .any(|line| line.contains("job_enqueued") && line.contains(TelemetryJob::NAME))
1628 );
1629 assert!(!rejected.iter().any(|line| fire(&line)));
1630 assert_eq!(
1631 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM crons")
1632 .fetch_one(&db)
1633 .await
1634 .unwrap(),
1635 0
1636 );
1637 sqlx::query("ALTER TABLE jobs DROP CONSTRAINT test_reject_job")
1638 .execute(&db)
1639 .await
1640 .unwrap();
1641 let start = lines.lock().unwrap().len();
1642 TelemetryJob
1643 .enqueue(state, "ordinary".into(), None)
1644 .await
1645 .unwrap();
1646 let ordinary = lines.lock().unwrap()[start..].to_vec();
1647 assert!(
1648 ordinary
1649 .iter()
1650 .any(|line| line.starts_with("span:jobs.enqueue")
1651 && line.contains("job.context")
1652 && line.contains(TelemetryJob::NAME))
1653 );
1654 assert!(
1655 ordinary
1656 .iter()
1657 .any(|line| line.contains("job_enqueued") && line.contains(TelemetryJob::NAME))
1658 );
1659 }
1660
1661 #[sqlx::test]
1662 async fn job_cron_fire_receipt_once_per_committed_interval(db: sqlx::PgPool) {
1663 let capture = EventCapture::default();
1664 let dispatch = capture.dispatch();
1665 let worker = job_worker(db.clone());
1666 worker
1667 .tick()
1668 .with_subscriber(dispatch.clone())
1669 .await
1670 .unwrap();
1671 let receipts = capture.fire_receipts(TestJob::NAME);
1672 assert_eq!(receipts.len(), 1, "{receipts:?}");
1673 assert_fire_receipt(&receipts[0], TestJob::NAME, None);
1674 assert_eq!(receipts[0].parent.as_deref(), Some("jobs.enqueue"));
1676
1677 worker
1679 .tick()
1680 .with_subscriber(dispatch.clone())
1681 .await
1682 .unwrap();
1683 assert_eq!(capture.fire_receipts(TestJob::NAME).len(), 1);
1684
1685 let previous = backdate(&db, TestJob::NAME, "2 minutes").await;
1686 worker.tick().with_subscriber(dispatch).await.unwrap();
1687 let receipts = capture.fire_receipts(TestJob::NAME);
1688 assert_eq!(receipts.len(), 2, "{receipts:?}");
1689 assert_fire_receipt(&receipts[1], TestJob::NAME, Some(previous));
1690 assert_eq!(receipts[1].parent.as_deref(), Some("jobs.enqueue"));
1691 assert_eq!(
1692 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM jobs")
1693 .fetch_one(&db)
1694 .await
1695 .unwrap(),
1696 2
1697 );
1698 }
1699
1700 #[sqlx::test]
1701 async fn callback_cron_fire_receipt_precedes_callback(db: sqlx::PgPool) {
1702 let capture = EventCapture::default();
1703 let dispatch = capture.dispatch();
1704 let mut registry = receipt_registry();
1705 registry.jobs.retain(|name, _| *name == RECEIPT_CALLBACK);
1706 let state = TestAppState {
1707 db: db.clone(),
1708 cookie_key: CookieKey::generate(),
1709 };
1710 let worker = crate::cron::Worker::new(state, registry);
1711 worker
1712 .tick()
1713 .with_subscriber(dispatch.clone())
1714 .await
1715 .unwrap();
1716 let receipts = capture.fire_receipts(RECEIPT_CALLBACK);
1717 assert_eq!(receipts.len(), 1, "{receipts:?}");
1718 assert_fire_receipt(&receipts[0], RECEIPT_CALLBACK, None);
1719 assert_eq!(receipts[0].parent.as_deref(), Some("cron_job.tick"));
1720
1721 worker
1722 .tick()
1723 .with_subscriber(dispatch.clone())
1724 .await
1725 .unwrap();
1726 assert_eq!(capture.fire_receipts(RECEIPT_CALLBACK).len(), 1);
1727
1728 let previous = backdate(&db, RECEIPT_CALLBACK, "2 minutes").await;
1729 worker.tick().with_subscriber(dispatch).await.unwrap();
1730 let receipts = capture.fire_receipts(RECEIPT_CALLBACK);
1731 assert_eq!(receipts.len(), 2, "{receipts:?}");
1732 assert_fire_receipt(&receipts[1], RECEIPT_CALLBACK, Some(previous));
1733 let order: Vec<String> = capture
1735 .messages()
1736 .into_iter()
1737 .filter(|message| message == "Enqueuing Task" || message == "callback body ran")
1738 .collect();
1739 assert_eq!(
1740 order,
1741 [
1742 "Enqueuing Task",
1743 "callback body ran",
1744 "Enqueuing Task",
1745 "callback body ran"
1746 ]
1747 );
1748 }
1749
1750 #[sqlx::test]
1751 async fn contended_claims_emit_no_fire_receipt(db: sqlx::PgPool) {
1752 let capture = EventCapture::default();
1753 let dispatch = capture.dispatch();
1754 let state = TestAppState {
1755 db: db.clone(),
1756 cookie_key: CookieKey::generate(),
1757 };
1758 let worker = crate::cron::Worker::new(state, receipt_registry());
1759 let mut previous = HashMap::new();
1760 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1761 let at = sqlx::query_scalar::<_, chrono::DateTime<Utc>>("INSERT INTO crons (cron_id, name, last_run_at, created_at, updated_at) VALUES ($1, $2, clock_timestamp() - interval '2 minutes', clock_timestamp(), clock_timestamp()) RETURNING last_run_at")
1762 .bind(uuid::Uuid::new_v4()).bind(name).fetch_one(&db).await.unwrap();
1763 previous.insert(name, at);
1764 }
1765 let mut blocker = db.begin().await.unwrap();
1767 sqlx::query("SELECT 1 FROM crons FOR UPDATE")
1768 .execute(&mut *blocker)
1769 .await
1770 .unwrap();
1771 tokio::time::timeout(
1772 Duration::from_secs(3),
1773 worker.tick().with_subscriber(dispatch.clone()),
1774 )
1775 .await
1776 .unwrap()
1777 .unwrap();
1778 let skipped = capture
1779 .messages()
1780 .iter()
1781 .filter(|message| *message == "Cron claim skipped")
1782 .count();
1783 assert_eq!(skipped, 2, "{:?}", capture.messages());
1784 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1785 assert!(capture.fire_receipts(name).is_empty(), "{name}");
1786 }
1787
1788 blocker.rollback().await.unwrap();
1789 worker.tick().with_subscriber(dispatch).await.unwrap();
1790 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1791 let receipts = capture.fire_receipts(name);
1792 assert_eq!(receipts.len(), 1, "{name}: {receipts:?}");
1793 assert_fire_receipt(&receipts[0], name, Some(previous[name]));
1794 }
1795 }
1796
1797 #[sqlx::test]
1798 async fn uncommitted_claims_emit_no_fire_receipt(db: sqlx::PgPool) {
1799 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1800 .await
1801 .unwrap();
1802 let capture = EventCapture::default();
1803 let dispatch = capture.dispatch();
1804 let state = TestAppState {
1805 db: db.clone(),
1806 cookie_key: CookieKey::generate(),
1807 };
1808 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1809 let mut registry = receipt_registry();
1810 registry.jobs.retain(|registered, _| *registered == name);
1811 let (sender, mut receiver) = tokio::sync::mpsc::channel(1);
1812 let pause = Arc::new(ClaimPause {
1813 claimed: sender,
1814 release: tokio::sync::Notify::new(),
1815 });
1816 registry.jobs.get_mut(name).unwrap().pause_after_claim = Some(pause.clone());
1817 let worker = crate::cron::Worker::new(state.clone(), registry);
1818 let task =
1819 tokio::spawn(async move { worker.tick().await }.with_subscriber(dispatch.clone()));
1820 let pid = tokio::time::timeout(Duration::from_secs(3), receiver.recv())
1821 .await
1822 .unwrap()
1823 .unwrap();
1824 assert!(
1826 sqlx::query_scalar::<_, bool>("SELECT pg_terminate_backend($1)")
1827 .bind(pid)
1828 .fetch_one(&other)
1829 .await
1830 .unwrap()
1831 );
1832 pause.release.notify_one();
1833 tokio::time::timeout(Duration::from_secs(3), task)
1834 .await
1835 .unwrap()
1836 .unwrap()
1837 .unwrap();
1838 assert!(capture.fire_receipts(name).is_empty(), "{name}");
1839 }
1840 assert_eq!(
1841 sqlx::query_scalar::<_, i64>("SELECT count(*) FROM crons")
1842 .fetch_one(&db)
1843 .await
1844 .unwrap(),
1845 0
1846 );
1847
1848 crate::cron::Worker::new(state, receipt_registry())
1849 .tick()
1850 .with_subscriber(dispatch)
1851 .await
1852 .unwrap();
1853 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1854 let receipts = capture.fire_receipts(name);
1855 assert_eq!(receipts.len(), 1, "{name}: {receipts:?}");
1856 assert_fire_receipt(&receipts[0], name, None);
1857 }
1858 }
1859
1860 #[sqlx::test]
1861 async fn two_pools_emit_one_fire_receipt_per_interval(db: sqlx::PgPool) {
1862 let other = sqlx::PgPool::connect_with((*db.connect_options()).clone())
1863 .await
1864 .unwrap();
1865 let capture = EventCapture::default();
1866 let dispatch = capture.dispatch();
1867 let make_worker = |pool| {
1868 let state = TestAppState {
1869 db: pool,
1870 cookie_key: CookieKey::generate(),
1871 };
1872 crate::cron::Worker::new(state, receipt_registry())
1873 };
1874 let first = make_worker(db.clone());
1875 let second = make_worker(other);
1876 let mut previous = HashMap::new();
1877 for interval in 1..=3 {
1878 if interval > 1 {
1879 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1880 previous.insert(name, backdate(&db, name, "2 minutes").await);
1881 }
1882 }
1883 let barrier = Arc::new(tokio::sync::Barrier::new(3));
1884 let (a, b, _) = async {
1885 tokio::join!(
1886 async {
1887 barrier.wait().await;
1888 first.tick().await
1889 },
1890 async {
1891 barrier.wait().await;
1892 second.tick().await
1893 },
1894 barrier.wait(),
1895 )
1896 }
1897 .with_subscriber(dispatch.clone())
1898 .await;
1899 a.unwrap();
1900 b.unwrap();
1901 for name in [TestJob::NAME, RECEIPT_CALLBACK] {
1902 let receipts = capture.fire_receipts(name);
1903 assert_eq!(receipts.len(), interval, "{name}: {receipts:?}");
1904 assert_fire_receipt(receipts.last().unwrap(), name, previous.get(name).copied());
1905 }
1906 }
1907 }
1908
1909 #[sqlx::test]
1910 async fn test_tick_creates_new_cron_record(db: sqlx::PgPool) {
1911 let app_state = TestAppState {
1912 db: db.clone(),
1913 cookie_key: CookieKey::generate(),
1914 };
1915 let mut registry = CronRegistry::new();
1916 registry.register_job(TestJob, None, Duration::from_secs(1));
1917
1918 let cron_job = registry.jobs.get(TestJob::NAME).unwrap();
1919 assert_eq!(cron_job.name, TestJob::NAME);
1920 assert!(
1921 matches!(cron_job.schedule, Schedule::Interval(IntervalSchedule(d)) if d == Duration::from_secs(1))
1922 );
1923
1924 let worker = crate::cron::Worker::new(app_state.clone(), registry);
1925
1926 let existing_record =
1927 sqlx::query!("SELECT cron_id FROM Crons where name = $1", TestJob::NAME)
1928 .fetch_optional(&app_state.db)
1929 .await
1930 .unwrap();
1931 assert!(
1932 existing_record.is_none(),
1933 "Record should not exist {}",
1934 existing_record.unwrap().cron_id
1935 );
1936
1937 worker.tick().await.unwrap();
1938
1939 let last_run = sqlx::query!(
1940 "SELECT last_run_at FROM Crons WHERE name = $1",
1941 TestJob::NAME
1942 )
1943 .fetch_one(&app_state.db)
1944 .await
1945 .unwrap();
1946
1947 let now = Utc::now();
1948 let last_run_at = last_run.last_run_at;
1949 let diff = now.signed_duration_since(last_run_at);
1950 assert!(diff.num_milliseconds() < 1000);
1951 }
1952
1953 #[sqlx::test]
1954 async fn test_tick_skips_updating_existing_cron_record(db: sqlx::PgPool) {
1955 let app_state = TestAppState {
1956 db: db.clone(),
1957 cookie_key: CookieKey::generate(),
1958 };
1959 let mut registry = CronRegistry::new();
1960 registry.register_job(TestJob, None, Duration::from_mins(1));
1961 let worker = crate::cron::Worker::new(app_state.clone(), registry);
1962
1963 let previously = Utc::now();
1964 sqlx::query!(
1965 "INSERT INTO Crons (cron_id, name, last_run_at, created_at, updated_at)
1966 VALUES ($1, $2, $3, $3, $3)
1967 ON CONFLICT (name)
1968 DO UPDATE SET
1969 last_run_at = $3",
1970 uuid::Uuid::new_v4(),
1971 TestJob::NAME,
1972 previously
1973 )
1974 .execute(&app_state.db)
1975 .await
1976 .unwrap();
1977
1978 worker.tick().await.unwrap();
1979
1980 let last_run = sqlx::query!(
1981 "SELECT last_run_at FROM Crons WHERE name = $1",
1982 TestJob::NAME
1983 )
1984 .fetch_one(&app_state.db)
1985 .await
1986 .unwrap();
1987
1988 let diff = last_run.last_run_at.signed_duration_since(previously);
1989 assert!(diff.num_milliseconds() < 50);
1990 }
1991
1992 #[sqlx::test]
1993 async fn test_tick_updates_cron_record_when_interval_elapsed(db: sqlx::PgPool) {
1994 let app_state = TestAppState {
1995 db: db.clone(),
1996 cookie_key: CookieKey::generate(),
1997 };
1998 let mut registry = CronRegistry::new();
1999 registry.register_job(TestJob, None, Duration::from_secs(1));
2000 let worker = crate::cron::Worker::new(app_state.clone(), registry);
2001
2002 let two_seconds_ago = Utc::now() - chrono::Duration::seconds(2);
2003 sqlx::query!(
2004 "INSERT INTO Crons (cron_id, name, last_run_at, created_at, updated_at)
2005 VALUES ($1, $2, $3, $3, $3)",
2006 uuid::Uuid::new_v4(),
2007 TestJob::NAME,
2008 two_seconds_ago
2009 )
2010 .execute(&app_state.db)
2011 .await
2012 .unwrap();
2013
2014 worker.tick().await.unwrap();
2015
2016 let last_run = sqlx::query!(
2017 "SELECT last_run_at FROM Crons WHERE name = $1",
2018 TestJob::NAME
2019 )
2020 .fetch_one(&app_state.db)
2021 .await
2022 .unwrap();
2023
2024 assert!(last_run.last_run_at > two_seconds_ago);
2025 let diff = Utc::now().signed_duration_since(last_run.last_run_at);
2026 assert!(diff.num_milliseconds() < 1000);
2027 }
2028
2029 #[sqlx::test]
2030 async fn test_tick_enqueues_failing_job_successfully(db: sqlx::PgPool) {
2031 let app_state = TestAppState {
2032 db: db.clone(),
2033 cookie_key: CookieKey::generate(),
2034 };
2035 let mut registry = CronRegistry::new();
2036 registry.register_job(FailingJob, None, Duration::from_secs(1));
2037
2038 let cron_job = registry.jobs.get(FailingJob::NAME).unwrap();
2039 let last_enqueue_map = HashMap::new();
2040 let worker_started_at = Utc::now();
2041
2042 let result = cron_job
2043 .tick(
2044 app_state.clone(),
2045 &last_enqueue_map,
2046 worker_started_at,
2047 chrono_tz::UTC,
2048 )
2049 .await;
2050 assert!(result.is_ok());
2051
2052 let cron_record = sqlx::query!(
2053 "SELECT last_run_at FROM Crons WHERE name = $1",
2054 FailingJob::NAME
2055 )
2056 .fetch_one(&app_state.db)
2057 .await
2058 .unwrap();
2059
2060 let now = Utc::now();
2061 let diff = now.signed_duration_since(cron_record.last_run_at);
2062 assert!(diff.num_milliseconds() < 1000);
2063
2064 let job_count = sqlx::query!(
2065 "SELECT COUNT(*) as count FROM jobs WHERE name = $1",
2066 FailingJob::NAME
2067 )
2068 .fetch_one(&app_state.db)
2069 .await
2070 .unwrap();
2071 assert_eq!(job_count.count.unwrap(), 1);
2072 }
2073
2074 #[sqlx::test]
2075 async fn test_tick_with_custom_function_error(db: sqlx::PgPool) {
2076 let app_state = TestAppState {
2077 db: db.clone(),
2078 cookie_key: CookieKey::generate(),
2079 };
2080 #[derive(Debug, thiserror::Error)]
2081 #[error("Custom function error")]
2082 struct CustomError;
2083
2084 let mut registry = CronRegistry::new();
2085 registry.register(
2086 "custom_failing",
2087 None,
2088 Duration::from_secs(1),
2089 |_app_state, _context| Box::pin(async { Err(CustomError) }),
2090 );
2091
2092 let cron_job = registry.jobs.get("custom_failing").unwrap();
2093 let last_enqueue_map = HashMap::new();
2094 let worker_started_at = Utc::now();
2095
2096 let result = cron_job
2097 .tick(
2098 app_state.clone(),
2099 &last_enqueue_map,
2100 worker_started_at,
2101 chrono_tz::UTC,
2102 )
2103 .await;
2104 assert!(result.is_err());
2105 match result.unwrap_err() {
2106 TickError::JobError(err) => {
2107 assert!(err.contains("CustomError"));
2108 }
2109 TickError::SqlxError(_) => panic!("Expected JobError"),
2110 }
2111
2112 let cron_count = sqlx::query!(
2113 "SELECT COUNT(*) as count FROM Crons WHERE name = $1",
2114 "custom_failing"
2115 )
2116 .fetch_one(&app_state.db)
2117 .await
2118 .unwrap();
2119 assert_eq!(cron_count.count.unwrap(), 1);
2120 }
2121
2122 #[sqlx::test]
2123 async fn test_worker_tick_with_multiple_jobs(db: sqlx::PgPool) {
2124 let app_state = TestAppState {
2125 db: db.clone(),
2126 cookie_key: CookieKey::generate(),
2127 };
2128 let mut registry = CronRegistry::new();
2129 registry.register_job(TestJob, None, Duration::from_secs(1));
2130 registry.register_job(SecondTestJob, None, Duration::from_secs(1));
2131
2132 assert_eq!(registry.jobs.len(), 2);
2133
2134 let worker = crate::cron::Worker::new(app_state.clone(), registry);
2135
2136 worker.tick().await.unwrap();
2137
2138 let test_job_record = sqlx::query!(
2139 "SELECT last_run_at FROM Crons WHERE name = $1",
2140 TestJob::NAME
2141 )
2142 .fetch_one(&app_state.db)
2143 .await
2144 .unwrap();
2145
2146 let second_job_record = sqlx::query!(
2147 "SELECT last_run_at FROM Crons WHERE name = $1",
2148 SecondTestJob::NAME
2149 )
2150 .fetch_one(&app_state.db)
2151 .await
2152 .unwrap();
2153
2154 let now = Utc::now();
2155 let diff1 = now.signed_duration_since(test_job_record.last_run_at);
2156 let diff2 = now.signed_duration_since(second_job_record.last_run_at);
2157
2158 assert!(diff1.num_milliseconds() < 1000);
2159 assert!(diff2.num_milliseconds() < 1000);
2160 }
2161
2162 #[sqlx::test]
2163 async fn test_worker_respects_existing_last_run_times(db: sqlx::PgPool) {
2164 let app_state = TestAppState {
2165 db: db.clone(),
2166 cookie_key: CookieKey::generate(),
2167 };
2168 let mut registry = CronRegistry::new();
2169 registry.register_job(TestJob, None, Duration::from_secs(10));
2170 registry.register_job(SecondTestJob, None, Duration::from_secs(5));
2171
2172 let worker = crate::cron::Worker::new(app_state.clone(), registry);
2173
2174 let recent_time = Utc::now() - chrono::Duration::seconds(3);
2175 let old_time = Utc::now() - chrono::Duration::seconds(10);
2176
2177 sqlx::query!(
2178 "INSERT INTO Crons (cron_id, name, last_run_at, created_at, updated_at)
2179 VALUES ($1, $2, $3, $3, $3)",
2180 uuid::Uuid::new_v4(),
2181 TestJob::NAME,
2182 recent_time
2183 )
2184 .execute(&app_state.db)
2185 .await
2186 .unwrap();
2187
2188 sqlx::query!(
2189 "INSERT INTO Crons (cron_id, name, last_run_at, created_at, updated_at)
2190 VALUES ($1, $2, $3, $3, $3)",
2191 uuid::Uuid::new_v4(),
2192 SecondTestJob::NAME,
2193 old_time
2194 )
2195 .execute(&app_state.db)
2196 .await
2197 .unwrap();
2198
2199 worker.tick().await.unwrap();
2200
2201 let test_job_record = sqlx::query!(
2202 "SELECT last_run_at FROM Crons WHERE name = $1",
2203 TestJob::NAME
2204 )
2205 .fetch_one(&app_state.db)
2206 .await
2207 .unwrap();
2208
2209 let second_job_record = sqlx::query!(
2210 "SELECT last_run_at FROM Crons WHERE name = $1",
2211 SecondTestJob::NAME
2212 )
2213 .fetch_one(&app_state.db)
2214 .await
2215 .unwrap();
2216
2217 let recent_diff = test_job_record
2218 .last_run_at
2219 .signed_duration_since(recent_time);
2220 assert!(recent_diff.num_milliseconds() < 100);
2221 assert!(second_job_record.last_run_at > old_time);
2222 }
2223
2224 #[sqlx::test]
2225 async fn test_tick_handles_future_last_run_time(db: sqlx::PgPool) {
2226 let app_state = TestAppState {
2227 db: db.clone(),
2228 cookie_key: CookieKey::generate(),
2229 };
2230 let mut registry = CronRegistry::new();
2231 registry.register_job(TestJob, None, Duration::from_secs(1));
2232
2233 let cron_job = registry.jobs.get(TestJob::NAME).unwrap();
2234
2235 let future_time = Utc::now() + chrono::Duration::hours(1);
2236 let mut last_enqueue_map = HashMap::new();
2237 last_enqueue_map.insert(TestJob::NAME.to_string(), future_time);
2238 let worker_started_at = Utc::now();
2239
2240 let result = cron_job
2241 .tick(
2242 app_state.clone(),
2243 &last_enqueue_map,
2244 worker_started_at,
2245 chrono_tz::UTC,
2246 )
2247 .await;
2248
2249 assert!(result.is_ok());
2251
2252 let cron_count = sqlx::query!(
2253 "SELECT COUNT(*) as count FROM Crons WHERE name = $1",
2254 TestJob::NAME
2255 )
2256 .fetch_one(&app_state.db)
2257 .await
2258 .unwrap();
2259 assert_eq!(
2260 cron_count.count.unwrap(),
2261 0,
2262 "Should not have created cron record with future last_run time"
2263 );
2264 }
2265
2266 #[sqlx::test]
2267 async fn test_cron_expression_scheduling(db: sqlx::PgPool) {
2268 let app_state = TestAppState {
2269 db: db.clone(),
2270 cookie_key: CookieKey::generate(),
2271 };
2272 let mut registry = CronRegistry::new();
2273
2274 registry
2276 .register_job_with_cron(TestJob, None, "0 * * * * * *")
2277 .unwrap();
2278
2279 let cron_job = registry.jobs.get(TestJob::NAME).unwrap();
2280 assert!(matches!(cron_job.schedule, Schedule::Cron(_)));
2281
2282 let last_enqueue_map = HashMap::new();
2284 let worker_started_at = Utc::now() - chrono::Duration::minutes(2);
2286 let result = cron_job
2287 .tick(
2288 app_state.clone(),
2289 &last_enqueue_map,
2290 worker_started_at,
2291 chrono_tz::UTC,
2292 )
2293 .await;
2294 assert!(result.is_ok());
2295
2296 let cron_record = sqlx::query!(
2298 "SELECT last_run_at FROM Crons WHERE name = $1",
2299 TestJob::NAME
2300 )
2301 .fetch_optional(&app_state.db)
2302 .await
2303 .unwrap();
2304
2305 assert!(cron_record.is_some());
2307 if let Some(record) = cron_record {
2308 let now = Utc::now();
2309 let diff = now.signed_duration_since(record.last_run_at);
2310 assert!(diff.num_milliseconds() < 1000);
2311 }
2312 }
2313
2314 #[sqlx::test]
2315 async fn test_cron_expression_respects_schedule(db: sqlx::PgPool) {
2316 let app_state = TestAppState {
2317 db: db.clone(),
2318 cookie_key: CookieKey::generate(),
2319 };
2320 let mut registry = CronRegistry::new();
2321
2322 registry
2324 .register_job_with_cron(TestJob, None, "0 30 * * * * *")
2325 .unwrap();
2326
2327 let cron_job = registry.jobs.get(TestJob::NAME).unwrap();
2328
2329 let last_run = Utc::now() - chrono::Duration::minutes(29);
2331 let mut last_enqueue_map = HashMap::new();
2332 last_enqueue_map.insert(TestJob::NAME.to_string(), last_run);
2333
2334 let worker_started_at = Utc::now();
2337 let result = cron_job
2338 .tick(
2339 app_state.clone(),
2340 &last_enqueue_map,
2341 worker_started_at,
2342 chrono_tz::UTC,
2343 )
2344 .await;
2345 assert!(result.is_ok());
2346 }
2347
2348 #[test]
2349 fn test_invalid_cron_expression() {
2350 let mut registry: CronRegistry<TestAppState> = CronRegistry::new();
2351
2352 let result = registry.register_with_cron(
2354 "invalid_cron",
2355 None,
2356 "invalid expression",
2357 |_app_state, _context| Box::pin(async { Ok::<(), std::io::Error>(()) }),
2358 );
2359
2360 assert!(result.is_err());
2361 }
2362
2363 #[sqlx::test]
2364 async fn test_mixed_interval_and_cron_jobs(db: sqlx::PgPool) {
2365 let app_state = TestAppState {
2366 db: db.clone(),
2367 cookie_key: CookieKey::generate(),
2368 };
2369 let mut registry = CronRegistry::new();
2370
2371 registry.register_job(TestJob, None, Duration::from_secs(1));
2373
2374 registry
2376 .register_job_with_cron(SecondTestJob, None, "* * * * * * *")
2377 .unwrap();
2378
2379 assert_eq!(registry.jobs.len(), 2);
2380
2381 let interval_job = registry.jobs.get(TestJob::NAME).unwrap();
2382 assert!(matches!(interval_job.schedule, Schedule::Interval(_)));
2383
2384 let cron_job = registry.jobs.get(SecondTestJob::NAME).unwrap();
2385 assert!(matches!(cron_job.schedule, Schedule::Cron(_)));
2386
2387 let mut worker = crate::cron::Worker::new(app_state.clone(), registry);
2389 worker.started_at = Utc::now() - chrono::Duration::seconds(2);
2390
2391 worker.tick().await.unwrap();
2393
2394 let test_job_count = sqlx::query!(
2395 "SELECT COUNT(*) as count FROM Crons WHERE name = $1",
2396 TestJob::NAME
2397 )
2398 .fetch_one(&app_state.db)
2399 .await
2400 .unwrap();
2401
2402 let second_job_count = sqlx::query!(
2403 "SELECT COUNT(*) as count FROM Crons WHERE name = $1",
2404 SecondTestJob::NAME
2405 )
2406 .fetch_one(&app_state.db)
2407 .await
2408 .unwrap();
2409
2410 assert_eq!(test_job_count.count.unwrap(), 1);
2411 assert_eq!(second_job_count.count.unwrap(), 1);
2412 }
2413
2414 #[test]
2415 fn test_entries_lists_names_and_schedule_strings() {
2416 let mut registry: CronRegistry<TestAppState> = CronRegistry::new();
2417
2418 registry.register(
2419 "interval_job",
2420 None,
2421 Duration::from_mins(5),
2422 |_app_state, _context| Box::pin(async { Ok::<(), std::io::Error>(()) }),
2423 );
2424 registry
2425 .register_with_cron(
2426 "cron_expr_job",
2427 None,
2428 "0 0 9 * * * *",
2429 |_app_state, _context| Box::pin(async { Ok::<(), std::io::Error>(()) }),
2430 )
2431 .unwrap();
2432
2433 let entries = registry.entries();
2434 assert_eq!(
2435 entries,
2436 vec![
2437 ("cron_expr_job", "0 0 9 * * * *".to_string()),
2438 ("interval_job", "300s".to_string()),
2439 ]
2440 );
2441 }
2442
2443 #[sqlx::test]
2449 async fn test_long_interval_last_run_only_advances_on_fire(db: sqlx::PgPool) {
2450 let app_state = TestAppState {
2451 db: db.clone(),
2452 cookie_key: CookieKey::generate(),
2453 };
2454 let mut registry = CronRegistry::new();
2455 registry.register_job(TestJob, None, Duration::from_mins(5));
2457 let worker = crate::cron::Worker::new(app_state.clone(), registry);
2458
2459 let two_minutes_ago = Utc::now() - chrono::Duration::minutes(2);
2461 sqlx::query!(
2462 "INSERT INTO Crons (cron_id, name, last_run_at, created_at, updated_at)
2463 VALUES ($1, $2, $3, $3, $3)",
2464 uuid::Uuid::new_v4(),
2465 TestJob::NAME,
2466 two_minutes_ago
2467 )
2468 .execute(&app_state.db)
2469 .await
2470 .unwrap();
2471
2472 for _ in 0..3 {
2474 worker.tick().await.unwrap();
2475
2476 let last_run = sqlx::query!(
2477 "SELECT last_run_at FROM Crons WHERE name = $1",
2478 TestJob::NAME
2479 )
2480 .fetch_one(&app_state.db)
2481 .await
2482 .unwrap();
2483
2484 let drift = last_run
2485 .last_run_at
2486 .signed_duration_since(two_minutes_ago)
2487 .num_milliseconds()
2488 .abs();
2489 assert!(
2490 drift < 50,
2491 "last_run_at must not advance on non-firing ticks (drifted {drift}ms)"
2492 );
2493 }
2494
2495 let job_count = sqlx::query!(
2497 "SELECT COUNT(*) as count FROM jobs WHERE name = $1",
2498 TestJob::NAME
2499 )
2500 .fetch_one(&app_state.db)
2501 .await
2502 .unwrap();
2503 assert_eq!(job_count.count.unwrap(), 0);
2504
2505 let six_minutes_ago = Utc::now() - chrono::Duration::minutes(6);
2507 sqlx::query!(
2508 "UPDATE Crons SET last_run_at = $1 WHERE name = $2",
2509 six_minutes_ago,
2510 TestJob::NAME
2511 )
2512 .execute(&app_state.db)
2513 .await
2514 .unwrap();
2515
2516 worker.tick().await.unwrap();
2517
2518 let last_run = sqlx::query!(
2519 "SELECT last_run_at FROM Crons WHERE name = $1",
2520 TestJob::NAME
2521 )
2522 .fetch_one(&app_state.db)
2523 .await
2524 .unwrap();
2525 assert!(
2526 last_run.last_run_at > six_minutes_ago,
2527 "cron should fire once the interval has elapsed"
2528 );
2529 let diff = Utc::now().signed_duration_since(last_run.last_run_at);
2530 assert!(diff.num_milliseconds() < 1000);
2531
2532 let job_count = sqlx::query!(
2533 "SELECT COUNT(*) as count FROM jobs WHERE name = $1",
2534 TestJob::NAME
2535 )
2536 .fetch_one(&app_state.db)
2537 .await
2538 .unwrap();
2539 assert_eq!(job_count.count.unwrap(), 1);
2540 }
2541}