上线三个月后的第一次事故：一个 Django 服务的日志、监控与故障复盘

log_format main '$remote_addr - $remote_user [$time_local] "$request" '
                '$status $body_bytes_sent "$http_referer" '
                '"$http_user_agent" "$http_x_forwarded_for" '
                'rt=$request_time urt=$upstream_response_time '
                'upstream=$upstream_addr';

access_log /var/log/nginx/access.log main;

# 最近 1000 行的状态码分布
tail -1000 /var/log/nginx/access.log | awk '{print $9}' | sort | uniq -c | sort -rn
#    612 502
#    288 200
#     97 499        ← 客户端主动断开（用户等不及关了页面）
#      3 504

# 找出最慢的请求
awk '{print $NF, $0}' /var/log/nginx/access.log | sort -rn | head -10

2026/03/11 14:03:22 [error] 8821#0: *152341 connect() to 127.0.0.1:8000 failed
(111: Connection refused) while connecting to upstream, client: ...

# 手工算 P95（没有 Prometheus 时的土办法）
awk '{print $NF}' /var/log/nginx/access.log | sort -n | awk '{a[NR]=$1} END{print a[int(NR*0.95)]}'

INFO 2026-03-11 14:03:11,221 views 处理下载请求
INFO 2026-03-11 14:03:11,228 views 处理下载请求
INFO 2026-03-11 14:03:41,221 views 请求失败

# settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'json': {
            '()': 'pythonjsonlogger.json.JsonFormatter',
            'format': '%(asctime)s %(levelname)s %(name)s %(message)s '
                      '%(request_id)s %(duration_ms)s %(user_id)s',
        },
    },
    'handlers': {
        'file': {
            'level': 'INFO',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': '/var/log/viddown/app.log',
            'maxBytes': 100 * 1024 * 1024,     # 100MB
            'backupCount': 10,                  # 最多 1GB
            'formatter': 'json',
        },
    },
    'loggers': {
        'downloader': {'handlers': ['file'], 'level': 'INFO', 'propagate': False},
    },
}

# middleware.py
import uuid
import time
import logging

logger = logging.getLogger('downloader.request')


class RequestLogMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        request.request_id = request.META.get('HTTP_X_REQUEST_ID') or uuid.uuid4().hex[:16]
        start = time.time()

        response = self.get_response(request)

        duration_ms = int((time.time() - start) * 1000)
        logger.info('request finished', extra={
            'request_id': request.request_id,
            'duration_ms': duration_ms,
            'path': request.path,
            'status': response.status_code,
            'user_id': getattr(request.user, 'id', None),
        })
        # 把 id 回给客户端，用户报障时可以直接给我们
        response['X-Request-ID'] = request.request_id
        return response

grep 'a3f9c2e1b8d04a7f' /var/log/viddown/app.log | jq .

log_format main '... rt=$request_id ...';
proxy_set_header X-Request-ID $request_id;    # 需要 nginx 生成或透传

SENSITIVE_KEYS = {'password', 'token', 'sig', 'signature', 'secret', 'cookie', 'authorization'}

def mask(data: dict) -> dict:
    return {k: ('***' if k.lower() in SENSITIVE_KEYS else v) for k, v in data.items()}

-- 1. 连接数按状态统计
SELECT state, count(*) FROM pg_stat_activity GROUP BY state ORDER BY count(*) DESC;
/*
 state              | count
--------------------+-------
 idle in transaction|    58     ← 危险信号
 active             |    31
 idle               |     9
*/

-- 2. 看当前上限
SHOW max_connections;                      -- 100
SELECT count(*) FROM pg_stat_activity;     -- 98

-- 3. 找出最老的事务
SELECT pid,
       now() - xact_start AS duration,
       state,
       wait_event_type,
       left(query, 80) AS query
FROM pg_stat_activity
WHERE xact_start IS NOT NULL
ORDER BY duration DESC
LIMIT 10;

-- 4. 看谁在等锁
SELECT pid, wait_event_type, wait_event, left(query, 60)
FROM pg_stat_activity
WHERE wait_event_type = 'Lock';

-- 温柔：取消这个连接的当前查询
SELECT pg_cancel_backend(<pid>);

-- 强硬：直接终止连接
SELECT pg_terminate_backend(<pid>);

-- 批量清理：终止所有 idle in transaction 超过 5 分钟的连接
SELECT pg_terminate_backend(pid)
FROM pg_stat_activity
WHERE state = 'idle in transaction'
  AND now() - state_change > interval '5 minutes';

redis-cli llen parse
redis-cli llen download
celery -A video_downloader inspect active

13:52  统计接口的全表扫描开始变慢（数据量增长到某个临界点）
   ↓
13:55  这个查询占住数据库连接（每个请求 8 秒）
   ↓
13:58  并发上来，连接被占满
   ↓
14:00  新请求拿不到连接 → Django 报 OperationalError
   ↓
14:01  用户看到错误 → 刷新页面 → 请求量翻倍
   ↓
14:03  连接彻底耗尽，gunicorn worker 全部卡在等连接
   ↓
14:03  nginx 连不上 → 502

DATABASES = {
    'default': {
        ...
        'OPTIONS': {
            'statement_timeout': 5000,      # 单条 SQL 超过 5 秒就取消（毫秒）
            'connect_timeout': 5,
        },
    }
}

async function fetchWithRetry(url, maxRetry = 3) {
    for (let i = 0; i < maxRetry; i++) {
        try {
            return await fetch(url);
        } catch (e) {
            if (i === maxRetry - 1) throw e;
            // 指数退避 + 随机抖动（避免所有客户端同时重试）
            const delay = Math.min(1000 * 2 ** i, 8000) + Math.random() * 1000;
            await new Promise(r => setTimeout(r, delay));
        }
    }
}

# settings.py 或数据库配置表
FEATURE_FLAGS = {
    'stats_page': False,        # 出事时改成 False，页面直接返回维护中
}

#!/bin/bash
# /opt/scripts/probe.sh —— 每分钟跑一次，失败就告警
URLS=("https://example.com/" "https://example.com/api/health")

for url in "${URLS[@]}"; do
    code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 10 "$url")
    if [ "$code" != "200" ]; then
        echo "ALERT: $url returned $code"
        # 发到告警渠道
    fi
done

def health(request):
    from django.db import connection
    from django.core.cache import cache
    checks = {}
    try:
        with connection.cursor() as c:
            c.execute('SELECT 1')
        checks['db'] = 'ok'
    except Exception as e:
        checks['db'] = f'fail: {e}'

    try:
        cache.set('health_check', '1', 5)
        checks['cache'] = 'ok' if cache.get('health_check') == '1' else 'fail'
    except Exception as e:
        checks['cache'] = f'fail: {e}'

    status = 200 if all(v == 'ok' for v in checks.values()) else 503
    return JsonResponse(checks, status=status)

#!/bin/bash
# /opt/scripts/metrics.sh —— 每 5 分钟跑，异常就告警
HOST=$(hostname)

# 数据库连接数
DB_CONN=$(psql -U viddown -h 127.0.0.1 -tAc "SELECT count(*) FROM pg_stat_activity")
DB_MAX=$(psql -U viddown -h 127.0.0.1 -tAc "SHOW max_connections")
if [ "$DB_CONN" -gt $((DB_MAX * 80 / 100)) ]; then
    echo "WARN: $HOST db connections $DB_CONN/$DB_MAX"
fi

# 队列长度
QUEUE=$(redis-cli llen download)
if [ "$QUEUE" -gt 1000 ]; then
    echo "WARN: $HOST queue length $QUEUE"
fi

# 磁盘
df -h | awk 'NR>1 && $5+0 > 85 {print "WARN: '"$HOST"' disk " $6 " " $5}'

# 5xx 比例（最近 1000 行）
ERR=$(tail -1000 /var/log/nginx/access.log | grep -c ' 5[0-9][0-9] ')
if [ "$ERR" -gt 10 ]; then
    echo "WARN: $HOST 5xx count in last 1000 req: $ERR"
fi

# 不好
except Exception:
    logger.error('下载失败')

# 好
except Exception:
    logger.error('下载失败', exc_info=True, extra={
        'task_id': task.id,
        'url': mask_url(task.url),      # 脱敏！
        'retry': retry_count,
        'file_size': task.size,
    })

start = time.time()
result = call_external_api()
duration = time.time() - start
if duration > 1.0:
    logger.warning('外部 API 慢', extra={'duration_ms': int(duration*1000), 'api': name})
logger.info('外部 API 完成', extra={'duration_ms': int(duration*1000)})

# 找出所有超过 5 秒的请求
jq 'select(.duration_ms > 5000)' /var/log/viddown/app.log

# 按接口统计错误数
jq -r 'select(.levelname=="ERROR") | .path' app.log | sort | uniq -c | sort -rn

# 事故复盘：<一句话描述>

## 影响
- 时间：2026-03-11 14:03 ~ 14:35（32 分钟）
- 影响范围：全部下载功能不可用，约 XXX 次请求失败
- 影响用户：约 XXX 人

## 时间线
| 时间 | 事件 |
|---|---|
| 13:52 | 根因触发 |
| 14:07 | 用户反馈（我们此时才知道） |
| ... | ... |

## 根因
<技术层面的根因，要具体到"哪行代码/哪个配置">

## 为什么没早发现
<监控/告警的缺失>

## 改进行动
| 行动 | 负责人 | 截止 | 状态 |
|---|---|---|---|
| 加 statement_timeout | 张三 | 03-12 | 已完成 |
| 建外部拨测 | 李四 | 03-15 | 已完成 |
| 慢查询治理 | 王五 | 03-20 | 进行中 |

## 做得好的地方
<也要写，比如恢复速度快、沟通及时>