Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Out of Memory Error #232

Closed
jtravisano opened this issue Oct 18, 2018 · 5 comments
Closed

Out of Memory Error #232

jtravisano opened this issue Oct 18, 2018 · 5 comments

Comments

@jtravisano
Copy link

We are consistently getting Out of Memory errors with Toxiproxy, with both the Docker image and the Windows executable. We are using version 2.1.3.

We've been creating a proxy for an AWS S3 bucket (i.e. bucketName.s3.amazonaws.com) and adding upstream and downstream latency toxics (with --toxicity 0.05). We then run a test that eventually uploads about 2000 small text files to S3. We're generally able to run a few of these tests before the server crashes. With the Windows server, we see the Toxiproxy process using up to ~9GB of available memory before crashing. Typically, the process will continue running for a few minutes after the tests complete before it crashes, but doesn't seem to free up any of the memory it's using before crashing.

Stack trace from the Docker image:

fatal error: runtime: out of memory

runtime stack:
runtime.throw(0x70636d, 0x16)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/panic.go:605 +0x95
runtime.sysMap(0xc454c20000, 0x100000, 0xc420150f00, 0x8b0938)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mem_linux.go:216 +0x1d0
runtime.(*mheap).sysAlloc(0x897880, 0x100000, 0x7f7ab65c5148)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/malloc.go:470 +0xd7
runtime.(*mheap).grow(0x897880, 0x1, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mheap.go:887 +0x60
runtime.(*mheap).allocSpanLocked(0x897880, 0x1, 0x8b0948, 0x7f7ab65c5148)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mheap.go:800 +0x334
runtime.(*mheap).alloc_m(0x897880, 0x1, 0x20000000e, 0x7f7ab65c5148)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mheap.go:666 +0x118
runtime.(*mheap).alloc.func1()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mheap.go:733 +0x4d
runtime.systemstack(0xc42002fe98)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/asm_amd64.s:360 +0xab
runtime.(*mheap).alloc(0x897880, 0x1, 0x7f7ab601000e, 0x7f7ab65c5148)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mheap.go:732 +0xa1
runtime.(*mcentral).grow(0x898f50, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mcentral.go:232 +0x94
runtime.(*mcentral).cacheSpan(0x898f50, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mcentral.go:106 +0x33a
runtime.(*mcache).refill(0x7f7ab7e0a6c8, 0x45950e, 0x7f7ab65c5148)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/mcache.go:123 +0xa4
runtime.(*mcache).nextFree.func1()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/malloc.go:557 +0x32
runtime.systemstack(0xc420017300)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/asm_amd64.s:344 +0x79
runtime.mstart()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/proc.go:1135

goroutine 214 [running]:
runtime.systemstack_switch()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/asm_amd64.s:298 fp=0xc4203c8c40 sp=0xc4203c8c38 pc=0x455930
runtime.(*mcache).nextFree(0x7f7ab7e0a6c8, 0xe, 0x18, 0x0, 0x452800)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/malloc.go:556 +0xa9 fp=0xc4203c8c98 sp=0xc4203c8c40 pc=0x4102b9
runtime.mallocgc(0x60, 0x6ee140, 0x1, 0x3)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/malloc.go:711 +0x6f0 fp=0xc4203c8d40 sp=0xc4203c8c98 pc=0x410b80
runtime.newobject(0x6ee140, 0xc4203c8d90)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/malloc.go:840 +0x38 fp=0xc4203c8d70 sp=0xc4203c8d40 pc=0x410ec8
runtime.makechan(0x6903e0, 0x1, 0xc454c1df80)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/chan.go:92 +0x1ac fp=0xc4203c8db8 sp=0xc4203c8d70 pc=0x4038bc
time.NewTimer(0x6fc23ac00, 0xc454c1b680)
        /usr/local/Cellar/go/1.9.4/libexec/src/time/sleep.go:84 +0x3a fp=0xc4203c8df8 sp=0xc4203c8db8 pc=0x47ee7a
time.After(0x6fc23ac00, 0x2)
        /usr/local/Cellar/go/1.9.4/libexec/src/time/sleep.go:151 +0x2b fp=0xc4203c8e18 sp=0xc4203c8df8 pc=0x47f12b
github.com/Shopify/toxiproxy/toxics.(*TimeoutToxic).Pipe(0xc4200668c0, 0xc42005d6c0)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/toxics/timeout.go:17 +0x62 fp=0xc4203c8fa0 sp=0xc4203c8e18 pc=0x62ea02
github.com/Shopify/toxiproxy/toxics.(*ToxicStub).Run(0xc42005d6c0, 0xc420056360)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/toxics/toxic.go:82 +0xb1 fp=0xc4203c8fd0 sp=0xc4203c8fa0 pc=0x62edb1
runtime.goexit()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/asm_amd64.s:2337 +0x1 fp=0xc4203c8fd8 sp=0xc4203c8fd0 pc=0x4584b1
created by github.com/Shopify/toxiproxy.(*ToxicLink).Start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:73 +0xbc

goroutine 1 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7f7ab7daef70, 0x72, 0xffffffffffffffff)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420134098, 0x72, 0xc42014ba00, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc420134098, 0xffffffffffffff00, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc420134080, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_unix.go:335 +0x1e2
net.(*netFD).accept(0xc420134080, 0x7159e8, 0xc42014bbe0, 0x40234b)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc42000c100, 0x6a0d60, 0xc42014bc10, 0x4010e7)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).AcceptTCP(0xc42000c100, 0xc42014bc58, 0xc42014bc60, 0xc42014bc50)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock.go:234 +0x49
net/http.tcpKeepAliveListener.Accept(0xc42000c100, 0x7153c0, 0xc420111e00, 0x85ba00, 0xc420109020)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/http/server.go:3120 +0x2f
net/http.(*Server).Serve(0xc42014e000, 0x85b540, 0xc42000c100, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/http/server.go:2695 +0x1b2
net/http.(*Server).ListenAndServe(0xc42014e000, 0xc42014e000, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/http/server.go:2636 +0xa9
net/http.ListenAndServe(0xc420015c80, 0xc, 0x0, 0x0, 0xc420015c80, 0xc)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/http/server.go:2882 +0x7f
github.com/Shopify/toxiproxy.(*ApiServer).Listen(0xc42006a028, 0x7fffd63cbf70, 0x7, 0x7011ba, 0x4)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/api.go:85 +0xec9
main.main()
        /Users/jpittis/src/github.com/Shopify/toxiproxy/cmd/toxiproxy.go:41 +0x19d

goroutine 19 [syscall, 1 minutes]:
os/signal.signal_recv(0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/sigqueue.go:131 +0xa6
os/signal.loop()
        /usr/local/Cellar/go/1.9.4/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.0
        /usr/local/Cellar/go/1.9.4/libexec/src/os/signal/signal_unix.go:28 +0x41

goroutine 20 [select, 1 minutes, locked to thread]:
runtime.gopark(0x715940, 0x0, 0x701829, 0x6, 0x18, 0x1)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/proc.go:287 +0x12c
runtime.selectgo(0xc42003af50, 0xc4200581e0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/select.go:395 +0x1149
runtime.ensureSigM.func1()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/signal_unix.go:511 +0x220
runtime.goexit()
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/asm_amd64.s:2337 +0x1

goroutine 3 [chan receive, 1 minutes]:
main.main.func1(0xc420058120)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/cmd/toxiproxy.go:37 +0x34
created by main.main
        /Users/jpittis/src/github.com/Shopify/toxiproxy/cmd/toxiproxy.go:36 +0x15f

goroutine 23 [IO wait]:
internal/poll.runtime_pollWait(0x7f7ab7daedf0, 0x72, 0xffffffffffffffff)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420152198, 0x72, 0xc4201bdc00, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc420152198, 0xffffffffffffff00, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc420152180, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_unix.go:335 +0x1e2
net.(*netFD).accept(0xc420152180, 0xc420052c28, 0xc4201bde30, 0xc4201bde70)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc42006a058, 0xc420068c80, 0x1c, 0xc42014e498)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).Accept(0xc42006a058, 0xc420068c80, 0x1c, 0x7f7ab7d6e120, 0xc42000c0e8)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock.go:247 +0x49
github.com/Shopify/toxiproxy.(*Proxy).server(0xc4200f42d0)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/proxy.go:136 +0x424
created by github.com/Shopify/toxiproxy.start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/proxy.go:197 +0x89

goroutine 24 [chan receive, 1 minutes]:
github.com/Shopify/toxiproxy.(*Proxy).server.func1(0xc4200f42d0, 0xc42005f350, 0x85b1c0, 0xc42006a058)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/proxy.go:116 +0x62
created by github.com/Shopify/toxiproxy.(*Proxy).server
        /Users/jpittis/src/github.com/Shopify/toxiproxy/proxy.go:115 +0x410

goroutine 215 [select, 1 minutes]:
github.com/Shopify/toxiproxy/stream.(*ChanReader).Read(0xc420396b10, 0xc4204a4000, 0x8000, 0x8000, 0x8000, 0x8000, 0x7f7ab7e0e850)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/stream/io_chan.go:95 +0x3a1
io.copyBuffer(0x8581c0, 0xc42003e7e0, 0x856c00, 0xc420396b10, 0xc4204a4000, 0x8000, 0x8000, 0xc42003e7e0, 0xc42003e7e0, 0x6badc0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:392 +0x123
io.Copy(0x8581c0, 0xc42003e7e0, 0x856c00, 0xc420396b10, 0x40435b, 0x42bf1b, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:362 +0x68
net.genericReadFrom(0x857140, 0xc42006a198, 0x856c00, 0xc420396b10, 0x0, 0x0, 0xc420195f00)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/net.go:595 +0x84
net.(*TCPConn).readFrom(0xc42006a198, 0x856c00, 0xc420396b10, 0x42bf1b, 0xc420195e50, 0x40eded)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock_posix.go:51 +0xa5
net.(*TCPConn).ReadFrom(0xc42006a198, 0x856c00, 0xc420396b10, 0x7f7ab7daf380, 0xc42006a198, 0x2a620150f01)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock.go:103 +0x5f
io.copyBuffer(0x857140, 0xc42006a198, 0x856c00, 0xc420396b10, 0x0, 0x0, 0x0, 0x6f22c0, 0x20000, 0x857140)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:386 +0x2bb
io.Copy(0x857140, 0xc42006a198, 0x856c00, 0xc420396b10, 0xc42006a198, 0xc420195fa0, 0xc420131920)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:362 +0x68
github.com/Shopify/toxiproxy.(*ToxicLink).Start.func2(0x7f7ab7d6e148, 0xc42006a198, 0xc42005d380, 0xc4204371e0, 0x1c)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:76 +0x83
created by github.com/Shopify/toxiproxy.(*ToxicLink).Start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:75 +0x1f8

goroutine 209 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7f7ab7dae1f0, 0x72, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420135118, 0x72, 0xffffffffffffff00, 0x858b80, 0x8552e0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc420135118, 0xc42048a000, 0x8000, 0x8000)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc420135100, 0xc42048a000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/internal/poll/fd_unix.go:126 +0x18a
net.(*netFD).Read(0xc420135100, 0xc42048a000, 0x8000, 0x8000, 0x2311443c3d, 0xa8, 0xa8)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/fd_unix.go:202 +0x52
net.(*conn).Read(0xc42006a198, 0xc42048a000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/net.go:176 +0x6d
io.copyBuffer(0x856c40, 0xc42006a1c8, 0x7f7ab7d6e120, 0xc42006a198, 0xc42048a000, 0x8000, 0x8000, 0x21, 0xc42001001c, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:392 +0x123
io.Copy(0x856c40, 0xc42006a1c8, 0x7f7ab7d6e120, 0xc42006a198, 0xc420059a40, 0xc420151680, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:362 +0x68
github.com/Shopify/toxiproxy.(*ToxicLink).Start.func1(0xc42005d2c0, 0x7f7ab7d6e120, 0xc42006a198)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:58 +0x5f
created by github.com/Shopify/toxiproxy.(*ToxicLink).Start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:57 +0x5d

goroutine 210 [select, 1 minutes]:
github.com/Shopify/toxiproxy/toxics.(*NoopToxic).Pipe(0xc4200227b8, 0xc42005d300)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/toxics/noop.go:8 +0x114
github.com/Shopify/toxiproxy/toxics.(*ToxicStub).Run(0xc42005d300, 0xc420056240)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/toxics/toxic.go:84 +0xd9
created by github.com/Shopify/toxiproxy.(*ToxicLink).Start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:73 +0xbc

goroutine 211 [select, 1 minutes]:
github.com/Shopify/toxiproxy/stream.(*ChanReader).Read(0xc420396ae0, 0xc42049a000, 0x8000, 0x8000, 0xa8, 0x0, 0x0)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/stream/io_chan.go:95 +0x3a1
io.copyBuffer(0x8581c0, 0xc42003e7d0, 0x856c00, 0xc420396ae0, 0xc42049a000, 0x8000, 0x8000, 0xc42003e7d0, 0xc42003e7d0, 0x6badc0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:392 +0x123
io.Copy(0x8581c0, 0xc42003e7d0, 0x856c00, 0xc420396ae0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:362 +0x68
net.genericReadFrom(0x857140, 0xc42006a1c0, 0x856c00, 0xc420396ae0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/net.go:595 +0x84
net.(*TCPConn).readFrom(0xc42006a1c0, 0x856c00, 0xc420396ae0, 0x0, 0xc420489650, 0x40eded)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock_posix.go:51 +0xa5
net.(*TCPConn).ReadFrom(0xc42006a1c0, 0x856c00, 0xc420396ae0, 0x7f7ab7daf380, 0xc42006a1c0, 0x2a600000001)
        /usr/local/Cellar/go/1.9.4/libexec/src/net/tcpsock.go:103 +0x5f
io.copyBuffer(0x857140, 0xc42006a1c0, 0x856c00, 0xc420396ae0, 0x0, 0x0, 0x0, 0x6f22c0, 0x0, 0x857140)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:386 +0x2bb
io.Copy(0x857140, 0xc42006a1c0, 0x856c00, 0xc420396ae0, 0xc42006a1c0, 0x0, 0x0)
        /usr/local/Cellar/go/1.9.4/libexec/src/io/io.go:362 +0x68
github.com/Shopify/toxiproxy.(*ToxicLink).Start.func2(0x7f7ab7d6e148, 0xc42006a1c0, 0xc42005d2c0, 0xc4204371c0, 0x1a)
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:76 +0x83
created by github.com/Shopify/toxiproxy.(*ToxicLink).Start
        /Users/jpittis/src/github.com/Shopify/toxiproxy/link.go:75 +0x1f8```
@chaosbox
Copy link
Contributor

hi
We saw a similar behaviour of exhausting the memory, when you add a timeout toxic, we found this is because of the looping around creating the timer objects.

from your stacktrace:

/Users/jpittis/src/github.com/Shopify/toxiproxy/toxics/timeout.go:17 +0x62 fp=0xc4203c8fa0 sp=0xc4203c8e18 pc=0x62ea02
github.com/Shopify/toxiproxy/toxics.(*ToxicStub).Run(0xc42005d6c0, 0xc420056360)

#231 will fix it.

cc: @xthexder

@pgeorgiev333
Copy link

Please merge and release.
Thanks

@jpittis
Copy link
Contributor

jpittis commented Dec 17, 2018

Waiting on a quick +1 from another maintainer and for the contributor to agree to the CLA.

Sorry for the long turnaround on this.

@jpittis
Copy link
Contributor

jpittis commented Jan 2, 2019

This has been merged into master but I haven't had the chance to cut a release yet.

Just got back from break so I should have time this week to cut a release.

@pgeorgiev333
Copy link

Thanks.
Waiting for it:)

This was referenced Jan 10, 2019
@jpittis jpittis closed this as completed Jan 22, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants