The text tcrypt prints to dmesg is a bit inconsistent. This makes it
difficult to process tcrypt results using scripts. This little series
makes the prints more consistent.
Anirudh Venkataramanan (4):
crypto: tcrypt - Use pr_cont to print test results
crypto: tcrypt - Use pr_info/pr_err
crypto: tcrypt - Drop module name from print string
crypto: tcrypt - Drop leading newlines from prints
crypto/tcrypt.c | 36 +++++++++++++++++-------------------
1 file changed, 17 insertions(+), 19 deletions(-)
--
2.37.2
The pr_fmt() define includes KBUILD_MODNAME, and so there's no need
for pr_err() to also print it. Drop module name from the print string.
Signed-off-by: Anirudh Venkataramanan <[email protected]>
---
crypto/tcrypt.c | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)
diff --git a/crypto/tcrypt.c b/crypto/tcrypt.c
index 511e9b4..35868d5 100644
--- a/crypto/tcrypt.c
+++ b/crypto/tcrypt.c
@@ -1340,8 +1340,7 @@ static void test_skcipher_speed(const char *algo, int enc, unsigned int secs,
req = skcipher_request_alloc(tfm, GFP_KERNEL);
if (!req) {
- pr_err("tcrypt: skcipher: Failed to allocate request for %s\n",
- algo);
+ pr_err("skcipher: Failed to allocate request for %s\n", algo);
goto out;
}
--
2.37.2
The top level print banners have a leading newline. It's not entirely
clear why this exists, but it makes it harder to parse tcrypt test output
using a script. Drop said newlines.
tcrypt output before this patch:
[...]
testing speed of rfc4106(gcm(aes)) (rfc4106-gcm-aesni) encryption
[...] test 0 (160 bit key, 16 byte blocks): 1 operation in 2320 cycles (16 bytes)
tcrypt output with this patch:
[...] testing speed of rfc4106(gcm(aes)) (rfc4106-gcm-aesni) encryption
[...] test 0 (160 bit key, 16 byte blocks): 1 operation in 2320 cycles (16 bytes)
Signed-off-by: Anirudh Venkataramanan <[email protected]>
---
crypto/tcrypt.c | 10 +++++-----
1 file changed, 5 insertions(+), 5 deletions(-)
diff --git a/crypto/tcrypt.c b/crypto/tcrypt.c
index 35868d5..8339838 100644
--- a/crypto/tcrypt.c
+++ b/crypto/tcrypt.c
@@ -335,7 +335,7 @@ static void test_mb_aead_speed(const char *algo, int enc, int secs,
crypto_req_done, &data[i].wait);
}
- pr_info("\ntesting speed of multibuffer %s (%s) %s\n", algo,
+ pr_info("testing speed of multibuffer %s (%s) %s\n", algo,
get_driver_name(crypto_aead, tfm), e);
i = 0;
@@ -586,7 +586,7 @@ static void test_aead_speed(const char *algo, int enc, unsigned int secs,
}
crypto_init_wait(&wait);
- pr_info("\ntesting speed of %s (%s) %s\n", algo,
+ pr_info("testing speed of %s (%s) %s\n", algo,
get_driver_name(crypto_aead, tfm), e);
req = aead_request_alloc(tfm, GFP_KERNEL);
@@ -888,7 +888,7 @@ static void test_ahash_speed_common(const char *algo, unsigned int secs,
return;
}
- pr_info("\ntesting speed of async %s (%s)\n", algo,
+ pr_info("testing speed of async %s (%s)\n", algo,
get_driver_name(crypto_ahash, tfm));
if (crypto_ahash_digestsize(tfm) > MAX_DIGEST_SIZE) {
@@ -1128,7 +1128,7 @@ static void test_mb_skcipher_speed(const char *algo, int enc, int secs,
crypto_init_wait(&data[i].wait);
}
- pr_info("\ntesting speed of multibuffer %s (%s) %s\n", algo,
+ pr_info("testing speed of multibuffer %s (%s) %s\n", algo,
get_driver_name(crypto_skcipher, tfm), e);
i = 0;
@@ -1335,7 +1335,7 @@ static void test_skcipher_speed(const char *algo, int enc, unsigned int secs,
return;
}
- pr_info("\ntesting speed of %s %s (%s) %s\n", async ? "async" : "sync",
+ pr_info("testing speed of %s %s (%s) %s\n", async ? "async" : "sync",
algo, get_driver_name(crypto_skcipher, tfm), e);
req = skcipher_request_alloc(tfm, GFP_KERNEL);
--
2.37.2
Currently, there's mixed use of printk() and pr_info()/pr_err(). The latter
prints the module name (because pr_fmt() is defined so) but the former does
not. As a result there's inconsistency in the printed output. For example:
modprobe mode=211:
[...] test 0 (160 bit key, 16 byte blocks): 1 operation in 2320 cycles (16 bytes)
[...] test 1 (160 bit key, 64 byte blocks): 1 operation in 2336 cycles (64 bytes)
modprobe mode=215:
[...] tcrypt: test 0 (160 bit key, 16 byte blocks): 1 operation in 2173 cycles (16 bytes)
[...] tcrypt: test 1 (160 bit key, 64 byte blocks): 1 operation in 2241 cycles (64 bytes)
Replace all instances of printk() with pr_info()/pr_err() so that the
module name is printed consistently.
Signed-off-by: Anirudh Venkataramanan <[email protected]>
---
crypto/tcrypt.c | 19 +++++++++----------
1 file changed, 9 insertions(+), 10 deletions(-)
diff --git a/crypto/tcrypt.c b/crypto/tcrypt.c
index 7c84206..511e9b4 100644
--- a/crypto/tcrypt.c
+++ b/crypto/tcrypt.c
@@ -586,8 +586,8 @@ static void test_aead_speed(const char *algo, int enc, unsigned int secs,
}
crypto_init_wait(&wait);
- printk(KERN_INFO "\ntesting speed of %s (%s) %s\n", algo,
- get_driver_name(crypto_aead, tfm), e);
+ pr_info("\ntesting speed of %s (%s) %s\n", algo,
+ get_driver_name(crypto_aead, tfm), e);
req = aead_request_alloc(tfm, GFP_KERNEL);
if (!req) {
@@ -635,8 +635,8 @@ static void test_aead_speed(const char *algo, int enc, unsigned int secs,
memset(iv, 0xff, iv_len);
crypto_aead_clear_flags(tfm, ~0);
- printk(KERN_INFO "test %u (%d bit key, %d byte blocks): ",
- i, *keysize * 8, bs);
+ pr_info("test %u (%d bit key, %d byte blocks): ",
+ i, *keysize * 8, bs);
memset(tvmem[0], 0xff, PAGE_SIZE);
@@ -888,8 +888,8 @@ static void test_ahash_speed_common(const char *algo, unsigned int secs,
return;
}
- printk(KERN_INFO "\ntesting speed of async %s (%s)\n", algo,
- get_driver_name(crypto_ahash, tfm));
+ pr_info("\ntesting speed of async %s (%s)\n", algo,
+ get_driver_name(crypto_ahash, tfm));
if (crypto_ahash_digestsize(tfm) > MAX_DIGEST_SIZE) {
pr_err("digestsize(%u) > %d\n", crypto_ahash_digestsize(tfm),
@@ -1459,9 +1459,8 @@ static void test_available(void)
const char **name = check;
while (*name) {
- printk("alg %s ", *name);
- printk(crypto_has_alg(*name, 0, 0) ?
- "found\n" : "not found\n");
+ pr_info("alg %s %s\n", *name,
+ (crypto_has_alg(*name, 0, 0) ? "found" : "not found"));
name++;
}
}
@@ -2882,7 +2881,7 @@ static int __init tcrypt_mod_init(void)
err = do_test(alg, type, mask, mode, num_mb);
if (err) {
- printk(KERN_ERR "tcrypt: one or more tests failed!\n");
+ pr_err("one or more tests failed!\n");
goto err_free_tv;
} else {
pr_debug("all tests passed\n");
--
2.37.2
For some test cases, a line break gets inserted between the test banner
and the results. For example, with mode=211 this is the output:
[...]
testing speed of rfc4106(gcm(aes)) (rfc4106-gcm-aesni) encryption
[...] test 0 (160 bit key, 16 byte blocks):
[...] 1 operation in 2373 cycles (16 bytes)
--snip--
[...]
testing speed of gcm(aes) (generic-gcm-aesni) encryption
[...] test 0 (128 bit key, 16 byte blocks):
[...] 1 operation in 2338 cycles (16 bytes)
Similar behavior is seen in the following cases as well:
modprobe tcrypt mode=212
modprobe tcrypt mode=213
modprobe tcrypt mode=221
modprobe tcrypt mode=300 sec=1
modprobe tcrypt mode=400 sec=1
This doesn't happen with mode=215:
[...] tcrypt:
testing speed of multibuffer rfc4106(gcm(aes)) (rfc4106-gcm-aesni) encryption
[...] tcrypt: test 0 (160 bit key, 16 byte blocks): 1 operation in 2215 cycles (16 bytes)
--snip--
[...] tcrypt:
testing speed of multibuffer gcm(aes) (generic-gcm-aesni) encryption
[...] tcrypt: test 0 (128 bit key, 16 byte blocks): 1 operation in 2191 cycles (16 bytes)
This print inconsistency is because printk() is used instead of pr_cont()
in a few places. Change these to be pr_cont().
checkpatch warns that pr_cont() shouldn't be used. This can be ignored in
this context as tcrypt already uses pr_cont().
Signed-off-by: Anirudh Venkataramanan <[email protected]>
---
crypto/tcrypt.c | 8 ++++----
1 file changed, 4 insertions(+), 4 deletions(-)
diff --git a/crypto/tcrypt.c b/crypto/tcrypt.c
index 59eb8ec..7c84206 100644
--- a/crypto/tcrypt.c
+++ b/crypto/tcrypt.c
@@ -517,8 +517,8 @@ static int test_aead_cycles(struct aead_request *req, int enc, int blen)
out:
if (ret == 0)
- printk("1 operation in %lu cycles (%d bytes)\n",
- (cycles + 4) / 8, blen);
+ pr_cont("1 operation in %lu cycles (%d bytes)\n",
+ (cycles + 4) / 8, blen);
return ret;
}
@@ -738,8 +738,8 @@ static int test_ahash_jiffies_digest(struct ahash_request *req, int blen,
return ret;
}
- printk("%6u opers/sec, %9lu bytes/sec\n",
- bcount / secs, ((long)bcount * blen) / secs);
+ pr_cont("%6u opers/sec, %9lu bytes/sec\n",
+ bcount / secs, ((long)bcount * blen) / secs);
return 0;
}
--
2.37.2
On 10/25/2022 5:15 PM, Anirudh Venkataramanan wrote:
> The text tcrypt prints to dmesg is a bit inconsistent. This makes it
> difficult to process tcrypt results using scripts. This little series
> makes the prints more consistent.
>
> Anirudh Venkataramanan (4):
> crypto: tcrypt - Use pr_cont to print test results
> crypto: tcrypt - Use pr_info/pr_err
> crypto: tcrypt - Drop module name from print string
> crypto: tcrypt - Drop leading newlines from prints
>
> crypto/tcrypt.c | 36 +++++++++++++++++-------------------
> 1 file changed, 17 insertions(+), 19 deletions(-)
>
I generated this series on top of crypto-2.6.git master branch, but I
believe I should have used crypto-2.6.git tag v6.1-p2 as the base instead.
I will resend v1 with the proper base.
Ani