Go 错误处理

金正皓
1,441 阅读11分钟
原文链接： zhuanlan.zhihu.com

本文尝试用最清晰的描述回答以下四个问题，当我们需要处理错误的时候：

  1. 什么时候选择 error
  2. 什么时候选择 log
  3. 什么时候选择 metrics
  4. 什么时候选择 panic

以及为什么做这样的选择。

用户分析

处理错误的关键是，谁来处理？

  • 对于你的用户而言：他们可能是一段代码，把你的代码做为lib来使用。他们可能是最终的用户，使用你的代码做为日常工具。
  • 对于你的同事（比如说运维）而言：他们负责喊你来修bug。
  • 对于你而言：你负责这段代码的正确运行，以及修复bug。

对于这三类人群，他们的诉求是完全不同的。错误处理的艺术就是同时让这三类人群满意。所以我们需要先对每个人群的诉求进行深入分析

你的用户

他们的目的是使用你的代码。当你的代码无法满足需求的时候，你得清晰地告诉他们。hey，这个时候你无法使用我了，因为我搞砸了。比如说

func ValidatePassport(passport string) (UserId, error)

这里返回的 error 就是用来给你的用户传递这个信息的。但是做为用户是需要推动问题解决的，你不能仅仅告诉他们我搞砸了，比如

func ValidatePassport(passport string) (UserId, bool)

如果你仅仅返回了 true/false，用户是无法知道这是一个问题。也不知道该怎么办。比如是否应该给你的公司打电话。用户希望得到的信息是这么几种

  • 当用户是一个真人的时候，他们只会把错误分成两类：
    • 噢，网络错误。那不用管了。等会再回来试试吧。
    • 未知错误。呀，这个不是重试能解决的。我得找人。这个错误消息得足够让我找到人，并且他能接下来跟进。比如得有个订单号什么的东西。
  • 当用户是一段程序得时候：我可以对指定的几种错误，进行针对性的处理。比如你告诉我文件不存在，那我可以创建一个新文件。

所以，error是给用户看的。不要把给你自己看的东西打到这个里面，比如stacktrace。太长的错误信息会让用户迷惑。error是一个完整的错误报告的索引，人们可以根据error里的内容按图索骥，很快还原现场。

那么panic是什么呢？当你的接口契约上没有error，但是又出错了的时候，怎么办？这个时候panic。panic意味着，给你的用户说，你不用管错误，错了算我的。使用panic，免除了用户对你出问题时进行容错的责任。panic是抛给自己看的。

你的同事

你们是一个团队，共同负责一个很大的平台。但是每个人都有自己的分工，负责自己的一块事情。当平台挂了，整个团队需要很快找到谁应该来负责，喊这个人来修bug。你可能就是那个需要来修bug的人。你需要提供足够的信息，让喊你来修bug的同事的工作更轻松。一般一个组织里，专门负责喊人来修bug的角色叫运维。

需要立即喊人来修bug的情况大多数就这两个场景

  • A 调用 B，最近一段时间的错误率是否飙升
  • A 调用 B，最近一段时间的延迟是否飙升

当这两个条件被满足的时候。A和B都会被喊来看问题。当A是最终用户的时候，则只有B会被喊来看问题，比如客户端团队。当B是外部团队的时候，则只有A会被喊来看问题，比如网络供应商出问题了。

所以，我们总共需要三个信息，以及若干附加信息

  1. 主叫方：发起调用的功能点名称。大粒度的是模块，小粒度的是函数。
  2. 被叫方：被调用的功能点的名称。
  3. 是否出错：出错了还是没出错。错误码可选。
  4. 延迟：调用耗时。可选。
  5. timestamp：可选。默认为当前时间
  6. 其他信息：上下文
countlog.Info("metric",
   "caller", "ValidatePassport",
   "callee", "Redis",
   "err", errors.New("some error"),
   "latency", time.Second * 1,
   "traceId", traceId
)

一条metric就是一条log。metric本身比error log打印得都更全。比如调用正常的情况下，metirc也会被上报的，而不仅仅只是在出错的情况下。所以 metric 上报是可以替代 error log的。

当然metric不会被直接打给你的同事们看。metric的信息要被多级聚合之后，成为measurement，绘制成曲线，变成告警才是有价值的信息。这些一般有运维的监控平台来负责。

所以，metric是给同事们看的。要在所有可能出错的地方都加上标准化的metric。metric至少要说明谁在调用谁，出错了没有。通过metric构成了一个职责链，按照这个链条，我们可以找到负责的人。比如api出错了，发现是调passport引起的，passport出错了发现是调redis引起的。有这样一个链条，可以快速地让redis团队介入问题处理，避免了逐级踢皮球。

你自己

用户通过error找到你的同事，你的同事通过metric找到了你。到你这之后，皮球就没法踢给别人了。你得修复问题。

如果幸运得话，error里的错误消息，加上同事提供的metric，你就能够猜到问题是怎么产生的了。但是不幸的话，你需要更多的信息。

countlog.Debug("file rotated",
  "traceId", traceId,
  "file", file
)

这种普通地日志，就是打给我们自己看的。他的作用就是当问题发生了之后，可以根据一部分的日志维度，找到关联的其他日志做为上下文，重建出故障现场。在这个例子里，traceId就是关联用的维度，file就是故障现场的上下文。

错误处理方式的选择

按照前面的分析，我们知道了四种工具的分类：

  • error：给使用者的错误消息
  • metric：一种特殊的日志。统计之后给同事看的。
  • log/panic：辅助自己定位bug用的

然后有以下规则

  • 所有你自己会出错，或者你的依赖方会出错的场景。你都需要在接口上返回error
  • 一般来说只有纯内存的操作才存在无error的api接口。但凡牵涉了磁盘或者网络，都要返回error。
  • 纯内存操作时遇到了无法解释的情况，比如数组越界。只能panic。因为接口上不返回error，但还是必须要报错。
  • 如果你不能提供更多的错误消息，直接返回底层依赖的error。
  • 如果底层依赖的error，在你的场景里时含糊的。比如json解析失败。你有责任提供更明确的错误消息做为error返回，不能直接返回底层依赖的error。毕竟error是一个索引，如果用户不能按图索骥找到解决问题的人，这个error是无效的。
  • error的错误消息尽量包含一些编号字段，无论是trace id还是订单号。方便场景还原。
  • 但凡调用了会返回error的函数，都需要打印metric日志。提供caller/callee/error。不仅仅是在出错的时候才打印错误日志，正确的时候也要打metric。什么时候输出到文件和控制台，这个是metric/log框架要考虑的事情。
  • 除了metric之外的日志都是给自己看的。要尽可能的用结构化的方式提供更多的上下文信息。
  • 所有的goroutine都必须在最上层处理panic。防止panic引起程序crash。因为进程重启需要花时间。fail fast 不用这么极端。能够把错误日志告警报出来就行了。
  • 所有的panic都要写入fatal级别的log，并且提供stacktrace
  • 每次临时添加fmt.Println用完又删掉，都是给你的日志基础设施提的一个bug。日志好使的话，为什么需要fmt.Println。

日志级别的选择

现有的日志框架在日志级别的处理上是不够灵活的。

countlog.Debug("metric",
   "caller", "ValidatePassport",
   "callee", "Redis",
   "err", err,
   "latency", time.Second * 1,
   "traceId", traceId
)

比如我在这里使用了Debug的日志级别并不代表这个log本身一直是不重要的。当err是非nil的时候，它应该是ERROR级别，而不是DEBUG级别了。Debug仅仅是代表在正常的情况下，不要打印到log文件里。

countlog.Trace("file rotated",
  "traceId", traceId,
  "file", file
)

设置成了Trace级别之后。一般情况下就扔掉了。但是更好的行为是，如果这个附近没有错误，这个log就是无用的，可以扔掉。如果附近有错误，则应该把log留下来做为故障现场的一部分。现在的日志框架都是逐条处理的。丢弃就直接丢弃了。如果能够在请求级别进行缓存，则出错的时候，可以记录下大量的现场。以上两点是对现有日志框架的吐槽。然后我们应该如何选择日志级别：

  • Trace：开发的时候定位问题用的。仅仅可能在开发的时候打开。日志的条数和请求数量n成正比，而且可能是n的数倍。开发的时候只在必要的情况下，才会打开。
  • Debug：线上定位问题时用的。仅仅可能在线上短暂的打开。日志的条数和请求数量是一个级别。开发时候的默认日志级别。一个日志框架必须在没有任何初始化的时候也能打印出Debug以及之上的日志来。否则在单元测试之类的场景就会很蛋疼。log4j就很蛋疼。对于日志框架来说，没有做任何初始化，就应该自己现在跑在开发者的IDE里。假设日志级别是Debug，输出是stderr，格式应该是人类可读的格式，是最合理的默认值。
  • Info：正常的线上日志级别。日志的条数要远小于请求数量。只在特殊事件发生时（系统状态发生迁移的时候）才打印出来。
  • Warn：可预见的错误，但是责任不在我。本质上也是Info。
  • Error：可以预见的错误发生了的时候使用。所有的metric日志，在error不是nil的时候，日志级别要自动变成Error。
  • Fatal：不可遇见的错误发生了的时候。也就是panic日志。

标准的错误处理案例

最naive的例子

func doX(ctx context.Context) error {
	file, err := os.OpenFile("/tmp/my-dir/abc", os.O_RDWR, 0666)
	if err != nil {
		return err
	}
	defer file.Close()
	_, err = file.Write([]byte("hello"))
	if err != nil {
		return err
	}
	return nil
}

每次写 if err != nil { return err } 的时候都充满了负罪感。总觉得应该再多做一点什么。我们第一个golang项目上线之后，大家都震惊了。这json.Unmarshal错误到底是哪里报的啊。然后一行一行的猜。然后无比怀念java的异常堆栈。

第二次的选择是，给错误加上一些“特征”。让错误容易定位到代码行：

func doA(ctx context.Context) error {
	file, err := os.OpenFile("/tmp/my-dir/abc", os.O_RDWR, 0666)
	if err != nil {
		return fmt.Errorf("failed to open file: %v", err)
	}
	defer file.Close()
	_, err = file.Write([]byte("hello"))
	if err != nil {
		return fmt.Errorf("failed to write: %v", err)
	}
	return nil
}

如果要更高级一些，可以把 fmt.Errorf 再封装一下。把行号之类的也给加进去。

但是这样做的问题是每一层都叠加自己的信息到error上。最后这个error就和java的异常堆栈log一样长了。如果你是library，你的用户用了你的api，看到这样的error会非常懵逼的。

一个优化策略就是只对最底层的错误封装一次。上面的报错就直接透传了。问题是，要记得哪些错误是最底层错误，哪些是已经封装过的，这个并不容易。按照我们前面的分析。error是给最终用户看的。所以除非可以添加一些信息把error讲得更容易让用户理解，否则不要把自己用的定位信息都加到error里。这里的os.OpenFile的报错已经包含了path了。完全特别大的再次封装的必要了。所以应该正确的做法是加日志。

func doY(ctx context.Context) error {
	defer func() {
		recovered := recover()
		if recovered != nil {
			countlog.Fatal("event!doY.panic",
				"err", recovered,
				"stacktrace", countlog.ProvideStacktrace)
		}
	}()
	start := time.Now()
	file, err := os.OpenFile("/tmp/my-dir/abc", os.O_RDWR, 0666)
	if err != nil {
		countlog.Error("event!metric",
			"callee", "ioutil.WriteFile", "ctx", ctx, "latency", time.Since(start))
		countlog.Error("event!doY.failed to open file", "err", err)
		return err
	}
	countlog.Trace("event!metric",
		"callee", "ioutil.WriteFile", "ctx", ctx, "latency", time.Since(start))
	defer func() {
		err = file.Close()
		if err != nil {
			countlog.Error("event!doY.failed to close file", "err", err)
		}
	}()
	_, err = file.Write([]byte("hello"))
	if err != nil {
		return err
	}
	return nil
}

在本来已经很冗长的go错误处理代码上加完善的日志是很难读的。

func doZ(ctx countlog.Context) error {
	defer countlog.LogPanic(recover()) // only necessary for goroutine
	file, err := os.OpenFile("/tmp/abc", os.O_RDWR, 0666)
	ctx.TraceMetric("callee!os.OpenFile", err)
	if err != nil {
		return err
	}
	defer countlog.Close(file)
	_, err = file.Write([]byte("hello"))
	ctx.TraceMetric("callee!file.Write", err)
	if err != nil {
		return err
	}
	return nil
}

这个是最终使用countlog精简之后的日志代码：v2pro/plz

avatar
文章
阅读
粉丝