Before:
This is the memory profile for dgraphassigner
without and with my sync.Pool
change.
Before
# From master branch
$ go build . && ./dgraphassigner --cpuprofile cpu.prof --memprofile mem.prof --debugmode --instanceIdx 0 --profile ":8080" --rdfgzips ~/benchmarks/data/names.gz,/home/mrjn/benchmarks/data/rdf-films.gz --uids ~/dgraph/u
$ go tool pprof dgraphassigner mem.prof
(pprof) top20
1950.50MB of 1991.59MB total (97.94%)
Dropped 99 nodes (cum <= 9.96MB)
Showing top 20 nodes out of 49 (cum >= 15.50MB)
flat flat% sum% cum cum%
321.56MB 16.15% 16.15% 321.56MB 16.15% github.com/dgraph-io/dgraph/posting.NewList
282.52MB 14.19% 30.33% 282.52MB 14.19% github.com/dgraph-io/dgraph/loader.(*state).readLines
217.50MB 10.92% 41.25% 360.01MB 18.08% github.com/dgraph-io/dgraph/uid.(*lockManager).newOrExisting
205.01MB 10.29% 51.55% 205.01MB 10.29% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newMockEntry
199.01MB 9.99% 61.54% 405.51MB 20.36% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).getBucketByIndex
142MB 7.13% 68.67% 142MB 7.13% github.com/dgraph-io/dgraph/uid.glob..func1
109.89MB 5.52% 74.19% 109.89MB 5.52% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).grow
97.50MB 4.90% 79.08% 97.50MB 4.90% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newRealEntryWithHashCode
92.50MB 4.64% 83.73% 92.50MB 4.64% github.com/dgraph-io/dgraph/posting.(*List).init
63.50MB 3.19% 86.92% 69.50MB 3.49% github.com/dgraph-io/dgraph/posting.(*List).getPostingList
56.50MB 2.84% 89.75% 205.99MB 10.34% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).PutIfMissing
38MB 1.91% 91.66% 38MB 1.91% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).add
32.50MB 1.63% 93.29% 1535.98MB 77.12% github.com/dgraph-io/dgraph/uid.GetOrAssign
29MB 1.46% 94.75% 41MB 2.06% github.com/dgraph-io/dgraph/rdf.Parse
29MB 1.46% 96.20% 991.56MB 49.79% github.com/dgraph-io/dgraph/posting.GetOrCreate
14.50MB 0.73% 96.93% 14.50MB 0.73% github.com/dgraph-io/dgraph/vendor/github.com/google/flatbuffers/go.(*Builder).growByteBuffer
14.50MB 0.73% 97.66% 14.50MB 0.73% strings.makeCutsetFunc
2.50MB 0.13% 97.79% 78.41MB 3.94% github.com/dgraph-io/dgraph/posting.(*List).AddMutation
2MB 0.1% 97.89% 45.50MB 2.28% github.com/dgraph-io/dgraph/loader.(*state).parseStream
1MB 0.05% 97.94% 15.50MB 0.78% github.com/dgraph-io/dgraph/posting.newPosting
Less important, but for completeness sake:
$ go tool pprof dgraphassigner cpu.prof ~/go/src/github.com/dgraph-io/dgraph/cmd/dgraphassigner
Entering interactive mode (type "help" for commands)
(pprof) top20
797.71s of 1025.79s total (77.77%)
Dropped 476 nodes (cum <= 5.13s)
Showing top 20 nodes out of 146 (cum >= 157.60s)
flat flat% sum% cum cum%
268.12s 26.14% 26.14% 273.62s 26.67% runtime.cgocall
117.51s 11.46% 37.59% 302.41s 29.48% runtime.scanobject
105.77s 10.31% 47.90% 105.77s 10.31% runtime.heapBitsForObject
85.41s 8.33% 56.23% 95.02s 9.26% runtime.greyobject
55.54s 5.41% 61.65% 208.15s 20.29% runtime.mallocgc
24.86s 2.42% 64.07% 25.41s 2.48% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).isDeleted
18.11s 1.77% 65.83% 19.49s 1.90% runtime.heapBitsSetType
14.99s 1.46% 67.30% 37.07s 3.61% runtime.gcmarkwb_m
14.08s 1.37% 68.67% 233.46s 22.76% runtime.systemstack
13.69s 1.33% 70.00% 40.28s 3.93% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).next
12.45s 1.21% 71.22% 12.45s 1.21% runtime/internal/atomic.Or8
11.32s 1.10% 72.32% 11.32s 1.10% runtime.memmove
8.29s 0.81% 73.13% 8.29s 0.81% runtime.memclr
8.23s 0.8% 73.93% 40.27s 3.93% runtime.writebarrierptr_nostore1
8.14s 0.79% 74.72% 8.14s 0.79% sync/atomic.LoadPointer
7.27s 0.71% 75.43% 7.27s 0.71% runtime/internal/atomic.Xchg
6.39s 0.62% 76.06% 16.40s 1.60% runtime.deferreturn
6.34s 0.62% 76.67% 6.34s 0.62% runtime._ExternalCode
6.32s 0.62% 77.29% 22.08s 2.15% runtime.shade
4.88s 0.48% 77.77% 157.60s 15.36% runtime.newobject
After the change
$ go tool pprof dgraphassigner mem.prof
(pprof) top20
1766.72MB of 1787.79MB total (98.82%)
Dropped 97 nodes (cum <= 8.94MB)
Showing top 20 nodes out of 40 (cum >= 46MB)
flat flat% sum% cum cum%
271.02MB 15.16% 15.16% 271.02MB 15.16% github.com/dgraph-io/dgraph/loader.(*state).readLines
268.05MB 14.99% 30.15% 268.05MB 14.99% github.com/dgraph-io/dgraph/posting.glob..func1
228.01MB 12.75% 42.91% 450.51MB 25.20% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).getBucketByIndex
222.51MB 12.45% 55.35% 222.51MB 12.45% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newMockEntry
216MB 12.08% 67.43% 351.01MB 19.63% github.com/dgraph-io/dgraph/uid.(*lockManager).newOrExisting
135MB 7.55% 74.99% 135MB 7.55% github.com/dgraph-io/dgraph/uid.glob..func1
83MB 4.64% 79.63% 83MB 4.64% github.com/dgraph-io/dgraph/posting.(*List).init
68.50MB 3.83% 83.46% 68.50MB 3.83% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newRealEntryWithHashCode
64.62MB 3.61% 87.07% 64.62MB 3.61% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).grow
59.50MB 3.33% 90.40% 59.50MB 3.33% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).add
53MB 2.96% 93.37% 186.12MB 10.41% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).PutIfMissing
46MB 2.57% 95.94% 46MB 2.57% github.com/dgraph-io/dgraph/posting.(*List).getPostingList
27MB 1.51% 97.45% 1349.20MB 75.47% github.com/dgraph-io/dgraph/uid.GetOrAssign
12.50MB 0.7% 98.15% 923.19MB 51.64% github.com/dgraph-io/dgraph/posting.GetOrCreate
11MB 0.62% 98.77% 373.51MB 20.89% github.com/dgraph-io/dgraph/posting.getFromMap
0.50MB 0.028% 98.79% 1349.70MB 75.50% github.com/dgraph-io/dgraph/loader.(*state).assignUidsOnly
0.50MB 0.028% 98.82% 117MB 6.54% github.com/dgraph-io/dgraph/posting.process
0 0% 98.82% 1349.20MB 75.47% github.com/dgraph-io/dgraph/loader.(*state).assignUid
0 0% 98.82% 46MB 2.57% github.com/dgraph-io/dgraph/posting.(*List).Length
0 0% 98.82% 46MB 2.57% github.com/dgraph-io/dgraph/posting.(*List).length
And CPU:
$ go tool pprof dgraphassigner cpu.prof ~/go/src/github.com/dgraph-io/dgraph/cmd/dgraphassigner
Entering interactive mode (type "help" for commands)
(pprof) top20
840.56s of 1073.19s total (78.32%)
Dropped 441 nodes (cum <= 5.37s)
Showing top 20 nodes out of 151 (cum >= 19.68s)
flat flat% sum% cum cum%
266.35s 24.82% 24.82% 271.59s 25.31% runtime.cgocall
134.65s 12.55% 37.37% 345.35s 32.18% runtime.scanobject
116.86s 10.89% 48.25% 116.86s 10.89% runtime.heapBitsForObject
96.97s 9.04% 57.29% 108.21s 10.08% runtime.greyobject
59.19s 5.52% 62.81% 238.92s 22.26% runtime.mallocgc
24.70s 2.30% 65.11% 25.22s 2.35% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).isDeleted
18.47s 1.72% 66.83% 19.63s 1.83% runtime.heapBitsSetType
14.60s 1.36% 68.19% 40.73s 3.80% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).next
13.72s 1.28% 69.47% 33.40s 3.11% runtime.gcmarkwb_m
13.47s 1.26% 70.72% 259.76s 24.20% runtime.systemstack
13.36s 1.24% 71.97% 13.36s 1.24% runtime/internal/atomic.Or8
11.91s 1.11% 73.08% 11.91s 1.11% runtime.memmove
8.64s 0.81% 73.88% 8.64s 0.81% runtime.memclr
7.96s 0.74% 74.62% 7.96s 0.74% sync/atomic.LoadPointer
7.55s 0.7% 75.33% 18.61s 1.73% runtime.deferreturn
7.21s 0.67% 76.00% 7.21s 0.67% runtime._ExternalCode
7.17s 0.67% 76.67% 7.17s 0.67% runtime/internal/atomic.Xchg
6.56s 0.61% 77.28% 34.92s 3.25% runtime.writebarrierptr_nostore1
5.84s 0.54% 77.82% 160.71s 14.97% runtime.newobject
5.38s 0.5% 78.32% 19.68s 1.83% runtime.shade
The particular code related to posting.List.
ROUTINE ======================== github.com/dgraph-io/dgraph/posting.glob..func1 in /home/mrjn/go/src/github.com/dgraph-io/dgraph/posting/list.go
268.05MB 268.05MB (flat, cum) 14.99% of Total
. . 94: listPool.Put(l)
. . 95:}
. . 96:
. . 97:var listPool = sync.Pool{
. . 98: New: func() interface{} {
268.05MB 268.05MB 99: return &List{}
. . 100: },
. . 101:}
. . 102:
. . 103:func getNew() *List {
. . 104: l := listPool.Get().(*List)
So, the memory usage regarding posting.List
decreases from 321MB to 268MB, which is down to 83.4%, so around 16% savings in memory.
TODO: Fill this in for dgraphloader.
$ go build . && ./dgraphloader --cpuprofile cpu.prof --memprofile mem.prof --instanceIdx 0 --postings ~/dgraph/p --rdfgzips ~/benchmarks/data/names.gz,/home/mrjn/benchmarks/data/rdf-films.gz --uids ~/dgraph/u --numCpu 1
....
INFO[0712] Counters ignored=0 len_cnq=0 package=loader parsed=2215925 pending=1393 processed=2214532 read=2224419
2016/09/18 14:57:21 lists.go:95: List merge counters. added: 0 merged: 32481 clean: 0 pending: 0 mapsize: 1706056 dirtysize: 487782
INFO[0713] Counters ignored=0 len_cnq=424 package=loader parsed=2224702 pending=3424 processed=2221278 read=2231160
INFO[0714] Counters ignored=0 len_cnq=10000 package=loader parsed=2237642 pending=13000 processed=2224642 read=2247643
INFO[0715] Counters ignored=0 len_cnq=10000 package=loader parsed=2238855 pending=13000 processed=2225855 read=2248856
INFO[0716] Counters ignored=0 len_cnq=10000 package=loader parsed=2239943 pending=13000 processed=2226943 read=2249944
INFO[0717] Counters ignored=0 len_cnq=10000 package=loader parsed=2243791 pending=13000 processed=2230791 read=2253299
INFO[0731] Counters ignored=0 len_cnq=0 package=loader parsed=2284337 pending=2853 processed=2281484 read=2294338
[1] 8330 killed ./dgraphloader --cpuprofile cpu.prof --memprofile mem.prof --instanceIdx 0
For whatever reason, dgraphloader
keeps getting killed. Even with a single CPU.
From master branch, the loader crashed on my desktop as well
With this change on my desktop, it actually completed, and here’s the memory profile.
(pprof) top20
1476.24MB of 1486.41MB total (99.32%)
Dropped 93 nodes (cum <= 7.43MB)
Showing top 20 nodes out of 54 (cum >= 46.50MB)
flat flat% sum% cum cum%
437.58MB 29.44% 29.44% 437.58MB 29.44% github.com/dgraph-io/dgraph/posting.glob..func1
246.51MB 16.58% 46.02% 246.51MB 16.58% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newMockEntry
244.01MB 16.42% 62.44% 490.51MB 33.00% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).getBucketByIndex
94MB 6.32% 68.76% 94MB 6.32% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.newRealEntryWithHashCode
66MB 4.44% 73.20% 66MB 4.44% github.com/dgraph-io/dgraph/posting.(*List).init
66MB 4.44% 77.64% 224.63MB 15.11% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).PutIfMissing
64.62MB 4.35% 81.99% 64.62MB 4.35% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*Hash).grow
61.50MB 4.14% 86.13% 61.50MB 4.14% github.com/dgraph-io/dgraph/vendor/github.com/zond/gotomic.(*element).add
55MB 3.70% 89.83% 55MB 3.70% github.com/dgraph-io/dgraph/posting.(*List).merge
46.50MB 3.13% 92.96% 46.50MB 3.13% bytes.makeSlice
24.50MB 1.65% 94.61% 24.50MB 1.65% github.com/dgraph-io/dgraph/posting.(*List).getPostingList
20MB 1.35% 95.95% 66.50MB 4.47% github.com/dgraph-io/dgraph/posting.Key
16MB 1.08% 97.03% 384.51MB 25.87% github.com/dgraph-io/dgraph/posting.getFromMap
15.50MB 1.04% 98.07% 1128.22MB 75.90% github.com/dgraph-io/dgraph/posting.GetOrCreate
15.50MB 1.04% 99.11% 540.38MB 36.35% github.com/dgraph-io/dgraph/uid.Get
3MB 0.2% 99.32% 7.50MB 0.5% runtime.allocm
0 0% 99.32% 27MB 1.82% bytes.(*Buffer).Write
0 0% 99.32% 19.50MB 1.31% bytes.(*Buffer).WriteByte
0 0% 99.32% 19.50MB 1.31% bytes.(*Buffer).WriteRune
0 0% 99.32% 46.50MB 3.13% bytes.(*Buffer).grow
(pprof) list posting.glob..func1
Total: 1.45GB
ROUTINE ======================== github.com/dgraph-io/dgraph/posting.glob..func1 in /home/mrjn/go/src/github.com/dgraph-io/dgraph/posting/list.go
437.58MB 437.58MB (flat, cum) 29.44% of Total
. . 94: listPool.Put(l)
. . 95:}
. . 96:
. . 97:var listPool = sync.Pool{
. . 98: New: func() interface{} {
437.58MB 437.58MB 99: return &List{}
. . 100: },
. . 101:}
. . 102:
. . 103:func getNew() *List {
. . 104: l := listPool.Get().(*List)
So, I think it does alleviate the memory usage by posting.List. Sending out the PR.