Polling based system modelling


#1

Thank you for building dgraph. It is an extremely useful tool.

Graph based analysis of our system has been working very nicely for me using dgraph i.e. read side works very nicely and efficiently for me. But I are facing some deployment challenges on the write side and need help.

Application:
Currently the system being modeled does not have a change set push mechanism. I have to pull the system state every x minutes and make a model out of it and then run analysis on it.

Scale:

  1. Small deployments with 50K nodes and ~50 predicates – ~250k triads
  2. Large deployments with 5M nodes and ~50 predicates - ~250M triads

Workflow:

  1. Collect system state every “x” minutes
  2. Build dgraph model and dgraph live load
  3. Perform Analysis using dgo’s queries
  4. Drop all state using dgo’s Dropall
  5. Repeat steps 1-4

Challenges:

  1. Memory footprint - Even for a very small deployments OOM issues with < 4G server memory
  2. Write throughput – Persistently degrading write throughput (dgraph live load time persistently increases)
  3. Errors - Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
    Lastcommit 31861 > current 31694. This would cause some commits to be lost.

Details:
Launched zero and alpha on a single 4G host using the following commands:
dgraph zero --profile_mode mem --my=localhost:5080 --log_dir /home/app/local-data/
dgraph alpha --badger.vlog disk --profile_mode mem --debugmode --pending_proposals 20 --max_retries 10 --lru_mb 1024 --zero localhost:5080 --log_dir /home/app/local-data/

Dgraph version : v1.0.12
Commit SHA-1 : 60d9ef0a
Commit timestamp : 2019-03-05 17:59:30 -0800
Branch : HEAD
Go version : go1.11.5

I0310 07:48:30.727075 41 server.go:117] Setting Badger table load option: mmap
I0310 07:48:30.727096 41 server.go:129] Setting Badger value log load option: disk

PPROF:
(pprof) top
Showing nodes accounting for 104511.83kB, 97.88% of 106775.89kB total
Dropped 299 nodes (cum <= 533.88kB)
Showing top 10 nodes out of 45
flat flat% sum% cum cum%
85200kB 79.79% 79.79% 85200kB 79.79% github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/badger/skl.newArena (inline)
15707.02kB 14.71% 94.50% 15707.02kB 14.71% github.com/dgraph-io/dgraph/dgraph/cmd/zero.(*Oracle).commit
1366.67kB 1.28% 95.78% 1366.67kB 1.28% github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/dgo/protos/api.(*TxnContext).Unmarshal
784kB 0.73% 96.52% 798.83kB 0.75% github.com/dgraph-io/dgraph/dgraph/cmd/zero.(*Oracle).Init
768kB 0.72% 97.24% 768kB 0.72% bufio.NewWriterSize
672.87kB 0.63% 97.87% 676.88kB 0.63% fmt.Sprintf
9.25kB 0.0087% 97.88% 85263.04kB 79.85% github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/badger.Open
4.02kB 0.0038% 97.88% 714.39kB 0.67% go.opencensus.io/trace.(*Span).lazyPrintfInternal
0 0% 97.88% 825.40kB 0.77% crypto/tls.(*Conn).Handshake
0 0% 97.88% 825.40kB 0.77% crypto/tls.(*Conn).clientHandshake

Persistently growing live loader times:
Iteration #0 - Collection Time: 8 sec, Dropall Time: 1 sec. (Schema rebuild + dgraph live load) Time: 18
Iteration #1 - Collection Time: 8 sec, Dropall Time: 3 sec. (Schema rebuild + dgraph live load) Time: 19
Iteration #2 - Collection Time: 7 sec, Dropall Time: 2 sec. (Schema rebuild + dgraph live load) Time: 16
Iteration #3 - Collection Time: 7 sec, Dropall Time: 2 sec. (Schema rebuild + dgraph live load) Time: 15
Iteration #4 - Collection Time: 7 sec, Dropall Time: 2 sec. (Schema rebuild + dgraph live load) Time: 17
Iteration #5 - Collection Time: 7 sec, Dropall Time: 2 sec. (Schema rebuild + dgraph live load) Time: 17
Iteration #6 - Collection Time: 8 sec, Dropall Time: 2 sec. (Schema rebuild + dgraph live load) Time: 19
….
Iteration #606 - Collection Time: 12 sec, Dropall Time: 28 sec. (Schema rebuild + dgraph live load) Time: 161
Iteration #607 - Collection Time: 13 sec, Dropall Time: 11 sec. (Schema rebuild + dgraph live load) Time: 121
Iteration #608 - Collection Time: 29 sec, Dropall Time: 51 sec. (Schema rebuild + dgraph live load) Time: 164
Iteration #609 - Collection Time: 14 sec, Dropall Time: 12 sec. (Schema rebuild + dgraph live load) Time: 77
Iteration #610 - Collection Time: 11 sec, Dropall Time: 10 sec. (Schema rebuild + dgraph live load) Time: 75
Iteration #611 - Collection Time: 12 sec, Dropall Time: 23 sec. (Schema rebuild + dgraph live load) Time: 126
Iteration #612 - Collection Time: 12 sec, Dropall Time: 11 sec. (Schema rebuild + dgraph live load) Time: 87
Iteration #613 - Collection Time: 13 sec, Dropall Time: 10 sec. (Schema rebuild + dgraph live load) Time: 79
Iteration #614 - Collection Time: 12 sec, Dropall Time: 11 sec. (Schema rebuild + dgraph live load) Time: 160
Iteration #615 - Collection Time: 16 sec, Dropall Time: 15 sec. (Schema rebuild + dgraph live load) Time: 91
Iteration #616 - Collection Time: 14 sec, Dropall Time: 12 sec. (Schema rebuild + dgraph live load) Time: 115
Iteration #617 - Collection Time: 21 sec, Dropall Time: 23 sec. (Schema rebuild + dgraph live load) Time: 103
Iteration #618 - Collection Time: 13 sec, Dropall Time: 15 sec. (Schema rebuild + dgraph live load) Time: 87
Iteration #619 - Collection Time: 15 sec, Dropall Time: 13 sec. (Schema rebuild + dgraph live load) Time: 138
Iteration #620 - Collection Time: 12 sec, Dropall Time: 9 sec. (Schema rebuild + dgraph live load) Time: 81

Rolling up key is persistently increasing
I0310 07:58:36.737999 41 draft.go:832] Rolled up 811561 keys. Done
I0310 08:03:37.216378 41 draft.go:832] Rolled up 1312774 keys. Done
I0310 08:08:35.801820 41 draft.go:832] Rolled up 580728 keys. Done
I0310 08:13:37.241667 41 draft.go:832] Rolled up 1051329 keys. Done
I0310 08:18:40.578270 41 draft.go:832] Rolled up 1574252 keys. Done
I0310 08:23:42.159081 41 draft.go:832] Rolled up 2015413 keys. Done
I0310 08:28:39.877649 41 draft.go:832] Rolled up 2498180 keys. Done
I0310 08:33:40.758281 41 draft.go:832] Rolled up 2933755 keys. Done
I0310 08:38:40.808806 41 draft.go:832] Rolled up 3301003 keys. Done
I0310 08:43:43.259903 41 draft.go:832] Rolled up 3805369 keys. Done
I0310 08:48:43.044181 41 draft.go:832] Rolled up 4240958 keys. Done
I0310 08:53:46.684116 41 draft.go:832] Rolled up 4659270 keys. Done
I0310 08:58:50.475537 41 draft.go:832] Rolled up 5077582 keys. Done
I0310 09:03:53.748848 41 draft.go:832] Rolled up 5457035 keys. Done
I0310 09:08:56.594330 41 draft.go:832] Rolled up 5861917 keys. Done
I0310 09:13:46.154505 41 draft.go:832] Rolled up 6175697 keys. Done
I0310 09:18:52.189320 41 draft.go:832] Rolled up 6541674 keys. Done
I0310 09:23:48.618286 41 draft.go:832] Rolled up 6907732 keys. Done
I0310 09:28:54.673409 41 draft.go:832] Rolled up 7273720 keys. Done
I0310 09:33:46.406966 41 draft.go:832] Rolled up 7587496 keys. Done
I0310 09:38:56.739350 41 draft.go:832] Rolled up 7901188 keys. Done
I0310 09:43:55.892759 41 draft.go:832] Rolled up 8162653 keys. Done
I0310 09:48:48.985765 41 draft.go:832] Rolled up 8528703 keys. Done
I0310 09:53:48.365227 41 draft.go:832] Rolled up 8842435 keys. Done
I0310 09:58:51.078716 41 draft.go:832] Rolled up 9181451 keys. Done
I0310 10:03:55.243785 41 draft.go:832] Rolled up 9469858 keys. Done
I0310 10:08:55.210827 41 draft.go:832] Rolled up 9783625 keys. Done
I0310 10:14:07.199900 41 draft.go:832] Rolled up 10097326 keys. Done
I0310 10:18:56.501713 41 draft.go:832] Rolled up 10411060 keys. Done
I0310 10:24:04.129261 41 draft.go:832] Rolled up 10724794 keys. Done
I0310 10:29:08.683819 41 draft.go:832] Rolled up 11038569 keys. Done
I0310 10:33:53.687167 41 draft.go:832] Rolled up 8819706 keys. Done
I0310 10:39:01.988586 41 draft.go:832] Rolled up 9238018 keys. Done
I0310 10:43:52.481476 41 draft.go:832] Rolled up 9604057 keys. Done
I0310 10:49:17.225194 41 draft.go:832] Rolled up 9970064 keys. Done
I0310 10:54:01.057382 41 draft.go:832] Rolled up 7578014 keys. Done
I0310 10:58:57.314680 41 draft.go:832] Rolled up 7980221 keys. Done
I0310 11:03:48.205559 41 draft.go:832] Rolled up 8310075 keys. Done
I0310 11:09:01.969841 41 draft.go:832] Rolled up 8676083 keys. Done
I0310 11:14:06.631869 41 draft.go:832] Rolled up 8937528 keys. Done
I0310 11:18:52.655785 41 draft.go:832] Rolled up 9251295 keys. Done
I0310 11:23:55.789366 41 draft.go:832] Rolled up 9617285 keys. Done
I0310 11:28:51.892827 41 draft.go:832] Rolled up 9931065 keys. Done
I0310 11:34:34.457566 41 draft.go:832] Rolled up 10244753 keys. Done
I0310 11:38:57.410809 41 draft.go:832] Rolled up 10558537 keys. Done
I0310 11:43:54.477776 41 draft.go:832] Rolled up 10872233 keys. Done
I0310 11:48:59.515405 41 draft.go:832] Rolled up 11238247 keys. Done
I0310 11:54:00.835314 41 draft.go:832] Rolled up 11499689 keys. Done
I0310 11:58:57.181773 41 draft.go:832] Rolled up 11761151 keys. Done
I0310 12:03:59.296035 41 draft.go:832] Rolled up 12074883 keys. Done
I0310 12:09:05.210024 41 draft.go:832] Rolled up 12359245 keys. Done
I0310 12:14:09.464689 41 draft.go:832] Rolled up 12597758 keys. Done
I0310 12:19:20.003213 41 draft.go:832] Rolled up 12859203 keys. Done
I0310 12:23:58.217910 41 draft.go:832] Rolled up 13120690 keys. Done
I0310 12:29:01.941091 41 draft.go:832] Rolled up 13340910 keys. Done
I0310 12:33:58.722786 41 draft.go:832] Rolled up 13668848 keys. Done
I0310 12:38:58.238137 41 draft.go:832] Rolled up 13980204 keys. Done
I0310 12:44:00.215551 41 draft.go:832] Rolled up 14271017 keys. Done
I0310 12:48:58.809155 41 draft.go:832] Rolled up 14532500 keys. Done
I0310 12:54:01.436111 41 draft.go:832] Rolled up 14846185 keys. Done
I0310 12:59:07.915644 41 draft.go:832] Rolled up 15107649 keys. Done
I0310 13:04:09.821216 41 draft.go:832] Rolled up 15316796 keys. Done
I0310 13:09:09.399790 41 draft.go:832] Rolled up 15578246 keys. Done
I0310 13:14:01.673231 41 draft.go:832] Rolled up 15839721 keys. Done
I0310 13:19:12.811899 41 draft.go:832] Rolled up 16085016 keys. Done
I0310 13:24:10.918377 41 draft.go:832] Rolled up 16310277 keys. Done
I0310 13:29:13.145464 41 draft.go:832] Rolled up 16571737 keys. Done
I0310 13:34:07.187589 41 draft.go:832] Rolled up 16833200 keys. Done
I0310 13:39:15.478029 41 draft.go:832] Rolled up 17094657 keys. Done
I0310 13:44:19.584203 41 draft.go:832] Rolled up 17303768 keys. Done
I0310 13:49:16.209979 41 draft.go:832] Rolled up 17565246 keys. Done
I0310 13:54:08.193395 41 draft.go:832] Rolled up 17774402 keys. Done
I0310 13:59:15.464287 41 draft.go:832] Rolled up 18035851 keys. Done
I0310 14:04:21.026813 41 draft.go:832] Rolled up 18244970 keys. Done
I0310 14:09:13.124543 41 draft.go:832] Rolled up 18506464 keys. Done
I0310 14:14:10.386755 41 draft.go:832] Rolled up 18715616 keys. Done
I0310 14:19:09.764494 41 draft.go:832] Rolled up 18924763 keys. Done
I0310 14:24:12.566202 41 draft.go:832] Rolled up 19144969 keys. Done
I0310 14:29:16.275373 41 draft.go:832] Rolled up 16568830 keys. Done
I0310 14:34:02.454556 41 draft.go:832] Rolled up 16830309 keys. Done
I0310 14:39:24.700718 41 draft.go:832] Rolled up 17091717 keys. Done
I0310 14:44:06.949160 41 draft.go:832] Rolled up 17323755 keys. Done
I0310 14:49:09.791672 41 draft.go:832] Rolled up 17573391 keys. Done
I0310 14:54:06.057725 41 draft.go:832] Rolled up 17846665 keys. Done
I0310 14:59:15.209656 41 draft.go:832] Rolled up 18085230 keys. Done
I0310 15:04:06.976614 41 draft.go:832] Rolled up 18294395 keys. Done
I0310 15:09:25.058237 41 draft.go:832] Rolled up 18555809 keys. Done
I0310 15:14:19.866535 41 draft.go:832] Rolled up 18748860 keys. Done
I0310 15:19:28.485475 41 draft.go:832] Rolled up 18974121 keys. Done
I0310 15:24:08.148052 41 draft.go:832] Rolled up 19143350 keys. Done
I0310 15:29:24.167319 41 draft.go:832] Rolled up 19340144 keys. Done
I0310 15:34:18.314207 41 draft.go:832] Rolled up 19549339 keys. Done
I0310 15:39:16.895901 41 draft.go:832] Rolled up 19758489 keys. Done
I0310 15:44:13.249204 41 draft.go:832] Rolled up 19967645 keys. Done
I0310 15:49:25.766061 41 draft.go:832] Rolled up 20229057 keys. Done
I0310 15:54:32.069269 41 draft.go:832] Rolled up 20385924 keys. Done
I0310 15:59:14.447480 41 draft.go:832] Rolled up 20595080 keys. Done
I0310 16:04:16.296523 41 draft.go:832] Rolled up 20804236 keys. Done
I0310 16:09:26.436652 41 draft.go:832] Rolled up 21013425 keys. Done
I0310 16:14:14.420381 41 draft.go:832] Rolled up 21222548 keys. Done
I0310 16:19:19.432049 41 draft.go:832] Rolled up 21431704 keys. Done
I0310 16:24:38.515674 41 draft.go:832] Rolled up 21588586 keys. Done
I0310 16:29:37.339863 41 draft.go:832] Rolled up 21745438 keys. Done
I0310 16:35:04.498308 41 draft.go:832] Rolled up 21902305 keys. Done
I0310 16:39:39.158184 41 draft.go:832] Rolled up 22059205 keys. Done
I0310 16:44:46.754500 41 draft.go:832] Rolled up 22163799 keys. Done
I0310 16:49:49.833046 41 draft.go:832] Rolled up 22268374 keys. Done
I0310 16:54:41.480663 41 draft.go:832] Rolled up 22372944 keys. Done
I0310 16:59:39.983152 41 draft.go:832] Rolled up 22531055 keys. Done
I0310 17:04:46.554135 41 draft.go:832] Rolled up 22686640 keys. Done
I0310 17:09:33.920894 41 draft.go:832] Rolled up 22843507 keys. Done
I0310 17:14:49.517425 41 draft.go:832] Rolled up 23000374 keys. Done
I0310 17:19:26.458257 41 draft.go:832] Rolled up 23157244 keys. Done
I0310 17:24:25.066285 41 draft.go:832] Rolled up 23314127 keys. Done
I0310 17:29:24.977495 41 draft.go:832] Rolled up 23471016 keys. Done
I0310 17:34:16.678580 41 draft.go:832] Rolled up 23586671 keys. Done
I0310 17:39:18.827368 41 draft.go:832] Rolled up 23732462 keys. Done

Errors:
Log file created at: 2019/03/10 11:57:50
Running on machine: model
Binary: Built with gc go1.11.5 for linux/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
E0310 11:57:50.751361 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 11:57:50.907513 41 draft.go:446] Lastcommit 31861 > current 31694. This would cause some commits to be lost.
E0310 12:08:33.791734 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 12:08:47.133355 41 draft.go:446] Lastcommit 32941 > current 32740. This would cause some commits to be lost.
E0310 12:52:33.442126 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 12:52:33.801909 41 draft.go:446] Lastcommit 37081 > current 37004. This would cause some commits to be lost.
E0310 13:01:08.263586 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 13:01:37.224349 41 draft.go:446] Lastcommit 37801 > current 37634. This would cause some commits to be lost.
E0310 13:38:35.900664 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 13:38:43.264303 41 draft.go:446] Lastcommit 41041 > current 40874. This would cause some commits to be lost.
E0310 13:58:37.409022 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 13:59:27.420201 41 draft.go:446] Lastcommit 42661 > current 42494. This would cause some commits to be lost.
E0310 14:24:33.944651 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 14:24:59.161431 41 draft.go:446] Lastcommit 44641 > current 44564. This would cause some commits to be lost.
E0310 14:31:08.027087 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 14:31:21.358396 41 draft.go:446] Lastcommit 45181 > current 45014. This would cause some commits to be lost.
E0310 14:58:34.868828 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 14:59:16.517739 41 draft.go:446] Lastcommit 47611 > current 47444. This would cause some commits to be lost.
E0310 15:07:07.540903 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 15:36:09.770776 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 15:36:48.390107 41 draft.go:446] Lastcommit 50311 > current 50144. This would cause some commits to be lost.
E0310 16:53:33.397967 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 16:53:43.390999 41 draft.go:446] Lastcommit 54991 > current 54824. This would cause some commits to be lost.
E0310 16:56:08.486855 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 16:56:26.050718 41 draft.go:446] Lastcommit 55081 > current 55004. This would cause some commits to be lost.
E0310 17:43:31.012058 41 groups.go:786] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
E0310 17:44:23.672109 41 draft.go:446] Lastcommit 57601 > current 57524. This would cause some commits to be lost.


(Manish R Jain) #2

Have you considered using bulk loader?


#3

Yes I am evaluating just that.
But I’ll have to shutdown alpha during bulk load, right? And alpha shutdown cannot be done from outside alpha. Is there a way to do that?


(Michel Conrado) #4

Yes, Bulk doesn’t work with an Alpha up.

If you’re using Docker o k8s try this repo https://github.com/MichelDiz/Dgraph-Bulk-Script

if you’re using Dgraph’s binaries. Just start the bulk with a Dgraph Zero and then start your Alpha from “~/dgraph/out/0/p”:

dgraph alpha -p ~/dgraph/out/0/p


#5

Thanks Michel. I am using Docker. I’ll try this.