search

micro / go-micro

A Go microservices framework
https://go-micro.dev
Apache License 2.0
21.95k stars 2.35k forks source link

Go-micro goroutine usage increases since v0.2.0 #227

Closed ynori7 closed 6 years ago

ynori7 commented 6 years ago

When updating to the lastest version of go-micro in my services I see the number of goroutines used skyrocket. On our staging servers, it's jumping from ~30 to ~380. I tried gradually going back to older versions until it went back to a reasonable number and it seems that with v0.1.4 the number of goroutines used is normal again.

I tried debugging it using the profiler and it looks like a lot of the goroutines are related to Consul. When I run it locally I get much smaller numbers, but I can still see about a 50% increase between v0.1.4 and any of the later versions.

Viewing the changes between 0.1.4 and 0.2.0 we see: https://github.com/micro/go-micro/compare/v0.1.4...v0.2.0

It was suggested that maybe this could be connected (perhaps when it's started more than once):


+    c.once.Do(func() {
+        go c.run()
+    })
+```

I had a service which was using a version of go-micro from October 26 (somewhere in the middle between 0.1.4 and 0.2.0) and that one does not seem to have this issue. There aren't very many commits in 0.2.0 after that point.
asim commented 6 years ago

Can you provide the profiling information? Also do you have an example of the flow that causes this? Is it request related? Is the service just sitting there doing nothing?

ynori7 commented 6 years ago

The services aren't doing anything special. I can see the spike immediately after deployment, and I observe the same behavior from both RPC services and APIs.

Here's some data:

/debug/pprof/

profiles:
0   block
374 goroutine
108 heap
0   mutex
12  threadcreate

Goroutines:

goroutine profile: total 371
116 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x689670 0x51f88a 0x51f9da 0x68a145 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51          /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c           /usr/local/go/src/net/net.go:176
#   0x68966f    net/http.(*persistConn).Read+0x13f  /usr/local/go/src/net/http/transport.go:1391
#   0x51f889    bufio.(*Reader).fill+0x119      /usr/local/go/src/bufio/bufio.go:97
#   0x51f9d9    bufio.(*Reader).Peek+0x39       /usr/local/go/src/bufio/bufio.go:129
#   0x68a144    net/http.(*persistConn).readLoop+0x184  /usr/local/go/src/net/http/transport.go:1539

116 @ 0x42da2c 0x43de79 0x68b8f5 0x45cec1
#   0x68b8f4    net/http.(*persistConn).writeLoop+0x164 /usr/local/go/src/net/http/transport.go:1759

114 @ 0x42da2c 0x43de79 0x68c408 0x682802 0x632069 0x631cfd 0x63339d 0x72b2de 0x72f3cf 0x745abf 0x743d46 0x45cec1
#   0x68c407    net/http.(*persistConn).roundTrip+0x607                                             /usr/local/go/src/net/http/transport.go:1970
#   0x682801    net/http.(*Transport).RoundTrip+0x991                                               /usr/local/go/src/net/http/transport.go:413
#   0x632068    net/http.send+0x1a8                                                     /usr/local/go/src/net/http/client.go:249
#   0x631cfc    net/http.(*Client).send+0xfc                                                    /usr/local/go/src/net/http/client.go:173
#   0x63339c    net/http.(*Client).Do+0x28c                                                 /usr/local/go/src/net/http/client.go:602
#   0x72b2dd    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api.(*Client).doRequest+0xbd       /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api/api.go:658
#   0x72f3ce    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api.(*Health).Service+0x15e        /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api/health.go:155
#   0x745abe    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch.serviceWatch.func1+0x16e /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch/funcs.go:154
#   0x743d45    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch.(*Plan).Run+0x285        /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch/plan.go:48

1 @ 0x410042 0x443a46 0x766292 0x45cec1
#   0x443a45    os/signal.signal_recv+0xa5  /usr/local/go/src/runtime/sigqueue.go:131
#   0x766291    os/signal.loop+0x21     /usr/local/go/src/os/signal/signal_unix.go:22

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x51f88a 0x52073c 0x5209a4 0x5fa190 0x5f9f9b 0x66da6a 0x75cfe1 0x7829d6 0x77f9a1 0x780d1c 0x781745 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189                                                      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51                                                          /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c                                                           /usr/local/go/src/net/net.go:176
#   0x51f889    bufio.(*Reader).fill+0x119                                                      /usr/local/go/src/bufio/bufio.go:97
#   0x52073b    bufio.(*Reader).ReadSlice+0x2b                                                      /usr/local/go/src/bufio/bufio.go:338
#   0x5209a3    bufio.(*Reader).ReadLine+0x33                                                       /usr/local/go/src/bufio/bufio.go:367
#   0x5fa18f    net/textproto.(*Reader).readLineSlice+0x6f                                              /usr/local/go/src/net/textproto/reader.go:55
#   0x5f9f9a    net/textproto.(*Reader).ReadLine+0x2a                                                   /usr/local/go/src/net/textproto/reader.go:36
#   0x66da69    net/http.ReadResponse+0xc9                                                      /usr/local/go/src/net/http/response.go:149
#   0x75cfe0    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport.(*httpTransportClient).Recv+0xf0   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport/http_transport.go:129
#   0x7829d5    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*poolConn).Recv+0x45         <autogenerated>:1
#   0x77f9a0    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcPlusCodec).ReadResponseHeader+0x50   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_codec.go:130
#   0x780d1b    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcStream).Recv+0x11b           /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_stream.go:73
#   0x781744    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).call.func2+0xa4      /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:112

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x5c8c75 0x5c91e0 0x5ccd30 0x52005b 0x4742e6 0x474458 0x8749fb 0x875364 0x886730 0x885fd8 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                         /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                         /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                         /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189                                              /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51                                                  /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c                                                   /usr/local/go/src/net/net.go:176
#   0x5c8c74    crypto/tls.(*block).readFromUntil+0x94                                          /usr/local/go/src/crypto/tls/conn.go:488
#   0x5c91df    crypto/tls.(*Conn).readRecord+0xdf                                          /usr/local/go/src/crypto/tls/conn.go:590
#   0x5ccd2f    crypto/tls.(*Conn).Read+0x10f                                               /usr/local/go/src/crypto/tls/conn.go:1134
#   0x52005a    bufio.(*Reader).Read+0x30a                                              /usr/local/go/src/bufio/bufio.go:213
#   0x4742e5    io.ReadAtLeast+0x85                                                 /usr/local/go/src/io/io.go:309
#   0x474457    io.ReadFull+0x57                                                    /usr/local/go/src/io/io.go:327
#   0x8749fa    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.readFrameHeader+0x7a        /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/frame.go:237
#   0x875363    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*Framer).ReadFrame+0xa3        /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/frame.go:492
#   0x88672f    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*clientConnReadLoop).run+0x8f  /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/transport.go:1477
#   0x885fd7    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*ClientConn).readLoop+0x67 /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/transport.go:1405

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a279 0x67b62f 0x67a2d2 0x67a019 0x67b1af 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41            /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a278    net.(*TCPListener).AcceptTCP+0x48       /usr/local/go/src/net/tcpsock.go:234
#   0x67b62e    net/http.tcpKeepAliveListener.Accept+0x2e   /usr/local/go/src/net/http/server.go:3120
#   0x67a2d1    net/http.(*Server).Serve+0x1b1          /usr/local/go/src/net/http/server.go:2695
#   0x67a018    net/http.(*Server).ListenAndServe+0xa8      /usr/local/go/src/net/http/server.go:2636
#   0x67b1ae    net/http.ListenAndServe+0x7e            /usr/local/go/src/net/http/server.go:2882

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a279 0x67b62f 0x67a2d2 0x67a019 0x67b1af 0x85cc35 0x85d37c 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                     /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1                                                        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41                                                            /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d                                                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a278    net.(*TCPListener).AcceptTCP+0x48                                                       /usr/local/go/src/net/tcpsock.go:234
#   0x67b62e    net/http.tcpKeepAliveListener.Accept+0x2e                                                   /usr/local/go/src/net/http/server.go:3120
#   0x67a2d1    net/http.(*Server).Serve+0x1b1                                                          /usr/local/go/src/net/http/server.go:2695
#   0x67a018    net/http.(*Server).ListenAndServe+0xa8                                                      /usr/local/go/src/net/http/server.go:2636
#   0x67b1ae    net/http.ListenAndServe+0x7e                                                            /usr/local/go/src/net/http/server.go:2882
#   0x85cc34    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.(*Manager).serve+0x174   /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.health-go/healthmanager.go:283
#   0x85d37b    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.addAfter.func1.1+0x5b    /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.health-go/micro.go:41

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a4b9 0x67a2d2 0x6791b3 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41        /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a4b8    net.(*TCPListener).Accept+0x48      /usr/local/go/src/net/tcpsock.go:247
#   0x67a2d1    net/http.(*Server).Serve+0x1b1      /usr/local/go/src/net/http/server.go:2695
#   0x6791b2    net/http.Serve+0x72         /usr/local/go/src/net/http/server.go:2323

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a4b9 0x75e103 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1                                                    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41                                                        /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d                                                      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a4b8    net.(*TCPListener).Accept+0x48                                                      /usr/local/go/src/net/tcpsock.go:247
#   0x75e102    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport.(*httpTransportListener).Accept+0x52   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport/http_transport.go:293

1 @ 0x42da2c 0x42db1e 0x404ac4 0x40476b 0x774016 0x45cec1
#   0x774015    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/server.(*rpcServer).Start.func1+0x45 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/server/rpc_server.go:397

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x86336f 0x45cec1
#   0x86336e    bitbucket.org/company/usersession/vendor/github.com/golang/glog.(*loggingT).flushDaemon+0x9e    /go/src/bitbucket.org/company/usersession/vendor/github.com/golang/glog/glog.go:882

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8edee0 0x45cec1
#   0x8ededf    bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor.(*meterS).init.func1+0x7f /go/src/bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor/meter.go:69

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8ee863 0x45cec1
#   0x8ee862    bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor.(*Recorder).init.func1+0x62   /go/src/bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor/recorder.go:48

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x901b43 0x45cec1
#   0x901b42    database/sql.(*DB).connectionOpener+0x52    /usr/local/go/src/database/sql/sql.go:871

1 @ 0x42da2c 0x43de79 0x459b80 0x45cec1
#   0x42da2b    runtime.gopark+0x12b        /usr/local/go/src/runtime/proc.go:287
#   0x43de78    runtime.selectgo+0x1148     /usr/local/go/src/runtime/select.go:395
#   0x459b7f    runtime.ensureSigM.func1+0x21f  /usr/local/go/src/runtime/signal_unix.go:511

1 @ 0x42da2c 0x43de79 0x68c408 0x682802 0x632069 0x631cfd 0x63339d 0x72b2de 0x72cb27 0x745650 0x743d46 0x45cec1
#   0x68c407    net/http.(*persistConn).roundTrip+0x607                                             /usr/local/go/src/net/http/transport.go:1970
#   0x682801    net/http.(*Transport).RoundTrip+0x991                                               /usr/local/go/src/net/http/transport.go:413
#   0x632068    net/http.send+0x1a8                                                     /usr/local/go/src/net/http/client.go:249
#   0x631cfc    net/http.(*Client).send+0xfc                                                    /usr/local/go/src/net/http/client.go:173
#   0x63339c    net/http.(*Client).Do+0x28c                                                 /usr/local/go/src/net/http/client.go:602
#   0x72b2dd    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api.(*Client).doRequest+0xbd       /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api/api.go:658
#   0x72cb26    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api.(*Catalog).Services+0xc6       /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/api/catalog.go:138
#   0x74564f    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch.servicesWatch.func1+0xff /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch/funcs.go:97
#   0x743d45    bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch.(*Plan).Run+0x285        /go/src/bitbucket.org/company/usersession/vendor/github.com/hashicorp/consul/watch/plan.go:48

1 @ 0x42da2c 0x43de79 0x74cb90 0x841c3b 0x841a97 0x45cec1
#   0x74cb8f    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/registry.(*consulWatcher).Next+0xef      /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/registry/consul_watcher.go:231
#   0x841c3a    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).watch+0xba   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache/cache.go:304
#   0x841a96    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).run+0x136    /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache/cache.go:276

1 @ 0x42da2c 0x43de79 0x758898 0x45cec1
#   0x758897    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/broker.(*httpBroker).run+0x287   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/broker/http_broker.go:198

1 @ 0x42da2c 0x43de79 0x77b190 0x782fe1 0x781ab1 0x781e83 0x45cec1
#   0x77b18f    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).call+0x8cf                                                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:121
#   0x782fe0    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).(bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.call)-fm+0xd0 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:254
#   0x781ab0    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call.func1+0x230                                                 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:289
#   0x781e82    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call.func2+0x32                                                  /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:299

1 @ 0x42da2c 0x43de79 0x77cd6f 0x8f0c52 0x8a3555 0x84822b 0x85139b 0x850bdd 0x45cec1
#   0x77cd6e    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call+0x5be                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:302
#   0x8f0c51    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2etracing-go.(*tracingWrapper).Call+0x551        /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.tracing-go/micro.go:81
#   0x8a3554    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*clientWrapper).Call+0x464     /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/micro.go:166
#   0x84822a    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*clientWrapper).Call+0xca                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/wrapper.go:36
#   0x85139a    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).fetchConfig+0x28a /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.configuration-go/config.go:192
#   0x850bdc    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).poll+0x5c     /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.configuration-go/config.go:144

1 @ 0x42da2c 0x43de79 0x842855 0x45cec1
#   0x842854    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).watch.func1+0xe4 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/selector/cache/cache.go:294

1 @ 0x42da2c 0x43de79 0x84765f 0x45cec1
#   0x84765e    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*service).run+0x11e /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/service.go:45

1 @ 0x42da2c 0x43de79 0x847d97 0x959499 0x42d576 0x45cec1
#   0x847d96    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*service).Run+0x206 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/service.go:154
#   0x959498    main.main+0x758                                                 /go/src/bitbucket.org/company/usersession/main.go:90
#   0x42d575    runtime.main+0x225                                              /usr/local/go/src/runtime/proc.go:195

1 @ 0x42da2c 0x43de79 0x8a3e74 0x8a75ba 0x89a7eb 0x45cec1
#   0x8a3e73    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRuntime+0x163                                                             /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/runtime.go:33
#   0x8a75b9    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRuntime)-fm+0x29 /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/metrics.go:79
#   0x89a7ea    bitbucket.org/company/usersession/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /go/src/bitbucket.org/company/usersession/vendor/gopkg.in/tomb.v2/tomb.go:153

1 @ 0x42da2c 0x43de79 0x8a4aad 0x8a760a 0x89a7eb 0x45cec1
#   0x8a4aac    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRusage+0x2dc                                                              /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/runtime.go:87
#   0x8a7609    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRusage)-fm+0x29  /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/metrics.go:80
#   0x89a7ea    bitbucket.org/company/usersession/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /go/src/bitbucket.org/company/usersession/vendor/gopkg.in/tomb.v2/tomb.go:153

1 @ 0x480df5 0x47e9c5 0x47cd99 0x4976a5 0x56e492 0x58126d 0x670982 0x45cec1
#   0x480df4    syscall.Syscall+0x4             /usr/local/go/src/syscall/asm_linux_amd64.s:18
#   0x47e9c4    syscall.read+0x54               /usr/local/go/src/syscall/zsyscall_linux_amd64.go:756
#   0x47cd98    syscall.Read+0x48               /usr/local/go/src/syscall/syscall_unix.go:162
#   0x4976a4    internal/poll.(*FD).Read+0x124          /usr/local/go/src/internal/poll/fd_unix.go:122
#   0x56e491    net.(*netFD).Read+0x51              /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c               /usr/local/go/src/net/net.go:176
#   0x670981    net/http.(*connReader).backgroundRead+0x61  /usr/local/go/src/net/http/server.go:660

1 @ 0x94fd12 0x94fb10 0x94c66b 0x9587b8 0x958abb 0x6772c4 0x678970 0x679f44 0x67619d 0x45cec1
#   0x94fd11    runtime/pprof.writeRuntimeProfile+0xa1  /usr/local/go/src/runtime/pprof/pprof.go:637
#   0x94fb0f    runtime/pprof.writeGoroutine+0x9f   /usr/local/go/src/runtime/pprof/pprof.go:599
#   0x94c66a    runtime/pprof.(*Profile).WriteTo+0x3aa  /usr/local/go/src/runtime/pprof/pprof.go:310
#   0x9587b7    net/http/pprof.handler.ServeHTTP+0x1b7  /usr/local/go/src/net/http/pprof/pprof.go:237
#   0x958aba    net/http/pprof.Index+0x1da      /usr/local/go/src/net/http/pprof/pprof.go:248
#   0x6772c3    net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/go/src/net/http/server.go:1918
#   0x67896f    net/http.(*ServeMux).ServeHTTP+0x12f    /usr/local/go/src/net/http/server.go:2254
#   0x679f43    net/http.serverHandler.ServeHTTP+0xb3   /usr/local/go/src/net/http/server.go:2619
#   0x67619c    net/http.(*conn).serve+0x71c        /usr/local/go/src/net/http/server.go:1801
asim commented 6 years ago

I'll have to debug later but this line might be where it's happening https://github.com/micro/go-micro/blob/master/registry/consul_watcher.go#L38

A new watcher starts a go routine. Could be that Stop doesn't actually kill the go routine. We're using the caching selector by default which makes use of the watcher. If the caching selector is spinning up a new watcher because of some error then it might be likely this is where you're seeing the issue. I don't think others are seeing it so it could be a transient thing related to the deployment.

ynori7 commented 6 years ago

Well I do also observe an increase even when I just run the service locally, it's just less noticeable. Locally with v0.1.4 I have about 22 active goroutines, and when I upgrade to v0.2.0 or higher it goes up to 33 active goroutines.

Also, in case it's helpful, here's some profiling output from the service (in the same environment as the other profiling info I posted) with v0.1.4.

/debug/pprof/

profiles:
0   block
27  goroutine
9   heap
0   mutex
9   threadcreate

Goroutines:

goroutine profile: total 27
2 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x689670 0x51f88a 0x51f9da 0x68a145 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51          /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c           /usr/local/go/src/net/net.go:176
#   0x68966f    net/http.(*persistConn).Read+0x13f  /usr/local/go/src/net/http/transport.go:1391
#   0x51f889    bufio.(*Reader).fill+0x119      /usr/local/go/src/bufio/bufio.go:97
#   0x51f9d9    bufio.(*Reader).Peek+0x39       /usr/local/go/src/bufio/bufio.go:129
#   0x68a144    net/http.(*persistConn).readLoop+0x184  /usr/local/go/src/net/http/transport.go:1539

2 @ 0x42da2c 0x43de79 0x68b8f5 0x45cec1
#   0x68b8f4    net/http.(*persistConn).writeLoop+0x164 /usr/local/go/src/net/http/transport.go:1759

1 @ 0x410042 0x443a46 0x7632a2 0x45cec1
#   0x443a45    os/signal.signal_recv+0xa5  /usr/local/go/src/runtime/sigqueue.go:131
#   0x7632a1    os/signal.loop+0x21     /usr/local/go/src/os/signal/signal_unix.go:22

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x51f88a 0x52073c 0x5209a4 0x5fa190 0x5f9f9b 0x66da6a 0x759ff1 0x77fa86 0x77ca51 0x77ddcc 0x77e7f5 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189                                                      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51                                                          /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c                                                           /usr/local/go/src/net/net.go:176
#   0x51f889    bufio.(*Reader).fill+0x119                                                      /usr/local/go/src/bufio/bufio.go:97
#   0x52073b    bufio.(*Reader).ReadSlice+0x2b                                                      /usr/local/go/src/bufio/bufio.go:338
#   0x5209a3    bufio.(*Reader).ReadLine+0x33                                                       /usr/local/go/src/bufio/bufio.go:367
#   0x5fa18f    net/textproto.(*Reader).readLineSlice+0x6f                                              /usr/local/go/src/net/textproto/reader.go:55
#   0x5f9f9a    net/textproto.(*Reader).ReadLine+0x2a                                                   /usr/local/go/src/net/textproto/reader.go:36
#   0x66da69    net/http.ReadResponse+0xc9                                                      /usr/local/go/src/net/http/response.go:149
#   0x759ff0    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport.(*httpTransportClient).Recv+0xf0   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport/http_transport.go:129
#   0x77fa85    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*poolConn).Recv+0x45         <autogenerated>:1
#   0x77ca50    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcPlusCodec).ReadResponseHeader+0x50   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_codec.go:130
#   0x77ddcb    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcStream).Recv+0x11b           /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_stream.go:73
#   0x77e7f4    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).call.func2+0xa4      /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:112

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x5c8c75 0x5c91e0 0x5ccd30 0x52005b 0x4742e6 0x474458 0x871c4b 0x8725b4 0x883980 0x883228 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                         /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                         /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                         /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189                                              /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51                                                  /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c                                                   /usr/local/go/src/net/net.go:176
#   0x5c8c74    crypto/tls.(*block).readFromUntil+0x94                                          /usr/local/go/src/crypto/tls/conn.go:488
#   0x5c91df    crypto/tls.(*Conn).readRecord+0xdf                                          /usr/local/go/src/crypto/tls/conn.go:590
#   0x5ccd2f    crypto/tls.(*Conn).Read+0x10f                                               /usr/local/go/src/crypto/tls/conn.go:1134
#   0x52005a    bufio.(*Reader).Read+0x30a                                              /usr/local/go/src/bufio/bufio.go:213
#   0x4742e5    io.ReadAtLeast+0x85                                                 /usr/local/go/src/io/io.go:309
#   0x474457    io.ReadFull+0x57                                                    /usr/local/go/src/io/io.go:327
#   0x871c4a    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.readFrameHeader+0x7a        /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/frame.go:237
#   0x8725b3    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*Framer).ReadFrame+0xa3        /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/frame.go:492
#   0x88397f    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*clientConnReadLoop).run+0x8f  /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/transport.go:1477
#   0x883227    bitbucket.org/company/usersession/vendor/golang.org/x/net/http2.(*ClientConn).readLoop+0x67 /go/src/bitbucket.org/company/usersession/vendor/golang.org/x/net/http2/transport.go:1405

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x49770a 0x56e492 0x58126d 0x670982 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x497709    internal/poll.(*FD).Read+0x189          /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56e491    net.(*netFD).Read+0x51              /usr/local/go/src/net/fd_unix.go:202
#   0x58126c    net.(*conn).Read+0x6c               /usr/local/go/src/net/net.go:176
#   0x670981    net/http.(*connReader).backgroundRead+0x61  /usr/local/go/src/net/http/server.go:660

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a279 0x67b62f 0x67a2d2 0x67a019 0x67b1af 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41            /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a278    net.(*TCPListener).AcceptTCP+0x48       /usr/local/go/src/net/tcpsock.go:234
#   0x67b62e    net/http.tcpKeepAliveListener.Accept+0x2e   /usr/local/go/src/net/http/server.go:3120
#   0x67a2d1    net/http.(*Server).Serve+0x1b1          /usr/local/go/src/net/http/server.go:2695
#   0x67a018    net/http.(*Server).ListenAndServe+0xa8      /usr/local/go/src/net/http/server.go:2636
#   0x67b1ae    net/http.ListenAndServe+0x7e            /usr/local/go/src/net/http/server.go:2882

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a279 0x67b62f 0x67a2d2 0x67a019 0x67b1af 0x859e85 0x85a5cc 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                     /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1                                                        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41                                                            /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d                                                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a278    net.(*TCPListener).AcceptTCP+0x48                                                       /usr/local/go/src/net/tcpsock.go:234
#   0x67b62e    net/http.tcpKeepAliveListener.Accept+0x2e                                                   /usr/local/go/src/net/http/server.go:3120
#   0x67a2d1    net/http.(*Server).Serve+0x1b1                                                          /usr/local/go/src/net/http/server.go:2695
#   0x67a018    net/http.(*Server).ListenAndServe+0xa8                                                      /usr/local/go/src/net/http/server.go:2636
#   0x67b1ae    net/http.ListenAndServe+0x7e                                                            /usr/local/go/src/net/http/server.go:2882
#   0x859e84    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.(*Manager).serve+0x174   /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.health-go/healthmanager.go:283
#   0x85a5cb    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.addAfter.func1.1+0x5b    /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.health-go/micro.go:41

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a4b9 0x67a2d2 0x6791b3 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41        /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a4b8    net.(*TCPListener).Accept+0x48      /usr/local/go/src/net/tcpsock.go:247
#   0x67a2d1    net/http.(*Server).Serve+0x1b1      /usr/local/go/src/net/http/server.go:2695
#   0x6791b2    net/http.Serve+0x72         /usr/local/go/src/net/http/server.go:2323

1 @ 0x42da2c 0x428b3a 0x428137 0x4968ee 0x49696d 0x498dc2 0x56eeb2 0x58be9e 0x58a4b9 0x75b113 0x45cec1
#   0x428136    internal/poll.runtime_pollWait+0x56                                                 /usr/local/go/src/runtime/netpoll.go:173
#   0x4968ed    internal/poll.(*pollDesc).wait+0xad                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x49696c    internal/poll.(*pollDesc).waitRead+0x3c                                                 /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498dc1    internal/poll.(*FD).Accept+0x1e1                                                    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56eeb1    net.(*netFD).accept+0x41                                                        /usr/local/go/src/net/fd_unix.go:238
#   0x58be9d    net.(*TCPListener).accept+0x2d                                                      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58a4b8    net.(*TCPListener).Accept+0x48                                                      /usr/local/go/src/net/tcpsock.go:247
#   0x75b112    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport.(*httpTransportListener).Accept+0x52   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/transport/http_transport.go:293

1 @ 0x42da2c 0x42db1e 0x404ac4 0x40476b 0x771026 0x45cec1
#   0x771025    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/server.(*rpcServer).Start.func1+0x45 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/server/rpc_server.go:397

1 @ 0x42da2c 0x42db1e 0x404ac4 0x40476b 0x8e9fcb 0x45cec1
#   0x8e9fca    bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor.(*fsmS).scheduleRetry.func1+0x3a  /go/src/bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor/fsm.go:55

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8605bf 0x45cec1
#   0x8605be    bitbucket.org/company/usersession/vendor/github.com/golang/glog.(*loggingT).flushDaemon+0x9e    /go/src/bitbucket.org/company/usersession/vendor/github.com/golang/glog/glog.go:882

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8eb130 0x45cec1
#   0x8eb12f    bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor.(*meterS).init.func1+0x7f /go/src/bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor/meter.go:69

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8ebab3 0x45cec1
#   0x8ebab2    bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor.(*Recorder).init.func1+0x62   /go/src/bitbucket.org/company/usersession/vendor/github.com/instana/golang-sensor/recorder.go:48

1 @ 0x42da2c 0x42db1e 0x404ac4 0x4047ab 0x8ff5f3 0x45cec1
#   0x8ff5f2    database/sql.(*DB).connectionOpener+0x52    /usr/local/go/src/database/sql/sql.go:871

1 @ 0x42da2c 0x43de79 0x459b80 0x45cec1
#   0x42da2b    runtime.gopark+0x12b        /usr/local/go/src/runtime/proc.go:287
#   0x43de78    runtime.selectgo+0x1148     /usr/local/go/src/runtime/select.go:395
#   0x459b7f    runtime.ensureSigM.func1+0x21f  /usr/local/go/src/runtime/signal_unix.go:511

1 @ 0x42da2c 0x43de79 0x7558f6 0x45cec1
#   0x7558f5    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/broker.(*httpBroker).run+0x425   /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/broker/http_broker.go:167

1 @ 0x42da2c 0x43de79 0x778240 0x780091 0x77eb61 0x77ef33 0x45cec1
#   0x77823f    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).call+0x8cf                                                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:121
#   0x780090    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).(bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.call)-fm+0xd0 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:254
#   0x77eb60    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call.func1+0x230                                                 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:289
#   0x77ef32    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call.func2+0x32                                                  /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:299

1 @ 0x42da2c 0x43de79 0x779e1f 0x8edea2 0x8a07a5 0x84568b 0x84e5eb 0x84de2d 0x45cec1
#   0x779e1e    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client.(*rpcClient).Call+0x5be                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/client/rpc_client.go:302
#   0x8edea1    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2etracing-go.(*tracingWrapper).Call+0x551        /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.tracing-go/micro.go:81
#   0x8a07a4    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*clientWrapper).Call+0x464     /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/micro.go:166
#   0x84568a    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*clientWrapper).Call+0xca                       /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/wrapper.go:36
#   0x84e5ea    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).fetchConfig+0x28a /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.configuration-go/config.go:192
#   0x84de2c    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).poll+0x5c     /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.configuration-go/config.go:144

1 @ 0x42da2c 0x43de79 0x84486f 0x45cec1
#   0x84486e    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*service).run+0x11e /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/service.go:45

1 @ 0x42da2c 0x43de79 0x8451f7 0x956f49 0x42d576 0x45cec1
#   0x8451f6    bitbucket.org/company/usersession/vendor/github.com/micro/go-micro.(*service).Run+0x206 /go/src/bitbucket.org/company/usersession/vendor/github.com/micro/go-micro/service.go:165
#   0x956f48    main.main+0x758                                                 /go/src/bitbucket.org/company/usersession/main.go:90
#   0x42d575    runtime.main+0x225                                              /usr/local/go/src/runtime/proc.go:195

1 @ 0x42da2c 0x43de79 0x8a10c4 0x8a480a 0x897a3b 0x45cec1
#   0x8a10c3    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRuntime+0x163                                                             /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/runtime.go:33
#   0x8a4809    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRuntime)-fm+0x29 /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/metrics.go:79
#   0x897a3a    bitbucket.org/company/usersession/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /go/src/bitbucket.org/company/usersession/vendor/gopkg.in/tomb.v2/tomb.go:153

1 @ 0x42da2c 0x43de79 0x8a1cfd 0x8a485a 0x897a3b 0x45cec1
#   0x8a1cfc    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRusage+0x2dc                                                              /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/runtime.go:87
#   0x8a4859    bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/usersession/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRusage)-fm+0x29  /go/src/bitbucket.org/company/usersession/vendor/bitbucket.org/company/com.company.lib.metrics-go/metrics.go:80
#   0x897a3a    bitbucket.org/company/usersession/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /go/src/bitbucket.org/company/usersession/vendor/gopkg.in/tomb.v2/tomb.go:153

1 @ 0x94d7c2 0x94d5c0 0x94a11b 0x956268 0x95656b 0x6772c4 0x678970 0x679f44 0x67619d 0x45cec1
#   0x94d7c1    runtime/pprof.writeRuntimeProfile+0xa1  /usr/local/go/src/runtime/pprof/pprof.go:637
#   0x94d5bf    runtime/pprof.writeGoroutine+0x9f   /usr/local/go/src/runtime/pprof/pprof.go:599
#   0x94a11a    runtime/pprof.(*Profile).WriteTo+0x3aa  /usr/local/go/src/runtime/pprof/pprof.go:310
#   0x956267    net/http/pprof.handler.ServeHTTP+0x1b7  /usr/local/go/src/net/http/pprof/pprof.go:237
#   0x95656a    net/http/pprof.Index+0x1da      /usr/local/go/src/net/http/pprof/pprof.go:248
#   0x6772c3    net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/go/src/net/http/server.go:1918
#   0x67896f    net/http.(*ServeMux).ServeHTTP+0x12f    /usr/local/go/src/net/http/server.go:2254
#   0x679f43    net/http.serverHandler.ServeHTTP+0xb3   /usr/local/go/src/net/http/server.go:2619
#   0x67619c    net/http.(*conn).serve+0x71c        /usr/local/go/src/net/http/server.go:1801
asim commented 6 years ago

Can you provide some actual information on what the service does because it would help with debugging.

When I run a greeter service I do not see any increase in go routines so I'm just trying to get more debugging info.

ynori7 commented 6 years ago

I have three different services where I observed the behavior, all completely different. One is a backend service which only receives RPC calls. One is an API which also sends RPC calls. One is an API which only sends other HTTP requests. All three show exactly the same behavior with no traffic.

No flags or environment variables are being set. The main.go is creating the micro service, initializing any clients and handlers necessary, pulling the configuration from our configuration service (it doesn't do this when I run it locally), and then running the service.

Here's an example from one of the APIs:

package main

import (
    "fmt"
    "time"
    "net/http"

    "bitbucket.org/company/api.v1.pricing/permissions"
    "bitbucket.org/company/lib.auth-go"
    authmicro "bitbucket.org/company/lib.auth-go/micro"
    configlib "bitbucket.org/company/lib.configuration-go"
    "bitbucket.org/company/lib.log-go"
    telemetry "bitbucket.org/company/lib.telemetry-go"

    "bitbucket.org/company/api.v1.pricing/config"
    "bitbucket.org/company/api.v1.pricing/handler"
    "bitbucket.org/company/api.v1.pricing/version"
    pricingProto "bitbucket.org/company/service.pricing-quote-api/proto/src/go"

    "bitbucket.org/company/lib.health-go"
    "github.com/micro/cli"
    "github.com/micro/go-micro"
    "github.com/micro/go-micro/server"
    microhttp "github.com/micro/go-plugins/server/http"
    _ "net/http/pprof"
)

func main() {
    tm := telemetry.New() //this is just for logging and metrics
    var (
        conf *config.Config = new(config.Config)
    )

    srv := microhttp.NewServer(
        server.Name(config.ServiceName),
    )

    // Create a new service. Optionally include some options here.
    service := micro.NewService(
        micro.Server(srv),
        tm.NewClientWrapper(),

        micro.Name(config.ServiceName),
        micro.Version(version.Version),
        micro.Metadata(map[string]string{
            "type":        "api",
            "description": "Backoffice API for Pricing",
        }),
        micro.RegisterTTL(time.Second*11),
        micro.RegisterInterval(time.Second*5),

        health.NewHealth(),
        micro.Flags(config.Flags(conf)...),
        micro.BeforeStart(authmicro.MicroWaitForPublicKeys(time.Second*30)), //this is for the authorization which is disabled when I'm running it locally
        auth.PermissionMapper(permissions.Permissions),
    )

    // Configure the telemetry lib for our service
    tm.ConfigureForService(service)

    // Init will parse the command line flags. Any flags set will
    // override the above settings. Options defined here will
    // override anything set on the command line.
    service.Init(
        micro.Action(func(c *cli.Context) {
            if err := configlib.ConfigureWithUpdates(service, c, conf, func(cfg *config.Config) {
                cfg.Log.UpdateCallback()
            }, true, false); err != nil {
                log.WithFields(log.Fields{"error": err}).Error("Failed to get service configuration")
            }
        }),
    )

    // Create clients
    pricingClient := pricingProto.NewPricingFeesClient("com.company.service.pricing-quote", service.Client())

    // Register handler
    h := handler.NewPricingHandler(pricingClient)
    router := handler.NewRouter(h)
    microHandler := srv.NewHandler(tm.HTTPHandlerWrapper(router, "Pricing"))
    srv.Handle(microHandler)

    log.Debug("Starting instance")

    if conf.ProfilingURI != "" {
        log.Infof("Starting profiling endpoint: %s/debug/pprof/", conf.ProfilingURI)
        go http.ListenAndServe(conf.ProfilingURI, nil)
    }

    // Run the server
    if err := service.Run(); err != nil {
        fmt.Println(err)
    }
}

When I run this locally with absolutely no requests or external communication happening, immediately after startup I see this:

Version 0.2.0:

/debug/pprof/

profiles:
0   block
32  goroutine
6   heap
0   mutex
12  threadcreate

full goroutine stack dump

goroutine profile: total 32
5 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x498a0a 0x56ed42 0x581e7d 0x68e2f0 0x52007a 0x5201ca 0x68edc5 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498a09    internal/poll.(*FD).Read+0x189      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56ed41    net.(*netFD).Read+0x51          /usr/local/go/src/net/fd_unix.go:202
#   0x581e7c    net.(*conn).Read+0x6c           /usr/local/go/src/net/net.go:176
#   0x68e2ef    net/http.(*persistConn).Read+0x13f  /usr/local/go/src/net/http/transport.go:1391
#   0x520079    bufio.(*Reader).fill+0x119      /usr/local/go/src/bufio/bufio.go:97
#   0x5201c9    bufio.(*Reader).Peek+0x39       /usr/local/go/src/bufio/bufio.go:129
#   0x68edc4    net/http.(*persistConn).readLoop+0x184  /usr/local/go/src/net/http/transport.go:1539

5 @ 0x42f0bc 0x43f4f9 0x690575 0x45e511
#   0x690574    net/http.(*persistConn).writeLoop+0x164 /usr/local/go/src/net/http/transport.go:1759

2 @ 0x42f0bc 0x43f4f9 0x691088 0x687482 0x636de9 0x636a7d 0x63811d 0x72e358 0x73297f 0x7490cf 0x747356 0x45e511
#   0x691087    net/http.(*persistConn).roundTrip+0x607                                             /usr/local/go/src/net/http/transport.go:1970
#   0x687481    net/http.(*Transport).RoundTrip+0x991                                               /usr/local/go/src/net/http/transport.go:413
#   0x636de8    net/http.send+0x1a8                                                     /usr/local/go/src/net/http/client.go:249
#   0x636a7c    net/http.(*Client).send+0xfc                                                    /usr/local/go/src/net/http/client.go:173
#   0x63811c    net/http.(*Client).Do+0x28c                                                 /usr/local/go/src/net/http/client.go:602
#   0x72e357    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api.(*Client).doRequest+0xb7        /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api/api.go:673
#   0x73297e    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api.(*Health).Service+0x15e     /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api/health.go:170
#   0x7490ce    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch.serviceWatch.func1+0x16e  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch/funcs.go:154
#   0x747355    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch.(*Plan).Run+0x285     /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch/plan.go:48

1 @ 0x4116e2 0x445036 0x769c92 0x45e511
#   0x445035    os/signal.signal_recv+0xa5  /usr/local/go/src/runtime/sigqueue.go:131
#   0x769c91    os/signal.loop+0x21     /usr/local/go/src/os/signal/signal_unix.go:22

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x498a0a 0x56ed42 0x581e7d 0x675602 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498a09    internal/poll.(*FD).Read+0x189          /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56ed41    net.(*netFD).Read+0x51              /usr/local/go/src/net/fd_unix.go:202
#   0x581e7c    net.(*conn).Read+0x6c               /usr/local/go/src/net/net.go:176
#   0x675601    net/http.(*connReader).backgroundRead+0x61  /usr/local/go/src/net/http/server.go:660

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58aed9 0x6802af 0x67ef52 0x67ec99 0x67fe2f 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41            /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58aed8    net.(*TCPListener).AcceptTCP+0x48       /usr/local/go/src/net/tcpsock.go:234
#   0x6802ae    net/http.tcpKeepAliveListener.Accept+0x2e   /usr/local/go/src/net/http/server.go:3120
#   0x67ef51    net/http.(*Server).Serve+0x1b1          /usr/local/go/src/net/http/server.go:2695
#   0x67ec98    net/http.(*Server).ListenAndServe+0xa8      /usr/local/go/src/net/http/server.go:2636
#   0x67fe2e    net/http.ListenAndServe+0x7e            /usr/local/go/src/net/http/server.go:2882

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58aed9 0x6802af 0x67ef52 0x67ec99 0x67fe2f 0x9802f5 0x980a3c 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56                                                     /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1                                                        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41                                                            /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d                                                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58aed8    net.(*TCPListener).AcceptTCP+0x48                                                       /usr/local/go/src/net/tcpsock.go:234
#   0x6802ae    net/http.tcpKeepAliveListener.Accept+0x2e                                                   /usr/local/go/src/net/http/server.go:3120
#   0x67ef51    net/http.(*Server).Serve+0x1b1                                                          /usr/local/go/src/net/http/server.go:2695
#   0x67ec98    net/http.(*Server).ListenAndServe+0xa8                                                      /usr/local/go/src/net/http/server.go:2636
#   0x67fe2e    net/http.ListenAndServe+0x7e                                                            /usr/local/go/src/net/http/server.go:2882
#   0x9802f4    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.(*Manager).serve+0x174    /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.health-go/healthmanager.go:274
#   0x980a3b    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.addAfter.func1.1+0x5b /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.health-go/micro.go:41

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58b119 0x67ef52 0x67de33 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41        /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58b118    net.(*TCPListener).Accept+0x48      /usr/local/go/src/net/tcpsock.go:247
#   0x67ef51    net/http.(*Server).Serve+0x1b1      /usr/local/go/src/net/http/server.go:2695
#   0x67de32    net/http.Serve+0x72         /usr/local/go/src/net/http/server.go:2323

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40615b 0x954fdb 0x45e511
#   0x954fda    bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor.(*fsmS).scheduleRetry.func1+0x3a   /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor/fsm.go:54

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40615b 0x983209 0x45e511
#   0x983208    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-plugins/server/http.(*httpServer).Start.func1+0x48  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-plugins/server/http/http.go:144

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x8cd83f 0x45e511
#   0x8cd83e    bitbucket.org/company/api.v1.pricing/vendor/github.com/golang/glog.(*loggingT).flushDaemon+0x9e /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/golang/glog/glog.go:882

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x956080 0x45e511
#   0x95607f    bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor.(*meterS).init.func1+0x7f  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor/meter.go:63

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x956a03 0x45e511
#   0x956a02    bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor.(*Recorder).init.func1+0x62    /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/instana/golang-sensor/recorder.go:57

1 @ 0x42f0bc 0x42f1ae 0x44cc10 0x8c43fa 0x45e511
#   0x44cc0f    time.Sleep+0x12f                                                                        /usr/local/go/src/runtime/time.go:65
#   0x8c43f9    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).poll+0x1f9 /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.configuration-go/config.go:181

1 @ 0x42f0bc 0x43f4f9 0x45b160 0x45e511
#   0x42f0bb    runtime.gopark+0x12b        /usr/local/go/src/runtime/proc.go:287
#   0x43f4f8    runtime.selectgo+0x1148     /usr/local/go/src/runtime/select.go:395
#   0x45b15f    runtime.ensureSigM.func1+0x21f  /usr/local/go/src/runtime/signal_unix.go:511

1 @ 0x42f0bc 0x43f4f9 0x691088 0x687482 0x636de9 0x636a7d 0x63811d 0x72e358 0x72fb97 0x748c60 0x747356 0x45e511
#   0x691087    net/http.(*persistConn).roundTrip+0x607                                             /usr/local/go/src/net/http/transport.go:1970
#   0x687481    net/http.(*Transport).RoundTrip+0x991                                               /usr/local/go/src/net/http/transport.go:413
#   0x636de8    net/http.send+0x1a8                                                     /usr/local/go/src/net/http/client.go:249
#   0x636a7c    net/http.(*Client).send+0xfc                                                    /usr/local/go/src/net/http/client.go:173
#   0x63811c    net/http.(*Client).Do+0x28c                                                 /usr/local/go/src/net/http/client.go:602
#   0x72e357    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api.(*Client).doRequest+0xb7        /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api/api.go:673
#   0x72fb96    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api.(*Catalog).Services+0xc6        /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/api/catalog.go:139
#   0x748c5f    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch.servicesWatch.func1+0xff  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch/funcs.go:97
#   0x747355    bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch.(*Plan).Run+0x285     /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/hashicorp/consul/watch/plan.go:48

1 @ 0x42f0bc 0x43f4f9 0x7501a0 0x84566b 0x8454c7 0x45e511
#   0x75019f    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/registry.(*consulWatcher).Next+0xef       /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/registry/consul_watcher.go:231
#   0x84566a    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).watch+0xba    /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache/cache.go:304
#   0x8454c6    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).run+0x136 /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache/cache.go:276

1 @ 0x42f0bc 0x43f4f9 0x846285 0x45e511
#   0x846284    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache.(*cacheSelector).watch.func1+0xe4  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/selector/cache/cache.go:294

1 @ 0x42f0bc 0x43f4f9 0x84b1af 0x45e511
#   0x84b1ae    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro.(*service).run+0x11e  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/service.go:45

1 @ 0x42f0bc 0x43f4f9 0x84b8e7 0x9aaaa4 0x42ec06 0x45e511
#   0x84b8e6    bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro.(*service).Run+0x206  /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/github.com/micro/go-micro/service.go:154
#   0x9aaaa3    main.main+0x763                                                 /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/main.go:97
#   0x42ec05    runtime.main+0x225                                              /usr/local/go/src/runtime/proc.go:195

1 @ 0x42f0bc 0x43f4f9 0x90c294 0x90f9da 0x904bab 0x45e511
#   0x90c293    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRuntime+0x163                                                              /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.metrics-go/runtime.go:33
#   0x90f9d9    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRuntime)-fm+0x29   /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.metrics-go/metrics.go:79
#   0x904baa    bitbucket.org/company/api.v1.pricing/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                         /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/gopkg.in/tomb.v2/tomb.go:163

1 @ 0x42f0bc 0x43f4f9 0x90cecd 0x90fa2a 0x904bab 0x45e511
#   0x90cecc    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRusage+0x2dc                                                               /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.metrics-go/runtime.go:87
#   0x90fa29    bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRusage)-fm+0x29    /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/bitbucket.org/company/lib.metrics-go/metrics.go:80
#   0x904baa    bitbucket.org/company/api.v1.pricing/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                         /home/sfinlay/work/src/bitbucket.org/company/api.v1.pricing/vendor/gopkg.in/tomb.v2/tomb.go:163

1 @ 0x9a1312 0x9a1110 0x99dc6b 0x9a9db8 0x9aa0bb 0x67bf44 0x67d5f0 0x67ebc4 0x67ae1d 0x45e511
#   0x9a1311    runtime/pprof.writeRuntimeProfile+0xa1  /usr/local/go/src/runtime/pprof/pprof.go:637
#   0x9a110f    runtime/pprof.writeGoroutine+0x9f   /usr/local/go/src/runtime/pprof/pprof.go:599
#   0x99dc6a    runtime/pprof.(*Profile).WriteTo+0x3aa  /usr/local/go/src/runtime/pprof/pprof.go:310
#   0x9a9db7    net/http/pprof.handler.ServeHTTP+0x1b7  /usr/local/go/src/net/http/pprof/pprof.go:237
#   0x9aa0ba    net/http/pprof.Index+0x1da      /usr/local/go/src/net/http/pprof/pprof.go:248
#   0x67bf43    net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/go/src/net/http/server.go:1918
#   0x67d5ef    net/http.(*ServeMux).ServeHTTP+0x12f    /usr/local/go/src/net/http/server.go:2254
#   0x67ebc3    net/http.serverHandler.ServeHTTP+0xb3   /usr/local/go/src/net/http/server.go:2619
#   0x67ae1c    net/http.(*conn).serve+0x71c        /usr/local/go/src/net/http/server.go:1801

Version 0.1.4:

/debug/pprof/

profiles:
0   block
19  goroutine
4   heap
0   mutex
11  threadcreate

full goroutine stack dump

goroutine profile: total 19
1 @ 0x4116e2 0x445036 0x766ca2 0x45e511
#   0x445035    os/signal.signal_recv+0xa5  /usr/local/go/src/runtime/sigqueue.go:131
#   0x766ca1    os/signal.loop+0x21     /usr/local/go/src/os/signal/signal_unix.go:22

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x498a0a 0x56ed42 0x581e7d 0x68e2f0 0x52007a 0x5201ca 0x68edc5 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x498a09    internal/poll.(*FD).Read+0x189      /usr/local/go/src/internal/poll/fd_unix.go:126
#   0x56ed41    net.(*netFD).Read+0x51          /usr/local/go/src/net/fd_unix.go:202
#   0x581e7c    net.(*conn).Read+0x6c           /usr/local/go/src/net/net.go:176
#   0x68e2ef    net/http.(*persistConn).Read+0x13f  /usr/local/go/src/net/http/transport.go:1391
#   0x520079    bufio.(*Reader).fill+0x119      /usr/local/go/src/bufio/bufio.go:97
#   0x5201c9    bufio.(*Reader).Peek+0x39       /usr/local/go/src/bufio/bufio.go:129
#   0x68edc4    net/http.(*persistConn).readLoop+0x184  /usr/local/go/src/net/http/transport.go:1539

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58aed9 0x6802af 0x67ef52 0x67ec99 0x67fe2f 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41            /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58aed8    net.(*TCPListener).AcceptTCP+0x48       /usr/local/go/src/net/tcpsock.go:234
#   0x6802ae    net/http.tcpKeepAliveListener.Accept+0x2e   /usr/local/go/src/net/http/server.go:3120
#   0x67ef51    net/http.(*Server).Serve+0x1b1          /usr/local/go/src/net/http/server.go:2695
#   0x67ec98    net/http.(*Server).ListenAndServe+0xa8      /usr/local/go/src/net/http/server.go:2636
#   0x67fe2e    net/http.ListenAndServe+0x7e            /usr/local/go/src/net/http/server.go:2882

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58aed9 0x6802af 0x67ef52 0x67ec99 0x67fe2f 0x97d545 0x97dc8c 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56                                                     /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c                                                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1                                                        /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41                                                            /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d                                                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58aed8    net.(*TCPListener).AcceptTCP+0x48                                                       /usr/local/go/src/net/tcpsock.go:234
#   0x6802ae    net/http.tcpKeepAliveListener.Accept+0x2e                                                   /usr/local/go/src/net/http/server.go:3120
#   0x67ef51    net/http.(*Server).Serve+0x1b1                                                          /usr/local/go/src/net/http/server.go:2695
#   0x67ec98    net/http.(*Server).ListenAndServe+0xa8                                                      /usr/local/go/src/net/http/server.go:2636
#   0x67fe2e    net/http.ListenAndServe+0x7e                                                            /usr/local/go/src/net/http/server.go:2882
#   0x97d544    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.(*Manager).serve+0x174   /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.health-go/healthmanager.go:274
#   0x97dc8b    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2ehealth-go.addAfter.func1.1+0x5b    /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.health-go/micro.go:41

1 @ 0x42f0bc 0x42a1ca 0x4297c7 0x497bee 0x497c6d 0x49a0c2 0x56f762 0x58cafe 0x58b119 0x67ef52 0x67de33 0x45e511
#   0x4297c6    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x497bed    internal/poll.(*pollDesc).wait+0xad /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x497c6c    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49a0c1    internal/poll.(*FD).Accept+0x1e1    /usr/local/go/src/internal/poll/fd_unix.go:335
#   0x56f761    net.(*netFD).accept+0x41        /usr/local/go/src/net/fd_unix.go:238
#   0x58cafd    net.(*TCPListener).accept+0x2d      /usr/local/go/src/net/tcpsock_posix.go:136
#   0x58b118    net.(*TCPListener).Accept+0x48      /usr/local/go/src/net/tcpsock.go:247
#   0x67ef51    net/http.(*Server).Serve+0x1b1      /usr/local/go/src/net/http/server.go:2695
#   0x67de32    net/http.Serve+0x72         /usr/local/go/src/net/http/server.go:2323

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40615b 0x95222b 0x45e511
#   0x95222a    bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor.(*fsmS).scheduleRetry.func1+0x3a  /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor/fsm.go:54

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40615b 0x980459 0x45e511
#   0x980458    bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-plugins/server/http.(*httpServer).Start.func1+0x48 /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-plugins/server/http/http.go:144

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x8caa8f 0x45e511
#   0x8caa8e    bitbucket.org/company/.api.v1.pricing/vendor/github.com/golang/glog.(*loggingT).flushDaemon+0x9e    /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/golang/glog/glog.go:882

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x9532d0 0x45e511
#   0x9532cf    bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor.(*meterS).init.func1+0x7f /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor/meter.go:63

1 @ 0x42f0bc 0x42f1ae 0x4064b4 0x40619b 0x953c53 0x45e511
#   0x953c52    bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor.(*Recorder).init.func1+0x62   /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/instana/golang-sensor/recorder.go:57

1 @ 0x42f0bc 0x42f1ae 0x44cc10 0x8c164a 0x45e511
#   0x44cc0f    time.Sleep+0x12f                                                                        /usr/local/go/src/runtime/time.go:65
#   0x8c1649    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2econfiguration-go.(*Configurator).poll+0x1f9    /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.configuration-go/config.go:181

1 @ 0x42f0bc 0x43f4f9 0x45b160 0x45e511
#   0x42f0bb    runtime.gopark+0x12b        /usr/local/go/src/runtime/proc.go:287
#   0x43f4f8    runtime.selectgo+0x1148     /usr/local/go/src/runtime/select.go:395
#   0x45b15f    runtime.ensureSigM.func1+0x21f  /usr/local/go/src/runtime/signal_unix.go:511

1 @ 0x42f0bc 0x43f4f9 0x690575 0x45e511
#   0x690574    net/http.(*persistConn).writeLoop+0x164 /usr/local/go/src/net/http/transport.go:1759

1 @ 0x42f0bc 0x43f4f9 0x8483bf 0x45e511
#   0x8483be    bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-micro.(*service).run+0x11e /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-micro/service.go:45

1 @ 0x42f0bc 0x43f4f9 0x848d47 0x9a7cf4 0x42ec06 0x45e511
#   0x848d46    bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-micro.(*service).Run+0x206 /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/github.com/micro/go-micro/service.go:165
#   0x9a7cf3    main.main+0x763                                                 /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/main.go:97
#   0x42ec05    runtime.main+0x225                                              /usr/local/go/src/runtime/proc.go:195

1 @ 0x42f0bc 0x43f4f9 0x9094e4 0x90cc2a 0x901dfb 0x45e511
#   0x9094e3    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRuntime+0x163                                                             /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.metrics-go/runtime.go:33
#   0x90cc29    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRuntime)-fm+0x29 /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.metrics-go/metrics.go:79
#   0x901dfa    bitbucket.org/company/.api.v1.pricing/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/gopkg.in/tomb.v2/tomb.go:163

1 @ 0x42f0bc 0x43f4f9 0x90a11d 0x90cc7a 0x901dfb 0x45e511
#   0x90a11c    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).monitorRusage+0x2dc                                                              /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.metrics-go/runtime.go:87
#   0x90cc79    bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.(*metricsImpl).(bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/com%2ecompany%2elib%2emetrics-go.monitorRusage)-fm+0x29  /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/bitbucket.org/company/.lib.metrics-go/metrics.go:80
#   0x901dfa    bitbucket.org/company/.api.v1.pricing/vendor/gopkg.in/tomb%2ev2.(*Tomb).run+0x2a                                                                                            /home/sfinlay/work/src/bitbucket.org/company/.api.v1.pricing/vendor/gopkg.in/tomb.v2/tomb.go:163

1 @ 0x482465 0x480035 0x47e409 0x4989a5 0x56ed42 0x581e7d 0x675602 0x45e511
#   0x482464    syscall.Syscall+0x4             /usr/local/go/src/syscall/asm_linux_amd64.s:18
#   0x480034    syscall.read+0x54               /usr/local/go/src/syscall/zsyscall_linux_amd64.go:756
#   0x47e408    syscall.Read+0x48               /usr/local/go/src/syscall/syscall_unix.go:162
#   0x4989a4    internal/poll.(*FD).Read+0x124          /usr/local/go/src/internal/poll/fd_unix.go:122
#   0x56ed41    net.(*netFD).Read+0x51              /usr/local/go/src/net/fd_unix.go:202
#   0x581e7c    net.(*conn).Read+0x6c               /usr/local/go/src/net/net.go:176
#   0x675601    net/http.(*connReader).backgroundRead+0x61  /usr/local/go/src/net/http/server.go:660

1 @ 0x99e562 0x99e360 0x99aebb 0x9a7008 0x9a730b 0x67bf44 0x67d5f0 0x67ebc4 0x67ae1d 0x45e511
#   0x99e561    runtime/pprof.writeRuntimeProfile+0xa1  /usr/local/go/src/runtime/pprof/pprof.go:637
#   0x99e35f    runtime/pprof.writeGoroutine+0x9f   /usr/local/go/src/runtime/pprof/pprof.go:599
#   0x99aeba    runtime/pprof.(*Profile).WriteTo+0x3aa  /usr/local/go/src/runtime/pprof/pprof.go:310
#   0x9a7007    net/http/pprof.handler.ServeHTTP+0x1b7  /usr/local/go/src/net/http/pprof/pprof.go:237
#   0x9a730a    net/http/pprof.Index+0x1da      /usr/local/go/src/net/http/pprof/pprof.go:248
#   0x67bf43    net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/go/src/net/http/server.go:1918
#   0x67d5ef    net/http.(*ServeMux).ServeHTTP+0x12f    /usr/local/go/src/net/http/server.go:2254
#   0x67ebc3    net/http.serverHandler.ServeHTTP+0xb3   /usr/local/go/src/net/http/server.go:2619
#   0x67ae1c    net/http.(*conn).serve+0x71c        /usr/local/go/src/net/http/server.go:1801
asim commented 6 years ago

If you run with v0.1.4 and flag --selector=cache you will see the same behaviour I believe.

I'm starting to see why this occurs. Because we introduce the caching selector, it makes use of the consul watcher which has the behaviour of adding a go routine per service it finds in the registry to keep track of watch updates it receives.

https://github.com/micro/go-micro/blob/master/registry/consul_watcher.go#L187L201

This is my initial guess. I need to dig into this code and see if thats exactly the case.

ynori7 commented 6 years ago

You're right. I just tried starting it up with and without that flag and here were the results:

Without: 

/debug/pprof/

profiles:
0   block
19  goroutine
4   heap
0   mutex
11  threadcreate

With:

/debug/pprof/

profiles:
0   block
31  goroutine
3   heap
0   mutex
10  threadcreate
asim commented 6 years ago

You can disable the caching selector with --selector=default or MICRO_SELECTOR=default but its probably a good idea to fix the issue with the go routines. Not a simple one to solve considering its related to functionality.

asim commented 6 years ago

I've been looking at a fix for this. Will likely involve a breaking change to the Watch interface to allow selective filtering of services. It's otherwise quite difficult to reimplement the consul watcher code.

asim commented 6 years ago

@ynori7 can you please test this PR https://github.com/micro/go-micro/pull/230. It will only cache services that have been called by the client.

asim commented 6 years ago

The PR was merged. This issue should now be resolved.