pkcs8 import performance

[nunojpg]

➜  botan git:(master) ✗ botan keygen --algo=ECDSA --der-out --passphrase=12345678 > pri       
➜  botan git:(master) ✗ botan pkcs8 --pass-in=12345678 --pass-out=12345678 --der-out pri > pub
➜  botan git:(master) ✗ time botan pkcs8 --pass-in=12345678 pub                        
-----BEGIN PRIVATE KEY-----
MIGHAgEAMBMGByqGSM49AgEGCCqGSM49AwEHBG0wawIBAQQg7U07M7nVAdOZXz2v
lOW4NSBctMUM96SllTLZ/bVdIrmhRANCAAQGwUj0KTK31bCGRMepToSyvcMR1N7/
PUXjBa/RtBrz1vdLkF8GbrfLhKqZKUQAHXj05M7fUm0OE835Vzpga9hO
-----END PRIVATE KEY-----
botan pkcs8 --pass-in=12345678 pub  0,33s user 0,01s system 99% **cpu 0,340 total**
➜  botan git:(master) ✗ time botan pkcs8 --pass-in=12345678 pri
-----BEGIN PRIVATE KEY-----
MIGHAgEAMBMGByqGSM49AgEGCCqGSM49AwEHBG0wawIBAQQg7U07M7nVAdOZXz2v
lOW4NSBctMUM96SllTLZ/bVdIrmhRANCAAQGwUj0KTK31bCGRMepToSyvcMR1N7/
PUXjBa/RtBrz1vdLkF8GbrfLhKqZKUQAHXj05M7fUm0OE835Vzpga9hO
-----END PRIVATE KEY-----
botan pkcs8 --pass-in=12345678 pri  0,14s user 0,00s system 99% **cpu 0,138 total**

The import of a public key takes much longer than the private key. I just want to confirm this is expected, as something intrinsic to PK or EC.

[randombit]

Possibly you posted the wrong terminal output here, but if not - pub is also a private key, just the re-encryption of the originally generated key.

The 300 milliseconds (.3s) is expected because for both keygen and pkcs8 cli tools, the --pbe-millis argument defaults to 300. And if I replicate your run on my machine I see .3s for each. I'm not sure why your initial key generation ended up using a smaller iteration count - possibly some clock scaling issue confused the tuning?

In any case 99% of the cost here is the intentionally costly key derivation rather than anything related to parsing the keys.

[nunojpg]

Oups. Yes, I got it wrong, so what I actually am observing is:

botan keygen --algo=ECDSA --der-out --passphrase=12345678 > pri
botan pkcs8 --pass-in=12345678 --pass-out=12345678 --der-out pri > pri2
time botan pkcs8 --pass-in=12345678 pri -> 0.14s
time botan pkcs8 --pass-in=12345678 pri2 -> 0.33s

botan keygen --pbe-millis=2000 --algo=ECDSA --der-out --passphrase=12345678 > pri
botan pkcs8 --pbe-millis=2000 --pass-in=12345678 --pass-out=12345678 --der-out pri > pri2
time botan pkcs8 --pass-in=12345678 pri -> 0.67s
time botan pkcs8 --pass-in=12345678 pri2 -> 2.03s

Can you take a look?

I see this both at my distro package and master with default ./configure,

[randombit]

I can't replicate this with master at least. Can you post botan asn1print of the two keys?

Specifically there will be a block looking something like this

  d= 3, l=  49:    SEQUENCE
  d= 4, l=   9:     OBJECT                                  PKCS5.PBKDF2 [1.2.840.113549.1.5.12]
  d= 4, l=  36:     SEQUENCE
  d= 5, l=  12:      OCTET STRING                           EB3B252D55E10FFACC2AA15C
  d= 5, l=   3:      INTEGER                                0x01B580
  d= 5, l=   1:      INTEGER                                32

The first integer is the iteration count

[randombit]

Are you using a laptop with aggressive clock scaling?

[nunojpg]

➜  botan git:(master) ✗ ./botan asn1print pri 
  d= 0, l= 244: SEQUENCE
  d= 1, l=  95:  SEQUENCE
  d= 2, l=   9:   OBJECT                                    PBE-PKCS5v20 [1.2.840.113549.1.5.13]
  d= 2, l=  82:   SEQUENCE
  d= 3, l=  49:    SEQUENCE
  d= 4, l=   9:     OBJECT                                  PKCS5.PBKDF2 [1.2.840.113549.1.5.12]
  d= 4, l=  36:     SEQUENCE
  d= 5, l=  12:      OCTET STRING                           EFFCF83DEB266F1A96F182DB
  d= 5, l=   3:      INTEGER                                0x089350
  d= 5, l=   1:      INTEGER                                32
  d= 5, l=  12:      SEQUENCE
  d= 6, l=   8:       OBJECT                                HMAC(SHA-256) [1.2.840.113549.2.9]
  d= 6, l=   0:       NULL
  d= 3, l=  29:    SEQUENCE
  d= 4, l=   9:     OBJECT                                  AES-256/CBC [2.16.840.1.101.3.4.1.42]
  d= 4, l=  16:     OCTET STRING                            81D7087ED0F051552EFE217EE538C5A0
  d= 1, l= 144:  OCTET STRING                               46906AA37F9C1B776F4203FD6A5ADBA8DE3D0101D257C6493124019605B55D7136AAAB67C3F2FEB011FF6D88F51C8CFEB5CB32CD308BC78275839AC922AEE5BBB7A5C4B73D902861B9AD4B7EE8AA76A5B475CF10E97372DFD63E43D0D4144B212791A88AE56186D16DEFC25BBDB32402477615298CEAD80D3B206CBE712DCB3D060C460A426C41DF67C84137A9FFAE81
➜  botan git:(master) ✗ ./botan asn1print pri2
  d= 0, l= 244: SEQUENCE
  d= 1, l=  95:  SEQUENCE
  d= 2, l=   9:   OBJECT                                    PBE-PKCS5v20 [1.2.840.113549.1.5.13]
  d= 2, l=  82:   SEQUENCE
  d= 3, l=  49:    SEQUENCE
  d= 4, l=   9:     OBJECT                                  PKCS5.PBKDF2 [1.2.840.113549.1.5.12]
  d= 4, l=  36:     SEQUENCE
  d= 5, l=  12:      OCTET STRING                           306269AFDA40862F91A98C1B
  d= 5, l=   3:      INTEGER                                0x19B9F0
  d= 5, l=   1:      INTEGER                                32
  d= 5, l=  12:      SEQUENCE
  d= 6, l=   8:       OBJECT                                HMAC(SHA-256) [1.2.840.113549.2.9]
  d= 6, l=   0:       NULL
  d= 3, l=  29:    SEQUENCE
  d= 4, l=   9:     OBJECT                                  AES-256/CBC [2.16.840.1.101.3.4.1.42]
  d= 4, l=  16:     OCTET STRING                            875F2944F960F45DBBFE67C6BA61A4A9
  d= 1, l= 144:  OCTET STRING                               B65988F7DA34237FAE622AA9A93787A34144B493160CB1A99FF571C4B18ACF4681D5882B0922F40BFEA027D1257EB36758FD67E8DC420C9D38151D1678C8EA38E1841E9CB3F6DBE1A283FC0EE857FC0586951067C410D55C9CC8121EDAECA1F76D3B11C47299C570B5189E0865880E59E12DF1830A378F22A8AEA463B57A65111B9BAAE13AD05702ED492F7C1408F2E3

Ubuntu 22.04, laptop, AMD Ryzen 7 4700U

The results are always reproducible.

[randombit]

Can you post output of

botan pbkdf_tune --algo='PBKDF2(SHA-256)' --check 300 300 300

[nunojpg]

Ok, this seems to be all over the place:

➜  vanilla-checkouts botan pbkdf_tune --algo='PBKDF2(SHA-256)' --check 300 300 300
For 300 ms selected PBKDF2(HMAC(SHA-256),1684000) took 301.255 msec to compute
For 300 ms selected PBKDF2(HMAC(SHA-256),1684000) took 302.546 msec to compute
For 300 ms selected PBKDF2(HMAC(SHA-256),1682000) took 302.378 msec to compute
➜  vanilla-checkouts botan pbkdf_tune --algo='PBKDF2(SHA-256)' --check 300 300 300
For 300 ms selected PBKDF2(HMAC(SHA-256),646000) took 137.959 msec to compute
For 300 ms selected PBKDF2(HMAC(SHA-256),1692000) took 302.832 msec to compute
For 300 ms selected PBKDF2(HMAC(SHA-256),1692000) took 302.467 msec to compute

[randombit]

OK as I suspected it looks like your core is running slowly during the tuning period, and we underestimate the cost.

Can you try the (master-only) option --tune-msec= with various values, and see how long you have to run the tuning loop in order to get consistent results?

[nunojpg]

I don't even know why would this tuning have to be done at all, and why don't this algorithms just use a predefined complexity that yield same result regardless of machine. For sure there is a reason, but I is not apparent to me.

Here goes:

for i in `seq 300`; do echo -n $i && ./botan pbkdf_tune --algo='PBKDF2(SHA-256)' --tune-msec=$i --check 300 300 300 | awk -F' ' '{printf(" "$7)}'; echo; sleep 1; done
1 294.126 303.215 298.745
2 126.476 300.318 298.774
3 125.762 302.55 296.998
4 125.375 302.702 298.311
5 125.025 303.704 298.523
6 124.564 302.649 297.829
7 121.875 301.802 299.123
8 121.722 302.627 299.322
9 119.71 302.498 299.039
10 126.837 320.422 317.1
11 119.571 304.717 299.178
12 120.3 302.161 298.915
13 122.521 302.325 298.991
14 117.432 304.21 299.244
15 117.589 302.552 298.979
16 117.281 301.056 299.852
17 117.382 303.165 297.456
18 117.804 302.89 298.838
19 115.369 302.693 298.662
20 116.255 302.506 299.183
21 111.804 299.145 295.74
22 112.569 301.719 297.806
23 113.084 302.813 297.717
24 111.993 300.701 299.118
25 115.342 302.749 299.082
26 110.743 303.498 300.209
27 110.846 303.547 299.202
28 109.812 302.831 297.869
29 124.639 347.88 343.128
30 106.432 302.071 298.406
31 106.34 302.633 298.794
32 106.225 303.334 299.189
33 107.435 302.675 298.959
34 107.44 302.678 299.137
35 107.548 303.19 299.179
36 96.8406 279.884 277.688
37 103.959 301.691 300.059
38 117.767 347.62 343.186
39 102.656 302.51 299.054
40 101.991 302.507 298.732
41 103.909 302.1 298.143
42 113.079 323.559 316.462
43 105.436 303.578 298.514
44 279.124 306.292 297.839
45 312.953 310.252 312.677
46 299.861 297.998 300.479
47 210.388 304.525 299.65
48 141.576 301.103 299.032
49 294.382 301.793 298.822
50 124.956 302.32 300.787
51 137.322 303.85 297.876
52 138.585 302.862 298.337
53 298.915 304.82 300.045
54 155.191 303.642 301.444
55 137.34 290.644 287.507
56 118.158 261.424 258.652
57 152.191 302.502 297.827
58 245.724 301.896 298.847
59 126.89 304.8 301.122
60 145.865 304.625 299.916
61 159.675 303.15 298.634
62 165.156 302.329 299.287
63 162.632 302.777 298.306
64 172.524 302.36 299.005
65 162.623 302.468 298.816
66 167.387 306.691 299.039
67 166.462 302.926 299.934
68 166.76 302.694 299.245
69 172.875 301.646 299.134
70 180.556 301.433 298.855
71 181.761 302.56 297.272
72 179.202 303.121 298.635
73 174.803 302.688 298.479
74 163.574 302.621 298.814
75 135.832 301.396 298.562
76 180.74 302.432 299.188
77 189.92 300.8 299.051
78 190.815 302.947 298.524
79 192.181 302.897 298.169
80 195.428 302.201 300.143
81 194.586 302.175 298.875
82 193.779 302.622 298.873
83 193.783 301.77 298.924
84 198.135 302.686 302.637
85 199.945 302.015 298.85
86 194.767 302.386 297.52
87 200.993 302.399 300.069
88 203.461 302.7 297.075
89 205.66 302.903 297.166
90 197.501 302.84 298.871
91 208.17 302.301 298.394
92 205.3 302.286 298.45
93 204.018 302.801 298.65
94 209.168 305.637 296.909
95 204.607 301.996 298.888
96 214.628 303.104 301.591
97 207.222 302.505 298.847
98 209.485 302.49 298.686
99 215.161 302.37 301.788
100 219.866 302.875 298.44
101 210.034 302.341 297.132
102 236.963 323.495 319.102
103 219.633 303.423 301.44
104 216.912 304.43 299.53
105 214.87 302.805 299.314
106 218.289 323.834 298.999
107 217.231 302.944 299.046
108 222.066 303.536 299.284
109 219.048 302.064 298.937
110 218.308 302.031 298.8
111 217.595 302.142 299.098
112 221.798 303.53 299.031
113 219.906 302.348 298.877
114 229.662 303.774 298.512
115 221.531 300.013 296.457
116 262.335 352.1 349.85
117 227.718 302.734 298.803
118 229.96 304.426 298.565
119 229.207 304.357 299.765
120 224.257 300.736 298.639
121 227.074 302.329 298.856
122 228.234 302.893 298.56
123 259.024 302.917 298.843
124 229.575 302.918 298.187
125 230.137 302.741 298.24
126 230.623 304.213 297.923
127 230.089 302.636 298.642
128 225.253 301.269 298.438
129 239.337 316.963 310.173
130 229.091 302.711 298.373
131 296.304 303.898 299.011
132 235.117 301.507 299.097
133 232.914 302.305 298.563
134 215.137 302.568 299.153
135 273.575 349.03 344.122
136 265.543 317.864 298.164
137 227.847 304.968 300.734
138 240.13 301.977 299.576
139 232.163 301.191 298.315
140 237.528 302.459 301.853
141 237.132 307.332 299.449
142 242.136 299.709 299.046
143 243.067 302.276 303.316
144 240.405 302.677 298.934
145 241.404 300.962 298.068
146 238.797 303.41 299.49
147 246.292 302.569 298.751
148 246.626 305.832 297.955
149 248.06 302.787 298.998
150 294.186 302.807 298.325
151 240.76 302.733 300.441
152 269.757 304.304 297.84
153 265.431 302.511 298.696
154 264.933 306.119 300.051
155 261.512 303.005 299.416
156 240.298 303.259 297.739
157 245.109 302.429 298.408
158 287.183 322 318.75
159 243.244 304.23 297.816
160 246.867 302.067 299.213
161 225.823 279.852 277.63
162 238.783 299.618 290.135
163 244.751 302.425 298.37
164 243.303 301.411 297.379
165 258.042 314.197 313.313
166 250.369 302.482 309.155
167 276.379 277.808 276.514
168 286.296 347.544 337.059
169 298.453 302.81 298.823
170 299.211 303.949 298.054
171 240.148 300.179 293.553
172 248.094 303.406 299.52
173 245.835 302.775 299.587
174 250.984 301.248 295.215
175 298.863 302.62 297.247
176 302.616 303.04 310.262
177 292.185 269.011 267.408
178 259.68 303.222 300.729
179 296.798 302.501 299.459
180 300.291 308.467 293.104
181 250.836 308.784 301.547
182 300.082 302.582 297.828
183 299.354 302.058 299.294
184 288.196 302.28 299.279
185 253.103 302.845 298.9
186 254.568 302.225 299.484
187 265.688 302.224 299.024
188 231.574 258.082 255.166
189 253.277 302.578 297.381
190 269.983 302.461 299.306
191 253.782 307.173 300.274
192 252.289 302.316 298.886
193 290.491 304.02 299.343
194 273.122 302.652 298.685
195 254.412 302.512 298.7
196 252.991 303.625 298.969
197 257.409 302.248 298.345
198 258.23 302.355 298.649
199 256.926 302.273 299.223
200 256.054 302.829 299.179
201 256.91 288.299 291.971
202 248.394 290.363 287.22
203 257.25 302.724 298.586
204 256.604 302.486 299.561
205 258.143 301.878 298.357
206 258.45 302.236 298.627
207 256.065 302.518 299.791
208 258.763 302.477 298.826
209 259.188 302.228 298.583
210 258.137 303.491 300.774
211 260.398 302.691 298.87
212 218.992 258.852 254.704
213 258.937 304.105 298.669
214 258.281 302.414 297.457
215 259.145 303.696 299.638
216 231.585 261.863 259.012
217 259.155 304.162 299.54
218 261.33 302.016 299.949
219 232.493 300.666 297.126
220 259.963 302.198 298.167
221 260.583 302.26 298.032
222 260.401 302.154 298.06
223 261.273 302.971 299.003
224 261.125 302.453 298.52
225 267.911 302.383 298.072
226 286.484 302.858 298.743
227 260.14 303.259 298.831
228 276.967 302.773 302.594
229 268.215 302.476 298.641
230 269.593 303.385 299.183
231 292.689 303.021 299.389
232 262.981 302.084 298.956
233 264.056 302.274 298.993
234 263.034 302.862 299.287
235 262.506 302.205 299.629
236 276.305 303.071 298.92
237 272.185 301.031 298.064
238 218.236 244.572 241.82
239 266.828 302.852 298.977
240 278.372 302.763 298.245
241 236.664 263.083 259.22
242 256.518 279.898 276.126
243 298.633 301.862 297.577
244 262.346 302.365 298.947
245 264.252 302.496 298.917
246 264.923 303.661 298.757
247 262.853 302.48 298.783
248 301.066 346.469 340.713
249 264.087 301.949 298.99
250 267.1 302.165 301.799
251 262.843 302.779 298.958
252 282.447 321.16 318.277
253 306.797 349.112 343.452
254 292.071 325.53 330.728
255 264.478 302.327 298.769
256 263.782 302.074 298.676
257 264.599 302.429 297.67
258 266.414 302.377 298.383
259 266.023 303.055 297.424
260 266.034 300.956 298.838
261 267.02 302.384 298.61
262 242.09 302.725 298.498
263 266.544 316.563 298.963
264 265.775 302.232 298.983
265 241.877 300.357 296.003
266 267.94 302.402 298.847
267 243.444 301.581 298.619
268 242.935 302.572 298.096
269 267.553 303.149 298.819
270 299.268 302.354 298.834
271 268.304 302.538 297.908
272 268.191 302.013 298.499
273 268.703 302.822 298.509
274 269.222 302.523 298.679
275 269.537 303.26 298.968
276 269.145 302.367 299.236
277 269.536 307.425 300.323
278 267.392 301.713 298.651
279 269.879 302.002 297.731
280 284.303 322.171 317.555
281 269.735 302.577 297.613
282 315.438 351.96 350.43
283 246.891 302.109 298.247
284 268.18 301.671 297.487
285 246.016 302.281 298.716
286 317.504 353.565 353.264
287 268.532 302.572 299.013
288 268.748 302.808 298.313
289 286.832 322.156 318.135
290 267.646 302.989 297.631
291 269.181 302.484 299.05
292 268.992 302.484 298.199
293 269.95 302.373 298.393
294 251.39 281.061 276.747
295 270.715 302.67 299.344
296 232.578 262.221 259.39
297 267.838 300.796 296.734
298 266.169 302.717 297.596
299 338.079 302.17 373.485
300 296.284 303.521 298.877

[randombit]

I don't even know why would this tuning have to be done at all, and why don't this algorithms just use a predefined complexity that yield same result regardless of machine.

In order to scale the KDF iterations as machines get faster. Otherwise one picks a "reasonable default" and it stays there forever which is why, statistically speaking, most private keys are encrypted with PBKDF2 with under 10,000 rounds. (Just checked this, OpenSSL 3.0 actually still uses 2048 iterations, lol lmao)

Are you sure you don't have some really aggressive power settings enabled? If I'm interpreting this correctly, even after 50 ms your CPU has not scaled to full speed - that's 10s of millions of cycles. This seems pretty strange to me, even the infamous AVX-512 penalties on Skylake were not that bad.

[nunojpg]

Default Ubuntu settings "Balanced". On power brick. There is really nothing fancy about my laptop.

Thanks for all the help and explanations. I think there is nothing to be done here.