[PATCH bpf-next] bpf: bpf_log() clean-up for kernel log output

[PATCH bpf-next] bpf: bpf_log() clean-up for kernel log output

[Hou Tao]

An extra newline will output for bpf_log() with BPF_LOG_KERNEL level
as shown below:

[   52.095704] BPF:The function test_3 has 12 arguments. Too many.
[   52.095704]
[   52.096896] Error in parsing func ptr test_3 in struct bpf_dummy_ops

Now all bpf_log() are ended by newline, so just remove the extra newline.

Also there is no need to calculate the left userspace buffer size
for kernel log output and to truncate the output by '\0' which
has already been done by vscnprintf(), so only do these for
userspace log output.

Signed-off-by: Hou Tao <houtao1@huawei.com>
---
 kernel/bpf/verifier.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index c6616e325803..7d4a313da86e 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -299,13 +299,13 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt,
 	WARN_ONCE(n >= BPF_VERIFIER_TMP_LOG_SIZE - 1,
 		  "verifier log line truncated - local buffer too short\n");
 
-	n = min(log->len_total - log->len_used - 1, n);
-	log->kbuf[n] = '\0';
-
 	if (log->level == BPF_LOG_KERNEL) {
-		pr_err("BPF:%s\n", log->kbuf);
+		pr_err("BPF:%s", log->kbuf);
 		return;
 	}
+
+	n = min(log->len_total - log->len_used - 1, n);
+	log->kbuf[n] = '\0';
 	if (!copy_to_user(log->ubuf + log->len_used, log->kbuf, n + 1))
 		log->len_used += n;
 	else
-- 
2.29.2

Re: [PATCH bpf-next] bpf: bpf_log() clean-up for kernel log output

[Martin KaFai Lau]

On Tue, Oct 26, 2021 at 09:38:19PM +0800, Hou Tao wrote:
> An extra newline will output for bpf_log() with BPF_LOG_KERNEL level
> as shown below:
> 
> [   52.095704] BPF:The function test_3 has 12 arguments. Too many.
> [   52.095704]
> [   52.096896] Error in parsing func ptr test_3 in struct bpf_dummy_ops
> 
> Now all bpf_log() are ended by newline, so just remove the extra newline.
bpf_verifier_vlog is also called by btf_verifier_log.
Not all of them is ended with newline.

> 
> Also there is no need to calculate the left userspace buffer size
> for kernel log output and to truncate the output by '\0' which
> has already been done by vscnprintf(), so only do these for
> userspace log output.
> 
> Signed-off-by: Hou Tao <houtao1@huawei.com>
> ---
>  kernel/bpf/verifier.c | 8 ++++----
>  1 file changed, 4 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> index c6616e325803..7d4a313da86e 100644
> --- a/kernel/bpf/verifier.c
> +++ b/kernel/bpf/verifier.c
> @@ -299,13 +299,13 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt,
>  	WARN_ONCE(n >= BPF_VERIFIER_TMP_LOG_SIZE - 1,
>  		  "verifier log line truncated - local buffer too short\n");
>  
> -	n = min(log->len_total - log->len_used - 1, n);
> -	log->kbuf[n] = '\0';
> -
>  	if (log->level == BPF_LOG_KERNEL) {
> -		pr_err("BPF:%s\n", log->kbuf);
> +		pr_err("BPF:%s", log->kbuf);
How about trim the tailing '\n' (if any) from kbuf?
or just test if kbuf is ended with '\n'?

>  		return;
>  	}
> +
> +	n = min(log->len_total - log->len_used - 1, n);
> +	log->kbuf[n] = '\0';
>  	if (!copy_to_user(log->ubuf + log->len_used, log->kbuf, n + 1))
>  		log->len_used += n;
>  	else
> -- 
> 2.29.2
> 

Re: [PATCH bpf-next] bpf: bpf_log() clean-up for kernel log output

[Hou Tao]

Hi,

On 10/27/2021 5:35 AM, Martin KaFai Lau wrote:
> On Tue, Oct 26, 2021 at 09:38:19PM +0800, Hou Tao wrote:
>> An extra newline will output for bpf_log() with BPF_LOG_KERNEL level
>> as shown below:
>>
>> [   52.095704] BPF:The function test_3 has 12 arguments. Too many.
>> [   52.095704]
>> [   52.096896] Error in parsing func ptr test_3 in struct bpf_dummy_ops
>>
>> Now all bpf_log() are ended by newline, so just remove the extra newline.
> bpf_verifier_vlog is also called by btf_verifier_log.
> Not all of them is ended with newline.
Yes, you are right. I miss that.

>> Also there is no need to calculate the left userspace buffer size
>> for kernel log output and to truncate the output by '\0' which
>> has already been done by vscnprintf(), so only do these for
>> userspace log output.
>>
>> Signed-off-by: Hou Tao <houtao1@huawei.com>
>> ---
>>  kernel/bpf/verifier.c | 8 ++++----
>>  1 file changed, 4 insertions(+), 4 deletions(-)
>>
>> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
>> index c6616e325803..7d4a313da86e 100644
>> --- a/kernel/bpf/verifier.c
>> +++ b/kernel/bpf/verifier.c
>> @@ -299,13 +299,13 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt,
>>  	WARN_ONCE(n >= BPF_VERIFIER_TMP_LOG_SIZE - 1,
>>  		  "verifier log line truncated - local buffer too short\n");
>>  
>> -	n = min(log->len_total - log->len_used - 1, n);
>> -	log->kbuf[n] = '\0';
>> -
>>  	if (log->level == BPF_LOG_KERNEL) {
>> -		pr_err("BPF:%s\n", log->kbuf);
>> +		pr_err("BPF:%s", log->kbuf);
> How about trim the tailing '\n' (if any) from kbuf?
> or just test if kbuf is ended with '\n'?
Testing whether or not kbuf is newline ended is OK for me.
Although it can not handle the output for the complex case (e.g.
btf_verifier_log_type(env, t, "vlen != 0")) in which a full line is break
into multiple parts and the newline is the last part, but it can handle
the output format for most btf_verifier_log()
(e.g. btf_verifier_log(env, "hdr_len not found")).
>
>>  		return;
>>  	}
>> +
>> +	n = min(log->len_total - log->len_used - 1, n);
>> +	log->kbuf[n] = '\0';
>>  	if (!copy_to_user(log->ubuf + log->len_used, log->kbuf, n + 1))
>>  		log->len_used += n;
>>  	else
>> -- 
>> 2.29.2
>>
> .