运维大神如何使用 Golang 日志监控应用程序

你是如何使用 Golang 日志监控你的应用程序的呢？Golang 没有异常，只有错误。所以你的第一印象可能就是开发 Golang 日志策略并非一件简单的事情。不>支持异常事实上并非什么问题，异常在不少编程语言中已经失去了其异常性：它>们过于被滥用以致于它们的做用都被忽视了。
-- Nils

本文导航
一、Golang 日志基础

• 使用 Golang “log” 库

二、为你 Golang 日志统一格式

• JSON 格式的结构优点
• 标准化 Golang 日志

三、Golang 日志上下文的力量

四、 Golang 日志对性能的影响

• 不要在 Goroutine 中使用日志
• 使用异步库
• 使用严重等级管理 Golang 日志

五、集中化 Golang 日志

六、但愿你享受你的 Golang 日志之旅

你是否厌烦了那些使用复杂语言编写的、难以部署的、老是在不停构建的解决方案？Golang 是解决这些问题的好方法，它和 C 语言同样快，又和 Python 同样简单。

可是你是如何使用 Golang 日志监控你的应用程序的呢？Golang 没有异常，只有错误。所以你的第一印象可能就是开发 Golang 日志策略并非一件简单的事情。不支持异常事实上并非什么问题，异常在不少编程语言中已经失去了其异常性：它们过于被滥用以致于它们的做用都被忽视了。

在进一步深刻以前，咱们首先会介绍 Golang 日志的基础，并讨论 Golang 日志标准、元数据意义、以及最小化 Golang 日志对性能的影响。经过日志，你能够追踪用户在你应用中的活动，快速识别你项目中失效的组件，并监控整体性能以及用户体验。

 Golang 日志基础

1) 使用 Golang “log” 库

Golang 给你提供了一个称为 “log” 的原生日志库[1] 。它的日志器完美适用于追踪简单的活动，例如经过使用可用的选项[2]在错误信息以前添加一个时间戳。

下面是一个 Golang 中如何记录错误日志的简单例子：

package main

import (

    "log"

    "errors"

    "fmt"

    )

func main() {

   /* 定义局部变量 */

  ...

   /* 除法函数，除以 0 的时候会返回错误 */

   ret,err = div(a, b)

if err != nil {

 log.Fatal(err)

    }

    fmt.Println(ret)

}

若是你尝试除以 0，你就会获得相似下面的结果：

2020/02/24 16:13:30 division by zero

你能够在这里[4]找到 Golang 日志的完整指南，以及 “log” 库[5]内可用函数的完整列表。

如今你就能够记录它们的错误以及根本缘由啦。

另外，日志也能够帮你将活动流拼接在一块儿，查找须要修复的错误上下文，或者调查在你的系统中单个请求如何影响其它应用层和 API。

为了得到更好的日志效果，你首先须要在你的项目中使用尽量多的上下文丰富你的 Golang 日志，并标准化你使用的格式。这就是 Golang 原生库能达到的极限。使用最普遍的库是 glog[6] 和 logrus[7]。必须认可还有不少好的库可使用。若是你已经在使用支持 JSON 格式的库，你就不须要再换其它库了，后面咱们会解释。

为你 Golang 日志统一格式

1) JSON 格式的结构优点

在一个项目或者多个微服务中结构化你的 Golang 日志多是最困难的事情，但一旦完成就很轻松了。结构化你的日志能使机器可读（参考咱们 收集日志的最佳实践博文[8]）。灵活性和层级是 JSON 格式的核心，所以信息可以轻易被人类和机器解析以及处理。

下面是一个使用 Logrus/Logmatic.io[9] 如何用 JSON 格式记录日志的例子：

package main

import (

        "log"

        "os"

)

func main() {

        // 按照所需读写权限建立文件

        f, err := os.OpenFile("filename", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644)

        if err != nil {

                log.Fatal(err)

        }   

        // 完成后延迟关闭，而不是习惯!

        defer f.Close()

        //设置日志输出到 f

        log.SetOutput(f)

        //测试用例

        log.Println("check to make sure it works")

}

会输出结果：

package main

import (

  log "github.com/Sirupsen/logrus"

  "github.com/logmatic/logmatic-go"

)

func main() {

    // 使用 JSONFormatter

    log.SetFormatter(&logmatic.JSONFormatter{})

        // 使用 logrus 像往常那样记录事件

    log.WithFields(log.Fields{"string": "foo", "int": 1, "float": 1.1 }).Info("My first ssl event from golang")

}

2) 标准化 Golang 日志

同一个错误出如今你代码的不一样部分，却以不一样形式被记录下来是一件可耻的事情。下面是一个因为一个变量错误致使没法肯定 web 页面加载状态的例子。一个开发者日志格式是：

message: 'unknown error: cannot determine loading status from unknown error: missing or invalid arg value client'</span>

另外一我的的格式倒是：

unknown error: cannot determine loading status - invalid client</span>

强制日志标准化的一个好的解决办法是在你的代码和日志库之间建立一个接口。这个标准化接口会包括全部你想添加到你日志中的可能行为的预约义日志消息。这么作能够防止出现不符合你想要的标准格式的自定义日志信息。这么作也便于日志调查。

 

因为日志格式都被统一处理，使它们保持更新也变得更加简单。若是出现了一种新的错误类型，它只须要被添加到一个接口，这样每一个组员都会使用彻底相同的信息。

最常使用的简单例子就是在 Golang 日志信息前面添加日志器名称和 id。你的代码而后就会发送 “事件” 到你的标准化接口，它会继续讲它们转化为 Golang 日志消息。

// 主要部分，咱们会在这里定义全部消息。

// Event 结构体很简单。为了当全部信息都被记录时能检索它们，

// 咱们维护了一个 Id

var (

    invalidArgMessage = Event{1, "Invalid arg: %s"}

    invalidArgValueMessage = Event{2, "Invalid arg value: %s => %v"}

    missingArgMessage = Event{3, "Missing arg: %s"}

)

// 在咱们应用程序中可使用的全部日志事件

func (l *Logger)InvalidArg(name string) {

    l.entry.Errorf(invalidArgMessage.toString(), name)

}

func (l *Logger)InvalidArgValue(name string, value interface{}) {

    l.entry.WithField("arg." + name, value).Errorf(invalidArgValueMessage.toString(), name, value)

}

func (l *Logger)MissingArg(name string) {

    l.entry.Errorf(missingArgMessage.toString(), name)

}

所以若是咱们使用前面例子中无效的参数值，咱们就会获得类似的日志信息：

time="2017-02-24T23:12:31+01:00" level=error msg="LoadPageLogger00003 - Missing arg: client - cannot determine loading status" arg.client=<nil> logger.name=LoadPageLogger

JSON 格式以下：

{"arg.client":null,"level":"error","logger.name":"LoadPageLogger","msg":"LoadPageLogger00003 - Missing arg: client - cannot determine loading status", "time":"2017-02-24T23:14:28+01:00"}

Golang 日志上下文的力量

如今 Golang 日志已经按照特定结构和标准格式记录，时间会决定须要添加哪些上下文以及相关信息。为了能从你的日志中抽取信息，例如追踪一个用户活动或者工做流，上下文和元数据的顺序很是重要。

例如在 logrus 库中能够按照下面这样使用 JSON 格式添加 hostname、appname 和 session 参数：

// 对于元数据，一般作法是经过复用来重用日志语句中的字段。

  contextualizedLog := log.WithFields(log.Fields{

    "hostname": "staging-1",

    "appname": "foo-app",

    "session": "1ce3f6v"

  })

contextualizedLog.Info("Simple event with global metadata")

元数据能够视为 javascript 片断。为了更好地说明它们有多么重要，让咱们看看几个 Golang 微服务中元数据的使用。你会清楚地看到是怎么在你的应用程序中跟踪用户的。这是由于你不只须要知道一个错误发生了，还要知道是哪一个实例以及什么模式致使了错误。假设咱们有两个按顺序调用的微服务。上下文信息保存在头部（header）中传输：

func helloMicroService1(w http.ResponseWriter, r *http.Request) {

client := &http.Client{}

// 该服务负责接收全部到来的用户请求

// 咱们会检查是不是一个新的会话仍是已有会话的另外一次调用

session := r.Header.Get("x-session")

if ( session == "") {

session = generateSessionId()

// 为新会话记录日志

}

// 每一个请求的 Track Id 都是惟一的，所以咱们会为每一个会话生成一个

track := generateTrackId()

// 调用你的第二个微服务，添加 session/track

reqService2, _ := http.NewRequest("GET", "http://localhost:8082/", nil)

reqService2.Header.Add("x-session", session)

reqService2.Header.Add("x-track", track)

resService2, _ := client.Do(reqService2)

….

当调用第二个服务时：

func helloMicroService2(w http.ResponseWriter, r *http.Request) {

// 相似以前的微服务，咱们检查会话并生成新的 track

session := r.Header.Get("x-session")

track := generateTrackId()

// 这一次，咱们检查请求中是否已经设置了一个 track id，

// 若是是，它变为父 track

parent := r.Header.Get("x-track")

if (session == "") {

w.Header().Set("x-parent", parent)

}

// 为响应添加 meta 信息

w.Header().Set("x-session", session)

w.Header().Set("x-track", track)

if (parent == "") {

w.Header().Set("x-parent", track)

}

// 填充响应

w.WriteHeader(http.StatusOK)

io.WriteString(w, fmt.Sprintf(aResponseMessage, 2, session, track, parent))

}

如今第二个微服务中已经有和初始查询相关的上下文和信息，一个 JSON 格式的日志消息看起来相似以下。

在第一个微服务：

{"appname":"go-logging","level":"debug","msg":"hello from ms 1","session":"eUBrVfdw","time":"2017-03-02T15:29:26+01:00","track":"UzWHRihF"}

在第二个微服务：

{"appname":"go-logging","level":"debug","msg":"hello from ms 2","parent":"UzWHRihF","session":"eUBrVfdw","time":"2017-03-02T15:29:26+01:00","track":"DPRHBMuE

若是在第二个微服务中出现了错误，多亏了 Golang 日志中保存的上下文信息，如今咱们就能够肯定它是怎样被调用的以及什么模式致使了这个错误。

若是你想进一步深挖 Golang 的追踪能力，这里还有一些库提供了追踪功能，例如 Opentracing[10]。这个库提供了一种简单的方式在或复杂或简单的架构中添加追踪的实现。它经过不一样步骤容许你追踪用户的查询，就像下面这样：

 

Golang 日志对性能的影响

1) 不要在 Goroutine 中使用日志

在每一个 goroutine 中建立一个新的日志器看起来很诱人。但最好别这么作。Goroutine 是一个轻量级线程管理器，它用于完成一个 “简单的” 任务。所以它不该该负责日志。它可能致使并发问题，由于在每一个 goroutine 中使用 log.New()会重复接口，全部日志器会并发尝试访问同一个 io.Writer。

为了限制对性能的影响以及避免并发调用 io.Writer，库一般使用一个特定的 goroutine 用于日志输出。

2) 使用异步库

尽管有不少可用的 Golang 日志库，要注意它们中的大部分都是同步的（事实上是伪异步）。缘由极可能是到如今为止它们中没有一个会因为日志严重影响性能。

但正如 Kjell Hedström 在他的实验[11]中展现的，使用多个线程建立成千上万日志，即使是在最坏状况下，异步 Golang 日志也会有 40% 的性能提高。所以日志是有开销的，也会对你的应用程序性能产生影响。若是你并不须要处理大量的日志，使用伪异步 Golang 日志库可能就足够了。但若是你须要处理大量的日志，或者很关注性能，Kjell Hedström 的异步解决方案就颇有趣（尽管事实上你可能须要进一步开发，由于它只包括了最小的功能需求）。

3）使用严重等级管理 Golang 日志

一些日志库容许你启用或停用特定的日志器，这可能会派上用场。例如在生产环境中你可能不须要一些特定等级的日志。下面是一个如何在 glog 库中停用日志器的例子，其中日志器被定义为布尔值：

type Log bool

func (l Log) Println(args ...interface{}) {

    fmt.Println(args...)

}

var debug Log = false

if debug {

    debug.Println("DEBUGGING")

}

而后你就能够在配置文件中定义这些布尔参数来启用或者停用日志器。

没有一个好的 Golang 日志策略，Golang 日志可能开销很大。开发人员应该抵制记录几乎全部事情的诱惑 - 尽管它很是有趣！若是日志的目的是为了获取尽量多的信息，为了不包含无用元素的日志的白噪音，必须正确使用日志。

集中化 Golang 日志

 

若是你的应用程序是部署在多台服务器上的，这样能够避免为了调查一个现象须要链接到每一台服务器的麻烦。日志集中确实有用。

使用日志装箱工具，例如 windows 中的 Nxlog，linux 中的 Rsyslog（默认安装了的）、Logstash 和 FluentD 是最好的实现方式。日志装箱工具的惟一目的就是发送日志，所以它们可以处理链接失效以及其它你极可能会遇到的问题。

这里甚至有一个 Golang syslog 软件包[12] 帮你将 Golang 日志发送到 syslog 守护进程。

但愿你享受你的 Golang 日志之旅

在你项目一开始就考虑你的 Golang 日志策略很是重要。若是在你代码的任意地方均可以得到全部的上下文，追踪用户就会变得很简单。从不一样服务中阅读没有标准化的日志是已经很痛苦的事情。一开始就计划在多个微服务中扩展相同用户或请求 id，后面就会容许你比较容易地过滤信息并在你的系统中跟踪活动。

你是在构架一个很大的 Golang 项目仍是几个微服务也会影响你的日志策略。一个大项目的主要组件应该有按照它们功能命名的特定 Golang 日志器。这使你能够当即判断出日志来自你的哪一部分代码。然而对于微服务或者小的 Golang 项目，只有较少的核心组件须要它们本身的日志器。但在每种情形中，日志器的数目都应该保持低于核心功能的数目。

你如今已经可使用 Golang 日志量化决定你的性能或者用户满意度啦！

今晚为你详细讲解直播，添加小助手wechat：17812796384 获取直播连接