Using sync.Pool for posting.List

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.

1 Like

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.