从P4小白到P7专家都是怎么打日志的?差得不是一星半点……

大厂码农老A 2025-11-11 09:50:54
国庆假期的某天,我正懒洋洋地躺在海滩的沙滩椅上,哈着冰啤酒,海风拂面,惬意极了。

 

突然,手机震动个不停。点开一看,是公司告警群里接连蹦出几条「「磁盘空间不足」」的告警消息。虽然这不是我负责的应用,但我还是好奇地戳进去瞄了一眼。原来是日志文件膨胀得太猛,把磁盘给塞满了。没多久,负责的同事在群里发话:“这日志文件忘了挂载运维平台的自动清理脚本了。”他手动删掉一些旧日志,磁盘占用瞬间恢复正常。

 

这事儿让我不由得陷入了沉思。打日志,看似程序员日常中最不起眼的小事 —— 后端、前端、客户端,谁不是天天在打?但稍有不慎,轻则导致磁盘占用飙升,重则在线上故障时因为缺失关键日志而束手无策。明明是基础操作,却常常被忽略。从这个磁盘告警就能看出来,就连大厂里不少人,也没把打日志这件“小事”当回事儿。这本质上是一种认知偏差:小事不处理,往往酿成大事。

 

所以,今天咱们就来聊聊这个每个程序员每天都在做,但90%的人都没做对的事——打日志。把我从坑里爬出来的经验,分享给你,避免你重蹈覆辙。

 

第一幕:小白打日志的那些坑

 

说起打日志的坑,我和身边的同事们可谓是身经百战,基本上把能踩的都踩了个遍。尤其是那些刚入职的P4小白,日志打得那叫一个随性,结果往往是自食苦果。

 

先说第一个经典坑:日志打了个寂寞。

 

之前有个供应链团队的合作同事,刚校招入职,化名小张吧。我们因为项目合作频繁,关系不错,他经常来找我讨教技术问题。

 

有一次,他遇到一个线上偶发Bug,用户反馈操作失败。他急吼吼地跑来求助:“A哥,我在SLS里翻了半天,只有一句‘order process error!’,根本不知道是哪个用户、哪笔订单、在哪行代码出的错!这Bug没法复现,告警也没触发,日志没线索,咋办啊?”

 

我让他把出问题的代码发给我瞧瞧。瞄了几眼瞬间明白了:他的问题不是Bug难复现,而是就算复现了,这日志也没卵用。代码大致是这样(伪代码,展示日志打印的问题):

 

  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
@Servicepublic class OrderService {    public void processOrder(OrderDTO order) {        try {            // ...此处省略50行业务逻辑...            // 问题实际在这里:在某种边界条件下,order.getCustomer()可能返回null,导致NPE            String customerName = order.getCustomer().getName();            log.info("OrderService start process order..."); // 这行日志没打任何关键信息            // ...此处省略另外50行业务逻辑...        } catch (Exception e) {            // 日志打了个寂寞。。。            log.error("OrderService#order process error!");        }    }}

 

大家仔细品品这段代码里的日志,相信不少新人都会心有戚戚焉。这里面藏着小白门常见的三大问题:

 

 
问题一:异常被莫名其妙地吃掉

 

看看catch块里,那个至关重要的Exception呢?直接被吃了!连完整的堆栈信息都不打印,也没有向上抛出,就这么被“吃干抹净”,不留痕迹。这就好比侦探赶到犯罪现场,发现一切证据都被擦得干干净净,还怎么破案?

 

 
问题二:没有任何关键信息

 

“OrderService#order process error!”——这是啥意思?哪个订单?哪个用户?哪个商品?日志里一个业务ID都没带。每秒钟成千上万笔订单涌入,这样的日志无异于大海捞针,纯纯浪费时间。

 

 
问题三:异常信息没有体现在日志中

 

error——到底是什么error?是NPE?数据库连接超时?还是RPC异常?一无所知。

 

最后,我叹了口气:“Bro,你的问题不是Bug无法复现,而是就算复现了,你这日志也定位不到问题。你这日志打了个寂寞啊”

 

第二幕:打日志的“三层境界”

 

是不是在小张身上看到了自己曾经的影子呢?你有思考过如何打日志这个问题吗?其实这里面还是有一些学问的。

 

在大厂这么多年,我总结出了打日志的“三层境界”,从P4小白到P7专家,每一级都有对应的行为特征和潜在“B面”灾难。咱们一层一层扒开,看看你处在哪一境界。

 

 
「第一境:P4小白 —— 日志 = “到此一游”的涂鸦」

 

「行为特征」:

 

  • 万物皆可用System.out.println()或e.printStackTrace()。

  • 日志内容随心所欲,比如log.info("111"), log.info("走到这里了")。

  • 热衷于用字符串拼接("value=" + var)来构建日志消息。

 

「潜在的“B面”灾难」:

 

  • 「性能杀手」:用字符串拼接,即使日志级别被禁用,也会强制执行字符串操作(浪费资源),在高并发下严重拖慢系统。

  • 「信息丢失」:习惯性地丢掉异常,只打印e.getMessage()而不记录完整的堆栈跟踪,丢弃了最关键的异常信息。

  • 「毫无价值」:无法关闭,无法分级,无法被集中式日志系统(如SLS)进行有效采集和分析。线上出事时,你只能干瞪眼。

 

 
「第二境:P5中级 —— 日志 = “业务流水账”」

 

P5级别的工程师,已经懂得封装Service,但处理异常的方式,也经常存在一些问题。来看小张的另一段代码示例:

 

  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
@Servicepublic class OrderService {    public void createOrder(OrderDTO order) {        try {            // ...业务逻辑...            String userName = null;            userName.toLowerCase(); // 这里会一个NPE        } catch (Exception e) {            // 注意:这里没有打印日志,直接向上抛出一个模糊的异常            throw new BizException("创建订单失败");         }    }}
@RestControllerpublic class OrderController {    @Autowired    private OrderService orderService;
    @PostMapping("/orders")    public void createOrder(@RequestBody OrderDTO order) {        try {            orderService.createOrder(order);        } catch (BizException e) {            // 日志在这里打印,但没有实际异常的详细堆栈和信息            log.error("处理创建订单请求失败!", e);         }    }}

 

笔者点评:兄弟们,看懂了吗?当线上出问题时,你在Controller层看到的日志,只会告诉你创建订单失败,你无法知道问题的根因其实是OrderService第XX行那个NPE。这就是异常日志的二次转手,破案线索,在第一现场就被破坏了。

 

我至今都记得,有一次为了排查一个履约单的Bug,我和另一个同事,花了整整一个通宵,在几十万行日志里,去定位一个被这样二次转手过的NPE。「那种感觉,才是真正的大海中捞针。」

 

「行为特征」:

 

  • 已经学会了使用日志门面(如SLF4J)和实现(如Logback),懂得INFO, WARN, ERROR的区别。

  • 日志内容开始关注业务流程,比如log.info("用户下单成功,订单号:{}", orderId)。

 

「潜在的“B面”灾难」:

 

  • 「信息孤岛,无法定位问题」:日志只能证明“这个方法被执行了”,但无法串联起一个完整的用户请求链路。一旦出问题,你看到的只是散落在几十台机器上的、毫无关联的日志碎片。

  • 「缺少关键上下文」:日志里只有orderId,但没有trace_id或其他关键的信息。大型系统中如果缺少trace_id这样的关联ID,当一个用户反馈问题时,我们根本无法从海量日志中,找到属于他的那几条。

 

 
「第三境:P6/P7专家 —— 日志 = 天网」

 

「行为特征」:

 

专家打日志,追求的不是简单“记录”,而是“可观测性”和“可诊断性”。他们会让日志成为系统的“黑匣子”。

 

「“B面”心法」:

 

1、「心法一:结构化一切」   

 

  • 「What」:不再打印纯文本,而是输出JSON格式的日志。  

  • 「Why」:结构化的日志,才能被SLS、ELK等系统完美解析、索引和聚合查询。这样才能解答“过去一小时,service_name为payment-processor且user_id为123的所有ERROR日志”这类问题。  

  • 「How」:例如,使用SLF4J + Logback,配合JSON Encoder:

 

  •  
log.error("{"event":"order_creation_failed", "order_id":"{}", "user_id":"{}", "error":"{}"}", orderId, userId, e.getMessage());

 

笔者:别小看这个JSON。有次618,我们需要紧急统计某个特定优惠券,在上海地区,因为库存不足而失败的下单次数。用文本日志,SRE需要花半小时写脚本去捞。「用结构化日志,我在SLS上只用10秒钟,就给出了答案。」 这,就是专家的效率。

 

2、「心法二:上下文为王 (MDC & trace_id)」 

 

  • 「What」:MDC(Mapped Diagnostic Context)是Java中记录与线程相关的上下文的一种机制。底层使用ThreadLocal。通过 MDC,我们可以为当前线程附加一些特定的上下文信息(例如用户 ID、事务 ID),这些信息会自动与日志关联,从而帮我们更有效地分析和跟踪日志。

  • 「Why」:每条日志必须包含trace_id,用于追踪请求在多个微服务间的流转。MDC像线程的“专属背包”,在入口处放入trace_id,后续日志自动携带。  

  • 「How」:在Interceptor中设置:

 

  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
public class TraceInterceptor implements HandlerInterceptor {     @Override     public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {         String traceId = UUID.randomUUID().toString();         MDC.put("trace_id", traceId);         return true;     } }

 

然后日志中会自动带上trace_id:

 

  •  
log.error("Order failed, orderId: {}", orderId);  // 会隐含trace_id

 

笔者:MDC就是线上排错的GPS。有一次,一个用户反馈他的账户余额显示异常。在没有trace_id的年代,我们需要去用户、交易、支付三个系统的几十台机器上,靠着userId和时间戳去人肉关联日志。

 

「有了」MDC「,我只需要拿到一个」trace_id「,就能在SLS或ELK里,一键拉出这个用户从App点击到数据库落地的完整生命周期。」 5分钟搞定。其实我们厂基本都用EagleEye,感兴趣的同学可以去搜搜。

 

3、「心法三:日志本身就是“炸弹”」   

 

  • 「What」:日志打印不当,可能会引发大型故障。  

  • 「Why」:举个栗子:Redis超时 → 海量错误日志 → 撑爆Logstash → 丢弃日志 → 关键线索丢失。这就是日志炸弹。  

  • 「How」:别直接打印复杂对象,只打印关键ID和字段。高频事件用采样,如只记录1%的INFO日志(参考EagleEye的采样策略)。

 

老A说:别以为日志打多了没事。我亲眼见过一个P2故障,就是因为一个同事在log.info里,打印了一个超大对象。「高并发流量一来,光是这个toString()方法的开销,就把整个集群的CPU干到了95%以上,比业务逻辑本身还耗资源。」 这是自杀式打日志。”

 

现在,针对第二境的坑,来看看P7专家的正确解法:

 

  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
  •  
@Servicepublic class OrderService {    public void createOrder(OrderDTO order) {        try {            // ...业务逻辑...            String userName = null;            userName.toLowerCase();        } catch (Exception e) {            // 正解:记录下最完整的错误和堆栈            log.error("创建订单核心逻辑发生异常!orderId: {}", order.getId(), e);             // 然后再向上抛出业务异常,通知上层调用失败            throw new BizException("创建订单失败", e); // 把原始异常作为cause传递        }    }}

 

笔者点评: 同样是抛出异常,但专家在抛出前,先用一行log.error,把包含了完整堆栈信息和关键业务ID(orderId)的第一手证据,牢牢地钉在了日志里。这,就是专业。

 

第三幕:宗师的视野——成熟日志系统的终极形态

 

在聊完打日志的三层境界后,我们不妨再往前走一步,思考一下 一个真正成熟的日志系统该是什么样子。

 

一个成熟的日志系统,不应该仅仅是记录信息的工具,而应该是整个系统可观测性的一个核心支柱。应该像一台精密的仪器,静静地运行,却能在关键时刻提供最有力的支持。 要达到这个目标,它必须具备三大核心能力。

 

 
「能力一:跨系统的“全局透视”能力」

 

在一个分布式架构中,我们面临的第一个挑战,就是信息孤岛。成熟的日志系统,首先要解决的就是「看得全」的问题。通过trace_id这根线索,将一个用户请求在几十个微服务之间的完整调用,串联成一条「可视化的调用链路」。就像阿里巴巴的EagleEye系统那样,它能让你在上帝视角,清晰地看到一个请求从前端到数据库的每一个环节,哪里卡壳、哪里高效,一目了然。

 

 
「能力二:恰到好处的数据呈现能力」

 

看得全,不等于信息越多越好。成熟的日志系统,追求的是「恰到好处」。

一方面,它的每一条日志,都采用「结构化的JSON格式」,只包含timestamp, trace_id, span_id, error_code等最关键的字段,做到清晰、完整却不冗余。

 

另一方面,它有完善的过期机制。通过基于时间(保留7天)或大小(超过1GB自动轮转)的「过期策略」,确保日志不会成为拖垮磁盘的定时炸弹——记得我们开头的那个告警故事吧?那就是反面教材。

 

 
「能力三:“先知先觉”的自动化响应能力」

 

看得全、看得清,最终是为了「效率高」。一个成熟的日志系统,应该是一个半自动化的哨兵。

当它通过trace_id发现某条链路的错误率超过阈值时,它能「自动触发告警」,通过钉钉通知到责任人。在更高级的系统中,它甚至应该能「触发自动化的修复脚本」——比如隔离故障节点、回滚配置。

 

这,才是日志的终点:从被动的记录员,进化为主动的系统守护神。

 

笔者感悟:一个工程师在日志层面的成长,就是从用日志记录,到用日志说话,再到用日志透视整个系统的过程。你打日志的水平,就是你对系统掌控能力的真实写照。

 
作者丨大厂码农老A
来源丨公众号:稀土掘金技术社区(ID:juejin1024)
dbaplus社群欢迎广大技术人员投稿,投稿邮箱:editor@dbaplus.cn
最新评论
访客 2024年04月08日

如果字段的最大可能长度超过255字节,那么长度值可能…

访客 2024年03月04日

只能说作者太用心了,优秀

访客 2024年02月23日

感谢详解

访客 2024年02月20日

一般干个7-8年(即30岁左右),能做到年入40w-50w;有…

访客 2023年08月20日

230721

活动预告