dead lock when goroutines exceeds MaxTotal
zhyhang opened this issue · 4 comments
zhyhang commented
Seeing
dead lock when goroutines exceeds MaxTotal:
Environment
go 1.11
go-commons-pool newest
ubuntu 18.04
Code
package main
import (
"bytes"
"context"
"crypto/md5"
"encoding/binary"
"fmt"
"github.com/gomodule/redigo/redis"
"github.com/jolestar/go-commons-pool"
"log"
"math/rand"
"net/http"
_ "net/http/pprof"
"strconv"
"sync"
"time"
)
func main() {
// dump stack info by http://localhost:6060/debug/pprof/goroutine?debug=2
go func() {
log.Println(http.ListenAndServe("localhost:6060", nil))
}()
// create commons pool
factory := pool.NewPooledObjectFactorySimple(
func(context.Context) (interface{}, error) {
return redis.Dial("tcp", ":6400")
})
ctx := context.TODO()
p := pool.NewObjectPoolWithDefaultConfig(ctx, factory)
p.Config.MaxTotal = 100
p.Config.MaxIdle = 100
defer p.Close(ctx)
// write to redis parallel
total := 100000
idCount := 10
// when <= 100 (MaxTotal) is OK, or else dead lock
parallel := 200
today := time.Now().Format("20060102")
rand.Seed(time.Now().Unix())
log.Println("begin write to redis")
for i := 0; i < total; {
batchWg := &sync.WaitGroup{}
for j := 0; j < parallel/idCount && i < total; j++ {
uuid := createUuid()
for k := 0; k < idCount; k++ {
idInt := rand.Intn(1000000)
id := strconv.Itoa(idInt)
field := ":" + today + ":" + id
batchWg.Add(1)
go incrCounter(batchWg, p, uuid+field)
}
i++
}
batchWg.Wait()
}
log.Println("end write to redis")
}
func incrCounter(wg *sync.WaitGroup, pool *pool.ObjectPool, key string) {
defer wg.Done()
ctx := context.TODO()
conn, _ := pool.BorrowObject(ctx)
if conn != nil {
defer pool.ReturnObject(ctx, conn)
} else {
return
}
redisConn := conn.(redis.Conn)
_, err := redisConn.Do("incr", key)
if err != nil {
log.Printf("incr error %v", err)
}
}
func createUuid() string {
randInt := rand.Int63()
intBytes := make([]byte, 8)
binary.BigEndian.PutUint64(intBytes, uint64(randInt))
md5Bytes := md5.Sum(intBytes)
buf := new(bytes.Buffer)
fmt.Fprintf(buf, "%x", md5Bytes)
return buf.String()
}Stack Trace
goroutine 228 [running]:
runtime/pprof.writeGoroutineStacks(0x857620, 0xc00048e000, 0x40d62f, 0xc000392360)
/home/zhyhang/workdoc/dev/go/src/runtime/pprof/pprof.go:678 +0xa7
runtime/pprof.writeGoroutine(0x857620, 0xc00048e000, 0x2, 0xae41e0, 0x0)
/home/zhyhang/workdoc/dev/go/src/runtime/pprof/pprof.go:667 +0x44
runtime/pprof.(*Profile).WriteTo(0xad5d60, 0x857620, 0xc00048e000, 0x2, 0xc00048e000, 0x7f5c13)
/home/zhyhang/workdoc/dev/go/src/runtime/pprof/pprof.go:328 +0x3e4
net/http/pprof.handler.ServeHTTP(0xc00037cb51, 0x9, 0x85a5c0, 0xc00048e000, 0xc0002ce000)
/home/zhyhang/workdoc/dev/go/src/net/http/pprof/pprof.go:245 +0x210
net/http/pprof.Index(0x85a5c0, 0xc00048e000, 0xc0002ce000)
/home/zhyhang/workdoc/dev/go/src/net/http/pprof/pprof.go:268 +0x723
net/http.HandlerFunc.ServeHTTP(0x80d5b0, 0x85a5c0, 0xc00048e000, 0xc0002ce000)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:1964 +0x44
net/http.(*ServeMux).ServeHTTP(0xae3400, 0x85a5c0, 0xc00048e000, 0xc0002ce000)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2361 +0x127
net/http.serverHandler.ServeHTTP(0xc0002b60d0, 0x85a5c0, 0xc00048e000, 0xc0002ce000)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2741 +0xab
net/http.(*conn).serve(0xc0002ae8c0, 0x85a940, 0xc000371a80)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:1847 +0x646
created by net/http.(*Server).Serve
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2851 +0x2f5
goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc00043c558)
/home/zhyhang/workdoc/dev/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc00043c550)
/home/zhyhang/workdoc/dev/go/src/sync/waitgroup.go:130 +0x64
main.main()
/home/zhyhang/code-go/src/github.com/zhyhang/gofirst/tools/deadpool.go:56 +0x36c
goroutine 20 [IO wait]:
internal/poll.runtime_pollWait(0x7faf71b262b0, 0x72, 0x0)
/home/zhyhang/workdoc/dev/go/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc0001d1718, 0x72, 0xc0001aa100, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc0001d1718, 0xffffffffffffff00, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc0001d1700, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_unix.go:384 +0x1a0
net.(*netFD).accept(0xc0001d1700, 0x40d62f, 0xc0002ae960, 0xa0)
/home/zhyhang/workdoc/dev/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc0002a4078, 0xc000042df0, 0x8dcf19d1, 0x6b34adfcd281e637)
/home/zhyhang/workdoc/dev/go/src/net/tcpsock_posix.go:139 +0x2e
net.(*TCPListener).AcceptTCP(0xc0002a4078, 0xc000042e18, 0x491246, 0x5bbc77ec)
/home/zhyhang/workdoc/dev/go/src/net/tcpsock.go:247 +0x47
net/http.tcpKeepAliveListener.Accept(0xc0002a4078, 0xc000042e68, 0x18, 0xc000062900, 0x6a6825)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:3232 +0x2f
net/http.(*Server).Serve(0xc0002b60d0, 0x85a7c0, 0xc0002a4078, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2826 +0x22f
net/http.(*Server).ListenAndServe(0xc0002b60d0, 0xc0002b60d0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2764 +0xb6
net/http.ListenAndServe(0x7f66e8, 0xe, 0x0, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:3004 +0x74
main.main.func1()
/home/zhyhang/code-go/src/github.com/zhyhang/gofirst/tools/deadpool.go:23 +0x3e
created by main.main
/home/zhyhang/code-go/src/github.com/zhyhang/gofirst/tools/deadpool.go:22 +0x47
goroutine 229 [IO wait]:
internal/poll.runtime_pollWait(0x7faf71aea958, 0x72, 0xc000167858)
/home/zhyhang/workdoc/dev/go/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc0001d1f18, 0x72, 0xffffffffffffff00, 0x8581c0, 0xaa6618)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc0001d1f18, 0xc000406000, 0x1000, 0x1000)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc0001d1f00, 0xc000406000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_unix.go:169 +0x179
net.(*netFD).Read(0xc0001d1f00, 0xc000406000, 0x1000, 0x1000, 0xc0001aba00, 0xc000167968, 0x69cff0)
/home/zhyhang/workdoc/dev/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0002a4098, 0xc000406000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/net.go:177 +0x68
net/http.(*connReader).Read(0xc0001cd080, 0xc000406000, 0x1000, 0x1000, 0x435c7c, 0xc0001b9680, 0x298)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:786 +0xfc
bufio.(*Reader).fill(0xc0001c39e0)
/home/zhyhang/workdoc/dev/go/src/bufio/bufio.go:100 +0x106
bufio.(*Reader).ReadSlice(0xc0001c39e0, 0xc0002ca00a, 0xc000167ac8, 0x40d1a3, 0x7faf71b6db30, 0x0, 0x203000)
/home/zhyhang/workdoc/dev/go/src/bufio/bufio.go:341 +0x36
bufio.(*Reader).ReadLine(0xc0001c39e0, 0xc0002ca000, 0x100, 0xf8, 0x7e4760, 0x1, 0x1000000ae41e0)
/home/zhyhang/workdoc/dev/go/src/bufio/bufio.go:370 +0x34
net/textproto.(*Reader).readLineSlice(0xc0001cd0b0, 0xc000404701, 0xc000167b98, 0x40deb8, 0x100, 0x7e4760)
/home/zhyhang/workdoc/dev/go/src/net/textproto/reader.go:55 +0x6f
net/textproto.(*Reader).ReadLine(0xc0001cd0b0, 0xc0002ca000, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/textproto/reader.go:36 +0x2b
net/http.readRequest(0xc0001c39e0, 0x0, 0xc0002ca000, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/http/request.go:958 +0x8c
net/http.(*conn).readRequest(0xc0002ae960, 0x85a940, 0xc0001ab980, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:966 +0x162
net/http.(*conn).serve(0xc0002ae960, 0x85a940, 0xc0001ab980)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:1788 +0x49e
created by net/http.(*Server).Serve
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:2851 +0x2f5
goroutine 2642 [runnable]:
syscall.Syscall(0x0, 0x69, 0xc000209241, 0x1, 0xffffffffffffffff, 0x0, 0xb)
/home/zhyhang/workdoc/dev/go/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.read(0x69, 0xc000209241, 0x1, 0x1, 0xc00005a000, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/syscall/zsyscall_linux_amd64.go:732 +0x5a
syscall.Read(0x69, 0xc000209241, 0x1, 0x1, 0x0, 0xc000060000, 0xc00044ef00)
/home/zhyhang/workdoc/dev/go/src/syscall/syscall_unix.go:172 +0x49
internal/poll.(*FD).Read(0xc0001d1e80, 0xc000209241, 0x1, 0x1, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/internal/poll/fd_unix.go:165 +0x119
net.(*netFD).Read(0xc0001d1e80, 0xc000209241, 0x1, 0x1, 0x1, 0xc00039adc0, 0xc00001e7b8)
/home/zhyhang/workdoc/dev/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0002a4090, 0xc000209241, 0x1, 0x1, 0x0, 0x0, 0x0)
/home/zhyhang/workdoc/dev/go/src/net/net.go:177 +0x68
net/http.(*connReader).backgroundRead(0xc000209230)
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:676 +0x5a
created by net/http.(*connReader).startBackgroundRead
/home/zhyhang/workdoc/dev/go/src/net/http/server.go:672 +0xd2
goroutine 2624 [select]:
github.com/jolestar/go-commons-pool/concurrent.(*TimeoutCond).Wait(0xc00008a420, 0x85a980, 0xc000094018, 0x0)
/home/zhyhang/code-go/src/github.com/jolestar/go-commons-pool/concurrent/cond.go:55 +0x14f
github.com/jolestar/go-commons-pool/collections.(*LinkedBlockingDeque).PollFirstWithContext(0xc00009c340, 0x85a980, 0xc000094018, 0x0, 0x0, 0x0, 0x0)
/home/zhyhang/code-go/src/github.com/jolestar/go-commons-pool/collections/queue.go:289 +0xba
github.com/jolestar/go-commons-pool.(*ObjectPool).borrowObject(0xc000122000, 0x85a980, 0xc000094018, 0x8, 0xc0001aab40, 0x1, 0xc00019a718)
/home/zhyhang/code-go/src/github.com/jolestar/go-commons-pool/pool.go:276 +0x45d
github.com/jolestar/go-commons-pool.(*ObjectPool).BorrowObject(0xc000122000, 0x85a980, 0xc000094018, 0xc0004558c0, 0x1, 0x1, 0xc000218320)
/home/zhyhang/code-go/src/github.com/jolestar/go-commons-pool/pool.go:141 +0x3f
main.incrCounter(0xc00043c550, 0xc000122000, 0xc000442f00, 0x30)
/home/zhyhang/code-go/src/github.com/zhyhang/gofirst/tools/deadpool.go:64 +0x8a
created by main.main
/home/zhyhang/code-go/src/github.com/zhyhang/gofirst/tools/deadpool.go:52 +0x2f1
molon commented
Anything updated?