search

natefinch / lumberjack

lumberjack is a log rolling package for Go
MIT License
4.81k stars 593 forks source link

Goroutine leak after closing Logger #205

Open myxo opened 7 months ago

myxo commented 7 months ago

Close command on logger does not close mill goroutine

Reproducer:

package main

import (
    "time"

    "gopkg.in/natefinch/lumberjack.v2"
)

func RunAndCloseLog() {
    logSink := &lumberjack.Logger{
        Filename: "test.log",
        MaxSize:  50, // megabytes
        MaxAge:   28, //days
        Compress: true,
    }

    _, _ = logSink.Write([]byte("line"))
    logSink.Close()
}

func main() {
    RunAndCloseLog()
    RunAndCloseLog()
    RunAndCloseLog()
    RunAndCloseLog()
    RunAndCloseLog()

    time.Sleep(time.Second * 30)
}

Then press Ctrl-4 (or use pprof to get all stacks)

^\SIGQUIT: quit

<some runtime stacks>

goroutine 6 [chan receive]:
runtime.gopark(0x404885?, 0x60?, 0x0?, 0x0?, 0x415a01?)
    /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc00010cef8 sp=0xc00010ced8 pc=0x433d6e
runtime.chanrecv(0xc000068070, 0xc00010cfaf, 0x1)
    /usr/local/go/src/runtime/chan.go:583 +0x3cd fp=0xc00010cf70 sp=0xc00010cef8 pc=0x405a6d
runtime.chanrecv2(0xc00006c180?, 0x5639e0?)
    /usr/local/go/src/runtime/chan.go:447 +0x12 fp=0xc00010cf98 sp=0xc00010cf70 pc=0x405692
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc00006c180)
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:379 +0x3f fp=0xc00010cfc8 sp=0xc00010cf98 pc=0x4a2fff
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1.1()
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x25 fp=0xc00010cfe0 sp=0xc00010cfc8 pc=0x4a3185
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00010cfe8 sp=0xc00010cfe0 pc=0x45d761
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1 in goroutine 1
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x96

goroutine 7 [chan receive]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000090ef8 sp=0xc000090ed8 pc=0x433d6e
runtime.chanrecv(0xc0000680e0, 0xc000090faf, 0x1)
    /usr/local/go/src/runtime/chan.go:583 +0x3cd fp=0xc000090f70 sp=0xc000090ef8 pc=0x405a6d
runtime.chanrecv2(0xc00006c240?, 0x0?)
    /usr/local/go/src/runtime/chan.go:447 +0x12 fp=0xc000090f98 sp=0xc000090f70 pc=0x405692
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc00006c240)
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:379 +0x3f fp=0xc000090fc8 sp=0xc000090f98 pc=0x4a2fff
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1.1()
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x25 fp=0xc000090fe0 sp=0xc000090fc8 pc=0x4a3185
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000090fe8 sp=0xc000090fe0 pc=0x45d761
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1 in goroutine 1
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x96

goroutine 8 [chan receive]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc00010def8 sp=0xc00010ded8 pc=0x433d6e
runtime.chanrecv(0xc000068150, 0xc00010dfaf, 0x1)
    /usr/local/go/src/runtime/chan.go:583 +0x3cd fp=0xc00010df70 sp=0xc00010def8 pc=0x405a6d
runtime.chanrecv2(0xc00006c300?, 0x0?)
    /usr/local/go/src/runtime/chan.go:447 +0x12 fp=0xc00010df98 sp=0xc00010df70 pc=0x405692
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc00006c300)
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:379 +0x3f fp=0xc00010dfc8 sp=0xc00010df98 pc=0x4a2fff
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1.1()
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x25 fp=0xc00010dfe0 sp=0xc00010dfc8 pc=0x4a3185
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00010dfe8 sp=0xc00010dfe0 pc=0x45d761
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1 in goroutine 1
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x96

goroutine 9 [chan receive]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc00008cef8 sp=0xc00008ced8 pc=0x433d6e
runtime.chanrecv(0xc0000681c0, 0xc00008cfaf, 0x1)
    /usr/local/go/src/runtime/chan.go:583 +0x3cd fp=0xc00008cf70 sp=0xc00008cef8 pc=0x405a6d
runtime.chanrecv2(0xc00006c3c0?, 0x0?)
    /usr/local/go/src/runtime/chan.go:447 +0x12 fp=0xc00008cf98 sp=0xc00008cf70 pc=0x405692
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc00006c3c0)
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:379 +0x3f fp=0xc00008cfc8 sp=0xc00008cf98 pc=0x4a2fff
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1.1()
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x25 fp=0xc00008cfe0 sp=0xc00008cfc8 pc=0x4a3185
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00008cfe8 sp=0xc00008cfe0 pc=0x45d761
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1 in goroutine 1
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x96

goroutine 10 [chan receive]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000111ef8 sp=0xc000111ed8 pc=0x433d6e
runtime.chanrecv(0xc000068230, 0xc000111faf, 0x1)
    /usr/local/go/src/runtime/chan.go:583 +0x3cd fp=0xc000111f70 sp=0xc000111ef8 pc=0x405a6d
runtime.chanrecv2(0xc00006c480?, 0x0?)
    /usr/local/go/src/runtime/chan.go:447 +0x12 fp=0xc000111f98 sp=0xc000111f70 pc=0x405692
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc00006c480)
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:379 +0x3f fp=0xc000111fc8 sp=0xc000111f98 pc=0x4a2fff
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1.1()
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x25 fp=0xc000111fe0 sp=0xc000111fc8 pc=0x4a3185
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000111fe8 sp=0xc000111fe0 pc=0x45d761
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1 in goroutine 1
    /home/nklimov/go/pkg/mod/gopkg.in/natefinch/lumberjack.v2@v2.2.1/lumberjack.go:390 +0x96
myxo commented 7 months ago

Personally I would add channel closing function to Close method, but comment says it explicitly close current file, not logger (which btw a bit misleading)

// Close implements io.Closer, and closes the current logfile.
func (l *Logger) Close() error {
    l.mu.Lock()
    defer l.mu.Unlock()
    if l.millCh != nil {
        close(l.millCh)
        l.millCh = nil
    }

    return l.close()
}
joint-song commented 5 months ago

I met the same problem too. Please fix it.