Python后端部署排障14:用户说刚才失败了,你能找到那一条请求吗 Python后端部署排障14用户说刚才失败了你能找到那一条请求吗同一时刻Nginx写了一行502应用写了几十行200Docker健康检查仍是healthy。三条信息都可能真实却不一定属于同一条请求。若把它们直接拼成故事就会得出“应用明明成功代理一定误报”的结论。排障首先需要一个可靠的关联键然后才讨论状态码、耗时和错误原因。QuoteOps沿用报价服务的X-Request-ID。入口接收合规的标识或生成新值再转发给应用应用将同一标识写进响应与结构化日志。日志只选择白名单字段不记录查询字符串、Authorization或请求正文。这样我们既能追踪一次创建报价又不需要把供应商数据和凭据变成遍布磁盘的副本。E13完整答案回滚流量恢复独立快照从课程根目录执行python3 lessons/14/answer_previous.py。它依赖正在运行的实验环境缺少环境会明确失败。完整代码如下E13: rollback preserves business data; restore a SQLite snapshot independently.importjsonfromcontextlibimportclosingfrompathlibimportPathimportsqlite3importsubprocessimportsysimporttempfilefromurllib.requestimportRequest,urlopen ROOTPath(__file__).resolve().parents[2]deflab(*args):resultsubprocess.run([sys.executable,str(ROOT/ops/labctl.py),*args],cwdROOT,checkTrue,textTrue,capture_outputTrue)returnjson.loads(result.stdout)defhttp(base,path,bodyNone):dataNoneifbodyisNoneelsejson.dumps(body).encode()requestRequest(basepath,datadata,headers{Content-Type:application/json})withurlopen(request,timeout8)asresponse:returnjson.load(response)defsnapshot(source,destination):# modero rejects a missing source instead of creating an empty database.withclosing(sqlite3.connect(source.as_uri()?modero,uriTrue))assrc:withclosing(sqlite3.connect(destination))asdst:src.backup(dst,pages64,sleep0.02)assertdst.execute(PRAGMA integrity_check).fetchone()(ok,)defprove_snapshot(exported):backupexported.parent/snapshot.sqliterestoredexported.parent/restored.sqlitewithclosing(sqlite3.connect(exported))asdb,db:beforedb.execute(SELECT * FROM quotes ORDER BY id).fetchall()assertbefore,Export should contain the exercise quotedb.execute(CREATE TABLE exercise_marker (value TEXT NOT NULL))db.execute(INSERT INTO exercise_marker VALUES (before))snapshot(exported,backup)withclosing(sqlite3.connect(exported))asdb,db:db.execute(UPDATE exercise_marker SET value after)snapshot(backup,restored)withclosing(sqlite3.connect(restored))asdb:assertdb.execute(SELECT value FROM exercise_marker).fetchone()(before,)assertdb.execute(SELECT * FROM quotes ORDER BY id).fetchall()beforewithclosing(sqlite3.connect(exported))asdb:assertdb.execute(SELECT value FROM exercise_marker).fetchone()(after,)return{quote_rows:len(before),restored_marker:before,source_marker:after,integrity_check:ok}defmain():statelab(status)basestate[http_url].rstrip(/)lab(release,green)beforehttp(base,/quotes,{sku:E13,supplier:rollback,quantity:2,unit_cents:125,shipping_cents:50})assertbefore[total_cents]300lab(rollback)asserthttp(base,/ops/version)[release]v1asserthttp(base,/quotes/before[id])beforewithtempfile.TemporaryDirectory(prefixquoteops-e13-)asname:exportedPath(name).resolve()/source.sqlitelab(export-db,--output,str(exported))evidenceprove_snapshot(exported)print(json.dumps({status:PASS,exercise:E13,release:v1,quote_id:before[id],unchanged:True,**evidence}))if__name____main__:main()代码创建的是可见业务记录备份实验修改的却是导出到临时目录中的专属标记表。after before比较完整HTTP响应包含金额、状态、版本和创建时间。恢复后的SQL比较则覆盖所有报价行。两种证据作用不同前者证明旧代码仍能处理新版本期间的数据后者证明备份副本保留了快照内容。输出PASS表示这些断言均已执行不能把注释或预计输出当成运行报告。先约定哪些字段值得记录应用访问日志的字段包括event、method、路由模板path、status、duration_ms和request_id。路由模板是/quotes/{quote_id}而不是带具体业务id的原始地址。这使日志聚合可以按同一操作统计避免每一条报价都产生一个新的维度。未知路由使用受控占位值避免攻击者把任意路径写进日志。Nginx记录入口状态、请求耗时、上游状态和上游耗时可以区分代理自己产生的错误与应用返回的错误。完整配置见deploy/nginx.conf阅读时重点确认它使用不带查询的路径字段而不是包含查询的$request或$request_uri。应用本身关闭Uvicorn默认访问日志避免另一路日志重新打印完整URL。安全要求必须覆盖整条日志链只修改业务logger不代表服务器访问日志也安全。还有一处容易漏掉Nginx请求级error日志可能自带原始请求行包含查询字符串不能沿用访问日志的格式白名单。因此本配置把error日志阈值设为crit保留严重运行错误常见502诊断使用结构化访问日志的upstream字段、Docker State和受控连接探测。不要期待默认配置一定打印逐请求的connect failed文本更不要为了一次排查随意降低级别后忘记恢复。临时加深诊断必须限定无秘密的受控请求和明确时间窗。不要为了“字段越全越好”记录请求体、cookie、Authorization或完整查询。调试信息复制到日志平台后保留时间和访问人群可能比业务数据库更广。确实需要定位某个业务对象时可在专门受控的审计流程使用经过评审的标识而不是临时在公共中间件里print(request)。本课程采用白名单是为了让每个新增字段都有明确理由。关联标识也需要限制。允许任意长度和换行的请求头进入日志会产生日志伪造、额外存储消耗和聚合困难。应用只接受由字母、数字、下划线和连字符组成的短标识否则生成随机值。它是追踪键不能用作身份认证或授权依据客户端可以提交一个合规值不能据此获得任何报价的访问权限。用一条可识别请求打穿日志链排查时先拿响应中的X-Request-ID。若客户端超时而拿不到响应可以在请求发出前设置自己生成的合规id并同时记录UTC时间、方法和目标环境。再按该id查入口日志与应用日志观察两层是否都存在。不要拿另一分钟的一条200填补当前请求的空白也不要在多实例环境只看一个容器。# 命令输出的URL、容器ID与当前active来自本次状态文件。python3 ops/labctl.py status python3 ops/labctl.py drill logsdrill logs负责生成受控请求并收集证据。下一课的E14答案还会独立发起POST给查询、正文和Authorization分别放入无真实秘密的随机标记读取edge及当前活动应用的日志断言同一个request_id出现同时断言这些标记没有出现。这种反向检查很关键能够找到id只能证明可追踪不能证明没有额外泄漏。正常业务日志主要写stdout/stderr由容器运行时收集应用不在容器里管理不断增长的日志文件。课程Compose为日志配置大小与文件数上限目的是把最坏磁盘占用限制在可解释范围内。限额不等于永久留存滚动覆盖后旧记录可能消失。需要更长保留期时应设计外部收集、访问控制和留存策略而不是单纯把本地文件限制调到无限大。用证据区分“未到应用”和“应用处理失败”同一个id出现在edge返回502但应用日志没有该id优先检查上游连接、服务名解析、进程监听和容器状态。应用没有日志不是最终定论日志可能被轮转、尚未刷新、查错容器或采集失败。先确认时间范围和实例再用访问日志中的上游地址与Docker运行状态佐证连接目标。当前配置不会保证提供逐请求error文本必须尊重实际采集边界。同一个id在应用返回503edge也返回503说明请求已进入应用并被应用主动拒绝。可以继续检查/ready、数据库是否迁移、数据目录权限以及忙锁情况。看到503就重启Nginx无法改变数据库状态。反过来如果edge是504而应用稍后记录200说明代理等待预算已用完后端却可能继续执行了业务这时盲目重试POST会引入重复操作风险。不要把所有500都当作同一种故障。应用异常日志记录异常类型和受控应用栈帧不把异常字符串、局部变量或请求体输出。访问日志提供请求id和状态异常日志提供同id的类型及代码位置两者组合才能落到可检查的执行路径。对于已知业务冲突例如旧version提交得到409应把它视为合同中的并发控制结果不能与未处理异常混为一谈。平均延迟会隐藏慢请求假设一百条请求中九十九条耗时十毫秒另一条耗时十秒平均值约为一百一十毫秒。平均值看起来仍可接受那位等待十秒的用户却有完全不同的体验。分位数回答“某个比例的请求不超过多长时间”因此p95与p99通常比平均值更能暴露尾部延迟。但样本只有几十条时p99几乎就是某个极端样本不应该包装成稳定容量结论。延迟指标要带上统计窗口、样本量和操作类型。创建报价与读取报价的工作不同若把它们混在一个平均值里流量结构变化就可能看起来像性能退化。失败请求也不能被默默排除否则系统大量快速失败时仪表盘可能显示“延迟很好”。课程实验规模适合解释测量方法不足以宣布某个生产吞吐量。同样要区分入口总耗时与上游耗时。前者可能包含排队、请求读取和响应发送后者描述代理与上游交互的一部分。两者之差不必全是“网络耗时”。时间字段来自不同组件时还需要考虑时钟同步和计时定义。排查时先读取当前软件的字段含义不要见到两个数字就机械相减。聚合时还要控制标签的基数。把request_id作为指标标签几乎每个请求都会创建一个新序列存储和查询成本会迅速增长把它留在日志中用于定位单次事件更合适。指标可以按受控路由模板、方法、状态类别与release汇总再从异常时间窗挑选代表性的日志样本。用户输入、完整URL和具体报价id都不适合直接充当无限扩张的指标维度。日志时间也不应只依赖终端显示。查阅容器日志时限定时间窗并记录采用UTC还是本地时区跨机器比较事件先确认时钟偏差。精确到毫秒的文本不代表时钟真的精确到毫秒。若两条日志的先后顺序与因果关系冲突优先使用请求id、业务version和操作阶段确认关联再检查计时条件而不是马上宣布系统出现了不可能的执行顺序。健康信号、日志和指标各回答一个问题健康端点回答某一时刻某个实例是否满足指定条件。日志解释某次离散事件指标呈现一段时间内的变化趋势。/health成功不意味着数据库可用/ready成功不意味着所有历史记录都正确没有错误日志也不意味着没有错误请求。三者互相补充任何一项都不是万能证明。实际值班可先确定影响范围失败比例、开始时间、受影响操作以及哪个发布版本。随后用代表性request_id贯穿入口和应用选择最有区分力的下一项检查。若已经有明确的上游连接拒绝就先验证监听和容器状态若证据指向数据准备问题就检查ready及存储。这样每次命令都在缩小问题空间日志才是决策材料而不是越堆越高的输出。本课练习E14关联可见敏感标记不可见自己生成一个合规request_id对/quotes发起创建请求查询、正文和Authorization各放一个不同的虚构随机标记。断言状态201、金额正确、响应头id一致然后读取本次edge和活动应用最近日志。两层都应出现该id和成功状态三类敏感标记均不应出现。保留命中的结构化日志作为证据不提交真实凭据。下一篇给出完整E14答案。我们将故障从“连接地址写错”推进到“资源确实不够”观察受限tmpfs写满、资源预算和退出码学习为什么看到137还不能直接说发生了OOM。课程目录《Linux、网络与后端部署排障从“接口能跑”走到“服务能维护”》 · 上一篇第13篇 · 下一篇第15篇