bolt benchmarking

db-benchmarks.md

old (leveldb) vs new (bolt):

jb@syno:~/src/github.com/syncthing/syncthing/internal/db (leveldb) $ go test -bench . -benchmem > ~/a
jb@syno:~/src/github.com/syncthing/syncthing/internal/db (leveldb) $ git checkout boltv2
Switched to branch 'boltv2'
jb@syno:~/src/github.com/syncthing/syncthing/internal/db (boltv2) $ go test -bench . -benchmem > ~/b
jb@syno:~/src/github.com/syncthing/syncthing/internal/db (boltv2) $ benchcmp ~/a ~/b
benchmark                    old ns/op     new ns/op     delta
Benchmark10kReplace          68852446      24119329      -64.97%
Benchmark10kUpdateChg        337298885     159390764     -52.74%
Benchmark10kUpdateSme        98782170      63312555      -35.91%
Benchmark10kUpdateChgOne     7420704       2626382       -64.61%
Benchmark10kNeed2k           43319692      21381319      -50.64%
Benchmark10kHaveFullList     16177255      15942284      -1.45%
Benchmark10kGlobal           111230379     44286628      -60.18%

benchmark                    old allocs     new allocs     delta
Benchmark10kReplace          178152         104740         -41.21%
Benchmark10kUpdateChg        567969         636204         +12.01%
Benchmark10kUpdateSme        238678         310134         +29.94%
Benchmark10kUpdateChgOne     89             283            +217.98%
Benchmark10kNeed2k           105388         96036          -8.87%
Benchmark10kHaveFullList     60230          60042          -0.31%
Benchmark10kGlobal           237501         200043         -15.77%

benchmark                    old bytes     new bytes     delta
Benchmark10kReplace          8243850       3017702       -63.39%
Benchmark10kUpdateChg        47108304      34855307      -26.01%
Benchmark10kUpdateSme        16116618      15353259      -4.74%
Benchmark10kUpdateChgOne     10956         122364        +1016.87%
Benchmark10kNeed2k           6565802       4848204       -26.16%
Benchmark10kHaveFullList     7611151       7585034       -0.34%
Benchmark10kGlobal           21427039      13825136      -35.48%
jb@syno:~/src/github.com/syncthing/syncthing/internal/db (boltv2) $ 

Bolt is vastly faster and allocates less memory, except in the fs.Update(protocol.LocalDevice, aSingleFile) where it is ten times less efficient memory wise... But we don't really do that operation anyway.

sync-benchmarks.md

Lets run the full sync test head to head:

leveldb

jb@syno:~/src/github.com/syncthing/syncthing/test (leveldb) $ go test -v -tags "integration benchmark" -run Bench
=== RUN TestBenchmarkTransferManyFiles
2015/05/24 22:47:48 Cleaning...
2015/05/24 22:47:49 Generating files...
2015/05/24 22:48:07 Starting sender...
2015/05/24 22:48:28 Starting receiver...
2015/05/24 22:48:29 {10 2015-05-24 22:48:29.705327515 +0200 CEST StateChanged map[folder:default from:idle to:scanning]}
2015/05/24 22:48:29 {13 2015-05-24 22:48:29.705480953 +0200 CEST StateChanged map[duration:0.000153115 folder:default from:scanning to:idle]}
2015/05/24 22:48:35 {79 2015-05-24 22:48:35.953981343 +0200 CEST StateChanged map[duration:6.248499273 folder:default from:idle to:syncing]}
2015/05/24 22:49:09 {100734 2015-05-24 22:49:09.278694203 +0200 CEST StateChanged map[duration:33.324711428 folder:default from:syncing to:idle]}
2015/05/24 22:49:09 Verifying...
2015/05/24 22:49:12 Result: Wall time: 33.32471286s
2015/05/24 22:49:12 Result: Utime: 47.970121s
2015/05/24 22:49:12 Result: Stime: 26.886712s
2015/05/24 22:49:12 Result: MaxRSS: 130988 KiB
--- PASS: TestBenchmarkTransferManyFiles (83.36s)
=== RUN TestBenchmarkTransferLargeFiles
2015/05/24 22:49:12 Cleaning...
2015/05/24 22:49:31 Generating files...
2015/05/24 22:49:42 Starting sender...
2015/05/24 22:50:03 Starting receiver...
2015/05/24 22:50:04 {10 2015-05-24 22:50:04.407362465 +0200 CEST StateChanged map[folder:default from:idle to:scanning]}
2015/05/24 22:50:04 {13 2015-05-24 22:50:04.407520322 +0200 CEST StateChanged map[folder:default from:scanning to:idle duration:0.000157486]}
2015/05/24 22:50:09 {26 2015-05-24 22:50:09.488503875 +0200 CEST StateChanged map[duration:5.080977999 folder:default from:idle to:syncing]}
2015/05/24 22:50:35 {806 2015-05-24 22:50:35.102551277 +0200 CEST StateChanged map[duration:25.614047109 folder:default from:syncing to:idle]}
2015/05/24 22:50:35 Verifying...
2015/05/24 22:50:39 Result: Wall time: 25.614047402s
2015/05/24 22:50:39 Result: Utime: 34.564375s
2015/05/24 22:50:39 Result: Stime: 3.859359s
2015/05/24 22:50:39 Result: MaxRSS: 33740 KiB
--- PASS: TestBenchmarkTransferLargeFiles (87.54s)
PASS
ok  	github.com/syncthing/syncthing/test	170.904s

bolt

jb@syno:~/src/github.com/syncthing/syncthing/test (boltv2) $ go test -v -tags "integration benchmark" -run Bench
=== RUN TestBenchmarkTransferManyFiles
2015/05/24 22:43:34 Cleaning...
2015/05/24 22:43:34 Generating files...
2015/05/24 22:43:53 Starting sender...
2015/05/24 22:44:14 Starting receiver...
2015/05/24 22:44:15 {10 2015-05-24 22:44:15.220921865 +0200 CEST StateChanged map[folder:default from:idle to:scanning]}
2015/05/24 22:44:15 {13 2015-05-24 22:44:15.221071207 +0200 CEST StateChanged map[to:idle duration:0.000148934 folder:default from:scanning]}
2015/05/24 22:44:20 {79 2015-05-24 22:44:20.980927121 +0200 CEST StateChanged map[duration:5.759854302 folder:default from:idle to:syncing]}
2015/05/24 22:46:07 {100828 2015-05-24 22:46:07.783754104 +0200 CEST StateChanged map[duration:106.80282665 folder:default from:syncing to:idle]}
2015/05/24 22:46:08 Verifying...
2015/05/24 22:46:10 Result: Wall time: 1m46.802826983s
2015/05/24 22:46:10 Result: Utime: 2m11.121146s
2015/05/24 22:46:10 Result: Stime: 35.1597s
2015/05/24 22:46:10 Result: MaxRSS: 111740 KiB
--- PASS: TestBenchmarkTransferManyFiles (156.69s)
=== RUN TestBenchmarkTransferLargeFiles
2015/05/24 22:46:10 Cleaning...
2015/05/24 22:46:29 Generating files...
2015/05/24 22:46:40 Starting sender...
2015/05/24 22:47:01 Starting receiver...
2015/05/24 22:47:02 {10 2015-05-24 22:47:02.13460981 +0200 CEST StateChanged map[folder:default from:idle to:scanning]}
2015/05/24 22:47:02 {13 2015-05-24 22:47:02.134797743 +0200 CEST StateChanged map[duration:0.000187514 folder:default from:scanning to:idle]}
2015/05/24 22:47:07 {26 2015-05-24 22:47:07.218998425 +0200 CEST StateChanged map[folder:default from:idle to:syncing duration:5.084199191]}
2015/05/24 22:47:33 {809 2015-05-24 22:47:33.131742074 +0200 CEST StateChanged map[to:idle duration:25.912743595 folder:default from:syncing]}
2015/05/24 22:47:33 Verifying...
2015/05/24 22:47:37 Result: Wall time: 25.912743649s
2015/05/24 22:47:37 Result: Utime: 36.541907s
2015/05/24 22:47:37 Result: Stime: 4.002212s
2015/05/24 22:47:37 Result: MaxRSS: 32264 KiB
--- PASS: TestBenchmarkTransferLargeFiles (87.07s)
PASS
ok  	github.com/syncthing/syncthing/test	243.765s

eh... bolt is 3.2 times slower...?