排查一次golang的协程泄漏

发表于 更新于 分类于 阅读次数： 本文字数： 4.3k 阅读时长 ≈ 4 分钟

在一个爬虫程序的优化后，意外出现了内存泄漏

泄漏非常缓慢，一般会在运行4小时后导致OOM。

检查了很多次代码，找不到问题

排查过程

众所周知，golang是自带pprof工具的

我利用pprof工具查看了内存使用情况

1
2
3
4
5
6
7
8
go tool pprof http://A.A.A.A:port/debug/pprof/heap
(pprof) top10
54.09MB of 64.63MB total (83.70%)
Dropped 356 nodes (cum <= 0.32MB)
Showing top 10 nodes out of 114 (cum >= 4.78MB)
      flat  flat%   sum%        cum   cum%
   17.51MB 27.09% 27.09%    17.51MB 27.09%  runtime.malg
...

显示最大的占用是malloc，才不到17MB，然而用top看明明有300MB+的内存使用

在看网页的heap信息

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
浏览器打开http://A.A.A.A:port/debug/pprof/heap

# runtime.MemStats
# Alloc = 110272584
# TotalAlloc = 498296256768
# Sys = 295814568
# Lookups = 33621
# Mallocs = 3957182680
# Frees = 3956354582
# HeapAlloc = 110272584
# HeapSys = 271319040
# HeapIdle = 152543232
# HeapInuse = 118775808
# HeapReleased = 13647872
# HeapObjects = 828098
# Stack = 5505024 / 5505024
# MSpan = 1932320 / 4538368
# MCache = 2400 / 16384
# BuckHashSys = 2101543
# NextGC = 126895285
# PauseNs = [822588 752071 864300 770201 995820 1251490 1485329 965733 1273680 823846 732038 736777 612430 548698 776820 995193 797632 1089269 640811 762021 735213 740990 596313 634118 598058 1035655 704670 748700 704525 766794 898956 643703 706317 790542 1243151 816982 671063 1218771 602327 563440 487044 611852 1034276 555311 870599 829135 969348 595902 667427 702981 1121949 1092622 988624 1969615 1611152 1659858 3028988 674981 312711 453628 295761 259532 296518 348242 421790 271391 434166 390314 349950 437216 365712 593817 511185 343430 819451 722146 1263431 794439 739593 811524 945488 754959 976288 805347 781069 765738 617832 1782126 758458 681900 648251 746756 1272853 606082 1963403 658746 659328 914294 536925 634717 680363 899159 1246974 2193705 2998923 2377172 1288806 2769948 3715148 1629277 1021776 1016037 1126600 1248132 2688438 1216716 1545570 929975 800006 825697 604449 706919 385476 1180384 454921 463917 692061 524241 442142 1101857 498095 686315 804743 600161 614467 639075 1267775 827990 10546393 1743214 2310168 1363886 890077 3297085 2689845 1959153 1059084 2276108 874426 1759785 1642150 857842 605835 478338 560387 425394 305536 1359196 443649 523223 980663 425527 457010 315502 349704 300721 869069 520260 352325 249856 307686 413781 478047 476992 550849 465021 382005 489809 395243 299363 263755 338891 260121 238459 295798 302545 485906 310986 411206 414924 419423 256153 231185 256008 1648588 314315 430330 227769 311496 461889 446779 441791 232480 232738 292745 577318 324686 437596 629044 414761 531275 551378 355132 495508 1953103 461654 366994 440719 446237 872105 937503 816369 835964 752421 891854 796362 970943 686769 652771 695281 769598 912813 657934 1086562 872019 873323 997656 777638 993199 814066 1208097 724351 1021921 649694 999053 509554 886265 629268 818947 445740 749960 656942 672297 898111 1009541 733674]
# NumGC = 11396
# DebugGC = false

查看了下golang关于runtime库的说明

1
2
3
4
5
6
7
type MemStats
type MemStats struct {
    // 一般统计
    Alloc      uint64 // 已申请且仍在使用的字节数
    Sys        uint64 // 从系统中获取的字节数（下面XxxSys之和）
    ...
}

最关键的的Alloc代表了代码使用的内存，Sys代表golang程序实际向系统申请的内存，和top的RES字段相对应

这么一看确实用了很多的内存

我只能猜测是因为我申请释放对象过快，导致产生了很多内存碎片，从而来不及GC到系统中。

就在我即将进行各种对象池优化的时候，看了眼

1
2
3
4
5
6
7
8
9
10
11
浏览器打开http://A.A.A.A:port/debug/pprof

/debug/pprof/

profiles:
0   block
150482 goroutine
2898    heap
13  threadcreate

full goroutine stack dump

卧槽？怎么肥四，15W协程？所有的协程对象我都控制池化了，这是协程泄漏了？

查了下代码，终于找到了原因。

代码debug

简化一下代码差不多是这个情况

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
package main

import (
	"fmt"
	"time"
)

func Test() <-chan string {
	c := make(chan string)
	go func() {
		defer close(c)
		defer fmt.Println("out1")
		for i := 0;i < 10;i++ {
			c <- fmt.Sprintf("%d",i)
		}
    }()
	return c
}

func main() {
	c := Test()
	for str := range c {
		fmt.Println(str)
		if str == "2" {
			break
        }
    }
	fmt.Println("out2")
	time.Sleep(time.Second * 100000)
}
1
2
3
4
5
输出
0
1
2
out2

此时Test中的协程泄漏了

在我的代码中，Test是一个第三方库提供的函数，返回值是一个单向管道

我在判断返回的某个值以后，就直接跳出了循环。此时第三方库内部的go协程会一直阻塞，导致泄漏

找到原因了就好修改了

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
package main

import (
	"fmt"
	"time"
)

func Test(cancelC <-chan struct{}) <-chan string {
	c := make(chan string)
	go func() {
		defer close(c)
		defer fmt.Println("out1")
		for i := 0;i < 10;i++ {
			select {
			case c <- fmt.Sprintf("%d",i):
			case <-cancelC:
				return
            }
		}
    }()
	return c
}

func main() {
	cancelC := make(chan struct{})
	c := Test(cancelC)
	for str := range c {
		fmt.Println(str)
		if str == "2" {
			close(cancelC)
			<-c
			break
        }
    }
	fmt.Println("out2")
	time.Sleep(time.Second * 100000)
}
1
2
3
4
5
0
1
2
out1
out2

传一个单向管道进去，进行select来退出就行了

但是这里有个点很重要，如果我调用Test函数不想中途退出怎么办呢？

golang的channel有个特性

未赋值初始化的channel永远是阻塞的

因此在调用Test的时候传入nil就行了

总结

当出现内存泄漏的时候，不要灯下黑忘记检查协程有没有泄漏

说起来，这个第三方库是不是需要一个原生的Stop函数？