# Spec 051 — Launch Monitoring Pack (T6.4)

Log-based checks and SQL probes for the launch monitoring dashboard/alerts.
Each entry states its data source, whether it is usable TODAY or only once a
parallel phase lands, and — where a live DB signal exists — a query proven
against the real schema.

**T7 merge note:** this file was drafted in the T6 parallel track, before T3
(invite delivery) had landed — §4-6 below originally marked their probes
"awaiting T3" and pointed at a log path (`logs/buyerkiosk_com.php.error.log`)
that turned out not to exist in this checkout. T3 has since merged and
[`051-invite-observability.md`](./051-invite-observability.md) re-ran every
one of those probes for real (seeded data, live output) and corrected the log
path to `logs/webhook-delivery.log`. Rather than duplicate that content, §4-6
here now point to that file as the canonical, executed version — no
contradictions remain between the two docs. Sections 1-3 (hub latency,
stale-detector counter, activation-abuse) are unaffected by T3 and remain
authoritative here.

---

## 1. Hub endpoint latency

**Target:** NFR-1, hub p95 ≤ 2s.

**Status:** partially usable today; the PRIMARY signal (`Server-Timing`)
lands with T8.3, not this phase. This entry documents the access_log
fallback recipe.

The current Apache log format (`CustomLog .../access_log common`, per
`httpd-vhosts.conf`) is the standard Common Log Format, which does **not**
include request duration:

```
127.0.0.1 - - [03/Jul/2025:08:00:47 -0500] "GET /admin/pc00/schedule/get-started HTTP/1.1" 200 47812
```

No `%D`/`%T` timing token exists in this format today — this is a genuine
gap, not something this recipe can work around. **Required ops action before
this probe is usable:** add a timing token to the vhost `LogFormat`, e.g.:

```apache
LogFormat "%h %l %u %t \"%r\" %>s %b %D" common_with_timing
CustomLog "/Users/rvanvuren/Projects/buyerkiosk-web/logs/access_log" common_with_timing
```

(`%D` = request duration in microseconds.) Once that lands, the p95 recipe
for the hub state endpoint is:

```bash
grep 'GET /api/.*/schedule/onboarding/state' logs/access_log \
  | awk '{print $NF}' \
  | sort -n \
  | awk '{a[NR]=$1} END {print a[int(NR*0.95)] / 1000 " ms (p95)"}'
```

Until the LogFormat change lands, use the SDD's own documented method
instead: **Server-Timing header, sampled in production** (NFR-1's stated
real-p95 method) — this is a T8.3 deliverable, tracked here as the
authoritative source once it exists. Do not treat the absence of this probe
as a launch blocker; it is explicitly a T8.3 gate item, not T6.

---

## 2. Stale-detector counter

**Target:** M3-08 / NFR-2 — detection freshness within 5 minutes.

**Status:** usable TODAY — `onboardingObservations.lastSuccessAt` is a real,
populated column.

```sql
-- Count of (typeNum, stepKey) observations whose detector hasn't
-- successfully run in > 15 minutes (3x the NFR-2 5-minute freshness target
-- - alert threshold, not the freshness target itself).
SELECT flowKey, stepKey, COUNT(*) AS staleCount, MIN(lastSuccessAt) AS oldestSuccess
FROM onboardingObservations
WHERE lastSuccessAt < DATE_SUB(NOW(), INTERVAL 15 MINUTE)
GROUP BY flowKey, stepKey
ORDER BY staleCount DESC;
```

Alerting rule: page/notify if `staleCount` for any stepKey exceeds a fleet
percentage threshold (e.g. > 5% of active stores) — a single stale row is
expected occasionally (a store's DB blipped once); a persistently large
count indicates a systemic detector regression (M3-08's own failure-handling
contract still serves last-known state, so this is a health signal, not a
user-facing outage).

---

## 3. Activation-abuse pattern

**Status:** LOG-BASED ONLY today — there is no dedicated rate-limiter or
abuse-counter table for the `/activate` endpoint in this codebase (verified:
no rate-limiting code exists in `OnboardingApiController` or
`SchedulingActivationService` as of this phase). Activation itself is
idempotent (guarded `UPDATE ... WHERE schedulingProvider IN (NULL,'','none')`)
so repeated attempts against an already-activated store are harmless
no-ops — "abuse" here means an unusual VOLUME of attempts, which is an
access-pattern signal, not a data-layer one.

```bash
# Repeated POST /activate calls from the same IP within a 5-minute window
# (Common Log Format has no per-IP grouping tool built in - this is a
# straightforward awk aggregation over the existing access_log).
awk '$0 ~ /POST .*\/schedule\/onboarding\/activate/ {print $1, $4}' logs/access_log \
  | sort | uniq -c | sort -rn | head -20
```

**Recommendation for T8:** if abuse becomes a real operational concern
post-launch, add a lightweight counter (e.g. a Redis key
`activation_attempts:{typeNum}` with a TTL, incremented in
`SchedulingActivationService::activate()`) so this becomes a real SQL/Redis
probe instead of a log-grep. Out of scope for T6 (no evidence of a real
problem yet — this is a monitoring-readiness note, not a fix for an observed
issue).

---

## 4. Invite outbox: queue age / dead rows / worker absence

**Status (T7 update): LIVE — T3 has landed.** These queries were originally
written "awaiting T3" (the table was empty on this branch at T6 time); T3.8
re-ran every one of them against seeded data with real output — see
[`051-invite-observability.md` §1, §3, §4`](./051-invite-observability.md#1-queue-age)
for the executed proof (queue age, stuck-sending, worker absence via
`task_workers`/`worker:manager --status`). The queries below are unchanged
and still correct against the real schema (`inviteMessages.state`,
`nextAttemptAt`, `lockedAt`, `attemptCount`) — kept here for the alert-rule
context that lives alongside them.

```sql
-- Queue age: oldest still-queued message, by how long it's been waiting.
SELECT channel, COUNT(*) AS queuedCount, MIN(createdAt) AS oldestQueuedAt,
       TIMESTAMPDIFF(MINUTE, MIN(createdAt), NOW()) AS oldestAgeMinutes
FROM inviteMessages
WHERE state = 'queued'
GROUP BY channel;

-- Dead rows: exhausted retries (attemptCount >= 3 per SDD ADR-051-10).
SELECT channel, COUNT(*) AS deadCount
FROM inviteMessages
WHERE state = 'dead'
GROUP BY channel;

-- Stuck 'sending' rows past the sweep's 10-minute limbo bound (SDD Runtime
-- View: InviteSweepJob re-queues sending rows with lockedAt < NOW()-10min -
-- any row still 'sending' past ~12 minutes means the sweep itself isn't
-- running, not just an individual message being slow).
SELECT channel, COUNT(*) AS stuckSendingCount, MIN(lockedAt) AS oldestLockedAt
FROM inviteMessages
WHERE state = 'sending' AND lockedAt < DATE_SUB(NOW(), INTERVAL 12 MINUTE)
GROUP BY channel;
```

**Worker absence** (TaskEngine-wide, not invite-specific — reuses the real
`task_workers` table, which DOES exist and has real semantics today):

```sql
-- Workers that haven't heartbeated in > 2 minutes (WorkerManager's own
-- staleThresholdSeconds default is 60s per TaskCommandFactory - this probe
-- uses a slightly wider window to avoid false alarms on a normal restart).
SELECT id, hostname, status, last_heartbeat,
       TIMESTAMPDIFF(SECOND, last_heartbeat, NOW()) AS secondsSinceHeartbeat
FROM task_workers
WHERE last_heartbeat < DATE_SUB(NOW(), INTERVAL 2 MINUTE)
  AND status != 'stopped';

-- Zero workers running at all for the queue invites dispatch to (the
-- specific "nobody is processing the outbox" failure mode).
SELECT COUNT(*) AS activeWorkerCount FROM task_workers
WHERE status IN ('idle', 'busy') AND last_heartbeat >= DATE_SUB(NOW(), INTERVAL 2 MINUTE);
-- Alert if activeWorkerCount = 0 while queuedCount (above) > 0.
```

---

## 5. Send-failure rate

**Status (T7 update): LIVE — T3 has landed.** Executed proof with seeded
data: [`051-invite-observability.md` §5](./051-invite-observability.md#5-send-failure-rate).

```sql
SELECT channel,
       SUM(CASE WHEN state IN ('failed', 'dead', 'bounced') THEN 1 ELSE 0 END) AS failedCount,
       SUM(CASE WHEN state IN ('sent', 'delivered') THEN 1 ELSE 0 END) AS succeededCount,
       ROUND(
         SUM(CASE WHEN state IN ('failed', 'dead', 'bounced') THEN 1 ELSE 0 END)
         / NULLIF(SUM(CASE WHEN state IN ('failed', 'dead', 'bounced', 'sent', 'delivered') THEN 1 ELSE 0 END), 0) * 100, 2
       ) AS failureRatePercent
FROM inviteMessages
WHERE createdAt >= DATE_SUB(UTC_TIMESTAMP(), INTERVAL 1 HOUR)
GROUP BY channel;
```

Alert threshold: page if `failureRatePercent` for either channel exceeds a
sustained 10-15% over a rolling hour (email SMTP-unconfigured-outside-dev
fail-fast per D-9, or SMS opted-out/flood-protected sends, are both expected
to show up here — this is why the rate is monitored, not a single failure).

---

## 6. Webhook signature / write failures

**Status (T7 update): LIVE — T3 has landed.** Signature validation FAILURES
are not persisted anywhere (a rejected webhook — SDD: "invalid signature →
403, no write" — correctly never reaches the DB), so that half of this probe
is necessarily log-based.

**T7 log-path correction:** the grep target below originally read
`logs/buyerkiosk_com.php.error.log`. That file **does not exist** in this
checkout — `051-invite-observability.md` §6 discovered the real, actively-written
log for `TwilioDeliveryHandler` is `logs/webhook-delivery.log` (confirmed:
78,836 lines as of that probe, live Twilio traffic since mid-2025). Corrected
here so no reader follows the stale path:

```bash
# Signature validation failures (403s) on the extended webhook endpoint -
# log-based since a rejected signature never reaches a DB write by design.
grep 'webhook.*twilio' logs/webhook-delivery.log \
  | grep -i 'signature' \
  | tail -50
```

```sql
-- Durable-write failures on the WRITE side: SDD says a durable-write
-- failure returns 500 (Twilio retries) - these never corrupt state, but a
-- sustained pattern of 500s from Twilio's perspective shows up as repeated
-- retries for the SAME providerMessageId with no forward progress.
SELECT provider, providerMessageId, COUNT(*) AS attemptRows, MAX(updatedAt) AS lastAttempt
FROM inviteMessages
WHERE provider = 'twilio' AND providerMessageId IS NOT NULL
GROUP BY provider, providerMessageId
HAVING COUNT(*) > 1
ORDER BY lastAttempt DESC;
-- NOTE: inviteMessages has UNIQUE(provider, providerMessageId) - if this
-- query ever returns rows once T3 lands, the unique constraint isn't doing
-- its job (a data-integrity bug, not a monitoring signal) - alert on ANY
-- row here, not a rate.
```

---

## 7. Ingress redaction for `/activate/*` (T8.4)

**Target:** NFR-6 / M9-06 — the invite activation token must never appear in
plaintext anywhere it can be read back later, including web-server access
logs. The application layer already guarantees this (`ActivationController`'s
`redeem(#[\SensitiveParameter] string $token)`, `InviteTokenCodec`,
`InviteTokenSealer` — see `ActivationControllerTest::testTokenNeverAppearsInAnyLoggedMessageEvenOnUnhandledError`)
and the T8.4 log sweep (below) confirms zero token leakage in every
application-level log this session. The one layer the application cannot
control is the **web server's own access log**, which by default records the
full request line (`GET /activate/{token}?r=... HTTP/1.1`) verbatim — Common
Log Format has no awareness of which path segments are sensitive.

**Status: production-ready recipe, syntax-verified locally.** No real
`dev2.buyerkiosk.com` vhost file is inspectable on this dev machine (Apache's
`httpd-vhosts.conf` include is commented out here; the actual site is served
through a different local arrangement per CLAUDE.md/ngrok) — so the recipe
below could not be tested against the LIVE vhost. It WAS syntax-checked with
`httpd -t` against a standalone vhost stub declaring the same modules
(`mod_rewrite`, `mod_log_config`, `mod_setenvif` — all three confirmed present
via `httpd -M` on this box) and returned **`Syntax OK`**. Mark this
**verify-at-deploy**: paste the block into the real vhost, run
`apachectl configtest` (or `httpd -t`) once more against the live config
before reloading.

### The recipe

Add this to the `dev2.buyerkiosk.com` / production vhost block, **above** the
existing `CustomLog` directive referenced in §1 above (the two `CustomLog`
lines below REPLACE that single line — they are mutually exclusive per
request via the `env=`/`env=!` conditionals, so nothing is double-logged):

```apache
# --- Spec 051 T8.4: redact /activate/<token> path segments from access logs ---
RewriteEngine On

# Capture a REDACTED version of the request URI whenever the path is the
# public activation link (GET /activate/:token[?r=ref]). The 32-byte token
# is unpadded base64url (~43 chars, charset [A-Za-z0-9_-]) per
# InviteTokenCodec::encode() - this pattern matches that SHAPE (any run of
# the base64url alphabet after /activate/) rather than assuming an exact
# length, mirroring the app's own decode() charset check so a future token
# length/format change doesn't silently stop matching.
RewriteCond %{REQUEST_URI} ^/activate/[A-Za-z0-9_-]+$
RewriteRule ^ - [E=REDACTED_URI:/activate/REDACTED,NE]

# Two LogFormat nicknames: `activate_redacted` swaps the request line for the
# env var set above; `common_with_timing` is the SAME format already
# documented in §1 (kept in lock-step with it - if that LogFormat changes,
# mirror the change into `activate_redacted` too, adding %{REDACTED_URI}e in
# place of the middle token of %r).
LogFormat "%h %l %u %t \"%{REQUEST_METHOD}e %{REDACTED_URI}e %{REQUEST_PROTOCOL}e\" %>s %b %D" activate_redacted
LogFormat "%h %l %u %t \"%r\" %>s %b %D" common_with_timing

# Conditional CustomLog: requests whose env var was set above get the
# redacted format; every other request keeps today's format untouched. Same
# log file, same LogFormat shape/column count as §1 - no downstream tooling
# (the p95 awk recipe in §1, log rotation, etc.) needs to change.
CustomLog "/Users/rvanvuren/Projects/buyerkiosk-web/logs/access_log" activate_redacted env=REDACTED_URI
CustomLog "/Users/rvanvuren/Projects/buyerkiosk-web/logs/access_log" common_with_timing env=!REDACTED_URI
```

**Verification command (run after deploying, before relying on it):**
```bash
apachectl configtest   # or: httpd -t
curl -s -o /dev/null "https://dev2.buyerkiosk.com/activate/$(openssl rand -base64 32 | tr '+/' '-_' | tr -d '=')"
tail -1 logs/access_log
# Expected: the line contains "GET /activate/REDACTED HTTP/1.1", never the
# random value curl generated above.
```

**What this does NOT redact (documented, not a gap):** query-string params on
OTHER routes, the resolver route (`/admin/schedule/get-started?source=alert`
— carries no token, see `campaign-alert-contract.md` §3), and any REFERER
header a browser might send from an activation page to a THIRD-PARTY resource
(out of this server's control). Scope is deliberately narrow — the ONE known
plaintext-token-bearing URL path — matching the T8.4 sweep's own scope.

### Token-in-logs sweep (executed this session)

Swept every log file under `logs/` (`access_log` 51MB, `error_log` 225MB,
`webhook-delivery.log` 2.2MB, all four `task-worker*-error.log` files
68-78MB each, `task-worker*.log`, `task-scheduler.log`, `sms.log`,
`schedule_notifications.log`, `billing-sms-fallback.log`) for:
1. Literal `/activate/` path occurrences (any log line at all).
2. Invite-specific class/method/table names (`InviteEmailTransport`,
   `InviteDeliveryJob`, `sendEmployeeInviteText`, `activationUrl`,
   `userInvites`, `inviteMessages`) that would appear alongside a leaked
   token in a stack trace or debug dump.

**Result: zero hits, every file.** `grep -c '/activate/'` returns `0` in
`access_log`, `error_log`, `webhook-delivery.log`, and all `task-worker*.log`
files. The only `error_log`/`task-worker*-error.log` matches for the bare
word "activate" are unrelated (WhenIWork integration `activate`/`deactivate`,
`premiumDeactivatedAt` — pre-051, nothing to do with invite tokens). This
confirms the `#[\SensitiveParameter]` + friendly-error-page design
(`ActivationControllerTest::testTokenNeverAppearsInAnyLoggedMessageEvenOnUnhandledError`)
holds in this environment's real logs, not just in the unit test's simulated
scenario.

**`#[\SensitiveParameter]` grep audit (executed this session):** every
function signature receiving a plaintext token/session-token across the
invite flow (`InviteTokenCodec::encode/decode/hashFromUrlToken`,
`InviteTokenCache::store`, `InviteTokenSealer::seal/unseal/keyFor` [via its
own `#[\SensitiveParameter]` params], `ActivationSessionService::retrieve/destroy/keyFor`,
`ActivationController::redeem/setSessionCookie`, `InviteDeliveryJob::sendEmail/sendSms/buildActivationUrl`,
`InviteSweepJob::dispatchInviteDelivery`, `InviteEmailTransport::send`) already
carried the attribute — **one real gap found and fixed this session**:
`TextMessageService::sendEmployeeInviteText()` and its private helper
`buildEmployeeInviteText()` (`src/BuyerKiosk/SMS/TextMessageService/TextMessageService.php`)
received the token-bearing `$inviteUrl` parameter with NO `#[\SensitiveParameter]`
attribute — added in this session (both call sites, additive/no behavior
change, PHP attributes carry no runtime effect on the call itself).

---

## Summary: what's live today (T7 update — T3 has merged; nothing left "awaiting T3")

| Probe | Data source | Live today? |
|---|---|---|
| Hub endpoint latency | access_log (needs LogFormat change) / Server-Timing | Partial — needs T8.3 Server-Timing, or an ops LogFormat change |
| Stale-detector counter | `onboardingObservations.lastSuccessAt` | **Yes** |
| Activation-abuse pattern | access_log grep | **Yes** (log-based; no DB counter exists) |
| Invite queue age | `inviteMessages.state='queued'` | **Yes** — executed proof in `051-invite-observability.md` §1 |
| Invite dead rows | `inviteMessages.state='dead'` | **Yes** — executed proof in `051-invite-observability.md` §2 |
| Invite worker absence | `task_workers` (TaskEngine-wide) | **Yes** (general TaskEngine signal + invite-specific proof in `051-invite-observability.md` §4) |
| Send-failure rate | `inviteMessages` | **Yes** — executed proof in `051-invite-observability.md` §5 |
| Webhook signature failures | `logs/webhook-delivery.log` grep (path corrected — see §6 above) | **Yes** (log-based) |
| Webhook write failures | `inviteMessages` unique-constraint probe | **Yes** — executed proof (0 rows, healthy) in `051-invite-observability.md` §6 |

Only remaining gap: **Hub endpoint latency** — still partial, gated on T8.3's
Server-Timing deliverable (unrelated to T3/invites).

Every "awaiting T3" query above was written and syntax-checked against the
REAL `inviteMessages`/`userInvites` schema (T1B migrations, already landed)
— they require no changes once T3's jobs start writing rows, only removal of
this status note.