How/where to regularly run profiling

[baentsch]

We currently run nightly profiling jobs for x86-64 and arm64 platforms publishing those results at https://openquantumsafe.org/benchmarking.

Now, it clearly is neither eco-/CO2-friendly nor economically sensible to run profiling too often, particularly if the frequency of new code merges is low.

Therefore this is to discuss how to improve things.

Some initial suggestions:

0. Don't change anything
1. Profiling to be run only manually on VMs otherwise suspended, i.e. and e.g. only when substantial code changes occurred.
2. Profiling to be run on dedicated machines (then also manually on "relevant" moments and when such machines are not used for other purposes): "Side benefit": No measurement inaccuracies caused by other "cloud execution load" becomes visible. Drawback: We may not see "true cloud" behaviour.
3. Profiling is extended to run on more platforms (suggestions welcome, which, where and how: The latter may also inform how to run x86-64 and arm64 tasks).
4. Somewhat orthogonal: We may increase or decrease the scope of things profiled: Maybe no OpenSSL handshake tests any more? Maybe no hybrid tests any more?
5. Keep using OpenSSL for common crypto operations (AES, SHA2) or only use liboqs "common" code (as already done for SHA3)?
6. Another orthogonal question: Shall we keep simple "speed" (iterations/sec) display or change to (hopefully more accurate "cycles counts" -- see Enabling use of ARM PMU for benchmarking when compiler flag is enabled liboqs#1141 (comment))? Drawback: Works "only" on platforms where cycle counts are available (e.g., not on s390).

[baentsch]

Additional thought: Add test runs on "interesting" hardware, like M1 or Raspberry.

[baentsch]

As a data point informing an answer to question 3 above: Just ran the same (aarch64) docker image on two different AWS VM types: t4g.large and t4g.nano. The runtime difference for the large set of performance tests was 9 seconds. Compared to the complete runtime of 6h26min that's less than 0.04% --> Moving profiling runs to "nano" (V)machine instances is reasonable&possible without a negative impact on accuracy. Add/edit: No single measurement deviates more than 2% except for some McEliece tests (keygen) -- which is expected.

[dstebila]

Okay, that sounds conclusive.

[baentsch]

Data points pertaining to question 5 above:

Configuration info
==================
Target platform:  x86_64-Linux-5.8.0-1041-aws
Compiler:         gcc (9.3.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.0
Git commit:       188e6a38b2bbc1795a105e21bc6925ac266df90b
OpenSSL enabled:  Yes (OpenSSL 1.1.1f  31 Mar 2020)
AES:              OpenSSL
SHA-2:            OpenSSL
SHA-3:            C
CPU exts compile-time:  ADX AES AVX AVX2 AVX512 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

=== test_aes correctness ===
Tests passed.

=== test_aes performance ===
Started at 2021-12-03 14:27:04
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |    5739078 |          1.000 |           0.174 |      0.386 |                       375 |        170
OQS_AES128_ECB_enc_sch         |   16776204 |          1.000 |           0.060 |      0.241 |                        90 |         77
OQS_AES128_ECB_enc             |    4973071 |          1.000 |           0.201 |      0.408 |                       443 |        175
OQS_AES256_ECB_load+free_sch   |    5609129 |          1.000 |           0.178 |      0.389 |                       384 |        158
OQS_AES256_ECB_enc_sch         |   15660256 |          1.000 |           0.064 |      0.248 |                        95 |         77
OQS_AES256_ECB_enc             |    4739663 |          1.000 |           0.211 |      0.416 |                       468 |        186
Ended at 2021-12-03 14:27:12

vs

Configuration info
==================
Target platform:  x86_64-Linux-5.8.0-1041-aws
Compiler:         gcc (9.3.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.0
Git commit:       188e6a38b2bbc1795a105e21bc6925ac266df90b
OpenSSL enabled:  No
AES:              NI
SHA-2:            C
SHA-3:            C
CPU exts compile-time:  ADX AES AVX AVX2 AVX512 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

=== test_aes correctness ===
Tests passed.

=== test_aes performance ===
Started at 2021-12-03 14:26:46
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |   10477038 |          1.000 |           0.095 |      0.299 |                       178 |        114
OQS_AES128_ECB_enc_sch         |   24407999 |          1.000 |           0.041 |      0.201 |                        29 |         44
OQS_AES128_ECB_enc             |    9485882 |          1.000 |           0.105 |      0.311 |                       190 |        114
OQS_AES256_ECB_load+free_sch   |    8930241 |          1.000 |           0.112 |      0.320 |                       220 |        112
OQS_AES256_ECB_enc_sch         |   21637536 |          1.000 |           0.046 |      0.213 |                        34 |         58
OQS_AES256_ECB_enc             |    7864568 |          1.000 |           0.127 |      0.338 |                       238 |        127
Ended at 2021-12-03 14:26:55

--> Speaks very much for using only OQS common code (as already is default for SHA3) for profiling. Anything speaking against that, @dstebila @christianpaquin @bhess ?

[dstebila]

So our AES NI implementation is better than OpenSSL's? Cool.

That doesn't address the question of SHA-2 however. We don't have an assembly version of SHA-2 on x86, if memory serves, so I would expect OpenSSL SHA-2 is still better than our C SHA-2.

[baentsch]

So our AES NI implementation is better than OpenSSL's? Cool.

Well, the difference is so large that I wonder whether NI is configured into this OpenSSL (standard ubuntu image) at all: Possibly it isn't, so we would need to build OpenSSL "natively" and with highest optimizations. But then again, would AWS not package the fastest code?? Edit: Just checked: AESNI is available in the default openssl:

openssl speed -elapsed -evp aes-128-cbc
You have chosen to measure elapsed time instead of user CPU time.
Doing aes-128-cbc for 3s on 16 size blocks: 120458741 aes-128-cbc's in 3.00s
Doing aes-128-cbc for 3s on 64 size blocks: 53413240 aes-128-cbc's in 3.00s
Doing aes-128-cbc for 3s on 256 size blocks: 13683919 aes-128-cbc's in 3.00s
Doing aes-128-cbc for 3s on 1024 size blocks: 3437555 aes-128-cbc's in 3.00s
Doing aes-128-cbc for 3s on 8192 size blocks: 430289 aes-128-cbc's in 3.00s
Doing aes-128-cbc for 3s on 16384 size blocks: 215136 aes-128-cbc's in 3.00s
OpenSSL 1.1.1f  31 Mar 2020
built on: Wed Nov 24 13:20:48 2021 UTC
options:bn(64,64) rc4(16x,int) des(int) aes(partial) blowfish(ptr) 
compiler: gcc -fPIC -pthread -m64 -Wa,--noexecstack -Wall -Wa,--noexecstack -g -O2 -fdebug-prefix-map=/build/openssl-dnfdFp/openssl-1.1.1f=. -fstack-protector-strong -Wformat -Werror=format-security -DOPENSSL_TLS_SECURITY_LEVEL=2 -DOPENSSL_USE_NODELETE -DL_ENDIAN -DOPENSSL_PIC -DOPENSSL_CPUID_OBJ -DOPENSSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DKECCAK1600_ASM -DRC4_ASM -DMD5_ASM -DAESNI_ASM -DVPAES_ASM -DGHASH_ASM -DECP_NISTZ256_ASM -DX25519_ASM -DPOLY1305_ASM -DNDEBUG -Wdate-time -D_FORTIFY_SOURCE=2
The 'numbers' are in 1000s of bytes per second processed.
type             16 bytes     64 bytes    256 bytes   1024 bytes   8192 bytes  16384 bytes
aes-128-cbc     642446.62k  1139482.45k  1167694.42k  1173352.11k  1174975.83k  1174929.41k

-> Now, indeed how can it be that our implementation is better? It's basically calls to the same HW-engine, no?

I would expect OpenSSL SHA-2 is still better than our C SHA-2.

Kind of correct: True for SHA256+384, not (totally) correct for SHA512.

But is it explicable that SHA3 numbers change (go down) when OpenSSL is disabled -- even though OQS_USE_SHA3_OPENSSL=OFF in both runs?

ubuntu@ip-172-31-13-189:~/git/liboqs/build-native$ ../build/tests/speed_common -d 10
Configuration info
==================
Target platform:  x86_64-Linux-5.11.0-1022-aws
Compiler:         gcc (9.3.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.1-rc1
Git commit:       ae6c7b479816bd441aa9a3c4b2dd1905195d94e0
OpenSSL enabled:  Yes (OpenSSL 1.1.1f  31 Mar 2020)
AES:              OpenSSL
SHA-2:            OpenSSL
SHA-3:            C
OQS build flags:  OQS_OPT_TARGET=auto CMAKE_BUILD_TYPE=Release 
CPU exts compile-time:  ADX AES AVX AVX2 AVX512 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

Speed test
==========
Started at 2021-12-14 07:54:36
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |   55938341 |         10.000 |           0.179 |      0.387 |                       382 |        131
OQS_AES128_ECB_enc_sch         |  163963448 |         10.000 |           0.061 |      0.242 |                        88 |         65
OQS_AES128_ECB_enc             |   45915468 |         10.000 |           0.218 |      0.418 |                       480 |        159
OQS_AES256_ECB_load+free_sch   |   55147344 |         10.000 |           0.181 |      0.390 |                       390 |        144
OQS_AES256_ECB_enc_sch         |  151065697 |         10.000 |           0.066 |      0.251 |                        96 |         73
OQS_AES256_ECB_enc             |   45927686 |         10.000 |           0.218 |      0.418 |                       481 |        163
OQS_SHA2_sha256                |   19033043 |         10.000 |           0.525 |      0.510 |                      1252 |        250
OQS_SHA2_sha384                |   22238857 |         10.000 |           0.450 |      0.506 |                      1064 |        226
OQS_SHA2_sha512                |   21694648 |         10.000 |           0.461 |      0.508 |                      1092 |        231
OQS_SHA3_sha3_256              |   21793957 |         10.000 |           0.459 |      0.519 |                      1086 |        363
OQS_SHA3_sha3_384              |   21690168 |         10.000 |           0.461 |      0.519 |                      1092 |        361
OQS_SHA3_sha3_512              |   21825456 |         10.000 |           0.458 |      0.519 |                      1085 |        361
OQS_SHA3_shake128              |   21683727 |         10.000 |           0.461 |      0.521 |                      1092 |        380
OQS_SHA3_shake256              |   21434040 |         10.000 |           0.467 |      0.522 |                      1106 |        390
Ended at 2021-12-14 07:57:23
ubuntu@ip-172-31-13-189:~/git/liboqs/build-native$ ./tests/speed_common -d 10
Configuration info
==================
Target platform:  x86_64-Linux-5.11.0-1022-aws
Compiler:         gcc (9.3.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.1-rc1
Git commit:       ae6c7b479816bd441aa9a3c4b2dd1905195d94e0
OpenSSL enabled:  No
AES:              NI
SHA-2:            C
SHA-3:            C
OQS build flags:  OQS_OPT_TARGET=auto CMAKE_BUILD_TYPE=Release 
CPU exts compile-time:  ADX AES AVX AVX2 AVX512 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

Speed test
==========
Started at 2021-12-14 08:05:43
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |  106281719 |         10.000 |           0.094 |      0.295 |                       176 |         85
OQS_AES128_ECB_enc_sch         |  208851215 |         10.000 |           0.048 |      0.216 |                        41 |         51
OQS_AES128_ECB_enc             |   89097216 |         10.000 |           0.112 |      0.324 |                       202 |        156
OQS_AES256_ECB_load+free_sch   |   89853763 |         10.000 |           0.111 |      0.322 |                       211 |        100
OQS_AES256_ECB_enc_sch         |  174076955 |         10.000 |           0.057 |      0.235 |                        53 |         67
OQS_AES256_ECB_enc             |   71659179 |         10.000 |           0.140 |      0.357 |                       268 |        193
OQS_SHA2_sha256                |   16679337 |         10.000 |           0.600 |      0.502 |                      1439 |        255
OQS_SHA2_sha384                |   22093833 |         10.000 |           0.453 |      0.522 |                      1072 |        388
OQS_SHA2_sha512                |   21708996 |         10.000 |           0.461 |      0.507 |                      1092 |        226
OQS_SHA3_sha3_256              |   19076203 |         10.000 |           0.524 |      0.510 |                      1251 |        244
OQS_SHA3_sha3_384              |   19100965 |         10.000 |           0.524 |      0.533 |                      1250 |        456
OQS_SHA3_sha3_512              |   18973688 |         10.000 |           0.527 |      0.510 |                      1258 |        242
OQS_SHA3_shake128              |   18991433 |         10.000 |           0.527 |      0.514 |                      1257 |        290
OQS_SHA3_shake256              |   19008923 |         10.000 |           0.526 |      0.521 |                      1256 |        248
Ended at 2021-12-14 08:08:37

[dstebila]

I don't see any use of the OQS_USE_SHA2_OPENSSL or OQS_USE_SHA3_OPENSSL flags that should lead to this difference. I don't observe significant differences when running locally (macOS, Intel AVX2, clang 13). A bit of a mystery...

[baentsch]

Looking at this again running on a pretty recent (x86_64) Ryzen 7 CPU running native with the latest liboqs code, OpenSSL and compiler delivers even more surprises:

• Some AES instructions are reported nearly an order of magnitude faster with "common" code (yikes!)
• SHA2-256 is better in OpenSSL, all other variants are better in liboqs common code

The above-mentioned difference in SHA3 doesn't exist, so it must have been a fluke.

Configuration info
==================
Target platform:  x86_64-Linux-5.16.14-051614-generic
Compiler:         gcc (11.2.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.2-dev
Git commit:       9dea0430ed764af2f0728793e783f04e5c0cd32d
OpenSSL enabled:  No
AES:              NI
SHA-2:            C
SHA-3:            C
OQS build flags:  OQS_OPT_TARGET=auto CMAKE_BUILD_TYPE=Release
CPU exts compile-time:  ADX AES AVX AVX2 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

Speed test
==========
Started at 2022-05-13 08:05:26
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |  245807281 |         10.000 |           0.041 |      0.198 |                        30 |         12
OQS_AES128_ECB_enc_sch         |  292926849 |         10.000 |           0.034 |      0.182 |                        18 |          8
OQS_AES128_ECB_enc             |  212083135 |         10.000 |           0.047 |      0.212 |                        42 |         11
OQS_AES256_ECB_load+free_sch   |  228865558 |         10.000 |           0.044 |      0.204 |                        36 |         11
OQS_AES256_ECB_enc_sch         |  274236669 |         10.000 |           0.036 |      0.188 |                        17 |         10
OQS_AES256_ECB_enc             |  186447597 |         10.000 |           0.054 |      0.225 |                        53 |         13
OQS_SHA2_sha256                |   26019400 |         10.000 |           0.384 |      0.487 |                       681 |         31
OQS_SHA2_sha384                |   33127790 |         10.000 |           0.302 |      0.459 |                       525 |         29
OQS_SHA2_sha512                |   33452512 |         10.000 |           0.299 |      0.458 |                       519 |         30
OQS_SHA3_sha3_256              |   28560832 |         10.000 |           0.350 |      0.477 |                       615 |         32
OQS_SHA3_sha3_384              |   28069625 |         10.000 |           0.356 |      0.479 |                       628 |         34
OQS_SHA3_sha3_512              |   28039999 |         10.000 |           0.357 |      0.479 |                       629 |         35
OQS_SHA3_shake128              |   27679303 |         10.000 |           0.361 |      0.481 |                       637 |         33
OQS_SHA3_shake256              |   27927604 |         10.000 |           0.358 |      0.480 |                       631 |         31
Ended at 2022-05-13 08:08:34

Configuration info
==================
Target platform:  x86_64-Linux-5.16.14-051614-generic
Compiler:         gcc (11.2.0)
Compile options:  [-march=native;-Werror;-Wall;-Wextra;-Wpedantic;-Wstrict-prototypes;-Wshadow;-Wformat=2;-Wfloat-equal;-Wwrite-strings;-O3;-fomit-frame-pointer;-fdata-sections;-ffunction-sections;-Wl,--gc-sections;-Wbad-function-cast]
OQS version:      0.7.2-dev
Git commit:       9dea0430ed764af2f0728793e783f04e5c0cd32d
OpenSSL enabled:  Yes (OpenSSL 3.0.2 15 Mar 2022)
AES:              OpenSSL
SHA-2:            OpenSSL
SHA-3:            C
OQS build flags:  OQS_OPT_TARGET=auto CMAKE_BUILD_TYPE=Release
CPU exts compile-time:  ADX AES AVX AVX2 BMI1 BMI2 PCLMULQDQ POPCNT SSE SSE2 SSE3

Speed test
==========
Started at 2022-05-13 08:08:36
Operation                      | Iterations | Total time (s) | Time (us): mean | pop. stdev | CPU cycles: mean          | pop. stdev
------------------------------ | ----------:| --------------:| ---------------:| ----------:| -------------------------:| ----------:
OQS_AES128_ECB_load+free_sch   |   29091452 |         10.000 |           0.344 |      0.475 |                       603 |         41
OQS_AES128_ECB_enc_sch         |  210542905 |         10.000 |           0.047 |      0.213 |                        41 |         11
OQS_AES128_ECB_enc             |   26236395 |         10.000 |           0.381 |      0.486 |                       675 |         40
OQS_AES256_ECB_load+free_sch   |   29363853 |         10.000 |           0.341 |      0.474 |                       598 |         33
OQS_AES256_ECB_enc_sch         |  208579488 |         10.000 |           0.048 |      0.214 |                        43 |         11
OQS_AES256_ECB_enc             |   26550964 |         10.000 |           0.377 |      0.485 |                       667 |         33
OQS_SHA2_sha256                |   34316720 |         10.000 |           0.291 |      0.455 |                       505 |         58
OQS_SHA2_sha384                |   24933443 |         10.000 |           0.401 |      0.490 |                       712 |         40
OQS_SHA2_sha512                |   23480702 |         10.000 |           0.426 |      0.495 |                       760 |         39
OQS_SHA3_sha3_256              |   28264892 |         10.000 |           0.354 |      0.485 |                       623 |        179
OQS_SHA3_sha3_384              |   28252363 |         10.000 |           0.354 |      0.485 |                       623 |        180
OQS_SHA3_sha3_512              |   27816293 |         10.000 |           0.360 |      0.487 |                       634 |        180
OQS_SHA3_shake128              |   27776970 |         10.000 |           0.360 |      0.489 |                       635 |        204
OQS_SHA3_shake256              |   27905281 |         10.000 |           0.358 |      0.488 |                       632 |        199
Ended at 2022-05-13 08:11:18

What I do find surprising, though, is that these massive differences don't show in OQS algorithms running: For example, considering Frodo is one of the few algorithms using common OQS code, Frodo640AES runs (minimally, but consistently) slower with the C code as compared to the OpenSSL AES/SHA2 --> Is it possible that the `speed_common test has a bug?

If it does not, I'm wondering whether the common AES code "cuts some corners"... If we think it doesn't (?) what about suggesting this AES implementation to the OpenSSL team? It looks like this (difference/savings) could even help reduce CO2 emissions given how often AES code is executed in (Open)SSL... :-)