Hi KP, Lorenz,
I need your help to debug a huge delay I'm seeing while running the test_progs.
To debug it I've added the following printf-s:
diff --git a/tools/testing/selftests/bpf/prog_tests/test_bprm_opts.c
b/tools/testing/selftests/bpf/prog_tests/test_bprm_opts.c
index 2559bb775762..cdd2182c83a2 100644
--- a/tools/testing/selftests/bpf/prog_tests/test_bprm_opts.c
+++ b/tools/testing/selftests/bpf/prog_tests/test_bprm_opts.c
@@ -66,8 +66,10 @@ static int run_set_secureexec(int map_fd, int secureexec)
* If the value of TMPDIR is set, the bash command returns 10
* and if the value is unset, it returns 20.
*/
+ null_fd = open("/dev/console", O_WRONLY);
+ dprintf(null_fd, "before_bash\n");
execle("/bin/bash", "bash", "-c",
- "[[ -z \"${TMPDIR}\" ]] || exit 10 && exit 20", NULL,
+ "echo running_bash > /dev/console;[[ -z
\"${TMPDIR}\" ]] || exit 10 && exit 20", NULL,
bash_envp);
exit(errno);
} else if (child_pid > 0) {
Then I do:
./test_progs -n 127
before_bash
running_bash
before_bash
running_bash
#127 test_bprm_opts:OK
Summary: 1/0 PASSED, 0 SKIPPED, 0 FAILED
and it takes a split second to execute. There is no visible delay.
But when I run it as:
./test_progs -n 98,127
#98 sk_lookup:OK
before_bash
// huge delay here
running_bash
before_bash
running_bash
#127 test_bprm_opts:OK
Summary: 2/46 PASSED, 0 SKIPPED, 0 FAILED
real 0m51.414s
user 0m0.808s
sys 0m35.731s
All 50 seconds are spent waiting after "before_bash" line is printed.
Something is drastically delaying execle("/bin/bash").
But replacing arg0 of "bash" with "sh" makes it fast !
execle("/bin/bash", "sh"
^^ instead of "bash".
I cannot explain all this at all.
sk_lookup test doing some netns and forking "ip",
but why would that slow down "bash" startup time?
And why would bash start quickly if it thinks that it's name is "sh" ?
For giggles I've tried:
execle("/bin/bash", "foobar"
and it's also slow.
Crazy ideas are welcome :)
