Diagnostic Twilio
TwiML that is not well-formed XML fails with 12100
The caller hears “an application error has occurred” and the line goes dead. Your handler ran, returned 200, and logged nothing unusual. Twilio logged 12100 Document parse failure, which means an XML parser looked at what you sent and refused it — and the usual reason is a single blank line that no code review will ever show you.
Sweep GET https://monitor.twilio.com/v1/Alerts?LogLevel=error&StartDate=YYYY-MM-DD for error_code == 12100, then fetch the interesting ones with GET https://monitor.twilio.com/v1/Alerts/{Sid}. response_body holds the exact bytes Twilio received and alert_text names the line and column. Neither is in the list response.
Diagnose the body rather than eyeballing it: output before the XML declaration, a UTF-8 byte order mark, an HTML error page where TwiML was expected, a missing <Response> root, a bare & in interpolated text, or a tag opened and never closed. Sweep LogLevel=warning in the same run too — its sibling 12200 is logged as a warning and never appears in an error-only query.
The problem in plain words
What makes 12100 disproportionately annoying is that the fault is usually invisible in the source. Nobody wrote invalid XML. The template is fine, the view is fine, the TwiML builder is fine — and then a newline after a closing PHP tag, or a stray line at the top of an included header, or a byte order mark added by an editor puts one character before the XML declaration. XML permits nothing there. The parser stops at position zero.
Meanwhile the caller gets the worst possible experience for something so small: a generic application-error recording and a dropped call, with no way for them to tell you what happened. Your own logs show a clean 200, because from the handler's point of view it did its job. The only place the truth exists is in the alert, and only if you fetch that alert individually.
And there is a quieter neighbour. TwiML that parses but uses a verb Twilio does not recognise raises 12200, which is logged at LogLevel=warning. A dashboard that only ever queries errors reports an account with no TwiML problems while every call silently skips a verb.
Why it happens
XML allows nothing before the declaration. Not a space, not a newline, not a byte order mark. Any of those and the document is malformed at the first byte, whatever follows it. This is why the failure is so often a whitespace character nobody can see in a diff.
The handler cannot tell that it failed. It returned 200 with a body it believes in. The rejection happens inside Twilio's parser, after the response has left your process, so nothing in your logging or your error tracker knows anything went wrong.
Unescaped text is the second cause and it is data-dependent. Interpolating a customer name containing & into <Say> produces invalid XML for that one caller and valid XML for everybody else. It passes every test written with sensible fixtures and fails in production on the account belonging to a company with an ampersand in its name.
The bytes are only on the single-alert fetch. response_body is blank on every row of GET /v1/Alerts. It is populated when you fetch one alert by SID, and it is the only place you can see what actually left your server — which matters here more than anywhere, because what left your server is not what your template says.
Its sibling hides at a different log level. 12200 schema validation is a warning, not an error. Sweeping only LogLevel=error is how a report comes back clean while calls quietly skip a misspelled verb.
The fix, as a flow
The script sweeps warnings as well as errors, because 12200 schema validation is logged at warning level and an error only query reports the account as clean while calls skip a verb.
How to fix it
Sweep both log levels, not just errors
GET https://monitor.twilio.com/v1/Alerts?LogLevel=error&StartDate=YYYY-MM-DD&PageSize=1000 for the 12100s, then the same query with LogLevel=warning for 12200. They are the same family of problem and only one of them is an error, so a single-level sweep gives a false all-clear.
Group by endpoint before you fetch anything
One broken template usually produces hundreds of identical alerts. Group by host and path first, then sample. That turns a report into a handful of lines and keeps the number of single-alert fetches proportional to the number of distinct problems rather than to traffic.
Fetch a sample by SID and read the actual bytes
GET https://monitor.twilio.com/v1/Alerts/{Sid} returns response_body: precisely what Twilio received, including the leading whitespace your editor will not show you. alert_text carries the line and column the parser stopped at. Print both, and print the first forty characters as a repr so an invisible character becomes visible.
Classify the body instead of reading it by eye
Leading whitespace, a byte order mark, an HTML error page, a missing <Response> root, a bare &, an unclosed tag: six causes with six different repairs, and each is a mechanical check over the body. Doing it by eye works until the body is 4 kB of generated TwiML.
Fix the emission point, then re-run over a fresh window
Emit the XML declaration as the first byte with nothing before it, save templates without a BOM, and XML-escape every interpolated value rather than the ones that looked risky. Then re-run with a window that starts after the deploy. Alerts are retained 30 days, so a stale window will keep showing you the old failures for a month.
How to check it worked
Re-run over a window that begins after the deploy. Both counts should be zero, including the warning-level one.
python3 twilio_twiml_parse_audit.py --days 1
# 0 endpoint(s) returning malformed TwiML, 0 schema warning(s) at LogLevel=warningThe full code
The diagnosis is a pure function over the response body, which is what makes this checkable at all: six causes, ordered so the earliest byte wins, and each with its own repair. The unclosed-tag check is a small tag balancer rather than a real XML parser, because a real parser refuses the document and tells you where — it does not tell you which element was left open, which is the thing you need to go and fix.
"""Report Twilio webhooks returning TwiML that is not well-formed XML.
Read only. GET requests and nothing else: give this an API Key with read access
rather than the account auth token. The repair is printed, never performed,
because this script holds a credential to an account that can send messages and
spend money.
"""
import argparse
import datetime as dt
import logging
import os
import re
import sys
from urllib.parse import unquote_plus, urlsplit
import requests
logging.basicConfig(level=logging.INFO, format="%(asctime)s %(levelname)s %(message)s")
log = logging.getLogger("twilio_twiml_parse_audit")
MONITOR = "https://monitor.twilio.com/v1"
PARSE_FAILURE = 12100
# Logged at LogLevel=warning, never at error. Sweeping one level is how an
# account with hundreds of skipped verbs reports as clean.
SCHEMA_WARNING = 12200
# Alerts are retained 30 days. A longer window is not more history, it is the
# same history under a label that makes the report look more thorough.
MAX_DAYS = 30
# A '&' that does not begin a named, decimal or hex entity. This is the second
# most common 12100 and the only one that depends on the data rather than the
# code: one customer with an ampersand in their name breaks one call.
UNESCAPED_AMP = re.compile(r"&(?!(?:[A-Za-z][A-Za-z0-9]*|#[0-9]+|#[xX][0-9A-Fa-f]+);)")
TAG = re.compile(r"<\s*(/?)\s*([A-Za-z][\w.:-]*)([^>]*?)(/?)\s*>", re.S)
LINE_AT = re.compile(r"line\s*[:= ]\s*(\d+)", re.I)
COLUMN_AT = re.compile(r"column\s*[:= ]\s*(\d+)", re.I)
def code_of(alert):
"""Read error_code off an alert as an integer, or None.
The Monitor API hands this back as a string while the Messages list hands
back a number for the same concept, and a check written for one and pointed
at the other matches nothing and reports a healthy account.
"""
raw = alert.get("error_code")
if raw is None or raw == "":
return None
try:
return int(raw)
except (TypeError, ValueError):
return None
def endpoint_of(url):
"""Lowercase host plus path, for grouping. Query string dropped."""
if not url:
return ""
parts = urlsplit(str(url).strip())
host = (parts.hostname or "").lower()
if not host:
return str(url).strip().lower().rstrip("/")
return host + (parts.path or "").rstrip("/")
def unbalanced(xml):
"""The name of the first element left open, or None.
Deliberately not an XML parser. A parser refuses the document and tells you
where it stopped, which is a position; what you need in order to fix it is
which element was never closed. Declarations, comments and self-closing tags
are skipped. Attribute values containing '>' will confuse it, which is worth
less than the answer it gives on every other document.
"""
body = re.sub(r"<\?.*?\?>", "", str(xml or ""), flags=re.S)
body = re.sub(r"<!--.*?-->", "", body, flags=re.S)
stack = []
for m in TAG.finditer(body):
closing, name, _attrs, selfclose = m.groups()
if selfclose:
continue
if closing:
if stack and stack[-1] == name:
stack.pop()
else:
return stack[-1] if stack else name
else:
stack.append(name)
return stack[-1] if stack else None
def diagnose(body):
"""Say why a response body is not well-formed TwiML. Pure.
Ordered so the earliest byte wins, because that is the order the parser
fails in: anything before the declaration ends the document at position
zero, whatever is wrong further down.
Returns (cause, detail).
"""
raw = "" if body is None else str(body)
if not raw.strip():
return ("no-body",
"the single-alert fetch returned an empty body. Either the "
"handler sent nothing, or this alert predates what the API "
"still stores.")
if raw.startswith("\ufeff"):
return ("byte-order-mark",
"the document begins with a UTF-8 byte order mark. XML allows "
"nothing before the declaration, and an editor added three "
"bytes no diff will show you.")
stripped = raw.lstrip()
if not raw.startswith("<"):
prefix = raw[:len(raw) - len(stripped)]
if prefix and stripped.startswith("<"):
return ("leading-whitespace",
"%d byte(s) of whitespace before the document. This is the "
"commonest 12100: a newline after a template header or a "
"closing tag in an included file." % len(prefix))
return ("leading-output",
"the response starts with %r rather than '<'. Something printed "
"before the document was emitted." % raw[:40])
low = stripped.lower()
if low.startswith("<!doctype html") or low.startswith("<html"):
return ("html-error-page",
"an HTML page, not TwiML. The handler threw and the framework "
"returned its error page with a 200 or a 500.")
if "<response" not in low:
return ("no-response-root",
"no <Response> element anywhere. TwiML has exactly one root and "
"this is not it.")
amp = UNESCAPED_AMP.search(raw)
if amp:
return ("unescaped-entity",
"a bare '&' at offset %d. Interpolated text was not XML-escaped, "
"so this breaks for one customer's name and nobody else's."
% amp.start())
open_tag = unbalanced(raw)
if open_tag:
return ("unclosed-tag",
"<%s> is opened and never closed." % open_tag)
return ("parses-here",
"this copy parses as far as these checks go. response_body is stored "
"with a size limit, so the break may be past the end of what was "
"kept: read the line and column out of alert_text.")
def location(alert_text):
"""Line and column from alert_text, best effort. Pure.
alert_text is a URL-encoded blob whose exact keys differ between products,
so this scans it rather than parsing a named field, and returns (None, None)
when the parser did not report a position. Guessing would be worse than
saying nothing.
"""
text = unquote_plus(str(alert_text or ""))
line = LINE_AT.search(text)
column = COLUMN_AT.search(text)
return (int(line.group(1)) if line else None,
int(column.group(1)) if column else None)
def group(alerts, code):
"""Bucket alerts with one error code by endpoint. Pure."""
out = {}
for a in alerts:
if code_of(a) != code:
continue
key = endpoint_of(a.get("request_url"))
row = out.setdefault(key, {"alerts": 0, "sids": [], "first": None,
"last": None})
row["alerts"] += 1
if len(row["sids"]) < 3:
row["sids"].append(a.get("sid"))
when = a.get("date_generated") or ""
if when:
row["first"] = when if row["first"] is None else min(row["first"], when)
row["last"] = when if row["last"] is None else max(row["last"], when)
return out
REPAIRS = {
"leading-whitespace": "emit the XML declaration as the first byte: strip "
"output before the template and check included files "
"for a trailing newline after their closing tag",
"leading-output": "something writes to the response before the document. "
"Find that write; XML allows nothing before the declaration",
"byte-order-mark": "save the template as UTF-8 without a BOM, or strip the "
"mark before writing the response",
"html-error-page": "the handler is throwing. Fix the exception, and return "
"a short TwiML document from the error branch rather than "
"a framework page",
"no-response-root": "wrap the document in a single <Response> element",
"unescaped-entity": "XML-escape every interpolated value, not the ones that "
"looked risky. Use the TwiML helper library rather than "
"string concatenation",
"unclosed-tag": "close the element, or emit it self-closed",
"parses-here": "read the line and column from alert_text and compare against "
"the full document your handler generates",
"no-body": "reproduce the request against the handler and capture what it "
"actually writes",
}
def get(session, url, **params):
r = session.get(url, params=params, timeout=30)
if r.status_code in (401, 403):
raise SystemExit("%d from Twilio: check TWILIO_ACCOUNT_SID and that the "
"API key belongs to that account with read access"
% r.status_code)
r.raise_for_status()
return r.json()
def list_alerts(session, since, limit, log_level="error"):
"""Page the Monitor alerts. next_page_url is absolute on this API."""
url = MONITOR + "/Alerts"
params = {"LogLevel": log_level, "StartDate": since, "PageSize": 1000}
out = []
while url and len(out) < limit:
page = get(session, url, **params)
out.extend(page.get("alerts", []))
url = (page.get("meta") or {}).get("next_page_url")
params = {}
return out[:limit]
def fetch_alert(session, sid):
"""One alert by SID: the only place response_body is populated."""
return get(session, "%s/Alerts/%s" % (MONITOR, sid))
def main():
ap = argparse.ArgumentParser(description=__doc__)
ap.add_argument("--days", type=int, default=1,
help="how far back to read alerts (Twilio keeps 30 days)")
ap.add_argument("--max-alerts", type=int, default=10000,
help="stop paging alerts after this many, per log level")
ap.add_argument("--sample", type=int, default=1,
help="alerts to fetch individually per endpoint for the "
"response body (each one is a request)")
args = ap.parse_args()
account = os.environ.get("TWILIO_ACCOUNT_SID")
key = os.environ.get("TWILIO_API_KEY")
secret = os.environ.get("TWILIO_API_SECRET")
if not (account and key and secret):
log.error("set TWILIO_ACCOUNT_SID, TWILIO_API_KEY and TWILIO_API_SECRET "
"(an API Key with read access, not the auth token)")
return 2
days = args.days
if days > MAX_DAYS:
log.warning("alerts are retained %d days; reading %d instead of %d",
MAX_DAYS, MAX_DAYS, days)
days = MAX_DAYS
session = requests.Session()
session.auth = (key, secret)
since = (dt.date.today() - dt.timedelta(days=days)).isoformat()
errors = list_alerts(session, since, args.max_alerts, "error")
warnings = list_alerts(session, since, args.max_alerts, "warning")
rows = group(errors, PARSE_FAILURE)
log.info("%d error alert(s) and %d warning alert(s) since %s, %d endpoint(s) "
"with 12100", len(errors), len(warnings), since, len(rows))
bad = 0
for key, row in sorted(rows.items()):
bad += 1
cause, detail = ("no-body", "not sampled")
line = column = None
for sid in row["sids"][:max(1, args.sample)]:
full = fetch_alert(session, sid)
cause, detail = diagnose(full.get("response_body"))
line, column = location(full.get("alert_text"))
if cause != "no-body":
break
log.warning("%-18s %s %d x 12100 %s", cause, key, row["alerts"], detail)
log.warning(" first %s, last %s", row["first"], row["last"])
if line is not None:
log.warning(" parser stopped at line %s, column %s", line, column)
log.warning(" repair: %s", REPAIRS.get(cause, "read the body by hand"))
schema = group(warnings, SCHEMA_WARNING)
for key, row in sorted(schema.items()):
log.warning("schema-warning %s %d x 12200 a verb or attribute is "
"misspelled or wrongly cased. Logged at LogLevel=warning, "
"so an error-only sweep never sees it and the call runs on "
"with the verb skipped.", key, row["alerts"])
log.info("%d endpoint(s) returning malformed TwiML, %d endpoint(s) with "
"schema warning(s) at LogLevel=warning", bad, len(schema))
return 1 if bad else 0
if __name__ == "__main__":
sys.exit(main())
/**
* Report Twilio webhooks returning TwiML that is not well-formed XML.
*
* Read only. GET requests and nothing else: give this an API Key with read
* access rather than the account auth token. The repair is printed, never
* performed.
*/
const MONITOR = 'https://monitor.twilio.com/v1';
const PARSE_FAILURE = 12100;
// Logged at LogLevel=warning, never at error. Sweeping one level is how an
// account with hundreds of skipped verbs reports as clean.
const SCHEMA_WARNING = 12200;
// Alerts are retained 30 days. A longer window is the same history mislabelled.
const MAX_DAYS = 30;
// A '&' that does not begin a named, decimal or hex entity.
const UNESCAPED_AMP = /&(?!(?:[A-Za-z][A-Za-z0-9]*|#[0-9]+|#[xX][0-9A-Fa-f]+);)/;
const TAG = /<\s*(\/?)\s*([A-Za-z][\w.:-]*)([^>]*?)(\/?)\s*>/g;
const LINE_AT = /line\s*[:= ]\s*(\d+)/i;
const COLUMN_AT = /column\s*[:= ]\s*(\d+)/i;
/** Read error_code off an alert as a number, or null. */
export function codeOf(alert) {
const raw = alert.error_code;
if (raw === null || raw === undefined || raw === '') return null;
const n = Number(raw);
return Number.isFinite(n) ? n : null;
}
/** Lowercase host plus path, for grouping. Query string dropped. */
export function endpointOf(url) {
if (!url) return '';
const raw = String(url).trim();
try {
const u = new URL(raw);
let path = u.pathname;
while (path.endsWith('/')) path = path.slice(0, -1);
return u.hostname.toLowerCase() + path;
} catch {
return raw.toLowerCase().replace(/\/+$/, '');
}
}
/**
* The name of the first element left open, or null. Deliberately not an XML
* parser: a parser tells you where it stopped, and what you need is which
* element was never closed.
*/
export function unbalanced(xml) {
const body = String(xml ?? '')
.replace(/<\?[\s\S]*?\?>/g, '')
.replace(/<!--[\s\S]*?-->/g, '');
const stack = [];
TAG.lastIndex = 0;
let m = TAG.exec(body);
while (m !== null) {
const [, closing, name, , selfclose] = m;
if (!selfclose) {
if (closing) {
if (stack.length && stack[stack.length - 1] === name) stack.pop();
else return stack.length ? stack[stack.length - 1] : name;
} else {
stack.push(name);
}
}
m = TAG.exec(body);
}
return stack.length ? stack[stack.length - 1] : null;
}
/**
* Say why a response body is not well-formed TwiML. Pure, ordered so the
* earliest byte wins. Returns [cause, detail].
*/
export function diagnose(body) {
const raw = body === null || body === undefined ? '' : String(body);
if (!raw.trim()) {
return ['no-body',
'the single-alert fetch returned an empty body. Either the handler sent ' +
'nothing, or this alert predates what the API still stores.'];
}
if (raw.startsWith('\uFEFF')) {
return ['byte-order-mark',
'the document begins with a UTF-8 byte order mark. XML allows nothing ' +
'before the declaration, and an editor added three bytes no diff will ' +
'show you.'];
}
const stripped = raw.replace(/^\s+/, '');
if (!raw.startsWith('<')) {
const prefix = raw.slice(0, raw.length - stripped.length);
if (prefix && stripped.startsWith('<')) {
return ['leading-whitespace',
`${prefix.length} byte(s) of whitespace before the document. This is ` +
'the commonest 12100: a newline after a template header or a closing ' +
'tag in an included file.'];
}
return ['leading-output',
`the response starts with ${JSON.stringify(raw.slice(0, 40))} rather ` +
"than '<'. Something printed before the document was emitted."];
}
const low = stripped.toLowerCase();
if (low.startsWith('<!doctype html') || low.startsWith('<html')) {
return ['html-error-page',
'an HTML page, not TwiML. The handler threw and the framework returned ' +
'its error page with a 200 or a 500.'];
}
if (!low.includes('<response')) {
return ['no-response-root',
'no <Response> element anywhere. TwiML has exactly one root and this is ' +
'not it.'];
}
const amp = UNESCAPED_AMP.exec(raw);
if (amp) {
return ['unescaped-entity',
`a bare '&' at offset ${amp.index}. Interpolated text was not ` +
"XML-escaped, so this breaks for one customer's name and nobody else's."];
}
const openTag = unbalanced(raw);
if (openTag) return ['unclosed-tag', `<${openTag}> is opened and never closed.`];
return ['parses-here',
'this copy parses as far as these checks go. response_body is stored with ' +
'a size limit, so the break may be past the end of what was kept: read the ' +
'line and column out of alert_text.'];
}
/**
* Line and column from alert_text, best effort. alert_text is a URL-encoded
* blob whose keys differ between products, so this scans rather than parses and
* returns nulls when there is no position to report.
*/
export function location(alertText) {
const text = decodeURIComponent(String(alertText ?? '').replace(/\+/g, ' '));
const line = LINE_AT.exec(text);
const column = COLUMN_AT.exec(text);
return [line ? Number(line[1]) : null, column ? Number(column[1]) : null];
}
/** Bucket alerts with one error code by endpoint. Pure. */
export function group(alerts, code) {
const out = new Map();
for (const a of alerts) {
if (codeOf(a) !== code) continue;
const key = endpointOf(a.request_url);
if (!out.has(key)) out.set(key, { alerts: 0, sids: [], first: null, last: null });
const row = out.get(key);
row.alerts += 1;
if (row.sids.length < 3) row.sids.push(a.sid);
const when = a.date_generated ?? '';
if (when) {
row.first = row.first === null || when < row.first ? when : row.first;
row.last = row.last === null || when > row.last ? when : row.last;
}
}
return out;
}
const REPAIRS = {
'leading-whitespace': 'emit the XML declaration as the first byte: strip ' +
'output before the template and check included files for a trailing ' +
'newline after their closing tag',
'leading-output': 'something writes to the response before the document. ' +
'Find that write; XML allows nothing before the declaration',
'byte-order-mark': 'save the template as UTF-8 without a BOM, or strip the ' +
'mark before writing the response',
'html-error-page': 'the handler is throwing. Fix the exception, and return a ' +
'short TwiML document from the error branch rather than a framework page',
'no-response-root': 'wrap the document in a single <Response> element',
'unescaped-entity': 'XML-escape every interpolated value, not the ones that ' +
'looked risky. Use the TwiML helper library rather than string concatenation',
'unclosed-tag': 'close the element, or emit it self-closed',
'parses-here': 'read the line and column from alert_text and compare against ' +
'the full document your handler generates',
'no-body': 'reproduce the request against the handler and capture what it ' +
'actually writes',
};
function authHeader(key, secret) {
return `Basic ${Buffer.from(`${key}:${secret}`).toString('base64')}`;
}
async function get(auth, url, params = {}) {
const u = new URL(url);
for (const [k, v] of Object.entries(params)) u.searchParams.set(k, v);
const res = await fetch(u, { headers: { Authorization: auth } });
if (res.status === 401 || res.status === 403) {
throw new Error(`${res.status} from Twilio: check TWILIO_ACCOUNT_SID and ` +
'that the API key belongs to that account with read access');
}
if (!res.ok) throw new Error(`${res.status} from ${u.pathname}`);
return res.json();
}
export async function listAlerts(auth, since, limit = 10000, logLevel = 'error') {
let url = `${MONITOR}/Alerts`;
let params = { LogLevel: logLevel, StartDate: since, PageSize: 1000 };
const out = [];
while (url && out.length < limit) {
const page = await get(auth, url, params);
out.push(...(page.alerts ?? []));
url = page.meta?.next_page_url ?? null;
params = {};
}
return out.slice(0, limit);
}
/** One alert by SID: the only place response_body is populated. */
export async function fetchAlert(auth, sid) {
return get(auth, `${MONITOR}/Alerts/${sid}`);
}
async function main() {
const account = process.env.TWILIO_ACCOUNT_SID;
const key = process.env.TWILIO_API_KEY;
const secret = process.env.TWILIO_API_SECRET;
if (!account || !key || !secret) {
console.error('set TWILIO_ACCOUNT_SID, TWILIO_API_KEY and TWILIO_API_SECRET ' +
'(an API Key with read access, not the auth token)');
process.exitCode = 2;
return;
}
const auth = authHeader(key, secret);
let days = Number(process.argv.includes('--days')
? process.argv[process.argv.indexOf('--days') + 1] : 1) || 1;
if (days > MAX_DAYS) {
console.warn(`alerts are retained ${MAX_DAYS} days; reading ${MAX_DAYS} instead`);
days = MAX_DAYS;
}
const since = new Date(Date.now() - days * 86400000).toISOString().slice(0, 10);
const errors = await listAlerts(auth, since, 10000, 'error');
const warnings = await listAlerts(auth, since, 10000, 'warning');
const rows = group(errors, PARSE_FAILURE);
console.log(`${errors.length} error alert(s) and ${warnings.length} warning ` +
`alert(s) since ${since}, ${rows.size} endpoint(s) with 12100`);
let bad = 0;
for (const [key, row] of [...rows.entries()].sort()) {
bad += 1;
let cause = 'no-body';
let detail = 'not sampled';
let line = null;
let column = null;
for (const sid of row.sids.slice(0, 1)) {
const full = await fetchAlert(auth, sid);
[cause, detail] = diagnose(full.response_body);
[line, column] = location(full.alert_text);
}
console.warn(`${cause.padEnd(18)} ${key} ${row.alerts} x 12100 ${detail}`);
console.warn(` first ${row.first}, last ${row.last}`);
if (line !== null) console.warn(` parser stopped at line ${line}, column ${column}`);
console.warn(` repair: ${REPAIRS[cause] ?? 'read the body by hand'}`);
}
const schema = group(warnings, SCHEMA_WARNING);
for (const [key, row] of [...schema.entries()].sort()) {
console.warn(`schema-warning ${key} ${row.alerts} x 12200 a verb or ` +
'attribute is misspelled or wrongly cased. Logged at ' +
'LogLevel=warning, so an error-only sweep never sees it and ' +
'the call runs on with the verb skipped.');
}
console.log(`${bad} endpoint(s) returning malformed TwiML, ${schema.size} ` +
'endpoint(s) with schema warning(s) at LogLevel=warning');
process.exitCode = bad ? 1 : 0;
}
// Only run when invoked directly. The test file imports this module, and without
// the guard main() would run there too, fail on the missing credentials and set a
// non-zero exit code that fails the whole test file even as every test passes.
if (import.meta.url === `file://${process.argv[1]}`) {
main().catch((err) => { console.error(err.message); process.exitCode = 2; });
}
Add a test
Every branch of diagnose() gets a body, because the ordering is the substance: a document with both a leading newline and an unclosed tag has to be reported as the leading newline, since that is where the parser actually stopped. The entity regex is pinned in both directions — & and & are fine, a bare & is not — and location() is pinned to return nothing rather than a guess when alert_text carries no position.
from twilio_twiml_parse_audit import (code_of, diagnose, endpoint_of, group,
location, unbalanced)
GOOD = '<?xml version="1.0" encoding="UTF-8"?>\n<Response><Say>Hi</Say></Response>'
def alert(sid, url, code="12100", when="2026-04-02T10:00:00Z"):
return {"sid": sid, "request_url": url, "error_code": code,
"date_generated": when}
def test_a_well_formed_document_is_not_flagged():
cause, _ = diagnose(GOOD)
assert cause == "parses-here"
def test_one_newline_before_the_declaration_is_the_commonest_cause():
cause, detail = diagnose("\n" + GOOD)
assert cause == "leading-whitespace"
assert "1 byte" in detail
def test_a_byte_order_mark_beats_every_other_check():
# It is the first byte, so it is where the parser stops, even though the
# rest of the document is also broken.
cause, _ = diagnose("\ufeff<Response><Say>Hi</Response>")
assert cause == "byte-order-mark"
def test_output_before_the_document_is_not_whitespace():
cause, detail = diagnose("Warning: undefined index\n" + GOOD)
assert cause == "leading-output"
assert "Warning" in detail
def test_a_framework_error_page_is_named_as_one():
cause, _ = diagnose("<!DOCTYPE html><html><body>500</body></html>")
assert cause == "html-error-page"
def test_a_document_with_no_response_root_is_its_own_cause():
cause, _ = diagnose("<Say>Hi</Say>")
assert cause == "no-response-root"
def test_a_bare_ampersand_is_caught_and_real_entities_are_not():
cause, detail = diagnose("<Response><Say>Ben & Jerry</Say></Response>")
assert cause == "unescaped-entity"
assert "offset" in detail
assert diagnose("<Response><Say>Ben & Jerry</Say></Response>")[0] == \
"parses-here"
assert diagnose("<Response><Say>Ben & Jerry</Say></Response>")[0] == \
"parses-here"
def test_an_unclosed_verb_is_named():
cause, detail = diagnose("<Response><Say>Hi</Response>")
assert cause == "unclosed-tag"
assert "<Say>" in detail
def test_self_closing_and_declared_tags_do_not_count_as_open():
assert unbalanced('<?xml version="1.0"?><Response><Hangup/></Response>') is None
assert unbalanced("<Response><!-- <Say> --></Response>") is None
def test_an_empty_body_is_reported_rather_than_guessed():
assert diagnose("")[0] == "no-body"
assert diagnose(None)[0] == "no-body"
def test_location_reads_a_position_and_admits_when_there_is_none():
assert location("Msg=Error+on+line+1%2C+column+3") == (1, 3)
assert location("ErrorCode=12100") == (None, None)
assert location(None) == (None, None)
def test_group_keeps_only_the_requested_code():
rows = group([alert("NO1", "https://a.example.com/voice?CallSid=CA1"),
alert("NO2", "https://a.example.com/voice"),
alert("NO3", "https://a.example.com/voice", code="12200")],
12100)
assert rows["a.example.com/voice"]["alerts"] == 2
assert code_of({"error_code": "12100"}) == 12100
assert endpoint_of("https://A.example.com/voice/") == "a.example.com/voice"
import { test } from 'node:test';
import assert from 'node:assert/strict';
import {
codeOf, diagnose, endpointOf, group, location, unbalanced,
} from './twilio-twiml-parse-audit.mjs';
const GOOD = '<?xml version="1.0" encoding="UTF-8"?>\n<Response><Say>Hi</Say></Response>';
const alert = (sid, url, code = '12100', when = '2026-04-02T10:00:00Z') => ({
sid, request_url: url, error_code: code, date_generated: when,
});
test('a well-formed document is not flagged', () => {
assert.equal(diagnose(GOOD)[0], 'parses-here');
});
test('one newline before the declaration is the commonest cause', () => {
const [cause, detail] = diagnose(`\n${GOOD}`);
assert.equal(cause, 'leading-whitespace');
assert.match(detail, /1 byte/);
});
test('a byte order mark beats every other check', () => {
assert.equal(diagnose('\uFEFF<Response><Say>Hi</Response>')[0], 'byte-order-mark');
});
test('output before the document is not whitespace', () => {
const [cause, detail] = diagnose(`Warning: undefined index\n${GOOD}`);
assert.equal(cause, 'leading-output');
assert.match(detail, /Warning/);
});
test('a framework error page is named as one', () => {
assert.equal(diagnose('<!DOCTYPE html><html><body>500</body></html>')[0],
'html-error-page');
});
test('a document with no Response root is its own cause', () => {
assert.equal(diagnose('<Say>Hi</Say>')[0], 'no-response-root');
});
test('a bare ampersand is caught and real entities are not', () => {
const [cause, detail] = diagnose('<Response><Say>Ben & Jerry</Say></Response>');
assert.equal(cause, 'unescaped-entity');
assert.match(detail, /offset/);
assert.equal(diagnose('<Response><Say>Ben & Jerry</Say></Response>')[0],
'parses-here');
assert.equal(diagnose('<Response><Say>Ben & Jerry</Say></Response>')[0],
'parses-here');
});
test('an unclosed verb is named', () => {
const [cause, detail] = diagnose('<Response><Say>Hi</Response>');
assert.equal(cause, 'unclosed-tag');
assert.match(detail, /<Say>/);
});
test('self-closing and declared tags do not count as open', () => {
assert.equal(unbalanced('<?xml version="1.0"?><Response><Hangup/></Response>'), null);
assert.equal(unbalanced('<Response><!-- <Say> --></Response>'), null);
});
test('an empty body is reported rather than guessed', () => {
assert.equal(diagnose('')[0], 'no-body');
assert.equal(diagnose(null)[0], 'no-body');
});
test('location reads a position and admits when there is none', () => {
assert.deepEqual(location('Msg=Error+on+line+1%2C+column+3'), [1, 3]);
assert.deepEqual(location('ErrorCode=12100'), [null, null]);
assert.deepEqual(location(null), [null, null]);
});
test('group keeps only the requested code', () => {
const rows = group([
alert('NO1', 'https://a.example.com/voice?CallSid=CA1'),
alert('NO2', 'https://a.example.com/voice'),
alert('NO3', 'https://a.example.com/voice', '12200'),
], 12100);
assert.equal(rows.get('a.example.com/voice').alerts, 2);
assert.equal(codeOf({ error_code: '12100' }), 12100);
assert.equal(endpointOf('https://A.example.com/voice/'), 'a.example.com/voice');
});
FAQ
How can one blank line break the whole document?
Because XML allows nothing before the declaration. Not a space, not a newline, not a byte order mark. The parser fails at the first byte and never looks at the rest, which is why the source can be perfect and the response still invalid.
My handler returns 200 and logs nothing. Where is the failure?
Inside Twilio's parser, after your response left the process. From the handler's point of view it succeeded. The only record is the alert, and the only place the bytes it sent are visible is the single-alert fetch, GET /v1/Alerts/{Sid}.
Why does the script sweep LogLevel=warning as well?
Because 12200, the schema validation failure for a misspelled or wrongly cased verb, is logged at warning level and never appears in an error-only query. It is the same family of problem: the document parses, the verb is skipped, the call runs on doing nothing. An error-only sweep reports that account as clean.
Why not just run the body through a real XML parser?
The script does the equivalent, but a parser answers a different question. It refuses the document and reports a position; what you need in order to fix it is which element was never closed, or that the first three bytes are a byte order mark. That is why the diagnosis is a small ordered set of named causes with named repairs.
The body came back looking valid. Now what?
Then read the line and column from alert_text and compare against the full document your handler generates. response_body is stored with a size limit, so on a large document the break can be past the end of the copy the API kept, and the script says so rather than declaring the endpoint healthy.
Related field notes
- A TwiML response over the 64 kB limit
- The wrong Content-Type on a TwiML response
- A number with no fallback URL drops the call
Sources
Every figure in this note is traced to one of these. Prices are list rates and change — check them for your own region before acting.
- Error 12100: document parse failure — Twilio Docs
- Error 12200: schema validation warning — Twilio Docs
- Monitor Alert resource — Twilio Docs
- TwiML for Programmable Voice — Twilio Docs
If your setup is misbehaving in a way this note does not cover, message me on LinkedIn with what you are seeing.