Diagnostic Slack
The dedupe key that does not survive the retry
There is a dedupe check in the handler. Somebody added it after the last incident, it has a Redis set behind it and a TTL and a test, and there are still three Jira tickets for one Slack message.
This note is not about whether you deduplicate. It assumes you do. It is about the two properties the key has to have and the one property the store has to have, and about the fact that a key can fail all three while looking completely reasonable in a code review.
An idempotency key for Slack event retries has to be stable (identical on the retry and on the original) and unique (different for two events you genuinely want processed separately). event.event_id is both. Most of the things people reach for instead fail one of them: the request signature is recomputed per delivery with a fresh timestamp, so it is never stable; event.ts is stable but is shared by every event about the same message; client_msg_id is stable and unique and simply is not there on bot messages, on subtyped messages, or on anything that is not a message at all.
Then there is the store. Slack's retry schedule ends at about five minutes, so a TTL under three hundred seconds is a key that survives the first retry and expires before the last one — which is why the bug reproduces only on the delivery that arrives five minutes late, and only sometimes. The script below audits the key expression against those two properties, audits the TTL against the schedule, and then measures the one thing a read token can measure directly: how often the field you chose is actually present in your workspace's real messages.
The problem in plain words
The duplicates themselves are easy to see and there is a note about seeing them. This one deliberately never counts a duplicate, because by the time you are reading this you have already counted them and have already written the guard that was supposed to stop them. The interesting failure is downstream of that decision: the guard is there, it runs, and it does not fire.
The most common reason is a key that is not stable. A retry is a fresh HTTP request: new X-Slack-Request-Timestamp, new X-Slack-Signature, new arrival time at your load balancer. Anything derived from the delivery rather than from the event changes on every attempt, so a set keyed on it accumulates one entry per delivery and rejects nothing. The code looks like deduplication. It is a log with an eviction policy.
The second reason is a key that is not always there. client_msg_id is a genuinely good identifier when it exists, and it exists only on messages a person typed into a Slack client. Bot messages do not carry it. Subtyped messages generally do not. Reactions, channel joins and app mentions of the non-message kind never did. So the expression event.client_msg_id evaluates to nothing for a substantial share of real traffic, and now the behaviour depends entirely on what your code does with a missing key: store it and every keyless event collides with every other keyless event, so the first one is processed and the rest are silently dropped; skip the check and every keyless event is processed once per delivery. One of those loses work and the other duplicates it, and neither is what the guard was for.
Why it happens
event_id is the only field designed for this. It identifies the event, not the delivery, and Slack sends the same one on every retry of it. It is present on every event type, it is opaque, and it needs no parsing. Almost every other candidate is something that happens to be unique often enough to pass a test.
Stable and unique are separate properties and most wrong keys fail exactly one. A key that fails stability dedupes nothing, which shows up as duplicates. A key that fails uniqueness dedupes too much, which shows up as missing work and is far harder to notice, because nobody files a ticket about the ticket that was not created.
The TTL is not a tuning parameter, it is a deadline set by Slack. Retries land at roughly zero, sixty and three hundred seconds. Anything under three hundred is arithmetically incapable of catching the last one. Sixty seconds is the value people pick because the first retry is at sixty, and it produces a system that deduplicates the retries you tested and not the ones that happen at load.
Under Socket Mode there is no retry header at all. The X-Slack-Retry-Num and X-Slack-Retry-Reason headers are an HTTP transport thing. An app that guards by checking whether the retry header is present has no guard when it moves to Socket Mode, and the move is usually made for unrelated reasons by somebody who has never read the dedupe code. Guard on the event id, which arrives the same way over both transports.
The retry reason tells you whether the original probably succeeded. http_timeout means Slack sent it, your service took the payload and then answered late, so the work very likely happened. connection_failed and ssl_error mean it probably did not. That distinction is worth reading when it is available, and it is a refinement on top of an event id check, never a replacement for one.
The fix, as a flow
The box that goes red here is the guard, which is the one box a reader arrives expecting to be the fix. It ran on every delivery and it rejected none of them, because the value it was keyed on is a property of the request rather than of the event. The fix branch asks three questions rather than one, and its two failing key rows fail in opposite directions.
How to fix it
Write down the key expression exactly as the code computes it
Not "we dedupe on the event", the actual expression: event.event_id, body.event.client_msg_id, sha256(raw_body), headers['x-slack-signature']. The whole audit turns on which of those it is, and the four are indistinguishable in a design document.
Check it for stability first
Does the retry carry the same value? Anything computed from the request rather than read out of the event fails here, and the failure is total: the guard runs on every delivery and rejects none of them. The script names which side of that line each known expression falls on.
Then check it for uniqueness
Do two events you want handled separately get different values? A message timestamp is stable and is shared by the message event, the reaction on it, and the edit of it, so a single set keyed on it will swallow two of the three. This is the failure that loses work rather than duplicating it.
Measure how often the field is actually there
This is the half a read token answers directly. Sample real messages from the workspace and count how many carry the field you chose. A key present on sixty percent of messages is not a key, it is a key and a coin flip, and the script reports the rate rather than the opinion.
Hold the TTL against the retry schedule, not against your intuition
Three hundred seconds is the floor and ten minutes is the number to use. Below three hundred the guard cannot see the last retry; the resulting bug appears minutes after the event, under load, on a delivery nobody is watching.
Make the downstream operation idempotent as well
A dedupe set is a cache and caches are lost. Putting the event id on the created record as an external key means that even a cold Redis cannot double-create, which turns a correctness property into a database constraint rather than a timing one.
How to check it worked
Re-run after moving to the event id and lengthening the TTL. The coverage line is the one that should change most, because it stops being a measurement of your traffic and starts being a constant.
python3 slack_dedupe_key_audit.py --key event_id --ttl 600 --channels 5
# key stable-unique event_id identifies the event, not the delivery
# ttl sufficient 600s covers the last retry at 300s with margin
# schedule retries 0, 60, 300 seconds after the original
# coverage always-present ts on 412 of 412 sampled message(s), 100.0%
# verdict ok the key is stable, unique and always presentThe full code
Three pure functions and one page of history per sampled channel. key_stability is a table of the expressions people actually write, each placed against the two properties a key needs, and the entries that fail are more instructive than the one that passes. ttl_verdict holds the store against Slack's schedule, where three hundred seconds is a fact rather than a preference. key_coverage is the part only a token can answer: how often the field you chose exists in this workspace's real messages.
"""Audit the idempotency key a Slack event handler dedupes on.
Read only. This script never counts duplicate messages; that is a different
question with a different script. It takes the key expression and TTL the
handler uses, places them against the two properties an idempotency key needs
and against Slack's retry schedule, and then samples history to measure how
often the chosen field is actually present in real traffic.
"""
import argparse
import logging
import os
import sys
import requests
logging.basicConfig(level=logging.INFO, format="%(asctime)s %(levelname)s %(message)s")
log = logging.getLogger("slack_dedupe_key_audit")
API = "https://slack.com/api/"
# Retries land at roughly these offsets, so the last one a store has to
# remember is five minutes old. A TTL under 300 cannot catch it, whatever else
# is right about the key.
RETRY_SCHEDULE_SECONDS = (0, 60, 300)
LAST_RETRY_SECONDS = 300
COMFORTABLE_TTL_SECONDS = 600
# The expressions people actually write, against the two properties a key
# needs: stable means the retry carries the same value, unique means two
# events you want handled separately get different ones. Failing stability
# dedupes nothing. Failing uniqueness dedupes too much, which loses work and
# is much harder to notice.
KEY_TABLE = {
"event_id": (True, True,
"identifies the event, not the delivery, and Slack sends the "
"same one on every retry of it. Present on every event type."),
"event.event_id": (True, True, "the same field, spelled with its envelope"),
"event_time": (True, False,
"stable, and only second granularity: two events in the same "
"second collide and one of them is silently dropped"),
"event.ts": (True, False,
"stable for one message and shared by every event about that "
"message, so the reaction and the edit collide with it"),
"ts": (True, False, "the same field without its envelope"),
"client_msg_id": (True, True,
"stable and unique where it exists, and it exists only on "
"messages a person typed into a Slack client. Check the "
"coverage line before trusting it."),
"x-slack-signature": (False, True,
"recomputed per delivery over a fresh request "
"timestamp, so the retry never matches the original. "
"A set keyed on this rejects nothing."),
"x-slack-request-timestamp": (False, True,
"the delivery's clock, not the event's"),
"received_at": (False, True, "your clock, which moves"),
"uuid": (False, True, "generated per delivery, so every delivery is new"),
"x-slack-retry-num": (False, False,
"a flag, not a key: it says whether this is a retry "
"and not which event it is. It is also absent under "
"Socket Mode, so a guard built on it disappears when "
"the transport changes."),
"body_hash": (True, True,
"identical across retries in practice, and brittle: it covers "
"envelope fields you do not control, and re-wrapping the "
"payload through your own queue changes it"),
}
def key_stability(expression):
"""Place a key expression against stability and uniqueness. Pure.
Returns a dict. The two properties are separate on purpose: a key that
fails stability produces duplicates, and a key that fails uniqueness
produces missing work, which nobody files a ticket about.
"""
name = str(expression or "").strip().lower().lstrip("$")
row = KEY_TABLE.get(name)
if row is None:
return {"verdict": "unrecognised", "stable": None, "unique": None,
"detail": "not an expression this script knows. Check it by "
"hand: does the retry carry the same value, and do "
"two different events get different ones?"}
stable, unique, detail = row
if stable and unique:
verdict = "stable-unique"
elif not stable and not unique:
verdict = "flag-not-key"
elif not stable:
verdict = "not-stable"
else:
verdict = "stable-collides"
if name == "client_msg_id":
verdict = "sparse"
return {"verdict": verdict, "stable": stable, "unique": unique,
"detail": detail}
def ttl_verdict(ttl_seconds):
"""Hold the dedupe store's TTL against Slack's retry schedule. Pure.
Three hundred seconds is not a preference. It is where the last retry
lands, and a shorter TTL is arithmetically incapable of catching it.
"""
if ttl_seconds is None:
return ("unbounded",
"nothing expires. Correct for deduplication and a memory leak "
"with a long fuse; ten minutes is enough and bounded.")
try:
ttl = float(ttl_seconds)
except (TypeError, ValueError):
return ("unreadable", "the ttl is not a number of seconds")
if ttl <= 0:
return ("no-ttl",
"nothing is remembered, so every delivery is the first one this "
"store has seen")
if ttl < LAST_RETRY_SECONDS:
return ("too-short",
"%ds expires before the last retry at %ds. This guard catches "
"the retry you tested and misses the one that arrives five "
"minutes later under load." % (int(ttl), LAST_RETRY_SECONDS))
if ttl < COMFORTABLE_TTL_SECONDS:
return ("no-margin",
"%ds covers the schedule exactly and leaves nothing for clock "
"skew or a slow queue" % int(ttl))
return ("sufficient",
"%ds covers the last retry at %ds with margin"
% (int(ttl), LAST_RETRY_SECONDS))
def key_coverage(messages, field):
"""Count how often the chosen field is present in real messages. Pure.
The half a read token answers directly. A key present on sixty percent of
traffic is not a key, and what happens to the other forty percent depends
on how the handler treats a missing value: store it and they all collide
with each other, skip the check and they are all processed per delivery.
"""
rows = list(messages or [])
name = str(field or "").strip()
if not rows:
return {"present": 0, "total": 0, "rate": 0.0, "verdict": "no-sample",
"detail": "no messages were sampled, so coverage is unmeasured"}
present = sum(1 for m in rows if isinstance(m, dict) and m.get(name))
total = len(rows)
rate = round(present * 100.0 / total, 1)
if present == 0:
return {"present": present, "total": total, "rate": rate, "verdict": "never",
"detail": "%s is on none of the %d sampled message(s); a key that "
"is always absent is not a key" % (name, total)}
if rate >= 99.5:
return {"present": present, "total": total, "rate": rate,
"verdict": "always-present",
"detail": "%s on %d of %d sampled message(s), %.1f%%"
% (name, present, total, rate)}
return {"present": present, "total": total, "rate": rate, "verdict": "sparse",
"detail": "%s is missing from %d of %d sampled message(s). Those "
"events either all collide on the empty key, losing work, "
"or all skip the guard, duplicating it."
% (name, total - present, total)}
def get(session, method, **params):
r = session.get(API + method, params=params, timeout=30)
try:
return r.json()
except ValueError:
return {"ok": False, "error": "unparseable_body"}
def main():
ap = argparse.ArgumentParser(description=__doc__)
ap.add_argument("--token-env", default="SLACK_BOT_TOKEN")
ap.add_argument("--key", default="event_id",
help="the key expression the handler dedupes on")
ap.add_argument("--ttl", default="600",
help="the dedupe store's ttl in seconds, or none")
ap.add_argument("--field", action="append", default=[],
help="message field to measure coverage for; repeatable")
ap.add_argument("--channels", type=int, default=5,
help="how many of the bot's channels to sample")
args = ap.parse_args()
findings = 0
key = key_stability(args.key)
good_key = key["verdict"] == "stable-unique"
(log.info if good_key else log.warning)(
"key %-14s %s %s", key["verdict"], args.key, key["detail"])
if not good_key:
findings += 1
ttl = None if str(args.ttl).strip().lower() in ("none", "") else args.ttl
state, detail = ttl_verdict(ttl)
(log.info if state == "sufficient" else log.warning)(
"ttl %-14s %s", state, detail)
log.info("schedule retries %s seconds after the original, so the "
"last one to remember is %ds old",
", ".join(str(x) for x in RETRY_SCHEDULE_SECONDS), LAST_RETRY_SECONDS)
if state != "sufficient":
findings += 1
fields = args.field or ["ts", "client_msg_id"]
token = os.environ.get(args.token_env)
if not token:
log.info("coverage skipped set %s to measure how often each "
"field is present", args.token_env)
else:
s = requests.Session()
s.headers.update({"Authorization": "Bearer " + token})
who = get(s, "auth.test")
if who.get("ok") is not True:
log.error("auth.test answered 200 with ok: false, error=%s", who.get("error"))
return 2
mine = get(s, "users.conversations", user=who.get("user_id", ""),
types="public_channel,private_channel", limit=200)
ids = [c.get("id") for c in (mine.get("channels") or [])][:max(args.channels, 1)]
sample = []
for cid in ids:
page = get(s, "conversations.history", channel=cid, limit=200)
if page.get("ok") is not True:
log.warning("coverage skipped %s on %s", page.get("error"), cid)
continue
sample.extend(page.get("messages") or [])
for name in fields:
cov = key_coverage(sample, name)
(log.info if cov["verdict"] == "always-present" else log.warning)(
"coverage %-14s %s", cov["verdict"], cov["detail"])
if cov["verdict"] == "sparse" and name == args.key:
findings += 1
if findings:
log.warning(" repair: dedupe on event.event_id, which identifies the "
"event rather than the delivery and arrives identically over "
"http and Socket Mode")
log.warning(" repair: give the store a ten minute ttl so the retry at "
"300 seconds is still remembered when it lands")
log.warning(" repair: put the event id on the created record as an "
"external key, so a cold dedupe cache cannot double-create")
return 1
log.info("verdict %-14s the key is stable, unique and always present", "ok")
return 0
if __name__ == "__main__":
sys.exit(main())
/**
* Audit the idempotency key a Slack event handler dedupes on.
*
* Read only. This script never counts duplicate messages; that is a different
* question with a different script. It takes the key expression and TTL the
* handler uses, places them against the two properties an idempotency key
* needs and against Slack's retry schedule, and then samples history to
* measure how often the chosen field is actually present in real traffic.
*/
const API = 'https://slack.com/api/';
// The last retry a store has to remember is five minutes old.
const RETRY_SCHEDULE_SECONDS = [0, 60, 300];
const LAST_RETRY_SECONDS = 300;
const COMFORTABLE_TTL_SECONDS = 600;
// The expressions people actually write, against the two properties a key
// needs. Failing stability dedupes nothing; failing uniqueness dedupes too
// much, which loses work and is much harder to notice.
const KEY_TABLE = new Map([
['event_id', [true, true,
'identifies the event, not the delivery, and Slack sends the same one on ' +
'every retry of it. Present on every event type.']],
['event.event_id', [true, true, 'the same field, spelled with its envelope']],
['event_time', [true, false,
'stable, and only second granularity: two events in the same second ' +
'collide and one of them is silently dropped']],
['event.ts', [true, false,
'stable for one message and shared by every event about that message, so ' +
'the reaction and the edit collide with it']],
['ts', [true, false, 'the same field without its envelope']],
['client_msg_id', [true, true,
'stable and unique where it exists, and it exists only on messages a ' +
'person typed into a Slack client. Check the coverage line before ' +
'trusting it.']],
['x-slack-signature', [false, true,
'recomputed per delivery over a fresh request timestamp, so the retry ' +
'never matches the original. A set keyed on this rejects nothing.']],
['x-slack-request-timestamp', [false, true, "the delivery's clock, not the event's"]],
['received_at', [false, true, 'your clock, which moves']],
['uuid', [false, true, 'generated per delivery, so every delivery is new']],
['x-slack-retry-num', [false, false,
'a flag, not a key: it says whether this is a retry and not which event it ' +
'is. It is also absent under Socket Mode, so a guard built on it ' +
'disappears when the transport changes.']],
['body_hash', [true, true,
'identical across retries in practice, and brittle: it covers envelope ' +
'fields you do not control, and re-wrapping the payload through your own ' +
'queue changes it']],
]);
/**
* Place a key expression against stability and uniqueness. Pure.
* The two properties are separate on purpose: failing stability produces
* duplicates, failing uniqueness produces missing work.
*/
export function keyStability(expression) {
const name = String(expression ?? '').trim().toLowerCase().replace(/^\$+/, '');
const row = KEY_TABLE.get(name);
if (!row) {
return {
verdict: 'unrecognised',
stable: null,
unique: null,
detail: 'not an expression this script knows. Check it by hand: does the ' +
'retry carry the same value, and do two different events get different ones?',
};
}
const [stable, unique, detail] = row;
let verdict = 'stable-collides';
if (stable && unique) verdict = 'stable-unique';
else if (!stable && !unique) verdict = 'flag-not-key';
else if (!stable) verdict = 'not-stable';
if (name === 'client_msg_id') verdict = 'sparse';
return { verdict, stable, unique, detail };
}
/**
* Hold the dedupe store's TTL against Slack's retry schedule. Pure.
* Three hundred seconds is where the last retry lands, not a preference.
*/
export function ttlVerdict(ttlSeconds) {
if (ttlSeconds === null || ttlSeconds === undefined) {
return ['unbounded',
'nothing expires. Correct for deduplication and a memory leak with a ' +
'long fuse; ten minutes is enough and bounded.'];
}
const ttl = Number(ttlSeconds);
if (!Number.isFinite(ttl)) return ['unreadable', 'the ttl is not a number of seconds'];
if (ttl <= 0) {
return ['no-ttl',
'nothing is remembered, so every delivery is the first one this store has seen'];
}
if (ttl < LAST_RETRY_SECONDS) {
return ['too-short',
`${Math.trunc(ttl)}s expires before the last retry at ${LAST_RETRY_SECONDS}s. ` +
'This guard catches the retry you tested and misses the one that arrives ' +
'five minutes later under load.'];
}
if (ttl < COMFORTABLE_TTL_SECONDS) {
return ['no-margin',
`${Math.trunc(ttl)}s covers the schedule exactly and leaves nothing for ` +
'clock skew or a slow queue'];
}
return ['sufficient',
`${Math.trunc(ttl)}s covers the last retry at ${LAST_RETRY_SECONDS}s with margin`];
}
/**
* Count how often the chosen field is present in real messages. Pure.
* A key present on sixty percent of traffic is not a key, and what happens to
* the other forty percent depends on how the handler treats a missing value.
*/
export function keyCoverage(messages, field) {
const rows = [...(messages ?? [])];
const name = String(field ?? '').trim();
if (rows.length === 0) {
return {
present: 0, total: 0, rate: 0, verdict: 'no-sample',
detail: 'no messages were sampled, so coverage is unmeasured',
};
}
const present = rows.filter((m) => m && typeof m === 'object' && m[name]).length;
const total = rows.length;
const rate = Math.round((present * 1000.0) / total) / 10;
if (present === 0) {
return {
present, total, rate, verdict: 'never',
detail: `${name} is on none of the ${total} sampled message(s); a key that ` +
'is always absent is not a key',
};
}
if (rate >= 99.5) {
return {
present, total, rate, verdict: 'always-present',
detail: `${name} on ${present} of ${total} sampled message(s), ${rate}%`,
};
}
return {
present, total, rate, verdict: 'sparse',
detail: `${name} is missing from ${total - present} of ${total} sampled ` +
'message(s). Those events either all collide on the empty key, losing ' +
'work, or all skip the guard, duplicating it.',
};
}
async function get(token, method, params) {
const qs = new URLSearchParams(params);
const res = await fetch(`${API}${method}?${qs}`, {
headers: { Authorization: `Bearer ${token}` },
});
try { return await res.json(); } catch { return { ok: false, error: 'unparseable_body' }; }
}
function arg(args, name, fallback = '') {
const i = args.indexOf(name);
return i === -1 ? fallback : args[i + 1];
}
function argAll(args, name) {
const out = [];
for (let i = 0; i < args.length; i += 1) {
if (args[i] === name && args[i + 1] !== undefined) out.push(args[i + 1]);
}
return out;
}
async function main() {
const args = process.argv.slice(2);
const keyExpr = arg(args, '--key', 'event_id');
const ttlArg = arg(args, '--ttl', '600');
const channels = Number(arg(args, '--channels', 5));
let findings = 0;
const key = keyStability(keyExpr);
const goodKey = key.verdict === 'stable-unique';
(goodKey ? console.log : console.warn)(
`key ${key.verdict.padEnd(14)} ${keyExpr} ${key.detail}`);
if (!goodKey) findings += 1;
const ttl = ['none', ''].includes(String(ttlArg).trim().toLowerCase()) ? null : ttlArg;
const [state, detail] = ttlVerdict(ttl);
(state === 'sufficient' ? console.log : console.warn)(
`ttl ${state.padEnd(14)} ${detail}`);
console.log(`schedule retries ${RETRY_SCHEDULE_SECONDS.join(', ')} seconds ` +
`after the original, so the last one to remember is ${LAST_RETRY_SECONDS}s old`);
if (state !== 'sufficient') findings += 1;
const fields = argAll(args, '--field');
const wanted = fields.length ? fields : ['ts', 'client_msg_id'];
const tokenEnv = arg(args, '--token-env', 'SLACK_BOT_TOKEN');
const token = process.env[tokenEnv];
if (!token) {
console.log(`coverage skipped set ${tokenEnv} to measure how often ` +
'each field is present');
} else {
const who = await get(token, 'auth.test', {});
if (who.ok !== true) {
console.error(`auth.test answered 200 with ok: false, error=${who.error}`);
process.exitCode = 2;
return;
}
const mine = await get(token, 'users.conversations', {
user: who.user_id ?? '', types: 'public_channel,private_channel', limit: '200',
});
const ids = (mine.channels ?? []).map((c) => c.id).slice(0, Math.max(channels, 1));
const sample = [];
for (const cid of ids) {
// eslint-disable-next-line no-await-in-loop
const page = await get(token, 'conversations.history', { channel: cid, limit: '200' });
if (page.ok !== true) {
console.warn(`coverage skipped ${page.error} on ${cid}`);
continue;
}
sample.push(...(page.messages ?? []));
}
for (const name of wanted) {
const cov = keyCoverage(sample, name);
(cov.verdict === 'always-present' ? console.log : console.warn)(
`coverage ${cov.verdict.padEnd(14)} ${cov.detail}`);
if (cov.verdict === 'sparse' && name === keyExpr) findings += 1;
}
}
if (findings) {
console.warn(' repair: dedupe on event.event_id, which identifies the event ' +
'rather than the delivery and arrives identically over http and Socket Mode');
console.warn(` repair: give the store a ten minute ttl so the retry at ` +
`${LAST_RETRY_SECONDS} seconds is still remembered when it lands`);
console.warn(' repair: put the event id on the created record as an external ' +
'key, so a cold dedupe cache cannot double-create');
process.exitCode = 1;
} else {
console.log('verdict ok the key is stable, unique and always present');
}
}
// Only run when invoked directly, so importing this module in the tests does
// not execute main() and fail the file on a missing token.
if (import.meta.url === `file://${process.argv[1]}`) {
main().catch((err) => { console.error(err.message); process.exitCode = 2; });
}
Add a test
The tests pin the two properties apart, because collapsing them is the mistake the whole note is about. The request signature is asserted to be unique and not stable, which is a guard that rejects nothing; the message timestamp is asserted to be stable and not unique, which is a guard that rejects too much and quietly loses work. The TTL boundary is pinned at exactly three hundred seconds in both directions, since that is Slack's number rather than anybody's preference, and coverage is asserted against a sample containing the message shapes that have no client_msg_id.
from slack_dedupe_key_audit import key_coverage, key_stability, ttl_verdict
SAMPLE = [
{"ts": "1735689600.000100", "user": "U01", "client_msg_id": "aaa-1"},
{"ts": "1735689601.000100", "user": "U01", "client_msg_id": "aaa-2"},
{"ts": "1735689602.000100", "user": "U02", "client_msg_id": "aaa-3"},
{"ts": "1735689603.000100", "bot_id": "B01"},
{"ts": "1735689604.000100", "bot_id": "B01"},
{"ts": "1735689605.000100", "subtype": "channel_join", "user": "U03"},
]
def test_the_event_id_is_the_only_expression_that_passes_both_properties():
row = key_stability("event_id")
assert row["verdict"] == "stable-unique"
assert row["stable"] is True and row["unique"] is True
assert key_stability("event.event_id")["verdict"] == "stable-unique"
def test_a_signature_is_unique_and_not_stable_so_it_rejects_nothing():
row = key_stability("x-slack-signature")
assert row["stable"] is False
assert row["unique"] is True
assert row["verdict"] == "not-stable"
def test_a_message_timestamp_is_stable_and_not_unique_so_it_rejects_too_much():
row = key_stability("event.ts")
assert row["stable"] is True
assert row["unique"] is False
assert row["verdict"] == "stable-collides"
assert key_stability("ts")["verdict"] == "stable-collides"
def test_the_retry_header_is_reported_as_a_flag_rather_than_a_key():
row = key_stability("x-slack-retry-num")
assert row["verdict"] == "flag-not-key"
assert "Socket Mode" in row["detail"]
def test_client_msg_id_is_kept_apart_from_the_keys_that_always_exist():
row = key_stability("client_msg_id")
assert row["verdict"] == "sparse"
assert row["stable"] is True and row["unique"] is True
def test_an_unknown_expression_is_never_guessed_at():
row = key_stability("some_field_we_invented")
assert row["verdict"] == "unrecognised"
assert row["stable"] is None
def test_the_ttl_boundary_is_the_last_retry_and_not_a_preference():
assert ttl_verdict(299)[0] == "too-short"
assert ttl_verdict(300)[0] == "no-margin"
assert ttl_verdict(599)[0] == "no-margin"
assert ttl_verdict(600)[0] == "sufficient"
def test_a_sixty_second_ttl_is_named_for_the_retry_it_misses():
state, detail = ttl_verdict(60)
assert state == "too-short"
assert "300s" in detail
def test_no_ttl_and_no_expiry_are_different_findings():
assert ttl_verdict(0)[0] == "no-ttl"
assert ttl_verdict(None)[0] == "unbounded"
assert ttl_verdict("soon")[0] == "unreadable"
def test_a_field_on_every_message_and_a_field_on_half_of_them():
assert key_coverage(SAMPLE, "ts")["verdict"] == "always-present"
cov = key_coverage(SAMPLE, "client_msg_id")
assert cov["verdict"] == "sparse"
assert cov["present"] == 3
assert cov["rate"] == 50.0
def test_a_missing_field_is_reported_as_never_rather_than_as_sparse():
cov = key_coverage(SAMPLE, "event_id")
assert cov["verdict"] == "never"
assert "not a key" in cov["detail"]
def test_an_empty_sample_is_unmeasured_rather_than_clean():
cov = key_coverage([], "ts")
assert cov["verdict"] == "no-sample"
assert cov["rate"] == 0.0
import { test } from 'node:test';
import assert from 'node:assert/strict';
import { keyCoverage, keyStability, ttlVerdict } from './slack-dedupe-key-audit.mjs';
const SAMPLE = [
{ ts: '1735689600.000100', user: 'U01', client_msg_id: 'aaa-1' },
{ ts: '1735689601.000100', user: 'U01', client_msg_id: 'aaa-2' },
{ ts: '1735689602.000100', user: 'U02', client_msg_id: 'aaa-3' },
{ ts: '1735689603.000100', bot_id: 'B01' },
{ ts: '1735689604.000100', bot_id: 'B01' },
{ ts: '1735689605.000100', subtype: 'channel_join', user: 'U03' },
];
test('the event id is the only expression that passes both properties', () => {
const row = keyStability('event_id');
assert.equal(row.verdict, 'stable-unique');
assert.equal(row.stable, true);
assert.equal(row.unique, true);
assert.equal(keyStability('event.event_id').verdict, 'stable-unique');
});
test('a signature is unique and not stable so it rejects nothing', () => {
const row = keyStability('x-slack-signature');
assert.equal(row.stable, false);
assert.equal(row.unique, true);
assert.equal(row.verdict, 'not-stable');
});
test('a message timestamp is stable and not unique so it rejects too much', () => {
const row = keyStability('event.ts');
assert.equal(row.stable, true);
assert.equal(row.unique, false);
assert.equal(row.verdict, 'stable-collides');
assert.equal(keyStability('ts').verdict, 'stable-collides');
});
test('the retry header is reported as a flag rather than a key', () => {
const row = keyStability('x-slack-retry-num');
assert.equal(row.verdict, 'flag-not-key');
assert.match(row.detail, /Socket Mode/);
});
test('client_msg_id is kept apart from the keys that always exist', () => {
const row = keyStability('client_msg_id');
assert.equal(row.verdict, 'sparse');
assert.equal(row.stable, true);
assert.equal(row.unique, true);
});
test('an unknown expression is never guessed at', () => {
const row = keyStability('some_field_we_invented');
assert.equal(row.verdict, 'unrecognised');
assert.equal(row.stable, null);
});
test('the ttl boundary is the last retry and not a preference', () => {
assert.equal(ttlVerdict(299)[0], 'too-short');
assert.equal(ttlVerdict(300)[0], 'no-margin');
assert.equal(ttlVerdict(599)[0], 'no-margin');
assert.equal(ttlVerdict(600)[0], 'sufficient');
});
test('a sixty second ttl is named for the retry it misses', () => {
const [state, detail] = ttlVerdict(60);
assert.equal(state, 'too-short');
assert.match(detail, /300s/);
});
test('no ttl and no expiry are different findings', () => {
assert.equal(ttlVerdict(0)[0], 'no-ttl');
assert.equal(ttlVerdict(null)[0], 'unbounded');
assert.equal(ttlVerdict('soon')[0], 'unreadable');
});
test('a field on every message and a field on half of them', () => {
assert.equal(keyCoverage(SAMPLE, 'ts').verdict, 'always-present');
const cov = keyCoverage(SAMPLE, 'client_msg_id');
assert.equal(cov.verdict, 'sparse');
assert.equal(cov.present, 3);
assert.equal(cov.rate, 50);
});
test('a missing field is reported as never rather than as sparse', () => {
const cov = keyCoverage(SAMPLE, 'event_id');
assert.equal(cov.verdict, 'never');
assert.match(cov.detail, /not a key/);
});
test('an empty sample is unmeasured rather than clean', () => {
const cov = keyCoverage([], 'ts');
assert.equal(cov.verdict, 'no-sample');
assert.equal(cov.rate, 0);
});
FAQ
Why event_id rather than the message timestamp?
Because the timestamp identifies the message and the event id identifies the event. A message being posted, reacted to and then edited produces three events that a timestamp-keyed set will treat as one, so two of the three are dropped as duplicates when neither is. The event id is different for each of them and identical across the retries of each, which is exactly the pair of properties the guard needs.
Is ten minutes not excessive for a TTL?
It is two entries per event in a set of short strings, for ten minutes. The alternative failure is worse than the memory: at sixty seconds the guard catches the retry at sixty and misses the one at three hundred, so the bug survives your testing and reappears only under the load that produced the slow deliveries in the first place. Three hundred seconds is the floor and six hundred is the number to use.
We moved to Socket Mode and started seeing duplicates again. Why?
Because the retry headers are an HTTP transport feature and Socket Mode does not carry them. Any guard written as “if the retry header is present, skip” silently becomes a no-op on the socket path. The event id is in the event payload itself and arrives identically over both transports, which is one more reason to key on it rather than on delivery metadata.
Should I short-circuit on X-Slack-Retry-Reason?
As a refinement, yes, and never as the guard. A reason of http_timeout means Slack sent the payload, your service accepted it, and the response was late, so the work has probably already been done. connection_failed and ssl_error suggest it has not. Reading that improves your odds on the cases the dedupe store missed; it does not replace the store, and it is unavailable over Socket Mode.
The dedupe check is right and duplicates still appear.
Then the duplicates are probably not retries, and the spacing will tell you: sub-second copies mean two delivery paths or two replicas handling the same event, hours apart means a scheduler running twice. Retry duplicates land at roughly sixty and three hundred seconds and nowhere else. Measuring that spacing is a different script, linked below, and it is the right one to run before changing any of this.
Related field notes
- counting the duplicates and reading their spacing
- why there are retries to deduplicate at all
- the other way one event becomes many
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.
- Events API - Slack Docs
- message event reference - Slack Docs
- Socket Mode - Slack Docs
- conversations.history method reference - Slack Docs
If your setup is misbehaving in a way this note does not cover, message me on LinkedIn with what you are seeing.