MongoDB Go Driver 如何记录日志

如果你也有这些疑问:golang 官方的 mongo driver 怎么记录日志,2. Golang mongo driver 如何打印sql,如何打印执行的命令,那么这篇文章会告诉你

为什么

如果你有这些问题:
1. golang 官方的 mongo driver 怎么执行了没有日志输出啊
2. golang mongo driver 如何记录sql,如何打印执行的命令
3. 想通过日志来检查 golang mongo 调用API是否符合预期

那么这篇文章可以继续看下去。

背景

在这之前我使用 MySQL 是比较多的,后来遇到有记录用户操作日志需求,随着数据量越来越大,MySQL 有些扛不住(慢),就换成了 Mongo,在使用Mongo过程中,发现没法记录日志,就是无法将打印代码发起的sql,之前使用gorm打印execute sql是很方便的。

在网上查了好久也没查到相关资料,就开始翻官方文档,和源码。

终于在不懈~ 打住,其实很简单,就在 ClientOptions 字段里:

// ClientOptions contains options to configure a Client instance. Each option can be set through setter functions. See
// documentation for each setter function for an explanation of the option.
type ClientOptions struct {
    AppName                  *string
    Auth                     *Credential
    AutoEncryptionOptions    *AutoEncryptionOptions
    ...
    MaxConnecting            *uint64
    PoolMonitor              *event.PoolMonitor
    Monitor                  *event.CommandMonitor // 执行的命令监视器(日志)
    ServerMonitor            *event.ServerMonitor
    ...

    err error
    uri string
    cs  *connstring.ConnString

github 代码地址

是的—— ClientOptions.Monitor 字段。

使用方法如下:

package mongolearn

import (
    "context"
    "fmt"
    "log"
    "time"

    "go.mongodb.org/mongo-driver/bson"
    "go.mongodb.org/mongo-driver/event"
    "go.mongodb.org/mongo-driver/mongo"
    "go.mongodb.org/mongo-driver/mongo/options"
)

var (
    mongoDsn = "mongodb://admin:123456@127.0.0.1:27017"
)

// TestConnUseDb sql monitor
func TestConnWithMonitor() {
    ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
    defer cancel()

    // client option
    var clientOpt = options.Client().ApplyURI(mongoDsn)

    // log monitor
    var logMonitor = event.CommandMonitor{
        Started: func(ctx context.Context, startedEvent *event.CommandStartedEvent) {
            log.Printf("mongo reqId:%d start on db:%s cmd:%s sql:%+v", startedEvent.RequestID, startedEvent.DatabaseName,
                startedEvent.CommandName, startedEvent.Command)
        },
        Succeeded: func(ctx context.Context, succeededEvent *event.CommandSucceededEvent) {
            log.Printf("mongo reqId:%d exec cmd:%s success duration %d ns", succeededEvent.RequestID,
                succeededEvent.CommandName, succeededEvent.DurationNanos)
        },
        Failed: func(ctx context.Context, failedEvent *event.CommandFailedEvent) {
            log.Printf("mongo reqId:%d exec cmd:%s failed duration %d ns", failedEvent.RequestID,
                failedEvent.CommandName, failedEvent.DurationNanos)
        },
    }
    // cmd monitor set
    clientOpt.SetMonitor(&logMonitor)
    client, err := mongo.Connect(ctx, clientOpt)
    if nil != err {
        fmt.Printf("mongo connect err %v\n", err)
    } else {
        fmt.Printf("mongo connect success~\n")
        defer func() {
            if err = client.Disconnect(ctx); err != nil {
                panic(err)
            }
        }()
    }

    // update test
    if re, err := client.Database("test").Collection("test").UpdateOne(ctx, bson.M{"name": "cc"}, bson.M{"$set": bson.M{"age": 12}}); err != nil {
        log.Printf("%v", err)
    } else {
        log.Printf("mongo update one re %+v", re)
    }
}

输出结果

mongo connect success~
2023/08/20 13:22:43 mongo reqId:6 start on db:test cmd:update sql:{"update": "test","ordered": true,"lsid": {"id": {"$binary":{"base64":"qfrrzSt7SkCN5ChY04/T5A==","subType":"04"}}},"$db": "test","updates": [{"q": {"name": "cc"},"u": {"$set": {"age": {"$numberInt":"12"}}}}]}
2023/08/20 13:22:43 mongo reqId:6 exec cmd:update success duration 44489114 ns
2023/08/20 13:22:43 mongo update one re &{MatchedCount:0 ModifiedCount:0 UpsertedCount:0 UpsertedID:<nil>}

# 下面是断开 mongo 时触发的命令
2023/08/20 13:22:43 mongo reqId:7 start on db:admin cmd:endSessions sql:{"endSessions": [{"id": {"$binary":{"base64":"qfrrzSt7SkCN5ChY04/T5A==","subType":"04"}}}],"$db": "admin"}
2023/08/20 13:22:43 mongo reqId:7 exec cmd:endSessions success duration 58037162 ns

通过以上日志可以看到,mongomonitor 按照 Started, Succeeded 顺序记录,最后才会执行函数外的 日志 。

结束

我看网上资料少,很多小伙伴都不知道,特此写一篇小文记录下。

golang.org/x/sys/unix/syscall.go: undefined: unsafe.Slice

糟了,到底是哪个包的升级,导致我编译通不过呢,来看看博主的解决方案

/x/sys@v0.4.0/unix/syscall.go:83:16: undefined: unsafe.Slice

golang 版本低于 1.17 时,go build 时报错

# golang.org/x/sys/unix
../../../go/pkg/mod/golang.org/x/sys@v0.4.0/unix/syscall.go:83:16: undefined: unsafe.Slice

解决否

已解决

方案

在项目 运行 
$ go mod graph | gmchart

gmchart 是一个将依赖可视化展示的工具——https://github.com/PaulXu-cn/go-mod-graph-chart, 安装后通过命令 gmchart 调用。

这里发现了2次引用 golang.org/x/sys, 但是发现在第二级,看不出谁引用了它,别急,我们点击找个点,展开看下。

展开后,发现有三个项目引用了它,这三个项目我在项目中都没有用到呢,那就至于猜了,这里最可疑的就是 grpc-example,那就是 grpc, 估计是高版的grpc依赖了高版本 API

检查项目内 go.mod

go 1.14

require (
    google.golang.org/grpc v1.52.0
)

发现项目内引用的 grpc 版本时 v1.52.0, 打开grpc项目发现,该项目已机遇 go1.17 构建。所以,这里我们需要降低 grpc 的版本

我们要找个 go 1.14 的,那,grpc v1.48.0 就满足 go v1.14 runtime 需求。

所以,回到项目将go.mod 调整如下

go 1.14

require (
    google.golang.org/grpc v1.48.0
)

然后更新加依赖,项目就能构建了。

Golang 遇到 note module requires Go 1.nn 解决之道,不升go

遇到note: module requires Go 1.17,或者 note: module requires Go 1.18 等报错该如何是好呢?可能你会搜索到很多升级Go版本的答案。有没有想过揪出到底是哪个包导致了升级呢?有不用升级Go版本的办法,想试试么?

在使用多版本的golang的小伙伴,往往会遇到这个问题。本文就如何不升级 go 版本来解决该问题。

怎么产生的

  1. 同时使用IDE和命令行,命令行go版本和IDE的go不是同一个版本。
  2. 多人协作同一个项目,别人使用不同版本的go加入了一个包且写入了一个较高版本号。
  3. go get 时选择了较高版本。

网上的大部分解决方案都是升级自己的go版本。那么如果不想升级有办法解决么?

不升Go版本

例如我遇到了:

# golang.org/x/sys/unix
../../go/pkg/mod/golang.org/x/sys@v0.3.0/unix/syscall.go:83:16: undefined: unsafe.Slice
../../go/pkg/mod/golang.org/x/sys@v0.3.0/unix/syscall_darwin.go:95:8: undefined: unsafe.Slice
../../go/pkg/mod/golang.org/x/sys@v0.3.0/unix/syscall_unix.go:118:7: undefined: unsafe.Slice
../../go/pkg/mod/golang.org/x/sys@v0.3.0/unix/sysvshm_unix.go:33:7: undefined: unsafe.Slice
note: module requires Go 1.17

尝试把 go.sum 删掉,再 go mod tidy 还是没用,依然报这个错。

这时看看 go.mod 文件

module github.com/PaulXu-cn/xxx

go 1.15

require (
    github.com/go-faker/faker/v4 v4.0.0-beta.4
    github.com/golang/protobuf v1.5.2
    github.com/snksoft/crc v1.1.0
    github.com/spf13/cobra v1.6.1
    github.com/spf13/viper v1.15.0
)

也就是说当前我的 go runtime1.15 的,
是引用了基于 go1.17 的包,需要把这个包降为依赖 go1.15的即可。那这里的哪个包需要降版本呢?

该项目简单,只有5个直接依赖,可以通过依次删除添加测出来,如果有很多依赖的话,又该怎么解决呢?

包后面带 // indirect 是间接依赖,删掉这一行不影响。
参考 https://go.dev/ref/mod

上工具

这里介绍个工具 gmchartgo mod 图像化展示工具 —— https://github.com/PaulXu-cn/go-mod-graph-chart

进入工作项目

cd goProejct

安装 gmchart

$ go install github.com/PaulXu-cn/go-mod-graph-chart/gmchart@latest

运行

$ go mod graph | gmchart
go mod graph version v0.5.3
the go mod graph will top in 60s
visit it by http://127.0.0.1:59760

go mod graph 是官方工具命令。 可展示出了该项目所有的依赖关系,只不过是文本形式展示,输出的内容多了,人眼看不出啥来。这里借用 gmchart 工具,可以将其依赖关系组织为 树状 渲染 web 页面,也就是和go 工具一样,跨平台的。

利用工具找问题

回到我们刚刚的报错啊, golang.org/x/sys 包依赖了 go1.17.

这里我们搜一下啊

search1

呦,一共有84个,我们再把版本号输入进去,缩小范围

search2

好的,定位到了1个,那就是它了,然后呢?

看了看 go.mod , 好像我们也没有直接引用它,要去 go.mod 删也没有得删。

如果是如下情况,带有 indirect 注释的,删除了也不能解决问题!

require(
    golang.org/x/sys v0.3.0 // indirect
)

这里有大聪明,建议我去 go.sum 里面去删,这是没用的哈,go mod tidy 一下又回来了。

找出直接依赖

  1. 用工具找到具体包
  2. 在界面中点击包
  3. 查看所有引入了该包的 包。这里我们看到了5个包,viper这个包是直接依赖,因此该调整这个包的版本

search_gif

serach_gif_mark

  1. 在 github 上找到 viper https://github.com/spf13/viper
  2. 打开 go.mod —— https://github.com/spf13/viper/blob/master/go.mod

viper_master

这里通过查看 vipergo.mod ,发现最新的 viper 已是基于 go1.17 , 我的项目 go get 了最新版本的 viper,所以,编译时就会报错——note: module requires Go 1.17

这里按理说不会拉取高版本的 viper,但这里是切换了go版本,导致了该情况。

  1. 项目要求是不高于 go1.15,那就依次便利 viper 的各个tag。好——viper@1.9.0 是当前版本最高且要求不高于 go1.15 的。https://github.com/spf13/viper/blob/v1.9.0/go.mod

  1. 把项目中 go.mod, 依赖—— viper 版本改为 v1.9.0 报错就解决了。

总结

我最近在做项目时,切换 go 版本遇到了该问题,顺手查了下,发现网上的答案都是让其升级 go 版本,其实就是依赖高版本的第三方包,这里借用工具,找出该包,通过降第三方包的方式也能解决该问题。

如果大家遇到同类问题,不想升go版本,可以试试改方案。

没有遇到也没关系,收藏一下,某天遇到了不想升go可以再翻出来看看

qrcode

参考

  • https://go.dev/ref/mod
  • https://github.com/PaulXu-cn/go-mod-graph-chart

Cannot create namespace centrum.policy in multi-document transaction.

Cannot create namespace centrum.policy in multi-document transaction.

Cannot create namespace xxx.xxx in multi-document transaction.

问题

看报错信息,就是说不能在 mongo 事务中创建表。

解决否

已解决

方案

这是说: 不能在事务中创建 collection 。但你一看 sql,没有创建表语句啊。

mongo 中,如果你操作的 collection 不存在是会自动创建的。但有个例外就是事务。

在事务中是无法创建表结构的。

所以,解决这个问题,就是在执行 mongo sql 前,先创建好要操作的 collection

参考

  • https://stackoverflow.com/questions/52585715/cannot-create-namespace-in-multi-document-transactionmongodb-4-0-spring-data-2

Mongo 副本集 选择副本后 连不上 server selection error

failed: server selection error: context deadline exceeded, current topology: { Type: ReplicaSetNoPrimary, Servers: [{ Addr: 127.0.0.1:27017, Type: Unknown, Last error: connection() error occurred during connection handshake: dial tcp 127.0.0.1:27017: connect: connection refused

Mongo 副本集 选主错误 server selection error

问题

failed: server selection error: context deadline exceeded, current topology: { Type: ReplicaSetNoPrimary, Servers: [{ Addr: 127.0.0.1:27017, Type: Unknown, Last error: connection() error occurred during connection handshake: dial tcp 127.0.0.1:27017: connect: connection refused

解决否

已解决

方案

登陆 mongo server 输入命令

rs.status()

rs.status

这里看图片里,name是: mongolab:27021, 那么应用也会用这个地址去连 mongodb,如果 dns 里没有 mongolab,那么应用是连不上这个 mongo 的,最终报错就是链接超时。

查看一下Mongo集群之间的通讯 IP,或者地址是怎么配置,是否配置的IP的应用端能访问的IP段。

例如,三个 mongo 集群配置在同一网段内—— 192.168.1.0 ,如果你也按照这个 IP 来配置副本集,那么 mongo 之间通信是没问题的,但如果应用端可能读取 replica 信息后,会那副本集配置的 IP 信息去访问其他节点,这个时候应用会拿着 192.168.1.0 这个网断的 IP 去访问 mongo,如果 mongo 和应用不在一个网段,就会导致如上问题。所以,mongoreplica 配置的IP也需是应用可访问的 IP

这也是,往往运维部署,发现,mongo 互通 OK,运维溜了。等应用来连,却连不上问题。

参考

  • https://www.mongodb.com/docs/manual/replication/
  • https://www.mongodb.com/docs/manual/reference/method/rs.initiate/