Figuring optimal options for usage pattern

App Development
1

I’m developing an application and stumbled upon an issue with performance. I’m pretty sure it’s not a bug in badger, but just me not knowing how to use it properly. So here goes.

What I’m doing is basically writing few million lines with a single prefix (for example ‘abc_’), after that I’m reading them with prefix read (I’ve tried both with iterators and with streaming read) and writing back another batch with a different prefix (‘hjk_’).
Issue is, it works fine up to a certain number of keys. For example, reading 3M keys and writing another batch of the same size back - takes 250 seconds (it does some additional logic, so I’d say that time is ok-ish). But the moment I’m trying to do the same thing with 6M keys - it’s 1300 seconds (i.e. 2x increase in rows - 5x increase in time).

I’m writing in transactions of 256 kv pairs. Keys are around 50 bytes or less, values - 1-4kb.

2

@ibrahim any ideas why?

3

A bit of logs. It shows that depending on number or rows (or level1 size) - read speed differs 10x…

Db is created like that:

	opts := badger.DefaultOptions(path)
	opts.SyncWrites = false
	opts.ZSTDCompressionLevel = 0
    db, err := badger.Open(opts)

Stream is created like that:

	stream.NumGo = 16              // Set number of goroutines to use for iteration.
	stream.Prefix = []byte(prefix) // Leave nil for iteration over the whole DB.
    stream.KeyToList = nil

Badger is v2.0.3

Here are some logs from larger dataset case.

E 2021-01-12T09:22:26.673000480Z badger 2021/01/12 09:22:26 DEBUG: LOG Compact. Added 1971908 keys. Skipped 0 keys. Iteration took: 832.198687ms
E 2021-01-12T09:22:27.493672166Z badger 2021/01/12 09:22:27 DEBUG: LOG Compact. Added 1971802 keys. Skipped 0 keys. Iteration took: 820.667313ms
E 2021-01-12T09:22:27.921785927Z badger 2021/01/12 09:22:27 DEBUG: LOG Compact. Added 396834 keys. Skipped 0 keys. Iteration took: 428.065151ms
E 2021-01-12T09:22:28.265462788Z badger 2021/01/12 09:22:28 DEBUG: Discard stats: map[]
E 2021-01-12T09:22:28.295491234Z badger 2021/01/12 09:22:28 INFO: LOG Compact 0->1, del 5 tables, add 4 tables, took 3.266690702s
E 2021-01-12T09:22:28.295541543Z badger 2021/01/12 09:22:28 INFO: Compaction for level: 0 DONE
E 2021-01-12T09:22:28.297402778Z badger 2021/01/12 09:22:28 INFO: 1 compactor(s) succeeded. One or more tables from level 0 compacted.
E 2021-01-12T09:22:28.297442456Z badger 2021/01/12 09:22:28 INFO:E 2021-01-12T09:22:28.297449291Z badger 2021/01/12 09:22:28 INFO: Level: 0.      0 B Size.      0 B Max.
E 2021-01-12T09:22:28.297455055Z badger 2021/01/12 09:22:28 INFO: Level: 1.   235 MB Size.   268 MB Max.
E 2021-01-12T09:22:28.297461408Z badger 2021/01/12 09:22:28 INFO: Level: 2.      0 B Size.   2.7 GB Max.
E 2021-01-12T09:22:28.297467334Z badger 2021/01/12 09:22:28 INFO: Level: 3.      0 B Size.    27 GB Max.
E 2021-01-12T09:22:28.297473616Z badger 2021/01/12 09:22:28 INFO: Level: 4.      0 B Size.   268 GB Max.
E 2021-01-12T09:22:28.297480325Z badger 2021/01/12 09:22:28 INFO: Level: 5.      0 B Size.   2.7 TB Max.
E 2021-01-12T09:22:28.297486583Z badger 2021/01/12 09:22:28 INFO: Level: 6.      0 B Size.    27 TB Max.
E 2021-01-12T09:22:28.299022831Z badger 2021/01/12 09:22:28 INFO: All tables consolidated into one level. Flattening done.
E 2021-01-12T09:22:29.313431076Z badger 2021/01/12 09:22:29 INFO: Badger.Stream Time elapsed: 01s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:30.323656437Z badger 2021/01/12 09:22:30 INFO: Badger.Stream Time elapsed: 02s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:31.315020862Z badger 2021/01/12 09:22:31 INFO: Badger.Stream Time elapsed: 03s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:32.325999347Z badger 2021/01/12 09:22:32 INFO: Badger.Stream Time elapsed: 04s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:33.317266699Z badger 2021/01/12 09:22:33 INFO: Badger.Stream Time elapsed: 05s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:34.327936093Z badger 2021/01/12 09:22:34 INFO: Badger.Stream Time elapsed: 06s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:35.318900003Z badger 2021/01/12 09:22:35 INFO: Badger.Stream Time elapsed: 07s, bytes sent: 0 B, speed: 0 B/sec
E 2021-01-12T09:22:36.078281052Z badger 2021/01/12 09:22:36 INFO: Badger.Stream Created batch of size: 2.2 MB in 171.799152ms.
E 2021-01-12T09:22:36.319448956Z badger 2021/01/12 09:22:36 INFO: Badger.Stream Time elapsed: 08s, bytes sent: 2.2 MB, speed: 279 kB/sec
E 2021-01-12T09:22:36.594446077Z badger 2021/01/12 09:22:36 INFO: Badger.Stream Created batch of size: 4.2 MB in 252.283291ms.
E 2021-01-12T09:22:37.470907385Z badger 2021/01/12 09:22:37 INFO: Badger.Stream Created batch of size: 17 MB in 866.387781ms.
E 2021-01-12T09:22:40.622869213Z badger 2021/01/12 09:22:40 INFO: Badger.Stream Created batch of size: 38 MB in 3.104839905s.
E 2021-01-12T09:22:41.033121436Z badger 2021/01/12 09:22:41 INFO: Badger.Stream Created batch of size: 4.2 MB in 399.814919ms.
E 2021-01-12T09:22:41.033166967Z badger 2021/01/12 09:22:41 INFO: Badger.Stream Time elapsed: 12s, bytes sent: 65 MB, speed: 5.4 MB/sec
E 2021-01-12T09:22:41.312781183Z badger 2021/01/12 09:22:41 INFO: Badger.Stream Time elapsed: 13s, bytes sent: 65 MB, speed: 5.0 MB/sec
E 2021-01-12T09:22:42.057356595Z badger 2021/01/12 09:22:42 INFO: Badger.Stream Created batch of size: 4.2 MB in 323.243053ms.
E 2021-01-12T09:22:42.803653590Z badger 2021/01/12 09:22:42 INFO: Badger.Stream Created batch of size: 4.2 MB in 481.84533ms.
E 2021-01-12T09:22:42.803719767Z badger 2021/01/12 09:22:42 INFO: Badger.Stream Time elapsed: 14s, bytes sent: 74 MB, speed: 5.3 MB/sec
E 2021-01-12T09:22:43.320460785Z badger 2021/01/12 09:22:43 INFO: Badger.Stream Time elapsed: 15s, bytes sent: 74 MB, speed: 4.9 MB/sec
E 2021-01-12T09:22:44.331202362Z badger 2021/01/12 09:22:44 INFO: Badger.Stream Time elapsed: 16s, bytes sent: 74 MB, speed: 4.6 MB/sec
E 2021-01-12T09:22:45.321897940Z badger 2021/01/12 09:22:45 INFO: Badger.Stream Time elapsed: 17s, bytes sent: 74 MB, speed: 4.3 MB/sec
E 2021-01-12T09:22:46.313073124Z badger 2021/01/12 09:22:46 INFO: Badger.Stream Time elapsed: 18s, bytes sent: 74 MB, speed: 4.1 MB/sec
E 2021-01-12T09:22:46.789621307Z badger 2021/01/12 09:22:46 INFO: Badger.Stream Created batch of size: 4.2 MB in 292.155049ms.
E 2021-01-12T09:22:47.314640789Z badger 2021/01/12 09:22:47 INFO: Badger.Stream Time elapsed: 19s, bytes sent: 78 MB, speed: 4.1 MB/sec
E 2021-01-12T09:22:48.218183151Z badger 2021/01/12 09:22:48 INFO: Badger.Stream Created batch of size: 4.2 MB in 354.909718ms.
E 2021-01-12T09:22:48.321814724Z badger 2021/01/12 09:22:48 INFO: Badger.Stream Time elapsed: 20s, bytes sent: 82 MB, speed: 4.1 MB/sec
E 2021-01-12T09:22:49.312918191Z badger 2021/01/12 09:22:49 INFO: Badger.Stream Time elapsed: 21s, bytes sent: 82 MB, speed: 3.9 MB/sec
E 2021-01-12T09:22:50.324965351Z badger 2021/01/12 09:22:50 INFO: Badger.Stream Time elapsed: 22s, bytes sent: 82 MB, speed: 3.7 MB/sec
E 2021-01-12T09:22:51.316073433Z badger 2021/01/12 09:22:51 INFO: Badger.Stream Time elapsed: 23s, bytes sent: 82 MB, speed: 3.6 MB/sec
E 2021-01-12T09:22:52.050502771Z badger 2021/01/12 09:22:52 INFO: Badger.Stream Created batch of size: 4.2 MB in 282.180495ms.
E 2021-01-12T09:22:52.327820406Z badger 2021/01/12 09:22:52 INFO: Badger.Stream Time elapsed: 24s, bytes sent: 86 MB, speed: 3.6 MB/sec
E 2021-01-12T09:22:52.956042893Z badger 2021/01/12 09:22:52 INFO: Badger.Stream Created batch of size: 4.2 MB in 241.496872ms.
E 2021-01-12T09:22:53.269350157Z badger 2021/01/12 09:22:53 INFO: Badger.Stream Created batch of size: 4.2 MB in 310.627869ms.
E 2021-01-12T09:22:53.330453533Z badger 2021/01/12 09:22:53 INFO: Badger.Stream Time elapsed: 25s, bytes sent: 95 MB, speed: 3.8 MB/sec
E 2021-01-12T09:22:54.245513808Z badger 2021/01/12 09:22:54 INFO: Badger.Stream Created batch of size: 4.2 MB in 305.376752ms.
E 2021-01-12T09:22:54.321375143Z badger 2021/01/12 09:22:54 INFO: Badger.Stream Time elapsed: 26s, bytes sent: 99 MB, speed: 3.8 MB/sec
E 2021-01-12T09:22:55.312405832Z badger 2021/01/12 09:22:55 INFO: Badger.Stream Time elapsed: 27s, bytes sent: 99 MB, speed: 3.7 MB/sec
E 2021-01-12T09:22:56.323444262Z badger 2021/01/12 09:22:56 INFO: Badger.Stream Time elapsed: 28s, bytes sent: 99 MB, speed: 3.5 MB/sec
E 2021-01-12T09:22:57.314521185Z badger 2021/01/12 09:22:57 INFO: Badger.Stream Time elapsed: 29s, bytes sent: 99 MB, speed: 3.4 MB/sec
E 2021-01-12T09:22:58.325847745Z badger 2021/01/12 09:22:58 INFO: Badger.Stream Time elapsed: 30s, bytes sent: 99 MB, speed: 3.3 MB/sec
E 2021-01-12T09:22:59.197757677Z badger 2021/01/12 09:22:59 INFO: Badger.Stream Created batch of size: 4.2 MB in 323.354417ms.
E 2021-01-12T09:22:59.316538627Z badger 2021/01/12 09:22:59 INFO: Badger.Stream Time elapsed: 31s, bytes sent: 103 MB, speed: 3.3 MB/sec
E 2021-01-12T09:23:00.328260711Z badger 2021/01/12 09:23:00 INFO: Badger.Stream Time elapsed: 32s, bytes sent: 103 MB, speed: 3.2 MB/sec
E 2021-01-12T09:23:01.319073586Z badger 2021/01/12 09:23:01 INFO: Badger.Stream Time elapsed: 33s, bytes sent: 103 MB, speed: 3.1 MB/sec
E 2021-01-12T09:23:02.330020911Z badger 2021/01/12 09:23:02 INFO: Badger.Stream Time elapsed: 34s, bytes sent: 103 MB, speed: 3.0 MB/sec

......

E 2021-01-12T09:38:08.342482619Z badger 2021/01/12 09:38:08 INFO: Badger.Stream Time elapsed: 15m40s, bytes sent: 3.3 GB, speed: 3.5 MB/sec
E 2021-01-12T09:38:08.656768058Z badger 2021/01/12 09:38:08 INFO: Badger.Stream Created batch of size: 4.2 MB in 118.708982ms.
E 2021-01-12T09:38:08.966824236Z badger 2021/01/12 09:38:08 INFO: Badger.Stream Created batch of size: 4.2 MB in 130.700352ms.
E 2021-01-12T09:38:09.326264306Z badger 2021/01/12 09:38:09 INFO: Badger.Stream Created batch of size: 4.2 MB in 114.966563ms.
E 2021-01-12T09:38:09.326310501Z badger 2021/01/12 09:38:09 INFO: Badger.Stream Time elapsed: 15m41s, bytes sent: 3.3 GB, speed: 3.5 MB/sec
E 2021-01-12T09:38:09.432720253Z badger 2021/01/12 09:38:09 INFO: Badger.Stream Created batch of size: 2.4 MB in 55.641721ms.

db folder looks like that:

# ls -la /db
total 7054984
drwxrwxrwx 2 root root      4096 Jan 12 09:58 .
drwxr-xr-x 1 root root      4096 Jan 12 09:20 ..
-rw------- 1 root root 517064057 Jan 12 09:21 000000.vlog
-rw------- 1 root root 518355720 Jan 12 09:21 000001.vlog
-rw------- 1 root root 518814861 Jan 12 09:21 000002.vlog
-rw------- 1 root root 519389162 Jan 12 09:22 000003.vlog
-rw------- 1 root root 519333986 Jan 12 09:22 000004.vlog
-rw------- 1 root root 519354124 Jan 12 09:22 000005.vlog
-rw------- 1 root root 523834346 Jan 12 09:40 000006.vlog
-rw------- 1 root root 528913256 Jan 12 09:43 000007.vlog
-rw------- 1 root root 528663764 Jan 12 09:45 000008.vlog
-rw------- 1 root root 532186075 Jan 12 09:48 000009.vlog
-rw------- 1 root root 531064533 Jan 12 09:52 000010.vlog
-rw------- 1 root root 530308193 Jan 12 09:55 000011.vlog
-rw------- 1 root root 474239399 Jan 12 09:58 000012.vlog
-rw------- 1 root root  73934489 Jan 12 09:57 000035.sst
-rw------- 1 root root    166997 Jan 12 09:58 000037.sst
-rw------- 1 root root  54098642 Jan 12 09:58 000038.sst
-rw------- 1 root root  73495966 Jan 12 09:58 000039.sst
-rw------- 1 root root  73495942 Jan 12 09:58 000040.sst
-rw------- 1 root root  73934542 Jan 12 09:58 000041.sst
-rw------- 1 root root  73934543 Jan 12 09:58 000042.sst
-rw------- 1 root root  39604705 Jan 12 09:58 000043.sst
-rw------- 1 root root        28 Jan 12 09:20 KEYREGISTRY
-rw-r--r-- 1 root root         2 Jan 12 09:20 LOCK
-rw------- 1 root root       364 Jan 12 09:58 MANIFEST

Same code, but with less data:

E 2021-01-12T10:05:42.129025889Z badger 2021/01/12 10:05:42 INFO: Level: 0.    86 MB Size.      0 B Max.
E 2021-01-12T10:05:42.129037786Z badger 2021/01/12 10:05:42 INFO: Level: 1.      0 B Size.   268 MB Max.
E 2021-01-12T10:05:42.129045296Z badger 2021/01/12 10:05:42 INFO: Level: 2.      0 B Size.   2.7 GB Max.
E 2021-01-12T10:05:42.129052106Z badger 2021/01/12 10:05:42 INFO: Level: 3.      0 B Size.    27 GB Max.
E 2021-01-12T10:05:42.129059106Z badger 2021/01/12 10:05:42 INFO: Level: 4.      0 B Size.   268 GB Max.
E 2021-01-12T10:05:42.129065472Z badger 2021/01/12 10:05:42 INFO: Level: 5.      0 B Size.   2.7 TB Max.
E 2021-01-12T10:05:42.129072159Z badger 2021/01/12 10:05:42 INFO: Level: 6.      0 B Size.    27 TB Max.
E 2021-01-12T10:05:42.129078996Z badger 2021/01/12 10:05:42 INFO: All tables consolidated into one level. Flattening done.
E 2021-01-12T10:05:42.531143911Z badger 2021/01/12 10:05:42 INFO: Badger.Stream Created batch of size: 8.4 MB in 352.064653ms.
E 2021-01-12T10:05:46.286431315Z badger 2021/01/12 10:05:46 INFO: Badger.Stream Created batch of size: 106 MB in 3.529047959s.
E 2021-01-12T10:05:46.286866954Z badger 2021/01/12 10:05:46 INFO: Badger.Stream Time elapsed: 04s, bytes sent: 115 MB, speed: 29 MB/sec
E 2021-01-12T10:05:50.265294641Z badger 2021/01/12 10:05:50 INFO: Badger.Stream Created batch of size: 139 MB in 3.770253278s.
E 2021-01-12T10:05:50.265420223Z badger 2021/01/12 10:05:50 INFO: Badger.Stream Time elapsed: 08s, bytes sent: 254 MB, speed: 32 MB/sec
E 2021-01-12T10:05:54.200690889Z badger 2021/01/12 10:05:54 INFO: Badger.Stream Created batch of size: 139 MB in 3.726223565s.
E 2021-01-12T10:05:58.292693168Z badger 2021/01/12 10:05:58 INFO: Badger.Stream Created batch of size: 139 MB in 3.968274934s.
E 2021-01-12T10:06:02.793288543Z badger 2021/01/12 10:06:02 INFO: Badger.Stream Created batch of size: 139 MB in 4.077728052s.
E 2021-01-12T10:06:02.797853871Z badger 2021/01/12 10:06:02 INFO: Badger.Stream Time elapsed: 20s, bytes sent: 671 MB, speed: 34 MB/sec
E 2021-01-12T10:06:03.618112109Z badger 2021/01/12 10:06:03 INFO: Badger.Stream Created batch of size: 30 MB in 800.871584ms.
E 2021-01-12T10:06:03.725143841Z badger 2021/01/12 10:06:03 INFO: Badger.Stream Created batch of size: 4.2 MB in 104.169267ms.
E 2021-01-12T10:06:03.725219878Z badger 2021/01/12 10:06:03 INFO: Badger.Stream Time elapsed: 21s, bytes sent: 704 MB, speed: 34 MB/sec
E 2021-01-12T10:06:04.155528275Z badger 2021/01/12 10:06:04 INFO: Badger.Stream Created batch of size: 4.2 MB in 125.427446ms.
E 2021-01-12T10:06:04.155620732Z badger 2021/01/12 10:06:04 INFO: Badger.Stream Time elapsed: 22s, bytes sent: 708 MB, speed: 32 MB/sec
E 2021-01-12T10:06:04.592828904Z badger 2021/01/12 10:06:04 INFO: Badger.Stream Created batch of size: 4.2 MB in 112.17097ms.
E 2021-01-12T10:06:04.881632248Z badger 2021/01/12 10:06:04 INFO: Badger.Stream Created batch of size: 4.2 MB in 100.503026ms.
E 2021-01-12T10:06:05.129869002Z badger 2021/01/12 10:06:05 INFO: Badger.Stream Time elapsed: 23s, bytes sent: 717 MB, speed: 31 MB/sec
E 2021-01-12T10:06:05.289992779Z badger 2021/01/12 10:06:05 INFO: Badger.Stream Created batch of size: 4.2 MB in 110.289111ms.
E 2021-01-12T10:06:05.445929881Z badger 2021/01/12 10:06:05 INFO: Badger.Stream Created batch of size: 4.2 MB in 136.135612ms.
E 2021-01-12T10:06:05.588782661Z badger 2021/01/12 10:06:05 INFO: Badger.Stream Created batch of size: 4.2 MB in 105.507628ms.
E 2021-01-12T10:06:05.873742442Z badger 2021/01/12 10:06:05 INFO: Badger.Stream Created batch of size: 4.2 MB in 110.543084ms.
E 2021-01-12T10:06:06.082028824Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Created batch of size: 4.2 MB in 144.211828ms.
E 2021-01-12T10:06:06.197760849Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Created batch of size: 4.2 MB in 99.04789ms.
E 2021-01-12T10:06:06.197805547Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Time elapsed: 24s, bytes sent: 742 MB, speed: 31 MB/sec
E 2021-01-12T10:06:06.497731157Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Created batch of size: 4.2 MB in 149.915505ms.
E 2021-01-12T10:06:06.617079416Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Created batch of size: 4.2 MB in 116.789795ms.
E 2021-01-12T10:06:06.854789326Z badger 2021/01/12 10:06:06 INFO: Badger.Stream Created batch of size: 4.2 MB in 153.26692ms.
E 2021-01-12T10:06:07.089937944Z badger 2021/01/12 10:06:07 INFO: Badger.Stream Created batch of size: 4.2 MB in 133.591477ms.
E 2021-01-12T10:06:07.129827054Z badger 2021/01/12 10:06:07 INFO: Badger.Stream Time elapsed: 25s, bytes sent: 759 MB, speed: 30 MB/sec