1-4-3-错误日志就是你的语言哲学

1.4.3 "错误日志就是你的语言哲学"

引言

错误日志常常被视为技术细节——"只要能定位问题就行"。

但实际上，日志是代码的一种叙述方式，反映了你如何理解系统。

好的日志讲述一个清晰的故事："系统做了什么，遇到了什么问题"
差的日志是一堆噪音："到处都是 print，但没有有用信息"

日志质量反映了程序员的思维质量。

日志的层次

层次1：噪音日志

print("here")
print("here2")
print("data:", data)
print("xxx")
print("debug")

问题：

没有上下文
不知道是哪里的日志
不知道什么时候输出的
事后很难理解

层次2：基础日志

logging.info("Processing order")
logging.info("Order processed")

稍好：至少有日志级别。

问题：缺少关键信息（哪个订单？结果如何？）

层次3：上下文日志

logging.info(f"Processing order {order_id}")
logging.info(f"Order {order_id} processed successfully, total={total}")

好处：有上下文，能追踪特定订单。

缺点：如果出错了，不知道详细原因。

层次4：结构化日志

logger.info("Processing order", extra={
    'order_id': order_id,
    'user_id': user.id,
    'items_count': len(items),
    'total_amount': total,
    'processing_time_ms': elapsed_ms
})

好处：

可搜索（按 order_id, user_id 搜索）
可聚合（统计平均处理时间）
可分析（哪些订单处理慢？）

层次5：叙事日志

# 开始处理
logger.info("Order processing started", extra={
    'order_id': order_id,
    'user_id': user.id,
    'items_count': len(items)
})

# 验证阶段
logger.info("Order validation passed", extra={
    'order_id': order_id
})

# 计算阶段
logger.info("Order total calculated", extra={
    'order_id': order_id,
    'subtotal': subtotal,
    'tax': tax,
    'total': total
})

# 保存阶段
logger.info("Order saved to database", extra={
    'order_id': order_id,
    'db_write_time_ms': db_time
})

# 完成
logger.info("Order processing completed", extra={
    'order_id': order_id,
    'total_time_ms': total_time
})

好处：讲述了一个完整的故事，重现了处理流程。

日志的语言哲学

原则1：日志要讲故事，不是喊口号

# 喊口号：没有信息量
logger.info("Success!")
logger.error("Failed!")

# 讲故事：提供上下文
logger.info(f"Successfully created user account for {email}")
logger.error(f"Failed to create user account for {email}: email already exists")

原则2：用业务语言，不只是技术语言

# 只有技术语言
logger.error("Database INSERT failed with code 1062")

# 业务 + 技术
logger.error(f"Cannot create user {email}: email already registered (DB error 1062: duplicate key)")

原则3：日志级别要准确

ERROR：需要立即关注的问题

logger.error(f"Payment processing failed for order {order_id}: {error}")
logger.error(f"Database connection lost: {error}")

WARNING：潜在问题，但系统仍可运行

logger.warning(f"Slow query detected: {query_time}ms for query {query}")
logger.warning(f"API rate limit reached, using fallback data")

INFO：重要的业务事件

logger.info(f"User {user_id} logged in from IP {ip}")
logger.info(f"Order {order_id} shipped, tracking number: {tracking}")

DEBUG：开发时有用的详细信息

logger.debug(f"Cache hit for key {cache_key}")
logger.debug(f"Parsing JSON response: {response_text[:100]}")

日志的反模式

反模式1：日志太少

def process_payment(order):
    # 没有任何日志
    charge_card(order.payment_method, order.total)
    order.status = 'paid'
    db.save(order)
    return True

问题：出错时完全不知道发生了什么。

反模式2：日志太多

def process_payment(order):
    logger.info("Entering process_payment")
    logger.info(f"order = {order}")
    logger.info("Calling charge_card")
    logger.info(f"payment_method = {order.payment_method}")
    logger.info(f"total = {order.total}")
    result = charge_card(order.payment_method, order.total)
    logger.info(f"charge_card returned {result}")
    logger.info("Setting order status")
    order.status = 'paid'
    logger.info(f"order.status is now {order.status}")
    logger.info("Saving to database")
    db.save(order)
    logger.info("Database save complete")
    logger.info("Returning True")
    return True

问题：噪音太多，淹没了关键信息。

反模式3：日志重复代码

# 日志只是重复代码
logger.info("Adding item to cart")
cart.add(item)

logger.info("Removing item from cart")
cart.remove(item)

代码已经说明了在做什么，日志应该记录"为什么"或"结果"。

# 更好：记录关键信息
logger.info(f"Added item {item.id} to cart {cart.id}, new total: {cart.total}")
logger.info(f"Removed item {item.id} from cart {cart.id}, refund: {refund_amount}")

反模式4：敏感信息泄露

# 危险：记录了密码
logger.info(f"User login attempt: username={username}, password={password}")

# 危险：记录了信用卡号
logger.info(f"Processing payment: card={card_number}")

# 正确：脱敏处理
logger.info(f"User login attempt: username={username}")
logger.info(f"Processing payment: card=****{card_number[-4:]}")

设计好的日志系统

设计1：关联 ID

每个请求/事务都有唯一 ID，所有相关日志都带上这个 ID。

import uuid

class RequestContext:
    def __init__(self):
        self.request_id = str(uuid.uuid4())

def process_order(order, context):
    logger.info("Order processing started", extra={
        'request_id': context.request_id,  # 关联 ID
        'order_id': order.id
    })

    # 所有后续日志都带上 request_id
    validate_order(order, context)
    save_order(order, context)

# 查日志时，可以用 request_id 过滤，看到完整的处理流程

设计2：分级日志

# 开发环境：DEBUG 及以上
logging.basicConfig(level=logging.DEBUG)

# 生产环境：INFO 及以上
logging.basicConfig(level=logging.INFO)

# 关键路径：始终记录（用 WARNING 或以上）
logger.warning(f"Critical operation: processing payment for ${amount}")

设计3：结构化日志

# 使用结构化日志库（如 structlog, python-json-logger）
import structlog

logger = structlog.get_logger()

logger.info("order_processed",
    order_id=order.id,
    user_id=user.id,
    amount=order.total,
    processing_time_ms=elapsed
)

# 输出 JSON，易于机器解析
# {"event": "order_processed", "order_id": 123, "user_id": 456, "amount": 99.9, ...}

设计4：错误上下文

try:
    process_payment(order)
except PaymentError as e:
    logger.error("Payment processing failed", extra={
        'order_id': order.id,
        'error_type': type(e).__name__,
        'error_message': str(e),
        'payment_method': order.payment_method.type,
        'amount': order.total,
    }, exc_info=True)  # exc_info=True 包含堆栈跟踪
    raise

日志的可观测性

观测1：性能日志

import time

def process_order(order):
    start_time = time.time()

    validate_order(order)
    save_order(order)
    send_notification(order)

    elapsed = (time.time() - start_time) * 1000

    logger.info("Order processed", extra={
        'order_id': order.id,
        'processing_time_ms': elapsed,
        'slow_query': elapsed > 1000  # 标记慢查询
    })

观测2：业务指标日志

# 记录业务指标，用于后续分析
logger.info("Order completed", extra={
    'order_id': order.id,
    'revenue': order.total,
    'items_count': len(order.items),
    'user_type': user.type,
    'discount_applied': order.discount > 0
})

# 后续可以聚合：
# - 今日总收入
# - 平均订单金额
# - VIP 用户占比

观测3：异常模式检测

# 记录异常事件
def handle_api_error(error):
    logger.warning("API error encountered", extra={
        'api_endpoint': error.endpoint,
        'error_code': error.code,
        'retry_count': error.retry_count
    })

# 如果某个endpoint错误率突然上升，可以发现问题

对使用AI的建议

AI生成的日志常见问题

# AI 可能生成
def process_order(order):
    print("Processing order")  # 使用 print 而不是 logging
    # ...
    print("Order processed")

# 应该改成
def process_order(order):
    logger.info(f"Processing order {order.id}")
    # ...
    logger.info(f"Order {order.id} processed successfully")

如何让AI生成好的日志

请为这个函数添加日志，要求：
1. 使用 logging 模块，不要用 print
2. 记录函数的输入参数
3. 记录关键步骤的执行
4. 记录执行时间
5. 如果出错，记录详细的错误信息和上下文
6. 使用结构化日志（extra 参数）

实践检查清单

写完代码后，检查日志：

关键操作都有日志（创建、更新、删除）
日志包含必要的上下文（ID、金额、用户等）
日志级别正确（ERROR/WARNING/INFO/DEBUG）
没有记录敏感信息（密码、信用卡号）
错误日志包含足够的调试信息
有性能相关的日志（慢查询、耗时操作）
日志可以串联起来讲述完整的故事

真实案例

案例：Netflix 的日志文化

Netflix 有一套严格的日志规范：

所有请求都有唯一的 request_id
关键指标都记录日志（响应时间、错误率）
使用结构化日志，便于搜索和分析
日志直接输入到分析系统（ELK, Splunk）

结果：能快速定位问题，甚至预测问题。

案例：糟糕的日志导致的事故

某公司的支付系统出现问题，用户投诉扣款异常。

调查时发现：

日志只有 "Payment processed successfully"
没有订单 ID、金额、用户 ID
无法确认哪些订单有问题

后果：花了一周时间人工核对数据库记录。

教训：关键业务操作的日志必须详尽。

总结

错误日志的语言哲学：

日志要讲故事——不是喊口号或重复代码
用业务语言 + 技术细节——让非技术人员也能理解大致问题
日志级别要准确——ERROR 是紧急的，INFO 是重要的
结构化日志——便于搜索、聚合、分析
关联 ID——串联起完整的请求链路
保护敏感信息——永远不记录密码、完整信用卡号

记住：

好的日志能让你在凌晨3点被叫醒时，快速理解发生了什么。

日志不是调试时的临时工具，而是生产系统的观测窗口。

写日志就像写给未来的自己的信——要清楚、准确、有用。

posted @ 2025-11-29 21:54 Jack_Q 阅读(0) 评论(0) 收藏举报

刷新页面返回顶部

hi-yingzi