实战分享：Golang中实现高性能日志记录与错误跟踪的艺术

1

Golang 日志库简介

在 Golang 的世界里，优秀的日志记录是开发者的得力助手。标准库log简洁而强大，足以满足基本需求，但随着项目复杂度的增加，你可能会寻找更强大的解决方案。这时候，像zap、logrus这样的第三方库就派上用场了。这些库提供了更多的配置选项和更高的性能，帮助开发者轻松应对复杂的日志记录场景。

1.1

标准库：log 包

Go 的标准库提供了一个名为 log 的简单日志包。虽然它很基础，但它是理解 Go 日志的一个很好的起点。

这是一个简单的例子：

package main


import (
    "log"
)


func main() {
    log.Println("This is a log message")
    log.Printf("Hello, %s!", "Gopher")
    log.Fatal("This is a fatal error")
}

1.2

slog 包

Go 1.21 引入了该 slog 软件包，为标准库带来了结构化日志记录功能。对于想要在不依赖第三方库的情况下实现结构化日志记录的开发人员来说，这一新增功能意义重大。

以下是使用的基本示例 slog：

import (
    "log/slog"
    "os"
)


func main() {
    logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
    logger.Info("User logged in",
        "username", "gopher",
        "user_id", 123,
        "login_attempt", 1)
}

Go 标准库日志包很简单，但缺少日志级别和结构化日志等功能。对于更复杂的应用程序，您可能需要使用第三方库，虽然 slog 可能不具备某些第三方库的所有功能，但将其纳入标准库使其成为希望尽量减少外部依赖的项目的一个有吸引力的选择。

这将输出 JSON 格式的日志：

{"time":"2023-09-16T10:30:00Z","level":"INFO","msg":"User logged in","username":"gopher","user_id":123,"login_attempt":1}

slog 主要特点：

• 开箱即用的结构化日志记录

• 支持不同的输出格式（JSON、文本）

• 可通过处理程序进行定制

• 与现有 Go 程序完美集成

1.3

其它的第三方日志库

Go 生态系统中有几个流行的日志库。让我们来看看其中最广泛使用的三个：

• Zerolog：以零分配 JSON 日志记录而闻名

• Zap：Uber 的超快结构化记录器

• Logrus：带有钩子的结构化记录器以下是一个快速比较：

// Zerolog
logger := zerolog.New(os.Stdout).With().Timestamp().Logger()
logger.Info().Str("library", "zerolog").Msg("This is a log message")


// Zap
logger, _ := zap.NewProduction()
defer logger.Sync()
logger.Info("This is a log message", zap.String("library", "zap"))


// Logrus
logrus.WithFields(logrus.Fields{
    "library": "logrus",
}).Info("This is a log message")

根据我的经验，Zerolog 和 Zap 提供最佳性能，而 Logrus 为来自其他语言的开发人员提供了更熟悉的界面。

2

各个日志库之间的比较

当然，下面是一个表格，从结构化日志、性能、类型安全、依赖项、日志轮换、使用广泛程度以及高级功能这七个方面来比较 log、slog、Zap、Zerolog 和 Logrus 这五种日志库：

2.1

详细说明

结构化日志:

• log 标准库不直接支持结构化日志。

• slog 是 Go 1.21 引入的新日志库，支持结构化日志记录。

• Zap、Zerolog 和 Logrus 都支持结构化日志，可以输出 JSON 或其他格式。

性能:

• log 性能一般，适合简单应用。

• slog 设计时考虑了性能，比 log 更高效。

• Zap 和 Zerolog 都是高性能的日志库，特别适用于高并发场景。

• Logrus 性能中等，但提供了丰富的功能。

类型安全:

• log 没有类型检查。

• slog 提供了一定程度的类型安全性。

• Zap 和 Zerolog 提供了较强的类型安全性。

• Logrus 在某些情况下可能需要显式转换，类型安全性较弱。

依赖项:

• log 和 slog 是标准库的一部分，没有外部依赖。

• Zap 和 Zerolog 的依赖较少，易于集成。

• Logrus 依赖较多，可能会影响项目的依赖管理。

日志轮换:

• log 和 slog 需要配合第三方库如 lumberjack 来实现日志轮换。

• Zap 自带日志轮换功能。

• Zerolog 和 Logrus 通常需要第三方库来实现日志轮换。

使用广泛程度:

• log 作为标准库，非常广泛。

• slog 是新引入的，正在逐步被更多项目采用。

• Zap 和 Logrus 都是广泛使用的第三方日志库。

• Zerolog 也较为流行，特别是在追求极致性能的应用中。

高级功能:

• log 提供基本的日志功能。

• slog 提供了一些新的特性，如结构化日志和灵活的配置选项。

• Zap 和 Zerolog 提供了丰富的高级功能，包括异步写入、自定义序列化等。

• Logrus 也提供了许多高级功能，如钩子（hooks）、自定义格式化器等。

这个表格可以帮助开发者根据具体需求选择合适的日志库。

日志库支持不同的日志级别（例如，DEBUG、INFO、WARN、ERROR）和输出格式（例如，JSON、控制台友好）。

您可以按照以下方式配置 Zerolog：

zerolog.SetGlobalLevel(zerolog.InfoLevel)
if os.Getenv("DEBUG") != "" {
    zerolog.SetGlobalLevel(zerolog.DebugLevel)
}


log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})

此设置允许您通过环境变量控制日志级别，这对于在不同环境中切换调试日志非常方便。

了解如何正确设置日志级别是每个 Go 程序员的基本功。从最紧急的panic到最常见的info，合理地使用不同的日志级别可以帮助我们快速定位问题所在。同时，定义良好的输出格式不仅能提高可读性，还能让自动化工具更容易解析。例如，JSON 格式的输出非常适合于现代微服务架构中的日志处理。

3

3. 可观察性平台集成

将 Golang 应用与流行的可观测性平台（如 Prometheus, ELK Stack, 或者 Jaeger）结合，可以极大地增强对系统状态的理解。通过适当的配置，你可以将应用程序产生的日志流式传输到这些平台上进行实时分析。这不仅有助于监控当前运行状况，也便于事后故障排查。

这是一个使用 olivere/elastic 包将日志发送到 Elasticsearch 的简单示例：

import (
    "context"
    "github.com/olivere/elastic/v7"
    "github.com/rs/zerolog"
    "github.com/rs/zerolog/log"
)


func main() {
    client, err := elastic.NewClient(elastic.SetURL("<http://localhost:9200>"))
    if err != nil {
        log.Fatal().Err(err).Msg("Failed to create Elasticsearch client")
    }


    hook := zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) {
        _, err := client.Index().
            Index("app-logs").
            BodyJson(e).
            Do(context.Background())
        if err != nil {
            log.Error().Err(err).Msg("Failed to send log to Elasticsearch")
        }
    })


    log.Logger = zerolog.New(os.Stdout).Hook(hook).With().Timestamp().Logger()


    log.Info().Str("foo", "bar").Msg("This log will be sent to Elasticsearch")
}

此设置将每条日志消息发送到 Elasticsearch，让您可以使用 Kibana 进行强大的日志分析和可视化。

4

最佳实践 和 日志性能

• 结构化日志：尽量采用结构化的数据格式来记录日志信息，比如使用 JSON。这样做的好处在于方便后续的数据分析。

• 异步写入：利用缓冲区或专门的日志收集服务来实现异步日志写入，减少对主程序执行的影响。

• 按需启用调试模式：生产环境中避免开启过细的日志记录，以免造成性能瓶颈；而在开发阶段则可以通过环境变量控制日志详细程度。

• 定期归档清理：为防止磁盘空间耗尽，定期归档旧日志并删除不再需要的历史记录。

• 适当使用日志级别：将 ERROR 保留用于特殊情况，将 INFO 用于常规操作。

• 包含上下文：始终在日志中包含相关上下文，例如请求 ID 或用户 ID。

• 注意敏感数据：切勿记录密码或 API 密钥等敏感信息。

• 对大容量日志使用采样：在高流量服务中，考虑对 DEBUG 日志进行采样以减少开销。

• 对日志进行基准测试：使用 Go 的基准测试工具来衡量日志对性能的影响。

这是一个比较字符串连接与使用字段的简单基准：

func BenchmarkLoggingConcat(b *testing.B) {
    logger := zerolog.New(ioutil.Discard)
    for i := 0; i < b.N; i++ {
        logger.Info().Msg("value is " + strconv.Itoa(i))
    }
}


func BenchmarkLoggingFields(b *testing.B) {
    logger := zerolog.New(ioutil.Discard)
    for i := 0; i < b.N; i++ {
        logger.Info().Int("value", i).Msg("")
    }
}

在我的测试中，使用字段的表现始终优于字符串连接，尤其是在大量数据的情况下。

4.1

案例

我们有一个基于 Go 的 API 服务，用于处理一套 Web 应用程序的用户身份验证。此服务会间歇性地出现 503 错误（服务不可用），我们无法轻松重现或调试。以下是我们最初知道的情况：

• 503 错误似乎是随机发生的，影响了大约 2% 的身份验证尝试。

• 这些错误与一天中的任何特定时间或交通模式无关。

• 我们现有的日志仅显示返回了 503 错误，没有任何其他上下文。我们最初的日志记录很少，而且没有帮助：

func handleAuthentication(w http.ResponseWriter, r *http.Request) {
    user, err := authenticateUser(r)
    if err != nil {
        log.Printf("Authentication failed: %v", err)
        http.Error(w, "Service Unavailable", http.StatusServiceUnavailable)
        return
    }


// ... rest of the handler
}


func authenticateUser(r *http.Request) (*User, error) {
// ... authentication logic
}

这些日志没有提供足够的上下文来理解为什么身份验证失败，或者为什么我们在身份验证失败时返回 503 错误而不是 401（未授权）。

4.2

解决方案

我们决定使用 Zap 实施更全面的日志记录策略：

• 添加了包含请求 ID、用户 ID（如果可用）和使用的身份验证方法的结构化日志。

• 为身份验证过程的每个步骤都提供了时间信息。

• 添加了更细粒度的错误日志，包括特定的错误类型。以下是我们改进日志记录的方法：

package main


import (
    "net/http"
    "time"


    "go.uber.org/zap"
    "github.com/google/uuid"
)


var logger *zap.Logger


func init() {
    var err error
    logger, err = zap.NewProduction()
    if err != nil {
        panic(err)
    }
}


func handleAuthentication(w http.ResponseWriter, r *http.Request) {
    requestID := uuid.New().String()
    startTime := time.Now()


    logger := logger.With(
        zap.String("request_id", requestID),
        zap.String("method", r.Method),
        zap.String("path", r.URL.Path),
    )


    logger.Info("Starting authentication process")


    user, err := authenticateUser(r, logger)
    if err != nil {
        logger.Error("Authentication failed",
            zap.Error(err),
            zap.Duration("duration", time.Since(startTime)),
        )


        if err == ErrDatabaseTimeout {
            http.Error(w, "Service Unavailable", http.StatusServiceUnavailable)
        } else {
            http.Error(w, "Unauthorized", http.StatusUnauthorized)
        }
        return
    }


    logger.Info("Authentication successful",
        zap.String("user_id", user.ID),
        zap.Duration("duration", time.Since(startTime)),
    )


// ... rest of the handler
}


func authenticateUser(r *http.Request, logger *zap.Logger) (*User, error) {
    authStartTime := time.Now()


// Extract credentials
    username, password, ok := r.BasicAuth()
    if !ok {
        logger.Warn("No authentication credentials provided")
        return nil, ErrNoCredentials
    }


// Check user in database
    user, err := getUserFromDB(username)
    if err != nil {
        if err == ErrDatabaseTimeout {
            logger.Error("Database timeout during authentication",
                zap.Error(err),
                zap.Duration("db_query_time", time.Since(authStartTime)),
            )
            return nil, ErrDatabaseTimeout
        }
        logger.Warn("User not found", zap.String("username", username))
        return nil, ErrUserNotFound
    }


// Verify password
    if !verifyPassword(user, password) {
        logger.Warn("Invalid password", zap.String("username", username))
        return nil, ErrInvalidPassword
    }


    logger.Debug("User authenticated successfully",
        zap.String("username", username),
        zap.Duration("auth_duration", time.Since(authStartTime)),
    )


    return user, nil
}

结果通过这些增强的日志，我们能够找出问题的根本原因：

• 503 错误是由于数据库超时而不是实际的身份验证失败而发生的。

• 当数据库连接池耗尽时就会发生这些超时。

• 连接池耗尽是由于单独的批处理作业占用连接时间过长造成的。

有了这些信息，我们能够：

• 增加我们的数据库连接池的大小。

• 优化批处理作业以更快地释放连接。

• 实现数据库操作的断路器，当数据库过载时快速失败。

结果如何？

我们的 503 错误率从 2% 下降到了 0.01%，并且我们能够正确区分服务不可用和实际身份验证失败。

此示例展示了有效日志记录的强大功能。通过包含关键上下文（请求 ID、错误类型、时间信息）并使用 Zap 进行结构化日志记录，我们能够快速识别并解决影响用户的重大问题。

从这次经历中我们可以得到一些关键的启示：

• 以适当的级别记录：对特殊情况使用错误，对重要但预期的问题使用警告，对一般操作事件使用信息，对详细的故障排除信息使用调试。

• 包括时间信息：记录关键操作的持续时间可以帮助识别性能瓶颈。

• 使用结构化日志记录：它使过滤和分析日志变得更加容易，特别是在集中式日志系统中聚合它们时。

• 记录上下文，而不仅仅是错误：在日志中包含相关上下文（如请求 ID 或用户 ID）可以更轻松地跟踪系统不同部分的问题。

• 具体说明错误：不要记录一般的错误消息，而要记录具体的错误类型。这样更容易区分不同的故障模式。

请记住，日志不仅仅用于调试错误 - 它们是了解应用程序在生产中的行为和性能的强大工具。花时间设置全面的日志记录，在解决复杂问题时，您会感谢自己。

5

总结

请记住，日志就像擦 PP 的卫生纸。因为厕所一直有，所以不会过多考虑它们，但是当它们不在时，您会多么想念它们（尤其是在凌晨 3 点生产发生不可描述问题的时候）。

构建一个健壮且高效的日志体系对于任何规模的应用都是至关重要的。通过选择合适的日志库、合理设定日志级别与格式，并巧妙地集成外部监控工具，我们可以大大提升软件的质量与用户体验。记住，在追求功能丰富的同时也不要忽略了性能优化——毕竟，谁都不希望因为日志机制而拖慢整个系统的响应速度。

推荐

A Big Picture of Kubernetes

Kubernetes入门培训（内含PPT）

原创不易，随手关注或者”在看“，诚挚感谢！