crypto: fix bogus error benchmarking pbkdf on fast machines

We're seeing periodic reports of errors like:

$ qemu-img create -f luks --object secret,data=123456,id=sec0 \
                  -o key-secret=sec0 luks-info.img 1M
  Formatting 'luks-info.img', fmt=luks size=1048576 key-secret=sec0
  qemu-img: luks-info.img: Unable to get accurate CPU usage

This error message comes from a recent attempt to workaround a
kernel bug with measuring rusage in long running processes:

  commit c72cab5ad9f849bbcfcf4be7952b8b8946cc626e
  Author: Tiago Pasqualini <tiago.pasqualini@canonical.com>
  Date:   Wed Sep 4 20:52:30 2024 -0300

    crypto: run qcrypto_pbkdf2_count_iters in a new thread

Unfortunately this has a subtle bug on machines which are very fast.

On the first time around the loop, the 'iterations' value is quite
small (1 << 15), and so will run quite fast. Testing has shown that
some machines can complete this benchmarking task in as little as
7 milliseconds.

Unfortunately the 'getrusage' data is not updated at the time of
the 'getrusage' call, it is done asynchronously by the scheduler.
The 7 millisecond completion time for the benchmark is short
enough that 'getrusage' sometimes reports 0 accumulated execution
time.

As a result the 'delay_ms == 0' sanity check in the above commit
is triggering non-deterministically on such machines.

The benchmarking loop intended to run multiple times, increasing
the 'iterations' value until the benchmark ran for > 500 ms, but
the sanity check doesn't allow this to happen.

To fix it, we keep a loop counter and only run the sanity check
after we've been around the loop more than 5 times. At that point
the 'iterations' value is high enough that even with infrequent
updates of 'getrusage' accounting data on fast machines, we should
see a non-zero value.

Fixes: https://lore.kernel.org/qemu-devel/ffe542bb-310c-4616-b0ca-13182f849fd1@redhat.com/
Fixes: https://bugzilla.redhat.com/show_bug.cgi?id=2336437
Reported-by: Thomas Huth <thuth@redhat.com>
Reported-by: Richard W.M. Jones <rjones@redhat.com>
Tested-by: Thomas Huth <thuth@redhat.com>
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
Message-ID: <20250109093746.1216300-1-berrange@redhat.com>
Signed-off-by: Thomas Huth <thuth@redhat.com>
(cherry picked from commit 145f12ea885c8fcfbe2d0ac5230630f071b5a9fb)
Signed-off-by: Michael Tokarev <mjt@tls.msk.ru>
This commit is contained in:
Daniel P. Berrangé 2025-01-09 09:37:46 +00:00 committed by Michael Tokarev
parent 2f5f6cb90a
commit dcb80cd908

View File

@ -107,7 +107,7 @@ static void *threaded_qcrypto_pbkdf2_count_iters(void *data)
size_t nsalt = iters_data->nsalt;
size_t nout = iters_data->nout;
Error **errp = iters_data->errp;
size_t scaled = 0;
uint64_t ret = -1;
g_autofree uint8_t *out = g_new(uint8_t, nout);
uint64_t iterations = (1 << 15);
@ -131,7 +131,17 @@ static void *threaded_qcrypto_pbkdf2_count_iters(void *data)
delta_ms = end_ms - start_ms;
if (delta_ms == 0) { /* sanity check */
/*
* For very small 'iterations' values, CPU (or crypto
* accelerator) might be fast enough that the scheduler
* hasn't incremented getrusage() data, or incremented
* it by a very small amount, resulting in delta_ms == 0.
* Once we've scaled 'iterations' x10, 5 times, we really
* should be seeing delta_ms != 0, so sanity check at
* that point.
*/
if (scaled > 5 &&
delta_ms == 0) { /* sanity check */
error_setg(errp, "Unable to get accurate CPU usage");
goto cleanup;
} else if (delta_ms > 500) {
@ -141,6 +151,7 @@ static void *threaded_qcrypto_pbkdf2_count_iters(void *data)
} else {
iterations = (iterations * 1000 / delta_ms);
}
scaled++;
}
iterations = iterations * 1000 / delta_ms;