SkinbaseNova/docs/optimization-m1-recommendation-jobs.md

# M1 — Nightly recommendation job failures

## 1. Executive Summary

Production Horizon marks `RecComputeSimilarByBehaviorJob` and `RecComputeSimilarHybridJob` failed every night with `MaxAttemptsExceededException` at **~02:18** and **~02:31**.

This is **not** the old 90-second Supervisor `queue:work` timeout. Production uses Horizon workers with **timeout=960**. The Redis queue connection has **`retry_after=90`**. A still-running nightly rebuild is treated as abandoned, re-queued, and Horizon `--tries=1` fails it.

```text
ROOT-H — Redis retry_after (90s) shorter than job runtime, interacting with Horizon tries=1
         and a single-job full-catalog scan (~50k artworks).
```

Local fix (not deployed):

1. Default `queue.connections.redis.retry_after` **1080** (> Horizon 960).
2. Fan-out Behavior and Hybrid rebuilds into cursor batches of 200, matching `RecComputeSimilarByTagsJob` (already chunked in production).

Mail queue `LLEN=3` is **deferred** (not entangled).

---

## 2. Production Symptom

```text
failed_jobs ≈ 329
RecComputeSimilarByBehaviorJob  ~02:18 daily
RecComputeSimilarHybridJob      ~02:31 daily
exception: Illuminate\Queue\MaxAttemptsExceededException
           "... has been attempted too many times."
```

Schedule (Europe/Ljubljana):

| Job | dailyAt |
| --- | ------- |
| RecComputeSimilarByTagsJob | 02:00 |
| RecComputeSimilarByBehaviorJob | 02:15 |
| RecComputeSimilarHybridJob | 02:30 |

Tags does **not** appear in the nightly failure list (already cursor-batched).

---

## 3. Production Evidence

PRODUCTION SERVER (`ssh server3`, read-only):

- `config('queue.connections.redis.retry_after')` = **90**
- `config('horizon.defaults.supervisor-default.timeout')` = **960**
- Horizon worker: `--queue=search --timeout=960 --tries=1 --memory=128`
- `recommendations.queue` = `default`
- CLI `memory_limit` = `-1` (Horizon 128 MB is post-job worker recycle, not the kill mechanism at 90s)
- Failed exception text is MaxAttemptsExceeded **without** a wrapped `TimeoutExceededException` / memory error
- Timing:

```text
Behavior  02:15 dispatch → fail ~02:18  (~180s or ~90s after the minute the scheduler actually queued it)
Hybrid    02:30 dispatch → fail ~02:31:33  (≈ retry_after 90s)
```

Laravel Redis queues use `retry_after` as the reservation TTL. If the job is still reserved after 90s, Redis exposes it again. The next pop has `attempts=2`. Horizon `--tries=1` then raises `MaxAttemptsExceededException` **before** the job body runs.

That matches the Hybrid `tries=1` failure ~90 seconds after start. Behavior’s class `$tries=2` is overridden by the worker `--tries=1`.

No production files, jobs, or services were changed during M1.

---

## 4. Local vs Production Code

| Item | Production `5af95f65` | Local `f52879ed` (before M1) |
| ---- | --------------------- | ---------------------------- |
| RecComputeSimilarByBehaviorJob | `$tries=2`, `$timeout=600`, **full `chunkById` catalog** | same |
| RecComputeSimilarHybridJob | `$tries=1`, `$timeout=900`, **full catalog**, WithoutOverlapping only per-artwork | same |
| RecComputeSimilarByTagsJob | cursor `afterArtworkId` batches of 200 | same |
| redis retry_after | 90 | 90 |

Local did **not** already contain this fix. M1 implements it.

---

## 5. Job Architecture (after M1)

Nightly catalog rebuild (`artworkId=null`):

```text
load ≤ batchSize artworks after cursor
→ process each
→ if batch full, dispatch next job with afterArtworkId = last id
```

Per-artwork rebuilds (observers) unchanged: Hybrid still uses `WithoutOverlapping` + `dontRelease()`.

| Job | tries | timeout | batch |
| --- | ----: | ------: | ----: |
| Behavior | 2 | 120s | 200 |
| Hybrid | 1 | 180s | 200 |
| Tags | 2 | 600s | 200 (already) |

---

## 6. Scheduler Flow

Unchanged. `Schedule::job(...)->dailyAt(...)->withoutOverlapping()`.

Behavior and Hybrid still start at 02:15 / 02:30; work continues as chained queue jobs instead of one 15+ minute reservation.

Root crontab that invokes `schedule:run` remains unseen (sudo). Empirical evidence (nightly fails + 10:30 sitemap files) shows the scheduler **is** running.

---

## 7. Horizon Configuration

Production supervisors unchanged in M1 (no deploy).

Local comment on `supervisor-default.timeout` now documents that **`retry_after` must exceed 960**.

Horizon `tries=1` remains. Batch jobs should finish well under 90s; `retry_after=1080` is the safety net for any remaining long job.

---

## 8. Failed Job Analysis

Grouped: Behavior then Hybrid, every night, same exception. No payload dump. No evidence of immediate SQL exception (would usually wrap a QueryException). No SIGKILL/memory lines inspected in failed_jobs. Horizon log at inspection time showed healthy `IndexUserJob` / Scout jobs, not the 02:xx window.

---

## 9. Lock / Middleware Analysis

Full-catalog Behavior: **no** WithoutOverlapping.

Full-catalog Hybrid: `middleware()` returns `[]` when `artworkId === null`. **Not** the failure path.

Scheduler `withoutOverlapping()` would **skip** dispatch, not fail a job.

**Disproved:** `$tries=1` + WithoutOverlapping release as the nightly cause.

**Proved:** Redis reservation TTL 90s vs long-running catalog job.

---

## 10. Runtime / Memory Analysis

PHP CLI memory is unlimited. Horizon `--memory=128` typically exits **after** a job. A 50k-artwork in-memory scan could still grow, but the 90-second fail clock is Redis, not 128 MB.

After chunking, each batch holds 200 models + pair rows, similar to the tags job that already succeeds.

---

## 11. Query Analysis

Behavior, per artwork:

- `UNION` on `rec_item_pairs` (`a_artwork_id` / `b_artwork_id` indexed)
- `artworks` `whereIn` related ids
- `updateOrCreate` on `rec_artwork_recs`

~50k × 3 queries in **one** reservation was unbounded vs 90s.

No new index in M1. Chunking reduces reservation time; query shape unchanged.

---

## 12. Root Cause Classification

```text
ROOT-H — Redis retry_after=90s < running catalog job
         + Horizon --tries=1
         + Behavior/Hybrid process the full catalog in one job
```

Not ROOT-C (memory) as primary. Not ROOT-B (900s timeout) as the **observed** fail time (~90s). After fixing retry_after alone, ROOT-B could appear next (~600–900s). Chunking prevents that.

---

## 13. Fix

1. `config/queue.php` redis `retry_after` default **1080** (`REDIS_QUEUE_RETRY_AFTER`).
2. `.env.example` documents the production requirement.
3. Behavior + Hybrid catalog runs use the same cursor fan-out as Tags.
4. Structured batch logs: `duration_ms`, `memory_mb`, `processed`, `has_more` (no PII).
5. Per-artwork try/catch on Behavior (Hybrid already had it).

Correctness: same scoring/persist per artwork; batches are sequential by `id`. Idempotent `updateOrCreate`.

---

## 14. Files Changed

```text
config/queue.php
config/horizon.php
.env.example
app/Jobs/RecComputeSimilarByBehaviorJob.php
app/Jobs/RecComputeSimilarHybridJob.php
tests/Unit/Jobs/RecComputeSimilarByBehaviorJobTest.php
tests/Unit/Jobs/RecComputeSimilarHybridJobTest.php
tests/Feature/Recommendations/RecComputeSimilarJobsTest.php
docs/optimization-m1-recommendation-jobs.md
```

No migrations.

---

## 15. Tests

```text
php artisan test --filter=RecComputeSimilar
Tests:    13 passed (16 assertions)
Duration: 15.67s
```

Covers retry_after vs Horizon timeout, cursor dispatch, partial batch no-dispatch, hybrid idempotency.

Full suite not re-run (known unrelated failures from earlier audits).

---

## 16. Performance Impact

Expected: many short default-queue jobs (~50k/200 ≈ 250 Behavior + 250 Hybrid) instead of two 15-minute jobs. Worker slots free between batches. Redis no longer duplicates in-flight catalog jobs.

---

## 17. Correctness Impact

Same rec lists; order of artwork processing remains increasing `id`. A crash mid-chain can resume by re-dispatching from the last completed cursor (or wait for the next night). No silent catch-all.

---

## 18. Deployment Requirements

```text
1. Deploy this release (includes config/queue.php).
2. Set production .env REDIS_QUEUE_RETRY_AFTER=1080 if you pin the value
   (default in config is already 1080 if unset).
3. php artisan config:cache (normal deploy optimize).
4. Restart Horizon via the usual Supervisor restart / queue:restart.
```

Without restarting Horizon, workers keep old cached config.

---

## 19. Post-Deploy Verification

```text
1. php artisan horizon:status → running
2. php artisan tinker: config('queue.connections.redis.retry_after') === 1080
3. Next night: no new MaxAttemptsExceeded for RecComputeSimilarByBehavior/Hybrid
4. rec_artwork_recs computed_at advances for similar_behavior and similar_hybrid
5. Horizon log: "[RecComputeSimilarByBehavior] Batch complete" with has_more true then false
6. failed_jobs count not increasing for these classes
7. Optional: sample duration_ms / memory_mb
```

Do not retry the 329 historical failures unless product wants a one-off backfill; they are the old reservation pattern.

---

## 20. Rollback Plan

```text
- Roll back the release symlink / previous release
- config:cache + Horizon restart
- No DB migration to roll back
- Cursor jobs in flight may still complete; safe
- No Redis lock cleanup required for catalog jobs
```

---

## 21. Deferred Findings

```text
DEFER TO M2/M1B: queues:mail LLEN=3, Horizon does not consume `mail`
DEFER: sitemap index stale
DEFER: artwork_metric_snapshots_hourly size
DEFER: swap / FPM / Sentry sample rates
```

---

## 22. Remaining Unknowns

- Exact `schedule:run` crontab user (sudo required)
- Whether any Behavior run ever reached the 600s job timeout (masked by 90s retry_after)
- Historical failed_jobs payloads not inspected (by design)