`data/yolo-overnight/log-errors-20260525-1058.md`

160 lines
# wallco-ai log error triage — 2026-05-25 10:58 PT

**Source:** `/root/.pm2/logs/wallco-ai-out.log` + `/root/.pm2/logs/wallco-ai-error.log`
(the literal path `logs/server.out.log` does not exist in the project; PM2 writes to its default
`~/.pm2/logs/wallco-ai-{out,error}.log`. Tailed last 2000 lines of each — covers ~30h window
2026-05-24 00:03 → 2026-05-25 09:01.)

**PM2 state:** wallco-ai is `online`, pid 1890751, uptime 2h, **119 lifetime restarts** across 4 days
(unstable_restarts = 0, last exit_code = 0 — i.e. PM2 has not tripped flap protection; visible
restart cadence in the log window is ~13 boots in 30h, consistent with manual `pm2 reload` deploys,
not crash-loops).

---

## Top buckets (non-NOTICE)

| # | Bucket | Count | Severity | First seen (window) | Last seen |
|---|--------|------:|----------|---------------------|-----------|
| 1 | `ERROR: column "ai_title" does not exist` | 11 | **PROD-CRITICAL** | 2026-05-24 (rotated) | 2026-05-25T05:54:33 |
| 2 | `[marketplace.db] ignoring non-URL DATABASE_URL/MARKETPLACE_DB_URL ("dw_unified")` | 13 | MISCONFIG | 2026-05-24T05:32:00 | 2026-05-25T08:21:27 |
| 3 | `[marketplace.db] query failed: SASL: SCRAM-SERVER-FIRST-MESSAGE: client password must be a string` | 2 | RESOLVED | 2026-05-24T05:32:23 | 2026-05-24T05:32:56 |
| 4 | `ValidationError: ERR_ERL_UNEXPECTED_X_FORWARDED_FOR` (express-rate-limit trust-proxy) | 1 trace | MISCONFIG | 2026-05-24T08:01:01 | 2026-05-24T08:01:01 |
| 5 | PG `NOTICE: relation … already exists, skipping` (~17 distinct relations × ~13 boots) | ~221 | NOISE | every restart | every restart |

All other lines in the window are routine startup banners (Marketplace/Chat/Review/Admin/Social/
Library mounts, `Designs loaded: NNNNN`, `file-cache refreshed: NNNNN files`, two trade-login magic
links). No uncaught exceptions, no segfaults, no OOM messages, no Node `unhandledRejection` traces.

---

## Bucket 1 — `column "ai_title" does not exist` — PROD-CRITICAL ⚠

**What's broken**

`spoon_all_designs` schema **has no** `ai_title`, `ai_pattern`, `ai_color_name`, `ai_reviewed_at`,
`ai_review_raw` columns. Three call sites in `server.js` assume they do:

| Line | Op | Endpoint / context | Behavior on failure |
|-----:|----|--------------------|---------------------|
| 16220 | SELECT | `POST /api/design/:id/upload-shopify` (admin → push design to Shopify) | Returns HTTP 500 `{error: 'db: ...'}` to caller |
| 17440 | UPDATE | Gemini vision pass that **writes** ai_title/ai_pattern/ai_color_name | Fails silently — these columns have never been populated for any row |
| 18687 | SELECT | "coordinates by style" recommender on `/design/:id` | Caught in try/catch → returns empty `coordinates_by_style: []` (silent UX degradation) |

Verified live (`psql dw_unified -c "\d spoon_all_designs"`): no `ai_*` columns exist on the table.

**Root cause (confirmed via second-opinion review)**

The "ai-designer" Gemini endpoint at ~line 17364 was written against a planned migration that
adds `ai_title TEXT, ai_pattern TEXT, ai_color_name TEXT, ai_reviewed_at TIMESTAMPTZ,
ai_review_raw JSONB` to `spoon_all_designs`. **The migration was never applied.** Writer and
both readers are internally consistent; only the schema is missing. As a result:

- `upload-shopify` admin endpoint has been **silently broken for at least 30h** (likely much longer).
- "Coordinates by style" suggestions on design detail pages have always been empty.
- Gemini vision review results have never been persisted.

**Recommended fix (do not auto-apply — needs Steve's nod)**

```sql
-- migrations/20260525_add_ai_review_columns.sql
ALTER TABLE spoon_all_designs
  ADD COLUMN IF NOT EXISTS ai_title       text,
  ADD COLUMN IF NOT EXISTS ai_pattern     text,
  ADD COLUMN IF NOT EXISTS ai_color_name  text,
  ADD COLUMN IF NOT EXISTS ai_reviewed_at timestamptz,
  ADD COLUMN IF NOT EXISTS ai_review_raw  jsonb;
```

Then backfill by replaying `/api/design/:id/ai-designer` with `apply:true` across existing rows.
Also worth wrapping the SELECT at server.js:16220 in a try/catch matching the pattern at 18687
so admin never sees a 500 if the migration is missing in another env.

---

## Bucket 2 — `marketplace.db ignoring non-URL DATABASE_URL` — MISCONFIG

**What it means**

`DATABASE_URL` (or `MARKETPLACE_DB_URL`) is set to the bare string `"dw_unified"` — a DB name,
not a connection URL. The marketplace DB layer rejects it as malformed and falls through to the
`PGHOST/PGUSER/PGPASSWORD/PGDATABASE` env vars instead. Logged once on every boot (13 times in
this window).

**Fix**

In `/root/public-projects/wallco-ai/.env`, either:
- (preferred) set `MARKETPLACE_DB_URL="postgresql://dw_admin@127.0.0.1:5432/dw_unified"`, OR
- delete the `DATABASE_URL=dw_unified` line entirely so the PG* fallbacks aren't a "fallthrough"
  but the documented path. Then redeploy via `./deploy-kamatera.sh`.

---

## Bucket 3 — `SASL: client password must be a string` — RESOLVED

**What happened**

When bucket 2 falls through to PG* env vars on a process that doesn't have `PGPASSWORD` set in
its environment, `pg` passes `undefined` to SCRAM and the server rejects with that exact
message. Only seen 2026-05-24T05:32 (2 occurrences); no recurrences after `.env` likely picked up
the password on a subsequent restart. **No action needed unless bucket 2's fix removes the
DATABASE_URL line without confirming PGPASSWORD is exported** — in that case re-verify before
deploy.

---

## Bucket 4 — `ERR_ERL_UNEXPECTED_X_FORWARDED_FOR` — MISCONFIG

**What it means**

express-rate-limit refused to use `req.ip` because Express's `trust proxy` is false (default) but
the request arrived with `X-Forwarded-For` (Cloudflare / nginx proxy). Without trust-proxy, all
rate-limit buckets key on the proxy's IP instead of the real client — defeats rate limiting.

**Fix (one-liner)**

In `server.js`, near the `const app = express()` setup, add:

```js
app.set('trust proxy', 1);   // trust first hop (nginx). For multi-hop, use the hop count.
```

Single trace observed (2026-05-24T08:01:01) — request was caught by the validator before reaching
the route, so the user got a 500. Low frequency but every hit is a real user denied service.

---

## Bucket 5 — PG `NOTICE: relation … already exists, skipping` — NOISE

**What it means**

Startup runs `CREATE TABLE IF NOT EXISTS` / `CREATE INDEX IF NOT EXISTS` for ~17 idempotent
bootstrap statements (`wallco_inspiration_pool`, `wallco_trade_users`, `wallco_saved_designs`,
`wallco_audit_log`, `design_ratings`, `studio_renders`, plus indexes). Each boot logs ~17 NOTICE
lines to stderr. With 13 boots in this window that's ~221 noise lines drowning real signal.

**Fix (optional, low priority)**

Either (a) gate the bootstrap behind a `BOOTSTRAP_SCHEMA=1` env var and skip on subsequent boots,
or (b) run the DDL once at the psql client level with `SET client_min_messages = warning;` to
suppress NOTICE noise from the server stderr.

---

## Escalation

Bucket 1 was escalated for a second-opinion root-cause review (in-conversation, not via
debate-team-fast skill — single LLM was sufficient since both writer and readers agree on the
schema shape, making the missing-migration diagnosis unambiguous). Verdict: apply the missing
migration. **Awaiting Steve's go-ahead before any DDL is run** — this is a soft-delete-style
gate per the escalation rules.

## Suggested action list (in priority order)

1. **[Steve approval needed]** Apply ai_* column migration → unblocks `/api/design/:id/upload-shopify` and the coordinates-by-style recommender.
2. **[Steve approval needed]** Backfill ai_* columns by replaying `/api/design/:id/ai-designer apply:true` over rated designs.
3. Fix `.env` `DATABASE_URL=dw_unified` → real URL or remove. Redeploy via `./deploy-kamatera.sh`.
4. Add `app.set('trust proxy', 1)` in server.js — single-line fix; ship next deploy.
5. (Optional) Wrap server.js:16220 SELECT in try/catch matching 18687 to harden the admin endpoint against future schema drift.
6. (Optional cleanup) Reduce schema-bootstrap NOTICE noise on restart.