英文:
Golang crypto/tls memory leak
问题
问题:为什么即使变量超出作用域并且使用(*tls.Conn).Close()
方法正确关闭了,*tls.Conn仍然没有被垃圾回收?下面是复现问题的完整代码。
动机:作为长时间运行的服务(> 24小时)的一部分,我已经尝试了2个websocket库(https://github.com/gorilla/websocket和https://github.com/gobwas/ws),它们在其生命周期内作为客户端维护了约10个websocket连接。有时它们会与服务器断开连接,在这种情况下我会建立新的连接。内存使用量在其生命周期内稳步增长,并且从内存分析来看,指向底层*tls.Conn对象的指针仍然存在于堆上(没有被垃圾回收)。
复现问题的完整代码:
package main
import (
"crypto/tls"
"fmt"
"log"
_ "net/http/pprof"
"os"
"os/signal"
"runtime"
"syscall"
"time"
)
func finalizer(_ interface{}) {
fmt.Println("finalizer called")
}
func main() {
// setup interrupt handler
c := make(chan os.Signal)
signal.Notify(c, os.Interrupt, syscall.SIGTERM)
for i := 0; i < 100; i++ {
go func() {
for {
tlsConnectThenCloseAfterWait()
}
}()
}
<-c
os.Exit(1)
}
func tlsConnectThenCloseAfterWait() {
conn, err := tls.Dial("tcp", "mail.google.com:443", &tls.Config{})
if err != nil {
log.Fatalln("failed to connect: " + err.Error())
}
defer func() {
err := conn.Close()
if err != nil {
log.Fatalln("closing conn failed")
}
}()
runtime.SetFinalizer(conn, finalizer)
conn.Write([]byte("hello how are you"))
timer := time.NewTimer(time.Second)
<-timer.C
}
GODEBUG=gctrace=1 ./main
的输出结果:
gc 1 @0.088s 1%: 0+9.0+0 ms clock, 0+12/11/0+0 ms cpu, 4->5->1 MB, 5 MB goal, 12 P
gc 2 @0.102s 3%: 0+4.9+0.99 ms clock, 0+5.9/6.0/0+11 ms cpu, 4->4->1 MB, 5 MB goal, 12 P
gc 3 @0.114s 5%: 0+4.9+1.0 ms clock, 0+3.9/10/2.9+12 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
gc 4 @0.171s 4%: 0+5.0+0 ms clock, 0+1.0/9.9/0+0 ms cpu, 4->5->3 MB, 5 MB goal, 12 P
gc 5 @0.196s 4%: 0+5.9+0 ms clock, 0+2.9/9.9/0+0 ms cpu, 5->7->3 MB, 6 MB goal, 12 P
gc 6 @0.352s 2%: 1.0+2.0+0 ms clock, 12+0/1.9/1.9+0 ms cpu, 6->7->4 MB, 7 MB goal, 12 P
gc 7 @0.365s 2%: 0.99+3.0+0 ms clock, 11+3.0/5.0/0+0 ms cpu, 7->8->5 MB, 8 MB goal, 12 P
gc 8 @0.399s 3%: 0+13+0 ms clock, 0+18/29/1.0+0 ms cpu, 9->11->6 MB, 10 MB goal, 12 P
gc 9 @1.278s 1%: 1.0+28+0 ms clock, 12+9.9/53/0+0 ms cpu, 10->13->9 MB, 13 MB goal, 12 P
gc 10 @1.433s 2%: 1.0+22+0 ms clock, 12+45/55/1.0+0 ms cpu, 14->16->9 MB, 18 MB goal, 12 P
gc 11 @1.534s 2%: 0+6.0+0 ms clock, 0+4.0/15/3.0+0 ms cpu, 16->17->11 MB, 19 MB goal, 12 P
gc 12 @2.479s 1%: 0+3.0+0 ms clock, 0+0/6.0/18+0 ms cpu, 20->20->12 MB, 22 MB goal, 12 P
gc 13 @2.656s 1%: 1.0+10+0 ms clock, 12+3.0/30/4.9+0 ms cpu, 23->25->16 MB, 25 MB goal, 12 P
gc 14 @3.737s 1%: 0+6.0+0 ms clock, 0+3.0/18/9.0+0 ms cpu, 31->33->20 MB, 33 MB goal, 12 P
gc 15 @4.830s 0%: 0+5.9+0 ms clock, 0+5.0/13/16+0 ms cpu, 39->40->25 MB, 41 MB goal, 12 P
gc 16 @6.733s 0%: 0.99+16+0.99 ms clock, 11+7.9/47/80+11 ms cpu, 50->50->32 MB, 51 MB goal, 12 P
gc 17 @8.140s 0%: 0.99+21+0 ms clock, 11+3.0/59/125+0 ms cpu, 64->64->42 MB, 65 MB goal, 12 P
gc 18 @11.168s 0%: 1.0+28+0 ms clock, 12+24/78/97+0 ms cpu, 82->82->54 MB, 84 MB goal, 12 P
gc 19 @14.433s 0%: 0.99+27+0 ms clock, 11+9.0/74/146+0 ms cpu, 106->106->70 MB, 108 MB goal, 12 P
gc 20 @18.883s 0%: 0+47+0 ms clock, 0+6.0/133/211+0 ms cpu, 137->138->91 MB, 140 MB goal, 12 P
gc 21 @24.437s 0%: 0.99+30+0.99 ms clock, 11+15/91/101+11 ms cpu, 177->178->118 MB, 182 MB goal, 12 P
gc 22 @31.872s 0%: 1.0+105+0 ms clock, 12+60/317/256+0 ms cpu, 230->233->155 MB, 236 MB goal, 12 P
gc 23 @41.705s 0%: 0+101+0 ms clock, 0+15/283/549+0 ms cpu, 302->303->200 MB, 310 MB goal, 12 P
gc 24 @54.302s 0%: 0+92+0 ms clock, 0+9.0/278/472+0 ms cpu, 390->392->260 MB, 400 MB goal, 12 P
gc 25 @70.777s 0%: 0+38+0 ms clock, 0+4.9/113/321+0 ms cpu, 508->508->337 MB, 521 MB goal, 12 P
gc 26 @92.203s 0%: 0+108+0 ms clock, 0+57/326/391+0 ms cpu, 658->662->442 MB, 675 MB goal, 12 P
gc 27 @120.781s 0%: 2.0+99+0 ms clock, 24+11/292/529+0 ms cpu, 862->864->574 MB, 884 MB goal, 12 P
finalizer从未被调用,内存不断增长。
使用go version go1.15.8 windows/amd64
还与此处的GitHub问题链接:https://github.com/golang/go/issues/41987
英文:
Question: Why is *tls.Conn not being garbage collected even after the variable goes out of scope, and it's properly closed using the (*tls.Conn).Close()
method? Full code to reproduce given below.
Motivation: I've tried 2 websocket libraries (https://github.com/gorilla/websocket and https://github.com/gobwas/ws) so far as part of long-running service (> 24 hours), which maintains ~10 websocket connections as a client throughout its lifetime. Sometimes they are disconnected from the server, in which case I make a new connection. The memory usage steadily grows throughout its lifetime, and from memory profiles, it points to the underlying *tls.Conn object staying on the heap. (not being garbage collected).
Full code to reproduce
package main
import (
"crypto/tls"
"fmt"
"log"
_ "net/http/pprof"
"os"
"os/signal"
"runtime"
"syscall"
"time"
)
func finalizer(_ interface{}) {
fmt.Println("finalizer called")
}
func main() {
// setup interrupt handler
c := make(chan os.Signal)
signal.Notify(c, os.Interrupt, syscall.SIGTERM)
for i := 0; i < 100; i++ {
go func() {
for {
tlsConnectThenCloseAfterWait()
}
}()
}
<-c
os.Exit(1)
}
func tlsConnectThenCloseAfterWait() {
conn, err := tls.Dial("tcp", "mail.google.com:443", &tls.Config{})
if err != nil {
log.Fatalln("failed to connect: " + err.Error())
}
defer func() {
err := conn.Close()
if err != nil {
log.Fatalln("closing conn failed")
}
}()
runtime.SetFinalizer(conn, finalizer)
conn.Write([]byte("hello how are you"))
timer := time.NewTimer(time.Second)
<-timer.C
}
Output of GODEBUG=gctrace=1 ./main
gc 1 @0.088s 1%: 0+9.0+0 ms clock, 0+12/11/0+0 ms cpu, 4->5->1 MB, 5 MB goal, 12 P
gc 2 @0.102s 3%: 0+4.9+0.99 ms clock, 0+5.9/6.0/0+11 ms cpu, 4->4->1 MB, 5 MB goal, 12 P
gc 3 @0.114s 5%: 0+4.9+1.0 ms clock, 0+3.9/10/2.9+12 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
gc 4 @0.171s 4%: 0+5.0+0 ms clock, 0+1.0/9.9/0+0 ms cpu, 4->5->3 MB, 5 MB goal, 12 P
gc 5 @0.196s 4%: 0+5.9+0 ms clock, 0+2.9/9.9/0+0 ms cpu, 5->7->3 MB, 6 MB goal, 12 P
gc 6 @0.352s 2%: 1.0+2.0+0 ms clock, 12+0/1.9/1.9+0 ms cpu, 6->7->4 MB, 7 MB goal, 12 P
gc 7 @0.365s 2%: 0.99+3.0+0 ms clock, 11+3.0/5.0/0+0 ms cpu, 7->8->5 MB, 8 MB goal, 12 P
gc 8 @0.399s 3%: 0+13+0 ms clock, 0+18/29/1.0+0 ms cpu, 9->11->6 MB, 10 MB goal, 12 P
gc 9 @1.278s 1%: 1.0+28+0 ms clock, 12+9.9/53/0+0 ms cpu, 10->13->9 MB, 13 MB goal, 12 P
gc 10 @1.433s 2%: 1.0+22+0 ms clock, 12+45/55/1.0+0 ms cpu, 14->16->9 MB, 18 MB goal, 12 P
gc 11 @1.534s 2%: 0+6.0+0 ms clock, 0+4.0/15/3.0+0 ms cpu, 16->17->11 MB, 19 MB goal, 12 P
gc 12 @2.479s 1%: 0+3.0+0 ms clock, 0+0/6.0/18+0 ms cpu, 20->20->12 MB, 22 MB goal, 12 P
gc 13 @2.656s 1%: 1.0+10+0 ms clock, 12+3.0/30/4.9+0 ms cpu, 23->25->16 MB, 25 MB goal, 12 P
gc 14 @3.737s 1%: 0+6.0+0 ms clock, 0+3.0/18/9.0+0 ms cpu, 31->33->20 MB, 33 MB goal, 12 P
gc 15 @4.830s 0%: 0+5.9+0 ms clock, 0+5.0/13/16+0 ms cpu, 39->40->25 MB, 41 MB goal, 12 P
gc 16 @6.733s 0%: 0.99+16+0.99 ms clock, 11+7.9/47/80+11 ms cpu, 50->50->32 MB, 51 MB goal, 12 P
gc 17 @8.140s 0%: 0.99+21+0 ms clock, 11+3.0/59/125+0 ms cpu, 64->64->42 MB, 65 MB goal, 12 P
gc 18 @11.168s 0%: 1.0+28+0 ms clock, 12+24/78/97+0 ms cpu, 82->82->54 MB, 84 MB goal, 12 P
gc 19 @14.433s 0%: 0.99+27+0 ms clock, 11+9.0/74/146+0 ms cpu, 106->106->70 MB, 108 MB goal, 12 P
gc 20 @18.883s 0%: 0+47+0 ms clock, 0+6.0/133/211+0 ms cpu, 137->138->91 MB, 140 MB goal, 12 P
gc 21 @24.437s 0%: 0.99+30+0.99 ms clock, 11+15/91/101+11 ms cpu, 177->178->118 MB, 182 MB goal, 12 P
gc 22 @31.872s 0%: 1.0+105+0 ms clock, 12+60/317/256+0 ms cpu, 230->233->155 MB, 236 MB goal, 12 P
gc 23 @41.705s 0%: 0+101+0 ms clock, 0+15/283/549+0 ms cpu, 302->303->200 MB, 310 MB goal, 12 P
gc 24 @54.302s 0%: 0+92+0 ms clock, 0+9.0/278/472+0 ms cpu, 390->392->260 MB, 400 MB goal, 12 P
gc 25 @70.777s 0%: 0+38+0 ms clock, 0+4.9/113/321+0 ms cpu, 508->508->337 MB, 521 MB goal, 12 P
gc 26 @92.203s 0%: 0+108+0 ms clock, 0+57/326/391+0 ms cpu, 658->662->442 MB, 675 MB goal, 12 P
gc 27 @120.781s 0%: 2.0+99+0 ms clock, 24+11/292/529+0 ms cpu, 862->864->574 MB, 884 MB goal, 12 P
The finalizer is never called, and the memory keeps on growing.
Using go version go1.15.8 windows/amd64
Also linked to the github issue here: https://github.com/golang/go/issues/41987
答案1
得分: 3
你似乎误用了runtime.SetFinalizer
;文档中有这样的说明:
[第一个参数] 必须是一个指针,指向通过调用
new
、取一个复合字面量的地址或取一个局部变量的地址分配的对象。
(我强调的部分)
如果我将&conn
(而不是conn
本身)传递给runtime.SetFinalizer
,finalizer确实会被调用,并且堆内存永远不会超过8 MB:
$ GODEBUG=gctrace=1 ./main
gc 1 @1.789s 0%: 0.041+0.67+0.018 ms clock, 0.33+0.31/1.0/2.3+0.14 ms cpu, 4->4->1 MB, 5 MB goal, 8 P
gc 2 @1.874s 0%: 0.044+0.69+0.015 ms clock, 0.35+0.20/1.0/2.4+0.12 ms cpu, 4->4->2 MB, 5 MB goal, 8 P
gc 3 @1.880s 0%: 0.064+0.79+0.014 ms clock, 0.51+0.22/1.1/2.3+0.11 ms cpu, 4->4->2 MB, 5 MB goal, 8 P
gc 4 @1.887s 0%: 0.14+1.5+0.080 ms clock, 1.1+1.6/2.5/0+0.64 ms cpu, 5->5->3 MB, 6 MB goal, 8 P
gc 5 @1.904s 0%: 0.097+1.1+0.025 ms clock, 0.77+1.0/1.9/2.6+0.20 ms cpu, 6->6->3 MB, 7 MB goal, 8 P
gc 6 @1.974s 0%: 0.12+1.7+0.12 ms clock, 0.99+1.4/2.9/1.2+0.98 ms cpu, 6->7->3 MB, 7 MB goal, 8 P
gc 7 @2.900s 0%: 0.22+1.9+0.025 ms clock, 1.8+5.7/2.9/0+0.20 ms cpu, 7->7->4 MB, 8finalizer called
MB goal, 8finalizer called
P
finalizer called
finalizer called
finalizer called
finalizer called
finalizer called
finalizer called
--snip--
使用-gcflags="-m"
编译程序可以看到局部变量conn
被移动到了堆上。我不是finalizer的专家(远远不是),但我怀疑你对runtime.SetFinalizer
的误用导致了对conn
变量的引用保留,从而使得每个实例都无法进行垃圾回收,因此导致了内存泄漏。
我不清楚为什么你想要使用finalizers;传统的观点是应尽量避免使用finalizers。
英文:
You seem to be misusing runtime.SetFinalizer
; here is what the doc says:
> The [first argument] must be a pointer to an object allocated by calling new
, by taking the address of a composite literal, or by taking the address of a local variable.
(my emphasis)
If I pass &conn
(rather than conn
itself) to runtime.SetFinalizer
, the finalizers do get called and the heap never exceeds 8 MB:
$ GODEBUG=gctrace=1 ./main
gc 1 @1.789s 0%: 0.041+0.67+0.018 ms clock, 0.33+0.31/1.0/2.3+0.14 ms cpu, 4->4->1 MB, 5 MB goal, 8 P
gc 2 @1.874s 0%: 0.044+0.69+0.015 ms clock, 0.35+0.20/1.0/2.4+0.12 ms cpu, 4->4->2 MB, 5 MB goal, 8 P
gc 3 @1.880s 0%: 0.064+0.79+0.014 ms clock, 0.51+0.22/1.1/2.3+0.11 ms cpu, 4->4->2 MB, 5 MB goal, 8 P
gc 4 @1.887s 0%: 0.14+1.5+0.080 ms clock, 1.1+1.6/2.5/0+0.64 ms cpu, 5->5->3 MB, 6 MB goal, 8 P
gc 5 @1.904s 0%: 0.097+1.1+0.025 ms clock, 0.77+1.0/1.9/2.6+0.20 ms cpu, 6->6->3 MB, 7 MB goal, 8 P
gc 6 @1.974s 0%: 0.12+1.7+0.12 ms clock, 0.99+1.4/2.9/1.2+0.98 ms cpu, 6->7->3 MB, 7 MB goal, 8 P
gc 7 @2.900s 0%: 0.22+1.9+0.025 ms clock, 1.8+5.7/2.9/0+0.20 ms cpu, 7->7->4 MB, 8finalizer called
MB goal, 8finalizer called
P
finalizer called
finalizer called
finalizer called
finalizer called
finalizer called
finalizer called
--snip--
Compiling the program with -gcflags="-m"
reveals that local variable conn
gets moved to the heap. I'm no finalizer expert (by far), but I suspect that your misuse of runtime.SetFinalizer
causes the retention of a reference to the conn
variable, thereby making each instance of it ineligible for garbage collection, hence the memory leak.
It's unclear to me why you'd want to use finalizers anyway; conventional wisdom is that finalizers are best avoided.
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库,让每个人都能够通过互相帮助和分享经验来进步。
评论