[BUG] crypto: caam - RSA encrypt doesn't always complete new data in out_buf

[Kepplinger-Novakovic Martin <Martin.Kepplinger-Novakovic@ginzinger.com>]

hi Horia, Pankaj, Gaurav and all interested,

I run imx6ul with FSL_CAAM* enabled and simply add ca.pem 
( openssl req -x509 -newkey rsa:4096 -keyout ca_key.pem -out ca.pem -nodes -days 365 -set_serial 01 -subj /CN=ginzinger.com )
to CONFIG_SYSTEM_TRUSTED_KEYS in order to use it to verify a squashfs rootfs via dm-verity
(but forget that for a moment, the failure is early during boot, rsa verify()).

This works until v6.6 and fails after ("crypto: ahash - optimize performance when wrapping shash")
but too much has happened that I could revert one and I might be wrong with that commit even.

I run v6.18 now where this works when I *disable* FSL_CAAM* completely and use the rsa-generic code.
Also it works, when I generate from elliptic curve key.

Only the CAAM+RSA case is failing in a weird way:

During boot, already the RSA .encrypt triggered from preparse() / verify() for all built-in keys/certs
(my own+the wireless regdb keys from mainline) fails for *some* and for *some not*, but *not*
always the same keys fail. They all sometimes fail and on a subsequent reboot a previously failing one *may* succeed.
If a verify() fails, it *always* fails here:

https://elixir.bootlin.com/linux/v6.18.12/source/crypto/rsassa-pkcs1.c#L266

but why? Because after the CAAM completion callback returning to the caller, out_buf
(that was set to the key-part inside of the request earlier) still holds *old* data,
and NOT the "encyption block" with 00 01 ff ff.... 

out_buf1 is (I assume valid because never changing) input data "out_buf" inside of "child_req".
Directly when caam jr dequeue() returns with the user-callback, I see 64 bytes (all?)
old data. SOMEHOW the cryto-wait needs 100ms or longer (no idea why) and after THAT,
out_buf has only the first 16 bytes old data (out_buf2 in the logs):


[    2.267849] start rsassa_pkcs1_verify
[    2.267857] child_req address: 0e805627 full size: 64 + 48 + 256 = 368
[    2.267898] out_buf1:00000000: f2da0387 afddc282 862f447c 934c5fd3  ........|D/.._L.
[    2.267923] out_buf1:00000010: 07feb948 f721bb17 aa4e2325 b9160c22  H.....!.%#N."...
[    2.267947] out_buf1:00000020: 469dae73 c3d9757c bf475749 ec97b733  s..F|u..IWG.3...
[    2.267970] out_buf1:00000030: c07540f5 a0f02246 13799c5d a3b8ffa1  .@u.F"..].y.....
[    2.267993] SRC BUF in out_buf1 CRC: 60791b87
[    2.268007] start caam_rsa_enc
[    2.268172] CAAM: calling caam_jr_enqueue
[    2.268238] jr areq+112:00000000: f2da0387 afddc282 862f447c 934c5fd3  ........|D/.._L.
[    2.268264] jr areq+112:00000010: 07feb948 f721bb17 aa4e2325 b9160c22  H.....!.%#N."...
[    2.268288] jr areq+112:00000020: 469dae73 c3d9757c bf475749 ec97b733  s..F|u..IWG.3...
[    2.268311] jr areq+112:00000030: c07540f5 a0f02246 13799c5d a3b8ffa1  .@u.F"..].y.....
[    2.275958] CAAM: completion callback
  here only old data!?
[    2.275986] jr deq userarg + 112:00000000: f2da0387 afddc282 862f447c 934c5fd3  ........|D/.._L.
[    2.276012] jr deq userarg + 112:00000010: 07feb948 f721bb17 aa4e2325 b9160c22  H.....!.%#N."...
[    2.276038] jr deq userarg + 112:00000020: 469dae73 c3d9757c bf475749 ec97b733  s..F|u..IWG.3...
[    2.276063] jr deq userarg + 112:00000030: c07540f5 a0f02246 13799c5d a3b8ffa1  .@u.F"..].y.....
[    2.276079] rsa_pub_done start
[    2.276092] calling akcipher_request_complete
[    2.276100] crypto_req_done calling complete
   why the delay here?
[    2.416791] OUT BUF in out_buf2 CRC: 12298efd
[    2.416810] mapping pa 8f551870 to va 1775c16c
   now only the first 16 bytes are old??
[    2.416843] out_buf2:00000000: f2da0387 afddc282 862f447c 934c5fd3  ........|D/.._L.
[    2.416868] out_buf2:00000010: ffffffff ffffffff ffffffff ffffffff  ................
[    2.416892] out_buf2:00000020: ffffffff ffffffff ffffffff ffffffff  ................
[    2.416915] out_buf2:00000030: ffffffff ffffffff ffffffff ffffffff  ................
[    2.416930] Encrypted value had no leading 0 byte.
[    2.416941] PKEY: crypto_sig_verify error: -22
[    2.416964] PKEY: <==public_key_verify_signature() = -22
[    2.416979] X.509: public_key_verify_signature error: -22


compare it to a successful run. Note that NO visible delay after "crypto_req_done calling complete".
New data immediately in caam jr dequeue().

[    2.148544] jr areq+112:00000000: a9fe4420 ea9bdd9e 087525ce f7532bf0   D.......%u..+S.
[    2.148569] jr areq+112:00000010: 4a1c365a 41d07f23 b92b123c 158a4e80  Z6.J#..A<.+..N..
[    2.148592] jr areq+112:00000020: a7401f5d c3322826 2d28065b 1e09083d  ].@.&(2.[.(-=...
[    2.148614] jr areq+112:00000030: e367e901 4515e633 8317ee39 7fff42db  ..g.3..E9....B..
[    2.152208] CAAM: completion callback
[    2.152265] jr deq userarg + 112:00000000: ffff0100 ffffffff ffffffff ffffffff  ................
[    2.152291] jr deq userarg + 112:00000010: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152316] jr deq userarg + 112:00000020: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152339] jr deq userarg + 112:00000030: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152354] rsa_pub_done start
[    2.152372] calling akcipher_request_complete
[    2.152380] crypto_req_done calling complete
[    2.152701] OUT BUF in out_buf2 CRC: 136f61c9
[    2.152719] mapping pa 8f551670 to va 3952caaf
[    2.152753] out_buf2:00000000: ffff0100 ffffffff ffffffff ffffffff  ................
[    2.152777] out_buf2:00000010: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152801] out_buf2:00000020: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152823] out_buf2:00000030: ffffffff ffffffff ffffffff ffffffff  ................
[    2.152860] PKEY: <==public_key_verify_signature() = 0
[    2.152874] X.509: Cert Self-signature verified
[    2.152880] X.509: <==x509_check_for_self_signed() = 0
[    2.152898] X.509: Cert Issuerrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrr: benh@debian.org
[    2.152910] X.509: Cert Subject: benh@debian.org
[    2.152921] X.509: Cert Key Algo: rsa
[    2.152930] X.509: Cert Valid period: 1580390773-4733990773
[    2.152947] X.509: Cert Signature: rsa + sha256

msleep(500) before checking out_buf[0] in crypto/rsassa-pkcs1.c doesn't help. 

Again, if I reboot as-is, a previously failing cert can succeed, so there is some kind of race-condition
involved here. Again, for rsa-generic without FSL_CAAM*, this never happens.

Can you tell what might go wrong? I'm kind of stuck but will keep debugging. I don't see
significant changes in the nxp/lf-6.12* tree either.

There has been quite some changes, most notably ("crypto: ahash - optimize performance when wrapping shash")
or ("crypto: rsassa-pkcs1 - Migrate to sig_alg backend") which squashes differnt changes into
one commit...

thank you in case you have time to have a look,

                                            martin