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.

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

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:

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):

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

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

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

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

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

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

- 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

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)