IpProxyPool的使用

背景

Go爬虫实践这篇文章中介绍了博主第一次使用Go写爬虫的小小实践，其中偶然用到了IpProxyPool这个Go实现的IP代理池项目，在使用中发现了一个小小的bug，在尝试查看源码解决时，突然发现这个项目是一个Go新手学习的不错的项目，非常感谢这个开源项目的作者，你的star有了！
这篇文章主要介绍自己是如何定位到这个开源项目的一个小bug，关于从这个开源项目中学到的知识会陆续补充到其他Go相关的文章中

bug的定位

bug的发现过程还是比较简单的，Go爬虫实践中使用到了此IP代理池，但是发现IP代理池运行一段时间后，请求/all获取随机的代理时会被阻塞掉，遂查看源码，使用最简单的打日志的方法，可将bug定位到IpModel.go:66的代码，可以发现这是一段使用gorm框架做SQL查询的代码，既然和数据库套上关系的阻塞，其实已经大致能猜到原因了
```
// GetAllIp 获取所有数据
func GetAllIp() []IP {
    db := database.GetDB()
    list := make([]IP, 0)
    err := db.Model(new(IP)).Find(&list)
    ipCount := len(list)
    if err.Error != nil {
        logger.Warnf("ip count: %d, error msg: %v\n", ipCount, err.Error)
        return nil
    }
    return list
}
```
结合此时的日志打印状态：运行一段时间后，run.go中本应周期性执行的storage.CheckProxy(<-ipChan)与go run(ipChan)的都不再执行，实际上这些goroutine同样阻塞在了使用gorm框架做SQL查询的代码上

goroutine状态

为了能更准确的查看goroutine的运行状态，于是尝试使用gops查看gouroutine的状态，其使用方法很简单，可直接参考这篇文章
- 需要注意的是如果要使用gops的命令行的话需要使用go install http://github.com/google/gops安装，自go1.17开始，go get只用来下载普通的包，安装可执行程序，应该使用 go install
在main.go中加入gops agent后，等待运行一段时间bug发现后，尝试使用gops stack ${agent}:${port}查看goroutine堆栈信息，可以从堆栈信息中总结出以下信息
```
goroutine 1552 [chan receive, 4 minutes]:
database/sql.(*Tx).awaitDone(0xc000907e80)
    /Users/lee/.go/go1.18.2/src/database/sql/sql.go:2189 +0x31
created by database/sql.(*DB).beginDC
    /Users/lee/.go/go1.18.2/src/database/sql/sql.go:1903 +0x23b
```
- 处于chan receive状态，也就是等待channel数据状态的goroutine的数量很多（实际上与后面提到的sqlDb.SetMaxOpenConns(100)的配置数量一直），这些goroutine可定位到Go官方的SQL库sql.go:1903，beginDC方法用来创建事务的，显然MySQL数据库事务的执行阻塞到了awaitDone方法上，可以猜测可能是事务没有正确的提交或回滚
```
// beginDC starts a transaction. The provided dc must be valid and ready to use.
func (db *DB) beginDC(ctx context.Context, dc *driverConn, release func(error), opts *TxOptions) (tx *Tx, err error) {
    // ...
    go tx.awaitDone()
    return tx, nil
}
```

MySQL运行状态

经过日志的定位后，问题最终定位到gorm与MySQL的交互上，执行show processlist这个MySQL脚本会发现有多个连接处于sleep状态，出现这种状态的原因一般就是MySQL客户端使用连接池时没有及时释放链接
在MySQL Console中执行show global status like 'Thread%';可以发现随着程序的运行，Threads_connected也是一直增加的，直到超过100，很明显这里是由阈值限制的，返回源码查找对应的设置
- 关于执行show global status like 'Thread%';的各个字段的说明以及其他查看MySQL连接的方法可参考MySQL查看连接数
关于阈值的设置可定位到源码的database.go:62，也即sqlDb.SetMaxOpenConns(100)，显然随着运行的时间增长，打开的链接数一直保持增加是不正常的，将阈值改的大点也只是拖延程序阻塞的时间罢了

gorm的使用

既然是连接未及时释放的问题，则应该看看gorm的使用是不是出了什么问题，经过简单的查询，发现已经有前人总结了使用gorm导致连接池打满的问题，经过与源码的比对最终定位到了问题：

// UpdateIp 更新数据
func UpdateIp(ip *IP) {
    db := database.GetDB().Begin()
    ipModel := ip
    ipMap := make(map[string]interface{}, 0)
    ipMap["proxy_speed"] = ip.ProxySpeed
    ipMap["update_time"] = util.FormatDateTime()
    if ipModel.ProxyId != 0 {
        err := db.Model(new(IP)).Where("proxy_id = ?", ipModel.ProxyId).Updates(ipMap)
        if err.Error != nil {
            logger.Errorf("update ip: %s, error msg: %v", ipModel.ProxyHost, err.Error)
            db.Rollback()
        }
        db.Commit()
    }
}

如果if ipModel.ProxyId != 0 条件不满足的话，事务不会被提交！事务对应的连接也就不会释放~，如果定位UpdateIp的使用，可以发现在源码的run.go:26，从ipChan读到IP数据最终交给UpdateIp处理，而数据在ipChan的另一端来源于run.go:42中注册的一系列fetcher方法，以其中的Ip33662为例，最终定位到IP对象的创建代码如下，显然proxyId并未指定，这最终导致UpdateIp方法中的连接资源的泄漏
```
ip := new(ipModel.IP)
ip.ProxyHost = proxyIp
ip.ProxyPort, _ = strconv.Atoi(proxyPort)
ip.ProxyType = proxyType
ip.ProxyLocation = proxyLocation
ip.ProxySpeed, _ = strconv.Atoi(proxySpeed)
ip.ProxySource = "http://www.ip3366.net"
ip.CreateTime = util.FormatDateTime()
ip.UpdateTime = util.FormatDateTime()
```

总结

前人的经验是宝贵的，如果遇到死胡同，不要钻牛角尖，多查多看多问

IpProxyPool的使用

IpProxyPool的使用

背景

bug的定位

goroutine状态

MySQL运行状态

gorm的使用

总结

参考

demoli

引用和评论

Docker基础知识

关于IP代理识别你必须知道的四件事！

vue2知识点：数据代理