Re: [PATCH v2] net/bpfilter: fix dprintf usage for /dev/kmsg

Re: [PATCH v2] net/bpfilter: fix dprintf usage for /dev/kmsg

[Bruno Meneguele]

[-- Attachment #1: Type: text/plain, Size: 1286 bytes --]

On Mon, Mar 30, 2020 at 03:48:12PM +0300, Martin Zaharinov wrote:
> Hi Bruno
> i see after release kernel 5.6.0 with your latest patch have strange
> messages please check:
> 
> [   31.025483] bpfilter: Loaded bpfilter_umh pid 2689
> [   31.025533] Started bpfilter
> [   31.042586] testing the buffer
> [   31.050822] testing the buffer
> [   31.059304] testing the buffer
> [   31.067747] testing the buffer
> [   31.148789] testing the buffer
> [   31.156130] testing the buffer
> [   31.164012] testing the buffer
> [   31.170685] testing the buffer
> [   31.176886] testing the buffer
> 
> when drop bpfilter module stop enter new messages in kmsg.
> 

Hi Martin,

these aren't really "strange messages", but the correct ones. They
started to appear now because before my patch the log wasn't working at
all. I'm not really aware what is the logic behind the bpfilter_umh
module, but AFAIK each iptable rule sent from kernel side to UMH
userspace code will generate one "testing the buffer" message.

I think we can silence it by limiting it to print only once, but I would
need to check with Alexei Starovoitov <ast@kernel.org> if it would be
fine (CC'ing here).

Thanks for the heads up :).

-- 
bmeneg 
PGP Key: http://bmeneg.com/pubkey.txt

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCH v2] net/bpfilter: fix dprintf usage for /dev/kmsg

[Bruno Meneguele]

[-- Attachment #1: Type: text/plain, Size: 1675 bytes --]

On Mon, Mar 30, 2020 at 10:13:15AM -0300, Bruno Meneguele wrote:
> On Mon, Mar 30, 2020 at 03:48:12PM +0300, Martin Zaharinov wrote:
> > Hi Bruno
> > i see after release kernel 5.6.0 with your latest patch have strange
> > messages please check:
> > 
> > [   31.025483] bpfilter: Loaded bpfilter_umh pid 2689
> > [   31.025533] Started bpfilter
> > [   31.042586] testing the buffer
> > [   31.050822] testing the buffer
> > [   31.059304] testing the buffer
> > [   31.067747] testing the buffer
> > [   31.148789] testing the buffer
> > [   31.156130] testing the buffer
> > [   31.164012] testing the buffer
> > [   31.170685] testing the buffer
> > [   31.176886] testing the buffer
> > 
> > when drop bpfilter module stop enter new messages in kmsg.
> > 
> 
> Hi Martin,
> 
> these aren't really "strange messages", but the correct ones. They
> started to appear now because before my patch the log wasn't working at
> all. I'm not really aware what is the logic behind the bpfilter_umh
> module, but AFAIK each iptable rule sent from kernel side to UMH
> userspace code will generate one "testing the buffer" message.
> 
> I think we can silence it by limiting it to print only once, but I would
> need to check with Alexei Starovoitov <ast@kernel.org> if it would be
> fine (CC'ing here).
> 
> Thanks for the heads up :).
> 

Wow, forget about all of that! That's actually my mistake!
This "testing the buffer" was actually added by my own patch! How could
I not see that? I'm really sorry and /thanks/ at the same time Martin.
I'm going to send a new patch removing it.


-- 
bmeneg 
PGP Key: http://bmeneg.com/pubkey.txt

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCH v2] net/bpfilter: fix dprintf usage for /dev/kmsg

[David Miller]

From: Bruno Meneguele <bmeneg@redhat.com>
Date: Thu, 12 Mar 2020 20:08:20 -0300

> The bpfilter UMH code was recently changed to log its informative messages to
> /dev/kmsg, however this interface doesn't support SEEK_CUR yet, used by
> dprintf(). As result dprintf() returns -EINVAL and doesn't log anything.
> 
> However there already had some discussions about supporting SEEK_CUR into
> /dev/kmsg interface in the past it wasn't concluded. Since the only user of
> that from userspace perspective inside the kernel is the bpfilter UMH
> (userspace) module it's better to correct it here instead waiting a conclusion
> on the interface.
> 
> Fixes: 36c4357c63f3 ("net: bpfilter: print umh messages to /dev/kmsg")
> Signed-off-by: Bruno Meneguele <bmeneg@redhat.com>

Applied, thank you.

[PATCH v2] net/bpfilter: fix dprintf usage for /dev/kmsg

[Bruno Meneguele]

The bpfilter UMH code was recently changed to log its informative messages to
/dev/kmsg, however this interface doesn't support SEEK_CUR yet, used by
dprintf(). As result dprintf() returns -EINVAL and doesn't log anything.

However there already had some discussions about supporting SEEK_CUR into
/dev/kmsg interface in the past it wasn't concluded. Since the only user of
that from userspace perspective inside the kernel is the bpfilter UMH
(userspace) module it's better to correct it here instead waiting a conclusion
on the interface.

Fixes: 36c4357c63f3 ("net: bpfilter: print umh messages to /dev/kmsg")
Signed-off-by: Bruno Meneguele <bmeneg@redhat.com>
---
 net/bpfilter/main.c | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/net/bpfilter/main.c b/net/bpfilter/main.c
index 77396a098fbe..efea4874743e 100644
--- a/net/bpfilter/main.c
+++ b/net/bpfilter/main.c
@@ -10,7 +10,7 @@
 #include <asm/unistd.h>
 #include "msgfmt.h"
 
-int debug_fd;
+FILE *debug_f;
 
 static int handle_get_cmd(struct mbox_request *cmd)
 {
@@ -35,9 +35,10 @@ static void loop(void)
 		struct mbox_reply reply;
 		int n;
 
+		fprintf(debug_f, "testing the buffer\n");
 		n = read(0, &req, sizeof(req));
 		if (n != sizeof(req)) {
-			dprintf(debug_fd, "invalid request %d\n", n);
+			fprintf(debug_f, "invalid request %d\n", n);
 			return;
 		}
 
@@ -47,7 +48,7 @@ static void loop(void)
 
 		n = write(1, &reply, sizeof(reply));
 		if (n != sizeof(reply)) {
-			dprintf(debug_fd, "reply failed %d\n", n);
+			fprintf(debug_f, "reply failed %d\n", n);
 			return;
 		}
 	}
@@ -55,9 +56,10 @@ static void loop(void)
 
 int main(void)
 {
-	debug_fd = open("/dev/kmsg", 00000002);
-	dprintf(debug_fd, "Started bpfilter\n");
+	debug_f = fopen("/dev/kmsg", "w");
+	setvbuf(debug_f, 0, _IOLBF, 0);
+	fprintf(debug_f, "Started bpfilter\n");
 	loop();
-	close(debug_fd);
+	fclose(debug_f);
 	return 0;
 }
-- 
2.24.1