[PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[Amery Hung]

Fix a race condition between the main test_progs thread and the traffic
monitoring thread. The traffic monitor thread tries to print a line
using multiple printf and use flockfile() to prevent the line from being
torn apart. Meanwhile, the main thread doing io redirection can reassign
or close stdout when going through tests. A deadlock as shown below can
happen.

       main                      traffic_monitor_thread
       ====                      ======================
                                 show_transport()
                                 -> flockfile(stdout)

stdio_hijack_init()
-> stdout = open_memstream(log_buf, log_cnt);
   ...
   env.subtest_state->stdout_saved = stdout;

                                    ...
                                    funlockfile(stdout)
stdio_restore_cleanup()
-> fclose(env.subtest_state->stdout_saved);

After the traffic monitor thread lock stdout, A new memstream can be
assigned to stdout by the main thread. Therefore, the traffic monitor
thread later will not be able to unlock the original stdout. As the
main thread tries to access the old stdout, it will hang indefinitely
as it is still locked by the traffic monitor thread.

The deadlock can be reproduced by running test_progs repeatedly with
traffic monitor enabled:

for ((i=1;i<=100;i++)); do
  ./test_progs -a flow_dissector_skb* -m '*'
done

Fix this by only calling printf once and remove flockfile()/funlockfile().

Signed-off-by: Amery Hung <ameryhung@gmail.com>
---
 tools/testing/selftests/bpf/network_helpers.c | 33 ++++++++-----------
 1 file changed, 13 insertions(+), 20 deletions(-)

diff --git a/tools/testing/selftests/bpf/network_helpers.c b/tools/testing/selftests/bpf/network_helpers.c
index 80844a5fb1fe..95e943270f35 100644
--- a/tools/testing/selftests/bpf/network_helpers.c
+++ b/tools/testing/selftests/bpf/network_helpers.c
@@ -771,12 +771,13 @@ static const char *pkt_type_str(u16 pkt_type)
 	return "Unknown";
 }
 
+#define MAX_FLAGS_STRLEN 21
 /* Show the information of the transport layer in the packet */
 static void show_transport(const u_char *packet, u16 len, u32 ifindex,
 			   const char *src_addr, const char *dst_addr,
 			   u16 proto, bool ipv6, u8 pkt_type)
 {
-	char *ifname, _ifname[IF_NAMESIZE];
+	char *ifname, _ifname[IF_NAMESIZE], flags[MAX_FLAGS_STRLEN] = "";
 	const char *transport_str;
 	u16 src_port, dst_port;
 	struct udphdr *udp;
@@ -817,29 +818,21 @@ static void show_transport(const u_char *packet, u16 len, u32 ifindex,
 
 	/* TCP or UDP*/
 
-	flockfile(stdout);
+	if (proto == IPPROTO_TCP)
+		snprintf(flags, MAX_FLAGS_STRLEN, "%s%s%s%s",
+			 tcp->fin ? ", FIN" : "",
+			 tcp->syn ? ", SYN" : "",
+			 tcp->rst ? ", RST" : "",
+			 tcp->ack ? ", ACK" : "");
+
 	if (ipv6)
-		printf("%-7s %-3s IPv6 %s.%d > %s.%d: %s, length %d",
+		printf("%-7s %-3s IPv6 %s.%d > %s.%d: %s, length %d%s\n",
 		       ifname, pkt_type_str(pkt_type), src_addr, src_port,
-		       dst_addr, dst_port, transport_str, len);
+		       dst_addr, dst_port, transport_str, len, flags);
 	else
-		printf("%-7s %-3s IPv4 %s:%d > %s:%d: %s, length %d",
+		printf("%-7s %-3s IPv4 %s:%d > %s:%d: %s, length %d%s\n",
 		       ifname, pkt_type_str(pkt_type), src_addr, src_port,
-		       dst_addr, dst_port, transport_str, len);
-
-	if (proto == IPPROTO_TCP) {
-		if (tcp->fin)
-			printf(", FIN");
-		if (tcp->syn)
-			printf(", SYN");
-		if (tcp->rst)
-			printf(", RST");
-		if (tcp->ack)
-			printf(", ACK");
-	}
-
-	printf("\n");
-	funlockfile(stdout);
+		       dst_addr, dst_port, transport_str, len, flags);
 }
 
 static void show_ipv6_packet(const u_char *packet, u32 ifindex, u8 pkt_type)
-- 
2.47.1

Re: [PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[Martin KaFai Lau]

On 2/13/25 3:32 PM, Amery Hung wrote:
> Fix a race condition between the main test_progs thread and the traffic
> monitoring thread. The traffic monitor thread tries to print a line
> using multiple printf and use flockfile() to prevent the line from being
> torn apart. Meanwhile, the main thread doing io redirection can reassign
> or close stdout when going through tests. A deadlock as shown below can
> happen.
> 
>         main                      traffic_monitor_thread
>         ====                      ======================
>                                   show_transport()
>                                   -> flockfile(stdout)
> 
> stdio_hijack_init()
> -> stdout = open_memstream(log_buf, log_cnt);
>     ...
>     env.subtest_state->stdout_saved = stdout;
> 
>                                      ...
>                                      funlockfile(stdout)
> stdio_restore_cleanup()
> -> fclose(env.subtest_state->stdout_saved);

Great debugging.

Does it mean that the main thread will start the next test before the 
traffic_monitor_thread has finished? Meaning the traffic_monitor_stop() does not 
wait for the traffic_monitor_thread somehow?

> 
> After the traffic monitor thread lock stdout, A new memstream can be
> assigned to stdout by the main thread. Therefore, the traffic monitor
> thread later will not be able to unlock the original stdout. As the
> main thread tries to access the old stdout, it will hang indefinitely
> as it is still locked by the traffic monitor thread.
> 
> The deadlock can be reproduced by running test_progs repeatedly with
> traffic monitor enabled:
> 
> for ((i=1;i<=100;i++)); do
>    ./test_progs -a flow_dissector_skb* -m '*'
> done
> 
> Fix this by only calling printf once and remove flockfile()/funlockfile().

Yep. I agree this patch should be the better way to print the one-liner regardless.

Re: [PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[Amery Hung]

On Thu, Feb 13, 2025 at 3:55 PM Martin KaFai Lau <martin.lau@linux.dev> wrote:
>
> On 2/13/25 3:32 PM, Amery Hung wrote:
> > Fix a race condition between the main test_progs thread and the traffic
> > monitoring thread. The traffic monitor thread tries to print a line
> > using multiple printf and use flockfile() to prevent the line from being
> > torn apart. Meanwhile, the main thread doing io redirection can reassign
> > or close stdout when going through tests. A deadlock as shown below can
> > happen.
> >
> >         main                      traffic_monitor_thread
> >         ====                      ======================
> >                                   show_transport()
> >                                   -> flockfile(stdout)
> >
> > stdio_hijack_init()
> > -> stdout = open_memstream(log_buf, log_cnt);
> >     ...
> >     env.subtest_state->stdout_saved = stdout;
> >
> >                                      ...
> >                                      funlockfile(stdout)
> > stdio_restore_cleanup()
> > -> fclose(env.subtest_state->stdout_saved);
>
> Great debugging.
>
> Does it mean that the main thread will start the next test before the
> traffic_monitor_thread has finished? Meaning the traffic_monitor_stop() does not
> wait for the traffic_monitor_thread somehow?

That part I think is fine. The race condition here happen between
subtests within the same "netns_new" scope. For example,
test_flow_dissector_skb_less_direct_attach.

>
> >
> > After the traffic monitor thread lock stdout, A new memstream can be
> > assigned to stdout by the main thread. Therefore, the traffic monitor
> > thread later will not be able to unlock the original stdout. As the
> > main thread tries to access the old stdout, it will hang indefinitely
> > as it is still locked by the traffic monitor thread.
> >
> > The deadlock can be reproduced by running test_progs repeatedly with
> > traffic monitor enabled:
> >
> > for ((i=1;i<=100;i++)); do
> >    ./test_progs -a flow_dissector_skb* -m '*'
> > done
> >
> > Fix this by only calling printf once and remove flockfile()/funlockfile().
>
> Yep. I agree this patch should be the better way to print the one-liner regardless.
>

Re: [PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[Martin KaFai Lau]

On 2/13/25 4:19 PM, Amery Hung wrote:
> On Thu, Feb 13, 2025 at 3:55 PM Martin KaFai Lau <martin.lau@linux.dev> wrote:
>>
>> On 2/13/25 3:32 PM, Amery Hung wrote:
>>> Fix a race condition between the main test_progs thread and the traffic
>>> monitoring thread. The traffic monitor thread tries to print a line
>>> using multiple printf and use flockfile() to prevent the line from being
>>> torn apart. Meanwhile, the main thread doing io redirection can reassign
>>> or close stdout when going through tests. A deadlock as shown below can
>>> happen.
>>>
>>>          main                      traffic_monitor_thread
>>>          ====                      ======================
>>>                                    show_transport()
>>>                                    -> flockfile(stdout)
>>>
>>> stdio_hijack_init()
>>> -> stdout = open_memstream(log_buf, log_cnt);
>>>      ...
>>>      env.subtest_state->stdout_saved = stdout;
>>>
>>>                                       ...
>>>                                       funlockfile(stdout)
>>> stdio_restore_cleanup()
>>> -> fclose(env.subtest_state->stdout_saved);
>>
>> Great debugging.
>>
>> Does it mean that the main thread will start the next test before the
>> traffic_monitor_thread has finished? Meaning the traffic_monitor_stop() does not
>> wait for the traffic_monitor_thread somehow?
> 
> That part I think is fine. The race condition here happen between
> subtests within the same "netns_new" scope. For example,
> test_flow_dissector_skb_less_direct_attach.

Got it. Thanks for the fix. Applied.

Re: [PATCH bpf-next v1] selftests/bpf: Fix stdout race condition in traffic monitor

[patchwork-bot+netdevbpf]

Hello:

This patch was applied to bpf/bpf-next.git (master)
by Martin KaFai Lau <martin.lau@kernel.org>:

On Thu, 13 Feb 2025 15:32:17 -0800 you wrote:
> Fix a race condition between the main test_progs thread and the traffic
> monitoring thread. The traffic monitor thread tries to print a line
> using multiple printf and use flockfile() to prevent the line from being
> torn apart. Meanwhile, the main thread doing io redirection can reassign
> or close stdout when going through tests. A deadlock as shown below can
> happen.
> 
> [...]

Here is the summary with links:
  - [bpf-next,v1] selftests/bpf: Fix stdout race condition in traffic monitor
    https://git.kernel.org/bpf/bpf-next/c/b99f27e90268

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html