Alexey Serbin has posted comments on this change. ( http://gerrit.cloudera.org:8080/16659 )
Change subject: KUDU-3210 Add lock before verifying signature ...................................................................... Patch Set 8: (1 comment) http://gerrit.cloudera.org:8080/#/c/16659/8/src/kudu/security/crypto.cc File src/kudu/security/crypto.cc: http://gerrit.cloudera.org:8080/#/c/16659/8/src/kudu/security/crypto.cc@145 PS8, Line 145: #if OPENSSL_VERSION_NUMBER < 0x10100000L : std::unique_lock<std::mutex> l(mutex); : #endif > I'm not sure to be honest. I just did some perf testing and don't really se Thank you for putting together this stats! They are definitely helpful to assess the performance hit of the additional locking. And it also gives better idea what tests were failing in FIPS mode and CaseLogic module. I'm not sure that Kudu client retries connection negotiation if it failed to verify the servers certificate. That would be odd, at least. I'll double check and report back with my findings. To add more color to the comparison, I ran a couple more tests to exercise the path in the connection negotiation, targeting the newly introduced global mutex in Continue(). That's rpc-bench with --enable_encryption (RELEASE build) with added `FLAGS_rpc_reopen_outbound_connections = true` to make client to establish a new connection for per RPC call. On top of that, I applied this patch. The results below are for the custom code with and without this patch. As you can see, request per second dropped from 1825.35 to 385.904 (sync version) and from 1810.24 to 389.786 (async version). That's almost 5x drop in performance (4.7x and 4.6x correspondingly). This looks a bit alarming, at least. RpcBench.BenchmarkCalls without this patch (i.e. without the global mutexes): [ RUN ] RpcBench.BenchmarkCalls WARNING: Logging before InitGoogleLogging() is written to STDERR I1102 22:30:06.225222 1741930 rpc-bench.cc:114] Mode: Sync I1102 22:30:06.225301 1741930 rpc-bench.cc:116] Client threads: 16 I1102 22:30:06.225309 1741930 rpc-bench.cc:122] Worker threads: 1 I1102 22:30:06.225317 1741930 rpc-bench.cc:123] Server reactors: 4 I1102 22:30:06.225323 1741930 rpc-bench.cc:124] Encryption: 1 I1102 22:30:06.225334 1741930 rpc-bench.cc:125] ---------------------------------- I1102 22:30:06.225340 1741930 rpc-bench.cc:126] Reqs/sec: 1825.35 I1102 22:30:06.225375 1741930 rpc-bench.cc:127] User CPU per req: 2341.53us I1102 22:30:06.225385 1741930 rpc-bench.cc:128] Sys CPU per req: 875.212us I1102 22:30:06.225394 1741930 rpc-bench.cc:129] Ctx Sw. per req: 20.8485 I1102 22:30:06.225402 1741930 rpc-bench.cc:130] Server reactor load histogram I1102 22:30:06.225409 1741930 rpc-bench.cc:131] Count: 1980 Mean: 4.01465 Percentiles: 0% (min) = 1 25% = 3 50% (med) = 3 75% = 3 95% = 9 99% = 10 99.9% = 11 99.99% = 11 100% (max) = 11 I1102 22:30:06.225433 1741930 rpc-bench.cc:132] Server reactor latency histogram I1102 22:30:06.225440 1741930 rpc-bench.cc:133] Count: 164937 Mean: 31.1397 Percentiles: 0% (min) = 0 25% = 11 50% (med) = 17 75% = 30 95% = 127 99% = 144 99.9% = 167 99.99% = 226 100% (max) = 778 [ OK ] RpcBench.BenchmarkCalls (10031 ms) RpcBench.BenchmarkCalls with this patch (i.e. with the global mutexes): [ RUN ] RpcBench.BenchmarkCalls WARNING: Logging before InitGoogleLogging() is written to STDERR I1102 22:29:43.955384 1741782 rpc-bench.cc:114] Mode: Sync I1102 22:29:43.955492 1741782 rpc-bench.cc:116] Client threads: 16 I1102 22:29:43.955503 1741782 rpc-bench.cc:122] Worker threads: 1 I1102 22:29:43.955509 1741782 rpc-bench.cc:123] Server reactors: 4 I1102 22:29:43.955516 1741782 rpc-bench.cc:124] Encryption: 1 I1102 22:29:43.955530 1741782 rpc-bench.cc:125] ---------------------------------- I1102 22:29:43.955538 1741782 rpc-bench.cc:126] Reqs/sec: 385.904 I1102 22:29:43.955571 1741782 rpc-bench.cc:127] User CPU per req: 3442.5us I1102 22:29:43.955580 1741782 rpc-bench.cc:128] Sys CPU per req: 1449.14us I1102 22:29:43.955590 1741782 rpc-bench.cc:129] Ctx Sw. per req: 25.4526 I1102 22:29:43.955631 1741782 rpc-bench.cc:130] Server reactor load histogram I1102 22:29:43.955642 1741782 rpc-bench.cc:131] Count: 1980 Mean: 0.644444 Percentiles: 0% (min) = 0 25% = 0 50% (med) = 0 75% = 1 95% = 2 99% = 3 99.9% = 3 99.99% = 4 100% (max) = 4 I1102 22:29:43.955672 1741782 rpc-bench.cc:132] Server reactor latency histogram I1102 22:29:43.955678 1741782 rpc-bench.cc:133] Count: 38011 Mean: 33.7189 Percentiles: 0% (min) = 0 25% = 12 50% (med) = 20 75% = 32 95% = 135 99% = 151 99.9% = 175 99.99% = 528 100% (max) = 721 [ OK ] RpcBench.BenchmarkCalls (10058 ms) RpcBench.BenchmarkCallsAsync without this patch (i.e. without the global mutexes): [ RUN ] RpcBench.BenchmarkCallsAsync I1102 22:30:16.275791 1741930 rpc-bench.cc:114] Mode: Async I1102 22:30:16.275837 1741930 rpc-bench.cc:118] Client reactors: 16 I1102 22:30:16.275846 1741930 rpc-bench.cc:119] Call concurrency: 60 I1102 22:30:16.275852 1741930 rpc-bench.cc:122] Worker threads: 1 I1102 22:30:16.275859 1741930 rpc-bench.cc:123] Server reactors: 4 I1102 22:30:16.275866 1741930 rpc-bench.cc:124] Encryption: 1 I1102 22:30:16.275873 1741930 rpc-bench.cc:125] ---------------------------------- I1102 22:30:16.275879 1741930 rpc-bench.cc:126] Reqs/sec: 1810.24 I1102 22:30:16.275905 1741930 rpc-bench.cc:127] User CPU per req: 2341.85us I1102 22:30:16.275914 1741930 rpc-bench.cc:128] Sys CPU per req: 857.57us I1102 22:30:16.275923 1741930 rpc-bench.cc:129] Ctx Sw. per req: 18.8286 I1102 22:30:16.275933 1741930 rpc-bench.cc:130] Server reactor load histogram I1102 22:30:16.275938 1741930 rpc-bench.cc:131] Count: 1980 Mean: 4.10253 Percentiles: 0% (min) = 1 25% = 3 50% (med) = 3 75% = 4 95% = 9 99% = 10 99.9% = 11 99.99% = 12 100% (max) = 12 I1102 22:30:16.275954 1741930 rpc-bench.cc:132] Server reactor latency histogram I1102 22:30:16.275961 1741930 rpc-bench.cc:133] Count: 162799 Mean: 32.0204 Percentiles: 0% (min) = 0 25% = 11 50% (med) = 18 75% = 30 95% = 127 99% = 146 99.9% = 175 99.99% = 912 100% (max) = 1533 [ OK ] RpcBench.BenchmarkCallsAsync (10056 ms) RpcBench.BenchmarkCallsAsync with this patch (i.e. with the global mutexes): [ RUN ] RpcBench.BenchmarkCallsAsync I1102 22:29:54.127874 1741782 rpc-bench.cc:114] Mode: Async I1102 22:29:54.127933 1741782 rpc-bench.cc:118] Client reactors: 16 I1102 22:29:54.127941 1741782 rpc-bench.cc:119] Call concurrency: 60 I1102 22:29:54.127948 1741782 rpc-bench.cc:122] Worker threads: 1 I1102 22:29:54.127955 1741782 rpc-bench.cc:123] Server reactors: 4 I1102 22:29:54.127962 1741782 rpc-bench.cc:124] Encryption: 1 I1102 22:29:54.127972 1741782 rpc-bench.cc:125] ---------------------------------- I1102 22:29:54.127979 1741782 rpc-bench.cc:126] Reqs/sec: 389.786 I1102 22:29:54.128002 1741782 rpc-bench.cc:127] User CPU per req: 3411.34us I1102 22:29:54.128011 1741782 rpc-bench.cc:128] Sys CPU per req: 1357.97us I1102 22:29:54.128019 1741782 rpc-bench.cc:129] Ctx Sw. per req: 23.0931 I1102 22:29:54.128028 1741782 rpc-bench.cc:130] Server reactor load histogram I1102 22:29:54.128036 1741782 rpc-bench.cc:131] Count: 2000 Mean: 0.65 Percentiles: 0% (min) = 0 25% = 0 50% (med) = 0 75% = 1 95% = 2 99% = 3 99.9% = 3 99.99% = 3 100% (max) = 3 I1102 22:29:54.128051 1741782 rpc-bench.cc:132] Server reactor latency histogram I1102 22:29:54.128058 1741782 rpc-bench.cc:133] Count: 38003 Mean: 34.1031 Percentiles: 0% (min) = 0 25% = 12 50% (med) = 20 75% = 32 95% = 132 99% = 150 99.9% = 219 99.99% = 1472 100% (max) = 1536 [ OK ] RpcBench.BenchmarkCallsAsync (10178 ms) -- To view, visit http://gerrit.cloudera.org:8080/16659 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ifafc7dcf91db910123276b657515e410bb7f6fcd Gerrit-Change-Number: 16659 Gerrit-PatchSet: 8 Gerrit-Owner: Attila Bukor <[email protected]> Gerrit-Reviewer: Alexey Serbin <[email protected]> Gerrit-Reviewer: Attila Bukor <[email protected]> Gerrit-Reviewer: Grant Henke <[email protected]> Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tidy Bot (241) Gerrit-Reviewer: Wenzhe Zhou <[email protected]> Gerrit-Comment-Date: Tue, 03 Nov 2020 06:56:08 +0000 Gerrit-HasComments: Yes
