Negative performances impact from 1.19 to 1.22 #759

jp-sentinel · 2019-12-03T15:00:44Z

Hello,

We are heavily using LevelDB in one or our product, and when we switched from 1.19 to 1.22 recently, we saw that our product is 7-10% slower with 1.22.

If we compare db_bunch result, we see this :

LevelDB:    version 1.19
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
------------------------------------------------
fillseq      :       4.384 micros/op;   25.2 MB/s     
fillsync     :      51.383 micros/op;    2.2 MB/s (1000 ops)
fillrandom   :       6.353 micros/op;   17.4 MB/s     
overwrite    :       7.314 micros/op;   15.1 MB/s     
readrandom   :       9.048 micros/op; (1000000 of 1000000 found)
readrandom   :       7.684 micros/op; (1000000 of 1000000 found)
readseq      :       0.301 micros/op;  368.0 MB/s    
readreverse  :       0.395 micros/op;  280.0 MB/s    
compact      : 1071433.000 micros/op;
readrandom   :       6.266 micros/op; (1000000 of 1000000 found)
readseq      :       0.276 micros/op;  401.2 MB/s    
readreverse  :       0.334 micros/op;  331.3 MB/s    
fill100K     :    1656.795 micros/op;   57.6 MB/s (1000 ops)
crc32c       :       3.073 micros/op; 1271.0 MB/s (4K per op)
snappycomp   :      24.433 micros/op;  159.9 MB/s (output: 55.1%)
snappyuncomp :       2.470 micros/op; 1581.6 MB/s    
acquireload  :      11.447 micros/op; (each op is 1000 loads)

LevelDB:    version 1.22
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
------------------------------------------------
fillseq      :       4.461 micros/op;   24.8 MB/s     
fillsync     :    6595.226 micros/op;    0.0 MB/s (1000 ops)
fillrandom   :       6.949 micros/op;   15.9 MB/s     
overwrite    :      10.130 micros/op;   10.9 MB/s     
readrandom   :       8.512 micros/op; (1000000 of 1000000 found)
readrandom   :       7.239 micros/op; (1000000 of 1000000 found)
readseq      :       0.305 micros/op;  363.2 MB/s    
readreverse  :       0.389 micros/op;  284.5 MB/s    
compact      : 1327342.000 micros/op;
readrandom   :       6.123 micros/op; (1000000 of 1000000 found)
readseq      :       0.275 micros/op;  401.8 MB/s    
readreverse  :       0.343 micros/op;  322.7 MB/s    
fill100K     :    2125.197 micros/op;   44.9 MB/s (1000 ops)
crc32c       :       1.681 micros/op; 2323.5 MB/s (4K per op)
snappycomp   :      24.751 micros/op;  157.8 MB/s (output: 55.1%)
snappyuncomp :       2.463 micros/op; 1586.2 MB/s

LevelDB 1.19 was compiled "as it" (it use -O2 & NDEBUG) and it include snappy.
LevelDB 1.22 was compiled in release mode (it also use -O2 & NDEBUG), and include libcrc32c + snappy.

All are compiled and tested with Xcode 10.3 (Apple LLVM version 10.0.1 (clang-1001.0.46.4)) on macOS 10.14.6 on a MacBook Pro (3,1 GHz Intel Core i7) with 16 GB RAM and 1 TB SSD.

If results are most of the time similar, we see a huge difference in fillsync (we are not using sync mode, so shouldn't impact us, but I'm wondering anyway), overwrite and fill100K (I exclude crc32, as it have better result in 1.22, probably because of libcrc32c).

Is it an known problem (I didn't find any other tickets) ? Is it something only happening on our side ?

Thank you.

The text was updated successfully, but these errors were encountered:

cmumford · 2019-12-09T21:45:02Z

I don't see a slowdown on my machine:

LevelDB:    version 1.22
Date:       Mon Dec  9 13:40:30 2019
CPU:        28 * Intel(R) Xeon(R) CPU E5-2690 v4 @ 2.60GHz
CPUCache:   35840 KB
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
------------------------------------------------
fillseq      :       1.715 micros/op;   64.5 MB/s     
fillsync     :       5.551 micros/op;   19.9 MB/s (1000 ops)
fillrandom   :       2.341 micros/op;   47.3 MB/s     
overwrite    :       2.609 micros/op;   42.4 MB/s     
readrandom   :       4.490 micros/op; (1000000 of 1000000 found)
readrandom   :       4.529 micros/op; (1000000 of 1000000 found)
readseq      :       0.213 micros/op;  519.5 MB/s    
readreverse  :       0.346 micros/op;  320.0 MB/s    
compact      :  366125.000 micros/op;
readrandom   :       3.120 micros/op; (1000000 of 1000000 found)
readseq      :       0.216 micros/op;  511.4 MB/s    
readreverse  :       0.262 micros/op;  421.5 MB/s    
fill100K     :     515.706 micros/op;  185.0 MB/s (1000 ops)
crc32c       :       1.682 micros/op; 2321.9 MB/s (4K per op)
snappycomp   :       4.428 micros/op;  882.2 MB/s (output: 55.1%)
snappyuncomp :       0.788 micros/op; 4958.3 MB/s

LevelDB:    version 1.19
Date:       Mon Dec  9 13:33:07 2019
CPU:        28 * Intel(R) Xeon(R) CPU E5-2690 v4 @ 2.60GHz
CPUCache:   35840 KB
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
------------------------------------------------
fillseq      :       2.095 micros/op;   52.8 MB/s     
fillsync     :      13.971 micros/op;    7.9 MB/s (1000 ops)
fillrandom   :       2.733 micros/op;   40.5 MB/s     
overwrite    :       2.997 micros/op;   36.9 MB/s     
readrandom   :       4.886 micros/op; (1000000 of 1000000 found)
readrandom   :       4.720 micros/op; (1000000 of 1000000 found)
readseq      :       0.240 micros/op;  460.6 MB/s    
readreverse  :       0.352 micros/op;  314.5 MB/s    
compact      :  415752.000 micros/op;
readrandom   :       3.561 micros/op; (1000000 of 1000000 found)
readseq      :       0.218 micros/op;  506.7 MB/s    
readreverse  :       0.258 micros/op;  429.6 MB/s    
fill100K     :     604.067 micros/op;  157.9 MB/s (1000 ops)
crc32c       :       3.665 micros/op; 1065.9 MB/s (4K per op)
snappycomp   :       4.674 micros/op;  835.7 MB/s (output: 55.1%)
snappyuncomp :       0.824 micros/op; 4743.3 MB/s    
acquireload  :       0.390 micros/op; (each op is 1000 loads)

1.22 compiles (by default) with -O3 whereas 1.19 was -O2

jp-sentinel · 2019-12-10T09:03:49Z

Thank you for your answer.

Your results are far better, even with 1.19. You are not using macOS, right ? (I know that macOS is not known for its exceptional I/O performances, and APFS doesn't help).

So yes, I'm not sure what is the problem on my side. I can retry with -O3, but I'm not sure it will make a huge difference with -O2.

Would be interesting to have results from another mac.

pwnall · 2019-12-10T12:06:17Z

fillsync was impacted by 296de8d

jp-sentinel · 2019-12-10T14:33:56Z

@pwnall Very interesting, thanks. So yes, it explains fillsync performance drop from 1.19 → 1.22.

Still have to understand why performances are a bit less good in other parts.

And from @cmumford reply, it's either specific to something I'm doing, either to specific to macOS…

I tested with -O3, I don't see significant changes.

cmumford · 2019-12-11T18:46:18Z

@jp-sentinel I'm running on Debian Linux. The benchmark doesn't run very long so it's hard learn too much from a single run.

soraphis · 2020-01-27T12:57:19Z

Building the project (release -O2) on windows 10 and running the benchmark:

12 * IIntel(R) Xeon(R) CPU E-2146 @3.5GHz

LevelDB:    version 1.22
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
WARNING: Snappy compression is not enabled
------------------------------------------------
fillseq      :     101.708 micros/op;    1.1 MB/s
fillsync     :     127.884 micros/op;    0.9 MB/s (1000 ops)
fillrandom   :     106.453 micros/op;    1.0 MB/s
overwrite    :     107.649 micros/op;    1.0 MB/s
readrandom   :       3.469 micros/op; (1000000 of 1000000 found)
readrandom   :       2.405 micros/op; (1000000 of 1000000 found)
readseq      :       0.232 micros/op;  476.5 MB/s
readreverse  :       0.383 micros/op;  288.9 MB/s
compact      : 2397672.000 micros/op;
readrandom   :       1.782 micros/op; (1000000 of 1000000 found)
readseq      :       0.215 micros/op;  514.7 MB/s
readreverse  :       0.352 micros/op;  314.1 MB/s
fill100K     :    1229.166 micros/op;   77.6 MB/s (1000 ops)
crc32c       :       1.407 micros/op; 2777.3 MB/s (4K per op)
snappycomp   :    4016.000 micros/op; (snappy failure)
snappyuncomp :    3964.000 micros/op; (snappy failure)

see fill* and overwrite. levelDB is way below your results.
also: i could not manage to compile with snappy (for now).

(it performed WAY better in 1.17, but i need the #339 changes which is in 1.22+)

jp-sentinel · 2020-01-27T13:16:11Z

@soraphis Indeed oO

soraphis · 2020-01-28T08:46:26Z

same system, but with WSL:

LevelDB:    version 1.22
Date:       Tue Jan 28 09:29:27 2020
CPU:        12 * Intel(R) Xeon(R) E-2146G CPU @ 3.50GHz
CPUCache:   256 KB
Keys:       16 bytes each
Values:     100 bytes each (50 bytes after compression)
Entries:    1000000
RawSize:    110.6 MB (estimated)
FileSize:   62.9 MB (estimated)
WARNING: Snappy compression is not enabled
------------------------------------------------
fillseq      :       6.190 micros/op;   17.9 MB/s
fillsync     :    1020.756 micros/op;    0.1 MB/s (1000 ops)
fillrandom   :       7.462 micros/op;   14.8 MB/s
overwrite    :       7.779 micros/op;   14.2 MB/s
readrandom   :       2.637 micros/op; (1000000 of 1000000 found)
readrandom   :       2.273 micros/op; (1000000 of 1000000 found)
readseq      :       0.137 micros/op;  808.5 MB/s
readreverse  :       0.248 micros/op;  446.2 MB/s
compact      :  597277.000 micros/op;
readrandom   :       1.359 micros/op; (1000000 of 1000000 found)
readseq      :       0.120 micros/op;  920.7 MB/s
readreverse  :       0.196 micros/op;  565.7 MB/s
fill100K     :     650.363 micros/op;  146.7 MB/s (1000 ops)
crc32c       :       1.089 micros/op; 3585.8 MB/s (4K per op)
snappycomp   :    2494.000 micros/op; (snappy failure)
snappyuncomp :    1732.000 micros/op; (snappy failure)

fill sync performs 18x better in the linux-subsystem.
fill random performs 15x better.

slowdown on windows is a result of Flush https://github.com/google/leveldb/blob/master/util/env_windows.cc#L290

changing flush to "return Status::OK()" makes fillsync 10x faster - but it sadly breaks repair functionality.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Negative performances impact from 1.19 to 1.22 #759

Negative performances impact from 1.19 to 1.22 #759

jp-sentinel commented Dec 3, 2019

cmumford commented Dec 9, 2019 •

edited

Loading

jp-sentinel commented Dec 10, 2019

pwnall commented Dec 10, 2019

jp-sentinel commented Dec 10, 2019 •

edited

Loading

cmumford commented Dec 11, 2019

soraphis commented Jan 27, 2020 •

edited

Loading

jp-sentinel commented Jan 27, 2020

soraphis commented Jan 28, 2020 •

edited

Loading

Negative performances impact from 1.19 to 1.22 #759

Negative performances impact from 1.19 to 1.22 #759

Comments

jp-sentinel commented Dec 3, 2019

cmumford commented Dec 9, 2019 • edited Loading

jp-sentinel commented Dec 10, 2019

pwnall commented Dec 10, 2019

jp-sentinel commented Dec 10, 2019 • edited Loading

cmumford commented Dec 11, 2019

soraphis commented Jan 27, 2020 • edited Loading

jp-sentinel commented Jan 27, 2020

soraphis commented Jan 28, 2020 • edited Loading

cmumford commented Dec 9, 2019 •

edited

Loading

jp-sentinel commented Dec 10, 2019 •

edited

Loading

soraphis commented Jan 27, 2020 •

edited

Loading

soraphis commented Jan 28, 2020 •

edited

Loading