ForceCLI/force

Out of memory error on large queries

Closed this issue · 5 comments

deanmorin commented

I'm running force in a docker container with 4GB of memory, and large queries I get an out of memory error. The stack trace is below.

Adding more memory to the container avoids the issue. It seems that force is holding the entire query result in memory.

I'm running the query like so:

$ force query "$QUERY_ON_BIG_OBJECT" --format:csv > out.csv

fatal error: runtime: out of memory

runtime stack:
runtime.throw(0xa03820, 0x16)
	/usr/local/go/src/runtime/panic.go:547 +0x90
runtime.sysMap(0xc889d20000, 0x9550000, 0x0, 0xc8f0d8)
	/usr/local/go/src/runtime/mem_linux.go:206 +0x9b
runtime.(*mheap).sysAlloc(0xc74e80, 0x9550000, 0x320000ac20)
	/usr/local/go/src/runtime/malloc.go:429 +0x191
runtime.(*mheap).grow(0xc74e80, 0x4aa8, 0x0)
	/usr/local/go/src/runtime/mheap.go:651 +0x63
runtime.(*mheap).allocSpanLocked(0xc74e80, 0x4aa5, 0xc81f1dd700)
	/usr/local/go/src/runtime/mheap.go:553 +0x4f6
runtime.(*mheap).alloc_m(0xc74e80, 0x4aa5, 0x100000000, 0x4d0980)
	/usr/local/go/src/runtime/mheap.go:437 +0x119
runtime.(*mheap).alloc.func1()
	/usr/local/go/src/runtime/mheap.go:502 +0x41
runtime.systemstack(0x7f7c65fa7928)
	/usr/local/go/src/runtime/asm_amd64.s:307 +0xab
runtime.(*mheap).alloc(0xc74e80, 0x4aa5, 0x10100000000, 0x20)
	/usr/local/go/src/runtime/mheap.go:503 +0x63
runtime.largeAlloc(0x95480e3, 0xc800000001, 0xc8218bb7c8)
	/usr/local/go/src/runtime/malloc.go:766 +0xb3
runtime.mallocgc.func3()
	/usr/local/go/src/runtime/malloc.go:664 +0x33
runtime.systemstack(0xc820016000)
	/usr/local/go/src/runtime/asm_amd64.s:291 +0x79
runtime.mstart()
	/usr/local/go/src/runtime/proc.go:1051

goroutine 1 [running]:
runtime.systemstack_switch()
	/usr/local/go/src/runtime/asm_amd64.s:245 fp=0xc8218bb660 sp=0xc8218bb658
runtime.mallocgc(0x95480e3, 0x8418a0, 0x7f7c00000001, 0x0)
	/usr/local/go/src/runtime/malloc.go:665 +0x9eb fp=0xc8218bb738 sp=0xc8218bb660
runtime.newarray(0x8418a0, 0x95480e3, 0xc8218bb7d8)
	/usr/local/go/src/runtime/malloc.go:798 +0xc9 fp=0xc8218bb778 sp=0xc8218bb738
runtime.makeslice(0x830ec0, 0x95480e3, 0x95480e3, 0x0, 0x0, 0x0)
	/usr/local/go/src/runtime/slice.go:32 +0x165 fp=0xc8218bb7c8 sp=0xc8218bb778
bytes.makeSlice(0x95480e3, 0x0, 0x0, 0x0)
	/usr/local/go/src/bytes/buffer.go:198 +0x64 fp=0xc8218bb818 sp=0xc8218bb7c8
bytes.(*Buffer).grow(0xc82027f7a0, 0x7b9, 0x4fad98)
	/usr/local/go/src/bytes/buffer.go:106 +0x282 fp=0xc8218bb8c0 sp=0xc8218bb818
bytes.(*Buffer).WriteString(0xc82027f7a0, 0xc8605c0000, 0x7b9, 0x2, 0x0, 0x0)
	/usr/local/go/src/bytes/buffer.go:143 +0x4b fp=0xc8218bb928 sp=0xc8218bb8c0
main.RenderForceRecordsCSV(0xc84d7b0000, 0x17472, 0x17800, 0x7ffcdd0b2f0c, 0x3, 0x0, 0x0)
	/root/go/src/github.com/heroku/force/display.go:362 +0xa3a fp=0xc8218bbbd0 sp=0xc8218bb928
main.DisplayForceRecordsf(0xc84d7b0000, 0x17472, 0x17800, 0x7ffcdd0b2f0c, 0x3)
	/root/go/src/github.com/heroku/force/display.go:171 +0xd2 fp=0xc8218bbd00 sp=0xc8218bbbd0
main.runQuery(0xc6b0a0, 0xc82000a1a0, 0x1, 0x2)
	/root/go/src/github.com/heroku/force/query.go:57 +0x4cf fp=0xc8218bbe60 sp=0xc8218bbd00
main.main()
	/root/go/src/github.com/heroku/force/main.go:56 +0x2f2 fp=0xc8218bbf50 sp=0xc8218bbe60
runtime.main()
	/usr/local/go/src/runtime/proc.go:188 +0x2b0 fp=0xc8218bbfa0 sp=0xc8218bbf50
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8218bbfa8 sp=0xc8218bbfa0

goroutine 17 [syscall, 4 minutes, locked to thread]:
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1998 +0x1

goroutine 5 [syscall, 4 minutes]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:116 +0x132
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:22 +0x18
created by os/signal.init.1
	/usr/local/go/src/os/signal/signal_unix.go:28 +0x37

goroutine 14 [IO wait, 1 minutes]:
net.runtime_pollWait(0x7f7c65fc3be0, 0x72, 0xc820126000)
	/usr/local/go/src/runtime/netpoll.go:160 +0x60
net.(*pollDesc).Wait(0xc82015c0d0, 0x72, 0x0, 0x0)
	/usr/local/go/src/net/fd_poll_runtime.go:73 +0x3a
net.(*pollDesc).WaitRead(0xc82015c0d0, 0x0, 0x0)
	/usr/local/go/src/net/fd_poll_runtime.go:78 +0x36
net.(*netFD).Read(0xc82015c070, 0xc820126000, 0x4000, 0x4000, 0x0, 0x7f7c65fbe050, 0xc820010140)
	/usr/local/go/src/net/fd_unix.go:250 +0x23a
net.(*conn).Read(0xc820022740, 0xc820126000, 0x4000, 0x4000, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:172 +0xe4
crypto/tls.(*block).readFromUntil(0xc8201072f0, 0x7f7c65fc4020, 0xc820022740, 0x5, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:460 +0xcc
crypto/tls.(*Conn).readRecord(0xc8200a8300, 0xacb317, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:562 +0x2d1
crypto/tls.(*Conn).Read(0xc8200a8300, 0xc820161000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:939 +0x167
net/http.noteEOFReader.Read(0x7f7c65fd3d58, 0xc8200a8300, 0xc8201097f8, 0xc820161000, 0x1000, 0x1000, 0x484753, 0x0, 0x0)
	/usr/local/go/src/net/http/transport.go:1690 +0x67
net/http.(*noteEOFReader).Read(0xc82000e2e0, 0xc820161000, 0x1000, 0x1000, 0xc8218b9d0d, 0x0, 0x0)
	<autogenerated>:284 +0xd0
bufio.(*Reader).fill(0xc820050420)
	/usr/local/go/src/bufio/bufio.go:97 +0x1e9
bufio.(*Reader).Peek(0xc820050420, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/bufio/bufio.go:132 +0xcc
net/http.(*persistConn).readLoop(0xc820109790)
	/usr/local/go/src/net/http/transport.go:1076 +0x177
created by net/http.(*Transport).dialConn
	/usr/local/go/src/net/http/transport.go:860 +0x10a6

goroutine 15 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc820109790)
	/usr/local/go/src/net/http/transport.go:1280 +0x472
created by net/http.(*Transport).dialConn
	/usr/local/go/src/net/http/transport.go:861 +0x10cb
dcarroll commented
cwarden commented

@dcarroll, did you see my comments in slack about force log? We could do something similar to what I did in f32daca, displaying the result, then fetching the next batch of records using the query locator. Non-JSON output requires a bit more work so that the header is only displayed once.

dcarroll commented
cwarden commented

I've opened #488 to write out the results as they are retrieved when using csv or json formats. (The default format requires all of the query results in order to calculate the column widths.)

cwarden commented

Fixed in v0.23.2.