Finding the cause of an AI incident
An incident is a time when a feature costs more or answers worse than the brief allows. You find its cause from the records: a cost log for when and how much, a trace for where.
Fernside Library's assistant has been live for a week. At noon the cost alert fires. Nobody changed the model, so the question is what changed.
By the end of this lesson
Note
I can work out what went wrong from the trace and the logs.
Key words
| Word | What it means | Example |
|---|---|---|
| Incident | a time the feature breaks its brief | |
| Cost log | a record of what each hour cost | |
| Trace | the steps one request went through | |
| Span | one step in a trace, with its time | model |
| Attempt | one call to the model for one request |
The cells students fill in are left blank in this preview.
Each record answers one question
Start by asking which record can answer what you need. Do not read everything.
The cost log answers when and how much. A trace answers where the time and the calls went inside one request. A list of events, such as a deploy, answers what changed.
Worked example: three records
| Record | It answers | It cannot answer |
|---|---|---|
| Cost log | Which hours cost more | Why they cost more |
| Trace | What one request did | How common it was |
| Event list | What changed, and when | Whether it mattered |
The cells students fill in are left blank in this preview.
When, where, then why
First find when: the hours that break the limit. Then where: a trace of one request from those hours. Last why: a cause that explains both.
Test the cause. If it is true, the log must show something else too. A cause that predicts nothing is a guess.
A common mistake
Warning
Many people think a cost spike means more users. Check requests as well as cost. If requests stay flat and attempts rise, each request costs more. The traffic did not grow.
Write the incident reader, part 1
docker exec -w /home/node/project agent sh -c "printf '%s\n' 'const fs = require(\"fs\");' '// Requests and model attempts for each hour. One attempt costs 5. The alert limit is 1500 an hour.' 'const HOURS = [[\"08\", 120, 126], [\"09\", 150, 158], [\"10\", 140, 149], [\"11\", 160, 520], [\"12\", 155, 310], [\"13\", 150, 160], [\"14\", 145, 152]];' 'const LIMIT = 1500;' 'const log = HOURS.map(function (h) {' ' return { hour: h[0], requests: h[1], attempts: h[2], cost: h[2] * 5 };' '});' 'fs.writeFileSync(\"cost-log.json\", JSON.stringify(log, null, 1));' > incident.js"Shown here, not run. Create a free account to press Run and type it into your own lab’s terminal.
Write the incident reader, part 2
docker exec -w /home/node/project agent sh -c "printf '%s\n' '// One request, r481, a question about fines, seen as spans.' 'const TRACE = [' ' { span: \"read_sheet\", attempt: 0, ms: 4, length: 0 },' ' { span: \"model\", attempt: 1, ms: 900, length: 52 },' ' { span: \"model\", attempt: 2, ms: 880, length: 51 },' ' { span: \"model\", attempt: 3, ms: 910, length: 55 },' ' { span: \"model\", attempt: 4, ms: 890, length: 53 },' ' { span: \"model\", attempt: 5, ms: 905, length: 54 },' ' { span: \"send_last\", attempt: 5, ms: 1, length: 54 },' '];' 'fs.writeFileSync(\"trace-r481.json\", JSON.stringify(TRACE, null, 1));' >> incident.js"Shown here, not run. Create a free account to press Run and type it into your own lab’s terminal.
Write the incident reader, part 3
docker exec -w /home/node/project agent sh -c "printf '%s\n' 'console.log(\"hour requests attempts per-request cost\");' 'for (const h of log) {' ' const ratio = (h.attempts / h.requests).toFixed(2);' ' console.log(h.hour + \":00\", h.requests, h.attempts, ratio, h.cost, h.cost > LIMIT ? \"OVER\" : \"ok\");' '}' >> incident.js"Shown here, not run. Create a free account to press Run and type it into your own lab’s terminal.
Write the incident reader, part 4
docker exec -w /home/node/project agent sh -c "printf '%s\n' 'for (const t of TRACE) {' ' console.log(t.span, t.attempt, t.ms + \" ms\", \"length \" + t.length, t.length > 40 ? \"too long\" : \"\");' '}' 'const tries = TRACE.filter(function (t) { return t.span === \"model\"; }).length;' 'console.log(\"Model attempts for r481:\", tries);' >> incident.js"Shown here, not run. Create a free account to press Run and type it into your own lab’s terminal.
Read the log and the trace
docker exec -w /home/node/project agent node incident.jsShown here, not run. Create a free account to press Run and type it into your own lab’s terminal.
What the Run prints
| Part | What it shows |
|---|---|
| 08:00 to 10:00 | About 1.05 attempts a request, cost 630 to 790 |
| 11:00 | 3.25 attempts a request, cost 2600, OVER |
| 12:00 | 2.00 attempts a request, cost 1550, OVER |
| 13:00 and 14:00 | Back to about 1.05, cost under 1500 |
| Trace of r481 | Five model spans, every length over 40 |
The cells students fill in are left blank in this preview.