Analysis of goland waiting lock problem

  • 2020-11-18 06:16:45
  • OfStack

Problem description:

I sent an URL request to the background, but it turned out that 1 was stuck. Instead of returning, 1 stuck

Problem analysis and positioning:

At first, I thought it was the network, or some other strange reason. After all, it was fine before.

This should be the first time to think about the environment, network, version of the program, or what has changed.

After a few more attempts, I found the same number. I thought to change the number of Pod to two, so I guess I was waiting for a lock or deadlock or something.

For debugging information, use the following link:
curl "127.0.0.1:43411 / debug pprof/goroutine & # 63; debug = 1" > 1.out
curl "127.0.0.1:43411 / debug pprof/goroutine & # 63; debug = 2" > 1.log

Search for stuck request method names, and if you find one, goroutine 17002 [semacquire, 5 minutes]: indicates that the goroutine 17002 was waiting for the lock for 5 minutes.

There is another running method with the same name, and I guess everyone is waiting for its lock. It looks like the code has a lock.
But the top layer of the goroutine call stack is SetDataNodeCarry, and when you look inside its method, you see that it has also added a lock, but it's simply locking a change to a field.
Analysis of its use of lock-related code, we do not overlap, every lock is just to ensure the atomicity and 1 sex of data, so there is no deadlock problem.

Read the code around SetDataNodeCarry, there is 1 for availCarryCount < needSelectedNum {}, I didn't look carefully before, but there might be a dead cycle here. The change of environment under 1 was analyzed, and it was because the environment was different that the cycle here could not be broken out.

conclusion

Encounter this kind of problem first can't panic, after can't escape the problem.

You need to document the problem as much as possible so that it can be restored, and you also need to debug based on the current situation. You should never think that the restart will be good, and you can't avoid the problem.

Later steps to solve the problem are ok, but the problem itself is not too difficult.

-- -- -- -- -- -- -- -- -- -- -- --


1 @ 0x47fc42 0x80fb0d 0x811270 0x80b86e 0x7ba758 0x7e0686 0x7f24fa 0x81d712 0x6ff9b4 0x7018b6 0x702c88 0x6fe971 0x469581
#0x47fc41 sync.(*RWMutex).Unlock+0xb1     /usr/local/go/src/sync/rwmutex.go:113
#0x80fb0c [go The file path ]m.(*Pod).SetDataNodeCarry+0x6c  /go/src/[go The file path ]m/t.go:777
#0x81126f [go The file path ]m.pts.ptsn+0x5f /go/src/[go The file path ]m/t.go:1059
#0x80b86d [go The file path ]m.(*t).ctcpd+0x83d /go/src/[go The file path ]m/t.go:453
#0x7ba757 [go The file path ]m.(*c).cDP+0x1e7  /go/src/[go The file path ]m/c.go:558
#0x7e0685 [go The file path ]m.(*m).cDP+0x375  /go/src/[go The file path ]m/handle_admin.go:353
#0x7f24f9 [go The file path ]m.(*m).ServeHTTP+0x1659   /go/src/[go The file path ]m/http_server.go:188
#0x81d711 [go The file path ]m.(*m).handlerWithInterceptor.func1+0x81  /go/src/[go The file path ]m/http_server.go:160
#0x6ff9b3 net/http.HandlerFunc.ServeHTTP+0x43    /usr/local/go/src/net/http/server.go:1995
#0x7018b5 net/http.(*ServeMux).ServeHTTP+0x1d5    /usr/local/go/src/net/http/server.go:2375
#0x702c87 net/http.serverHandler.ServeHTTP+0xa7    /usr/local/go/src/net/http/server.go:2774
#0x6fe970 net/http.(*conn).serve+0x850     /usr/local/go/src/net/http/server.go:1878


2 @ 0x43c20f 0x44c609 0x44c5df 0x44c37d 0x47ecb9 0x7ba6ad 0x7e0686 0x7f24fa 0x81d712 0x6ff9b4 0x7018b6 0x702c88 0x6fe971 0x469581
#0x44c37c sync.runtime_SemacquireMutex+0x3c   /usr/local/go/src/runtime/sema.go:71
#0x47ecb8 sync.(*Mutex).Lock+0x108    /usr/local/go/src/sync/mutex.go:134
#0x7ba6ac [go The file path ]m.(*c).cDP+0x13c /go/src/[go The file path ]m/c.go:554
#0x7e0685 [go The file path ]m.(*m).cDP+0x375 /go/src/[go The file path ]m/handle_admin.go:353
#0x7f24f9 [go The file path ]m.(*m).ServeHTTP+0x1659  /go/src/[go The file path ]m/http_server.go:188
#0x81d711 [go The file path ]m.(*m).handlerWithInterceptor.func1+0x81 /go/src/[go The file path ]m/http_server.go:160
#0x6ff9b3 net/http.HandlerFunc.ServeHTTP+0x43   /usr/local/go/src/net/http/server.go:1995
#0x7018b5 net/http.(*ServeMux).ServeHTTP+0x1d5   /usr/local/go/src/net/http/server.go:2375
#0x702c87 net/http.serverHandler.ServeHTTP+0xa7   /usr/local/go/src/net/http/server.go:2774
#0x6fe970 net/http.(*conn).serve+0x850    /usr/local/go/src/net/http/server.go:1878

goroutine 13994 [runnable]:
sync.(*Mutex).Lock(0xc002300468)
	/usr/local/go/src/sync/mutex.go:72 +0x2c9
sync.(*RWMutex).Lock(0xc002300468)
	/usr/local/go/src/sync/rwmutex.go:93 +0x2d
[go The file path ]m.(*Pod).SetDataNodeCarry(0xc0023003f0, 0x4024000000000000)
	/go/src/[go The file path ]m/t.go:774 +0x36
[go The file path ]m.pts.ptsn(0xc003b17810, 0x2, 0x2, 0x0, 0x3)
	/go/src/[go The file path ]m/t.go:1059 +0x60
[go The file path ]m.(*t).ctcpd(0xc0000ef090, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x3, 0x6, 0xc002275958, ...)
	/go/src/[go The file path ]m/t.go:453 +0x83e
[go The file path ]m.(*c).cDP(0xc00223c000, 0xc00286e673, 0xe, 0xc00286e65f, 0x6, 0x0, 0x0, 0x0)
	/go/src/[go The file path ]m/c.go:558 +0x1e8
[go The file path ]m.(*m).cDP(0xc0009aca90, 0xabfd80, 0xc0031a1260, 0xc00296be00)
	/go/src/[go The file path ]m/handle_admin.go:353 +0x376
[go The file path ]m.(*m).ServeHTTP(0xc0009aca90, 0xabfd80, 0xc0031a1260, 0xc00296be00)
	/go/src/[go The file path ]m/http_server.go:188 +0x165a
[go The file path ]m.(*m).handlerWithInterceptor.func1(0xabfd80, 0xc0031a1260, 0xc00296be00)
	/go/src/[go The file path ]m/http_server.go:160 +0x82
net/http.HandlerFunc.ServeHTTP(0xc000990300, 0xabfd80, 0xc0031a1260, 0xc00296be00)
	/usr/local/go/src/net/http/server.go:1995 +0x44
net/http.(*ServeMux).ServeHTTP(0x10a3520, 0xabfd80, 0xc0031a1260, 0xc00296be00)
	/usr/local/go/src/net/http/server.go:2375 +0x1d6
net/http.serverHandler.ServeHTTP(0xc0000dad00, 0xabfd80, 0xc0031a1260, 0xc00296be00)
	/usr/local/go/src/net/http/server.go:2774 +0xa8
net/http.(*conn).serve(0xc003b19860, 0xac1d80, 0xc0009a9e40)
	/usr/local/go/src/net/http/server.go:1878 +0x851
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2884 +0x2f4


goroutine 17002 [semacquire, 5 minutes]:
sync.runtime_SemacquireMutex(0xc0026fc460, 0x419400)
	/usr/local/go/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0xc0026fc45c)
	/usr/local/go/src/sync/mutex.go:134 +0x109
[go The file path ]m.(*c).cDP(0xc00223c000, 0xc00002a083, 0xe, 0xc00002a06f, 0x6, 0x0, 0x0, 0x0)
	/go/src/[go The file path ]m/c.go:554 +0x13d
[go The file path ]m.(*m).cDP(0xc0009aca90, 0xabfd80, 0xc0031a0620, 0xc002988900)
	/go/src/[go The file path ]m/handle_admin.go:353 +0x376
[go The file path ]m.(*m).ServeHTTP(0xc0009aca90, 0xabfd80, 0xc0031a0620, 0xc002988900)
	/go/src/[go The file path ]m/http_server.go:188 +0x165a
[go The file path ]m.(*m).handlerWithInterceptor.func1(0xabfd80, 0xc0031a0620, 0xc002988900)
	/go/src/[go The file path ]m/http_server.go:160 +0x82
net/http.HandlerFunc.ServeHTTP(0xc000990300, 0xabfd80, 0xc0031a0620, 0xc002988900)
	/usr/local/go/src/net/http/server.go:1995 +0x44
net/http.(*ServeMux).ServeHTTP(0x10a3520, 0xabfd80, 0xc0031a0620, 0xc002988900)
	/usr/local/go/src/net/http/server.go:2375 +0x1d6
net/http.serverHandler.ServeHTTP(0xc0000dad00, 0xabfd80, 0xc0031a0620, 0xc002988900)
	/usr/local/go/src/net/http/server.go:2774 +0xa8
net/http.(*conn).serve(0xc003b18640, 0xac1d80, 0xc00298e940)
	/usr/local/go/src/net/http/server.go:1878 +0x851
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2884 +0x2f4



goroutine 14532 [semacquire, 11 minutes]:
sync.runtime_SemacquireMutex(0xc0026fc460, 0x419400)
	/usr/local/go/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0xc0026fc45c)
	/usr/local/go/src/sync/mutex.go:134 +0x109
[go The file path ]m.(*c).cDP(0xc00223c000, 0xc003f74303, 0xe, 0xc003f742ef, 0x6, 0x0, 0x0, 0x0)
	/go/src/[go The file path ]m/c.go:554 +0x13d
[go The file path ]m.(*m).cDP(0xc0009aca90, 0xabfd80, 0xc00454a620, 0xc004544800)
	/go/src/[go The file path ]m/handle_admin.go:353 +0x376
[go The file path ]m.(*m).ServeHTTP(0xc0009aca90, 0xabfd80, 0xc00454a620, 0xc004544800)
	/go/src/[go The file path ]m/http_server.go:188 +0x165a
[go The file path ]m.(*m).handlerWithInterceptor.func1(0xabfd80, 0xc00454a620, 0xc004544800)
	/go/src/[go The file path ]m/http_server.go:160 +0x82
net/http.HandlerFunc.ServeHTTP(0xc000990300, 0xabfd80, 0xc00454a620, 0xc004544800)
	/usr/local/go/src/net/http/server.go:1995 +0x44
net/http.(*ServeMux).ServeHTTP(0x10a3520, 0xabfd80, 0xc00454a620, 0xc004544800)
	/usr/local/go/src/net/http/server.go:2375 +0x1d6
net/http.serverHandler.ServeHTTP(0xc0000dad00, 0xabfd80, 0xc00454a620, 0xc004544800)
	/usr/local/go/src/net/http/server.go:2774 +0xa8
net/http.(*conn).serve(0xc002e17540, 0xac1d80, 0xc002a74780)
	/usr/local/go/src/net/http/server.go:1878 +0x851
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2884 +0x2f4

conclusion


Related articles: