Thanks for the response.
Thanks for the tip on badger fill
. I ran in the VM mentioned above and it crashed with fatal error: runtime: cannot allocate memory
. Here are some snippets of the logs:
~/go/bin/badger fill -k 128 -v 1 -m 1870 --dir ./test_dir/
Listening for /debug HTTP requests at port: 8080
badger 2019/04/09 06:30:04 INFO: All 0 tables opened in 0s
badger 2019/04/09 06:30:04 INFO: Written keys: 100000
badger 2019/04/09 06:30:05 INFO: Written keys: 200000
badger 2019/04/09 06:30:05 INFO: Written keys: 300000
badger 2019/04/09 06:30:05 INFO: Written keys: 400000
badger 2019/04/09 06:30:05 INFO: Written keys: 500000
badger 2019/04/09 06:30:05 INFO: Written keys: 600000
badger 2019/04/09 06:30:06 DEBUG: Storing value log head: {Fid:0 Len:42 Offset:68108178}
badger 2019/04/09 06:30:06 INFO: Written keys: 700000
badger 2019/04/09 06:30:06 INFO: Written keys: 800000
badger 2019/04/09 06:32:14 INFO: Written keys: 39300000
badger 2019/04/09 06:32:14 DEBUG: LOG Compact. Added 452420 keys. Skipped 0 keys. Iteration took: 376.596396ms
badger 2019/04/09 06:32:14 DEBUG: Discard stats: map[]
badger 2019/04/09 06:32:14 INFO: LOG Compact 1->2, del 6 tables, add 6 tables, took 3.892761801s
badger 2019/04/09 06:32:14 INFO: Compaction for level: 1 DONE
badger 2019/04/09 06:32:14 INFO: Got compaction priority: {level:1 score:1.3857654333114624 dropPrefix:[]}
badger 2019/04/09 06:32:14 INFO: Running for level: 1
badger 2019/04/09 06:32:15 INFO: Written keys: 39400000
badger 2019/04/09 06:32:15 DEBUG: LOG Compact. Added 452428 keys. Skipped 0 keys. Iteration took: 347.817725ms
badger 2019/04/09 06:32:15 DEBUG: LOG Compact. Added 452350 keys. Skipped 0 keys. Iteration took: 337.985284ms
badger 2019/04/09 06:32:15 INFO: Written keys: 39500000
badger 2019/04/09 06:32:15 DEBUG: LOG Compact. Added 452427 keys. Skipped 0 keys. Iteration took: 349.230227ms
badger 2019/04/09 06:32:15 INFO: Written keys: 39600000
badger 2019/04/09 06:32:15 DEBUG: LOG Compact. Added 452425 keys. Skipped 0 keys. Iteration took: 342.149219ms
badger 2019/04/09 06:32:15 DEBUG: LOG Compact. Added 452418 keys. Skipped 0 keys. Iteration took: 346.880402ms
badger 2019/04/09 06:32:15 INFO: Written keys: 39700000
badger 2019/04/09 06:32:16 DEBUG: LOG Compact. Added 452425 keys. Skipped 0 keys. Iteration took: 815.765027ms
badger 2019/04/09 06:32:16 DEBUG: LOG Compact. Added 450327 keys. Skipped 0 keys. Iteration took: 920.722591ms
badger 2019/04/09 06:32:16 INFO: Written keys: 39800000
badger 2019/04/09 06:32:16 DEBUG: LOG Compact. Added 438941 keys. Skipped 0 keys. Iteration took: 483.397659ms
badger 2019/04/09 06:32:17 INFO: Written keys: 39900000
badger 2019/04/09 06:32:17 INFO: Written keys: 40000000
badger 2019/04/09 06:32:17 DEBUG: Discard stats: map[]
badger 2019/04/09 06:32:17 INFO: LOG Compact 1->2, del 4 tables, add 4 tables, took 2.79223449s
badger 2019/04/09 06:32:17 INFO: Compaction for level: 1 DONE
badger 2019/04/09 06:32:17 INFO: Got compaction priority: {level:1 score:1.1305567659437656 dropPrefix:[]}
badger 2019/04/09 06:32:17 INFO: Running for level: 1
badger 2019/04/09 06:41:25 INFO: LOG Compact 2->3, del 4 tables, add 4 tables, took 4.10984117s
badger 2019/04/09 06:41:25 INFO: Compaction for level: 2 DONE
badger 2019/04/09 06:41:25 DEBUG: LOG Compact. Added 451468 keys. Skipped 0 keys. Iteration took: 701.442203ms
badger 2019/04/09 06:41:25 INFO: Written keys: 195500000
badger 2019/04/09 06:41:26 DEBUG: Storing value log head: {Fid:74 Len:45 Offset:136216431}
badger 2019/04/09 06:41:26 INFO: Written keys: 195600000
badger 2019/04/09 06:41:26 DEBUG: LOG Compact. Added 452282 keys. Skipped 0 keys. Iteration took: 578.094859ms
badger 2019/04/09 06:41:26 INFO: Written keys: 195700000
badger 2019/04/09 06:41:26 INFO: Written keys: 195800000
badger 2019/04/09 06:41:27 DEBUG: LOG Compact. Added 450930 keys. Skipped 0 keys. Iteration took: 679.329394ms
badger 2019/04/09 06:41:27 INFO: Written keys: 195900000
badger 2019/04/09 06:41:27 DEBUG: Storing value log head: {Fid:75 Len:45 Offset:34054074}
badger 2019/04/09 06:41:27 INFO: Written keys: 196000000
badger 2019/04/09 06:41:27 DEBUG: LOG Compact. Added 450334 keys. Skipped 0 keys. Iteration took: 551.186796ms
badger 2019/04/09 06:41:27 INFO: Written keys: 196100000
badger 2019/04/09 06:41:28 INFO: Written keys: 196200000
badger 2019/04/09 06:41:28 DEBUG: LOG Compact. Added 450840 keys. Skipped 0 keys. Iteration took: 777.465481ms
badger 2019/04/09 06:41:28 INFO: Written keys: 196300000
badger 2019/04/09 06:41:28 DEBUG: Storing value log head: {Fid:75 Len:45 Offset:102162312}
badger 2019/04/09 06:41:28 DEBUG: LOG Compact. Added 320117 keys. Skipped 0 keys. Iteration took: 506.657232ms
badger 2019/04/09 06:41:29 INFO: Written keys: 196400000
badger 2019/04/09 06:41:29 INFO: Written keys: 196500000
badger 2019/04/09 06:41:29 DEBUG: Discard stats: map[]
badger 2019/04/09 06:41:29 INFO: LOG Compact 0->1, del 8 tables, add 8 tables, took 5.855125085s
badger 2019/04/09 06:41:29 INFO: Compaction for level: 0 DONE
badger 2019/04/09 06:41:29 INFO: Got compaction priority: {level:1 score:1.9661771543323994 dropPrefix:[]}
badger 2019/04/09 06:41:29 INFO: Running for level: 1
badger 2019/04/09 06:41:29 INFO: Written keys: 196600000
badger 2019/04/09 06:41:29 DEBUG: Storing value log head: {Fid:75 Len:45 Offset:170270550}
badger 2019/04/09 06:41:29 DEBUG: LOG Compact. Added 452386 keys. Skipped 0 keys. Iteration took: 410.431503ms
badger 2019/04/09 06:41:29 INFO: Written keys: 196700000
badger 2019/04/09 06:41:29 INFO: Got compaction priority: {level:1 score:1.7109682112932205 dropPrefix:[]}
badger 2019/04/09 06:41:29 INFO: Running for level: 1
badger 2019/04/09 06:41:30 INFO: Written keys: 196800000
badger 2019/04/09 06:41:30 INFO: Written keys: 196900000
badger 2019/04/09 06:41:30 DEBUG: LOG Compact. Added 452605 keys. Skipped 0 keys. Iteration took: 681.923915ms
badger 2019/04/09 06:41:30 DEBUG: LOG Compact. Added 451489 keys. Skipped 0 keys. Iteration took: 655.931998ms
badger 2019/04/09 06:41:30 INFO: Written keys: 197000000
badger 2019/04/09 06:41:30 INFO: Written keys: 197100000
badger 2019/04/09 06:41:31 DEBUG: Storing value log head: {Fid:76 Len:45 Offset:68108193}
badger 2019/04/09 06:41:31 INFO: Written keys: 197200000
badger 2019/04/09 06:41:31 DEBUG: LOG Compact. Added 452553 keys. Skipped 0 keys. Iteration took: 1.121580149s
badger 2019/04/09 06:41:31 DEBUG: LOG Compact. Added 452588 keys. Skipped 0 keys. Iteration took: 1.132710899s
badger 2019/04/09 06:41:31 INFO: Written keys: 197300000
badger 2019/04/09 06:41:32 INFO: Written keys: 197400000
badger 2019/04/09 06:41:32 INFO: Written keys: 197500000
badger 2019/04/09 06:41:32 INFO: Written keys: 197600000
badger 2019/04/09 06:41:32 DEBUG: LOG Compact. Added 452801 keys. Skipped 0 keys. Iteration took: 1.179788511s
badger 2019/04/09 06:41:32 DEBUG: LOG Compact. Added 452701 keys. Skipped 0 keys. Iteration took: 1.214919477s
fatal error: runtime: cannot allocate memory
runtime stack:
runtime.throw(0x96175d, 0x1f)
/usr/local/go/src/runtime/panic.go:617 +0x72
runtime.persistentalloc1(0x4000, 0x0, 0xd94638, 0x7fc480446910)
/usr/local/go/src/runtime/malloc.go:1235 +0x2b7
runtime.persistentalloc.func1()
/usr/local/go/src/runtime/malloc.go:1189 +0x45
runtime.persistentalloc(0x4000, 0x0, 0xd94638, 0x7fc47f1ccf40)
/usr/local/go/src/runtime/malloc.go:1188 +0x82
runtime.(*fixalloc).alloc(0xd7e600, 0x1)
/usr/local/go/src/runtime/mfixalloc.go:80 +0xf5
runtime.(*mheap).allocSpanLocked(0xd7c100, 0x1, 0xd94608, 0x7fc47f1ccd00)
/usr/local/go/src/runtime/mheap.go:1175 +0x191
runtime.(*mheap).alloc_m(0xd7c100, 0x1, 0x45000c, 0x7fc47f1ccd00)
/usr/local/go/src/runtime/mheap.go:977 +0xc2
runtime.(*mheap).alloc.func1()
/usr/local/go/src/runtime/mheap.go:1048 +0x4c
runtime.systemstack(0x0)
/usr/local/go/src/runtime/asm_amd64.s:351 +0x66
runtime.mstart()
/usr/local/go/src/runtime/proc.go:1153
goroutine 1 [running]:
runtime.systemstack_switch()
/usr/local/go/src/runtime/asm_amd64.s:311 fp=0xc0001a6918 sp=0xc0001a6910 pc=0x45b450
runtime.(*mheap).alloc(0xd7c100, 0x1, 0x1000c, 0xc423430e00)
/usr/local/go/src/runtime/mheap.go:1047 +0x8a fp=0xc0001a6968 sp=0xc0001a6918 pc=0x42625a
runtime.(*mcentral).grow(0xd7c780, 0x0)
/usr/local/go/src/runtime/mcentral.go:256 +0x95 fp=0xc0001a69b0 sp=0xc0001a6968 pc=0x419195
runtime.(*mcentral).cacheSpan(0xd7c780, 0x80)
/usr/local/go/src/runtime/mcentral.go:106 +0x2ff fp=0xc0001a6a10 sp=0xc0001a69b0 pc=0x418c9f
runtime.(*mcache).refill(0x7fc77e96a8b8, 0xc)
/usr/local/go/src/runtime/mcache.go:135 +0x86 fp=0xc0001a6a30 sp=0xc0001a6a10 pc=0x418736
runtime.(*mcache).nextFree(0x7fc77e96a8b8, 0xc, 0xc000040070, 0xc000040000, 0xbc0a3c26413bc608)
/usr/local/go/src/runtime/malloc.go:786 +0x88 fp=0xc0001a6a68 sp=0xc0001a6a30 pc=0x40d058
runtime.mallocgc(0x50, 0x921f00, 0x1, 0xc423430e00)
/usr/local/go/src/runtime/malloc.go:939 +0x76e fp=0xc0001a6b08 sp=0xc0001a6a68 pc=0x40d96e
runtime.newobject(0x921f00, 0x0)
/usr/local/go/src/runtime/malloc.go:1068 +0x38 fp=0xc0001a6b38 sp=0xc0001a6b08 pc=0x40dd78
github.com/dgraph-io/badger.(*WriteBatch).Set(...)
/home/ubuntu/go/src/github.com/dgraph-io/badger/batch.go:92
github.com/dgraph-io/badger/badger/cmd.fill(0xd6ccc0, 0xc00014e300, 0x0, 0x8, 0x0, 0x0)
/home/ubuntu/go/src/github.com/dgraph-io/badger/badger/cmd/fill.go:82 +0x370 fp=0xc0001a6d58 sp=0xc0001a6b38 pc=0x84c370
github.com/spf13/cobra.(*Command).execute(0xd6ccc0, 0xc00014e280, 0x8, 0x8, 0xd6ccc0, 0xc00014e280)
/home/ubuntu/go/src/github.com/spf13/cobra/command.go:762 +0x465 fp=0xc0001a6e40 sp=0xc0001a6d58 pc=0x841065
github.com/spf13/cobra.(*Command).ExecuteC(0xd6d640, 0xc0000edf40, 0x432ef3, 0xd3634c)
/home/ubuntu/go/src/github.com/spf13/cobra/command.go:850 +0x2fc fp=0xc0001a6f18 sp=0xc0001a6e40 pc=0x841b0c
github.com/spf13/cobra.(*Command).Execute(...)
/home/ubuntu/go/src/github.com/spf13/cobra/command.go:800
github.com/dgraph-io/badger/badger/cmd.Execute()
/home/ubuntu/go/src/github.com/dgraph-io/badger/badger/cmd/root.go:40 +0x32 fp=0xc0001a6f78 sp=0xc0001a6f18 pc=0x850232
main.main()
/home/ubuntu/go/src/github.com/dgraph-io/badger/badger/main.go:41 +0x54 fp=0xc0001a6f98 sp=0xc0001a6f78 pc=0x8517b4
runtime.main()
/usr/local/go/src/runtime/proc.go:200 +0x20c fp=0xc0001a6fe0 sp=0xc0001a6f98 pc=0x43083c
runtime.goexit()
/usr/local/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001a6fe8 sp=0xc0001a6fe0 pc=0x45d521
goroutine 34 [IO wait, 11 minutes]:
internal/poll.runtime_pollWait(0x7fc77e888ea8, 0x72, 0x0)
/usr/local/go/src/runtime/netpoll.go:182 +0x56
internal/poll.(*pollDesc).wait(0xc0001ce098, 0x72, 0x0, 0x0, 0x953673)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(...)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0001ce080, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1ba
net.(*netFD).accept(0xc0001ce080, 0x916440, 0x50, 0xc0001ac320)
/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00015a038, 0xc000064a80, 0x7fc77e969460, 0x0)
/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).AcceptTCP(0xc00015a038, 0x40dd78, 0x30, 0x916440)
/usr/local/go/src/net/tcpsock.go:247 +0x48
net/http.tcpKeepAliveListener.Accept(0xc00015a038, 0x916440, 0xc000148660, 0x8c34e0, 0xd63cd0)
/usr/local/go/src/net/http/server.go:3264 +0x2f
net/http.(*Server).Serve(0xc0001aa000, 0xa0ba60, 0xc00015a038, 0x0, 0x0)
/usr/local/go/src/net/http/server.go:2859 +0x22d
net/http.(*Server).ListenAndServe(0xc0001aa000, 0xc0001aa000, 0xc0001a4fc0)
/usr/local/go/src/net/http/server.go:2797 +0xe4
net/http.ListenAndServe(...)
/usr/local/go/src/net/http/server.go:3037
main.main.func1()
/home/ubuntu/go/src/github.com/dgraph-io/badger/badger/main.go:32 +0x19f
created by main.main
/home/ubuntu/go/src/github.com/dgraph-io/badger/badger/main.go:29 +0x35
goroutine 35 [select]:
github.com/dgraph-io/badger/y.(*WaterMark).process(0xc0001502c0, 0xc00013ee20)
/home/ubuntu/go/src/github.com/dgraph-io/badger/y/watermark.go:207 +0x2d1
created by github.com/dgraph-io/badger/y.(*WaterMark).Init
/home/ubuntu/go/src/github.com/dgraph-io/badger/y/watermark.go:74 +0xc9
goroutine 36 [select]:
github.com/dgraph-io/badger/y.(*WaterMark).process(0xc000150300, 0xc00013ee20)
/home/ubuntu/go/src/github.com/dgraph-io/badger/y/watermark.go:207 +0x2d1
created by github.com/dgraph-io/badger/y.(*WaterMark).Init
/home/ubuntu/go/src/github.com/dgraph-io/badger/y/watermark.go:74 +0xc9
goroutine 37 [select]:
github.com/dgraph-io/badger.(*DB).updateSize(0xc000300000, 0xc00013eec0)
/home/ubuntu/go/src/github.com/dgraph-io/badger/db.go:952 +0x12f
created by github.com/dgraph-io/badger.Open
/home/ubuntu/go/src/github.com/dgraph-io/badger/db.go:266 +0x810
goroutine 185 [running]:
goroutine running on other thread; stack unavailable
created by github.com/dgraph-io/badger.(*levelsController).startCompact
/home/ubuntu/go/src/github.com/dgraph-io/badger/levels.go:329 +0x89
goroutine 186 [running]:
goroutine running on other thread; stack unavailable
created by github.com/dgraph-io/badger.(*levelsController).startCompact
/home/ubuntu/go/src/github.com/dgraph-io/badger/levels.go:329 +0x89
goroutine 187 [running]:
goroutine running on other thread; stack unavailable
created by github.com/dgraph-io/badger.Open
/home/ubuntu/go/src/github.com/dgraph-io/badger/db.go:279 +0x10cc
goroutine 189 [select]:
github.com/dgraph-io/badger.(*DB).doWrites(0xc000300000, 0xc00000e320)
/home/ubuntu/go/src/github.com/dgraph-io/badger/db.go:689 +0x2bc
created by github.com/dgraph-io/badger.Open
/home/ubuntu/go/src/github.com/dgraph-io/badger/db.go:312 +0xd19
The only logs in this timeframe for the system are these entries from /var/log/syslog
Apr 9 06:40:40 userver systemd[1]: Starting Cleanup of Temporary Directories...
Apr 9 06:40:40 userver systemd[1]: Started Cleanup of Temporary Directories.
badger info
information from the directory
EXTRA]
[2019-04-09T06:41:30-05:00] 001651.sst 68 MB
[2019-04-09T06:41:30-05:00] 001652.sst 68 MB
[2019-04-09T06:41:30-05:00] 001653.sst 68 MB
[2019-04-09T06:41:31-05:00] 001654.sst 65 MB
[2019-04-09T06:41:31-05:00] 001655.sst 68 MB
[2019-04-09T06:41:31-05:00] 001656.sst 68 MB
[2019-04-09T06:41:32-05:00] 001657.sst 0 B
[2019-04-09T06:41:32-05:00] 001658.sst 0 B
[2019-04-09T06:30:04-05:00] LOCK 5 B
[Summary]
Level 0 size: 388 MB
Level 1 size: 528 MB
Level 2 size: 2.6 GB
Level 3 size: 8.8 GB
Total index size: 12 GB
Value log size: 17 GB
Abnormalities:
9 extra files.
0 missing files.
0 empty files.
0 truncated manifests.