On Mon, 18 Sep 2023 15:43:00 +0200 Janusz Krzysztofik <[email protected]> wrote:
> We obtain KTAP report from /dev/kmsg. That file is now opened from > igt_ktest_begin(), a function originally designed for i915 selftests and > now reused with kunit tests. The original intention of opening that file > was to dump kernel messages to stderr on selftest error. For that > purpose, the file is now opened in non-blocking mode so we don't end up > waiting for more kernel messages than already available. Since our ktap > parser code reuses the file descriptor, we now have to loop over > EAGAIN responses, waiting for more KTAP data. Since we have no sleeps > inside those loops, extremely high CPU usage can be observed. > > Simplify reading KTAP reports by first switching the file descriptor back > to blocking mode. > > While being at it, fix read errors other than EPIPE likely unintentionally > ignored when reading first line of KTAP data. > > v2: Drop EINTR handling as not applicable since SIGINT default signal > handler kills the whole process anyway, > - update commit description to also mention read error handling fix. > > Signed-off-by: Janusz Krzysztofik <[email protected]> > Acked-by: Mauro Carvalho Chehab <[email protected]> # v1 LGTM. Reviewed-by: Mauro Carvalho Chehab <[email protected]> > --- > lib/igt_kmod.c | 7 +++++- > lib/igt_ktap.c | 66 +++++++++++++++++--------------------------------- > 2 files changed, 28 insertions(+), 45 deletions(-) > > diff --git a/lib/igt_kmod.c b/lib/igt_kmod.c > index 7392276401..96240543a7 100644 > --- a/lib/igt_kmod.c > +++ b/lib/igt_kmod.c > @@ -24,6 +24,7 @@ > #include <ctype.h> > #include <signal.h> > #include <errno.h> > +#include <fcntl.h> > #include <sys/utsname.h> > > #include "igt_aux.h" > @@ -758,12 +759,16 @@ static void __igt_kunit(struct igt_ktest *tst, const > char *opts) > { > struct kmod_module *kunit_kmod; > bool is_builtin; > - int ret; > struct ktap_test_results *results; > struct ktap_test_results_element *temp; > + int flags, ret; > > igt_skip_on_f(tst->kmsg < 0, "Could not open /dev/kmsg\n"); > > + flags = fcntl(tst->kmsg, F_GETFL, 0) & ~O_NONBLOCK; > + igt_skip_on_f(fcntl(tst->kmsg, F_SETFL, flags) == -1, > + "Could not set /dev/kmsg to blocking mode\n"); > + > igt_skip_on(lseek(tst->kmsg, 0, SEEK_END) < 0); > > igt_skip_on(kmod_module_new_from_name(kmod_ctx(), "kunit", > &kunit_kmod)); > diff --git a/lib/igt_ktap.c b/lib/igt_ktap.c > index 5bc5e003d7..282e44176e 100644 > --- a/lib/igt_ktap.c > +++ b/lib/igt_ktap.c > @@ -59,17 +59,12 @@ static int log_to_end(enum igt_log_level level, int fd, > while (*lend == '\0') { > igt_log(IGT_LOG_DOMAIN, level, "%s", record); > > - while (read(fd, record, BUF_LEN) < 0) { > - if (errno == EPIPE) { > + if (read(fd, record, BUF_LEN) < 0) { > + if (errno == EPIPE) > igt_warn("kmsg truncated: too many messages. > You may want to increase log_buf_len in kmcdline\n"); > - return -2; > - } > - > - if (errno == EAGAIN) > - /* No records available */ > - continue; > + else > + igt_warn("an error occurred while reading kmsg: > %m\n"); > > - igt_warn("kmsg truncated: unknown error (%m)\n"); > return -2; > } > > @@ -173,17 +168,12 @@ static int find_next_tap_subtest(int fd, char *record, > char *test_name, bool is_ > return -1; > > if (is_builtin) { > - while (read(fd, record, BUF_LEN) < 0) { > - if (errno == EPIPE) { > + if (read(fd, record, BUF_LEN) < 0) { > + if (errno == EPIPE) > igt_warn("kmsg truncated: too many messages. > You may want to increase log_buf_len in kmcdline\n"); > - return -2; > - } > + else > + igt_warn("an error occurred while reading kmsg: > %m\n"); > > - if (errno == EAGAIN) > - /* No records available */ > - continue; > - > - igt_warn("kmsg truncated: unknown error (%m)\n"); > return -2; > } > } > @@ -209,17 +199,12 @@ static int find_next_tap_subtest(int fd, char *record, > char *test_name, bool is_ > if (cutoff) > cutoff[0] = '\0'; > > - while (read(fd, record, BUF_LEN) < 0) { > - if (errno == EPIPE) { > + if (read(fd, record, BUF_LEN) < 0) { > + if (errno == EPIPE) > igt_warn("kmsg truncated: too many messages. > You may want to increase log_buf_len in kmcdline\n"); > - return -2; > - } > - > - if (errno == EAGAIN) > - /* No records available */ > - continue; > + else > + igt_warn("unknown error reading kmsg (%m)\n"); > > - igt_warn("kmsg truncated: unknown error (%m)\n"); > return -2; > } > > @@ -356,17 +341,12 @@ static int parse_tap_level(int fd, char > *base_test_name, int test_count, bool *f > char base_test_name_for_next_level[BUF_LEN + 1]; > > for (int i = 0; i < test_count; i++) { > - while (read(fd, record, BUF_LEN) < 0) { > - if (errno == EAGAIN) > - /* No records available */ > - continue; > - > - if (errno == EPIPE) { > + if (read(fd, record, BUF_LEN) < 0) { > + if (errno == EPIPE) > igt_warn("kmsg truncated: too many messages. > You may want to increase log_buf_len in kmcdline\n"); > - return -1; > - } > + else > + igt_warn("error reading kmsg (%m)\n"); > > - igt_warn("kmsg truncated: unknown error (%m)\n"); > return -1; > } > > @@ -494,15 +474,13 @@ igt_ktap_parser_start: > test_name[0] = '\0'; > test_name[BUF_LEN] = '\0'; > > - while (read(fd, record, BUF_LEN) < 0) { > - if (errno == EAGAIN) > - /* No records available */ > - continue; > - > - if (errno == EPIPE) { > + if (read(fd, record, BUF_LEN) < 0) { > + if (errno == EPIPE) > igt_warn("kmsg truncated: too many messages. You may > want to increase log_buf_len in kmcdline\n"); > - goto igt_ktap_parser_end; > - } > + else > + igt_warn("error reading kmsg (%m)\n"); > + > + goto igt_ktap_parser_end; > } > > test_count = find_next_tap_subtest(fd, record, test_name, is_builtin);
