[LTP] [PATCH 1/3] kmsg01: set/restore console log level

[LTP] [PATCH 1/3] kmsg01: set/restore console log level

[Jan Stancek]

commit 497564c77836 "kmsg01: lower the volume of message going to console"
lowered message priority for the flood of messages that try to overwrite
whole buffer. This works only for default console_loglevel. If anything
increases console_loglevel (for example a call to console_verbose()
via lockdep) system starts flooding also console. This causes a failure
on systems with slower serial console, because test is unable to
complete in 5 minutes.

Before patch:
  <timeout>

After patch:
  real	0m9.219s
  user	0m0.289s
  sys	0m4.027s

Signed-off-by: Jan Stancek <jstancek@redhat.com>
---
 testcases/kernel/logging/kmsg/kmsg01.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)

diff --git a/testcases/kernel/logging/kmsg/kmsg01.c b/testcases/kernel/logging/kmsg/kmsg01.c
index 294d0a2d1495..393acdcc71c6 100644
--- a/testcases/kernel/logging/kmsg/kmsg01.c
+++ b/testcases/kernel/logging/kmsg/kmsg01.c
@@ -52,7 +52,10 @@
 #define NUM_READ_RETRY 10
 #define NUM_OVERWRITE_MSGS 1024
 #define READ_TIMEOUT 5
+#define PRINTK "/proc/sys/kernel/printk"
+#define CONSOLE_LOGLEVEL_QUIET   4
 
+static int console_loglevel = -1;
 
 /*
  * inject_msg - write message to /dev/kmsg
@@ -571,7 +574,23 @@ static void test_kmsg(void)
 	test_seek();
 }
 
+static void setup(void)
+{
+	if (access(PRINTK, F_OK) == 0) {
+		SAFE_FILE_SCANF(PRINTK, "%d", &console_loglevel);
+		SAFE_FILE_PRINTF(PRINTK, "%d", CONSOLE_LOGLEVEL_QUIET);
+	}
+}
+
+static void cleanup(void)
+{
+	if (console_loglevel != -1)
+		SAFE_FILE_PRINTF(PRINTK, "%d", console_loglevel);
+}
+
 static struct tst_test test = {
+	.setup = setup,
+	.cleanup = cleanup,
 	.needs_root = 1,
 	.test_all = test_kmsg,
 	.min_kver = "3.5.0"
-- 
1.8.3.1

[LTP] [PATCH 2/3] kmsg01: specify read timeout in usec

[Jan Stancek]

Signed-off-by: Jan Stancek <jstancek@redhat.com>
---
 testcases/kernel/logging/kmsg/kmsg01.c | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/testcases/kernel/logging/kmsg/kmsg01.c b/testcases/kernel/logging/kmsg/kmsg01.c
index 393acdcc71c6..b81c077cbd23 100644
--- a/testcases/kernel/logging/kmsg/kmsg01.c
+++ b/testcases/kernel/logging/kmsg/kmsg01.c
@@ -51,7 +51,7 @@
 #define NUM_READ_MSGS 3
 #define NUM_READ_RETRY 10
 #define NUM_OVERWRITE_MSGS 1024
-#define READ_TIMEOUT 5
+#define READ_TIMEOUT 5000000
 #define PRINTK "/proc/sys/kernel/printk"
 #define CONSOLE_LOGLEVEL_QUIET   4
 
@@ -148,14 +148,14 @@ static int get_msg_fields(const char *msg, unsigned long *prio,
 /*
  * timed_read - if possible reads from fd or times out
  * @fd:           fd to read from
- * @timeout_sec:  timeout in seconds
+ * @timeout_usec: timeout in useconds
  *
  * RETURNS:
  *   read bytes on successful read
  *  -1 on read() error, errno reflects read() errno
  *  -2 on timeout
  */
-static int timed_read(int fd, int timeout_sec)
+static int timed_read(int fd, long timeout_usec)
 {
 	int ret, tmp;
 	struct timeval timeout;
@@ -163,8 +163,8 @@ static int timed_read(int fd, int timeout_sec)
 
 	FD_ZERO(&read_fds);
 	FD_SET(fd, &read_fds);
-	timeout.tv_sec = timeout_sec;
-	timeout.tv_usec = 0;
+	timeout.tv_sec = timeout_usec / 1000000;
+	timeout.tv_usec = timeout_usec % 1000000;
 
 	ret = select(fd + 1, &read_fds, 0, 0, &timeout);
 	switch (ret) {
@@ -183,14 +183,14 @@ static int timed_read(int fd, int timeout_sec)
  *                   read fails or times out. This ignores any
  *                   EPIPE errors.
  * @fd:           fd to read from
- * @timeout_sec:  timeout in seconds for every read attempt
+ * @timeout_usec: timeout in useconds for every read attempt
  *
  * RETURNS:
  *     0 on read reaching eof
  *    -1 on read error, errno reflects read() errno
  *    -2 on timeout
  */
-static int timed_read_kmsg(int fd, int timeout_sec)
+static int timed_read_kmsg(int fd, long timeout_usec)
 {
 	int child, status, ret = 0;
 	int pipefd[2];
@@ -226,7 +226,7 @@ static int timed_read_kmsg(int fd, int timeout_sec)
 
 	/* parent reads pipe until it reaches eof or until read times out */
 	do {
-		TEST(timed_read(pipefd[0], timeout_sec));
+		TEST(timed_read(pipefd[0], timeout_usec));
 	} while (TEST_RETURN > 0);
 	SAFE_CLOSE(pipefd[0]);
 
-- 
1.8.3.1

[LTP] [PATCH 3/3] kmsg01: use lower timeout for test_read_block()

[Jan Stancek]

Test is currently expecting that read will block for ~5 seconds.
This is a problem for busy systems, where there are many messages
periodically generated. One example is ie31200_edac module,
which periodically generates a message every second on debug
kernels.

Signed-off-by: Jan Stancek <jstancek@redhat.com>
---
 testcases/kernel/logging/kmsg/kmsg01.c | 5 ++---
 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/testcases/kernel/logging/kmsg/kmsg01.c b/testcases/kernel/logging/kmsg/kmsg01.c
index b81c077cbd23..7f077c9a3f4c 100644
--- a/testcases/kernel/logging/kmsg/kmsg01.c
+++ b/testcases/kernel/logging/kmsg/kmsg01.c
@@ -51,7 +51,6 @@
 #define NUM_READ_MSGS 3
 #define NUM_READ_RETRY 10
 #define NUM_OVERWRITE_MSGS 1024
-#define READ_TIMEOUT 5000000
 #define PRINTK "/proc/sys/kernel/printk"
 #define CONSOLE_LOGLEVEL_QUIET   4
 
@@ -252,7 +251,7 @@ static void test_read_nonblock(void)
 	tst_res(TINFO, "TEST: nonblock read");
 	fd = SAFE_OPEN("/dev/kmsg", O_RDONLY | O_NONBLOCK);
 
-	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
+	TEST(timed_read_kmsg(fd, 5000000));
 	if (TEST_RETURN == -1 && TEST_ERRNO == EAGAIN)
 		tst_res(TPASS, "non-block read returned EAGAIN");
 	else
@@ -268,7 +267,7 @@ static void test_read_block(void)
 	tst_res(TINFO, "TEST: blocking read");
 	fd = SAFE_OPEN("/dev/kmsg", O_RDONLY);
 
-	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
+	TEST(timed_read_kmsg(fd, 500000));
 	if (TEST_RETURN == -2)
 		tst_res(TPASS, "read blocked");
 	else
-- 
1.8.3.1

[LTP] [PATCH 1/3] kmsg01: set/restore console log level

[Cyril Hrubis]

Hi!
Looks good.

-- 
Cyril Hrubis
chrubis@suse.cz

[LTP] [PATCH 3/3] kmsg01: use lower timeout for test_read_block()

[Cyril Hrubis]

Hi!
> Test is currently expecting that read will block for ~5 seconds.
> This is a problem for busy systems, where there are many messages
> periodically generated. One example is ie31200_edac module,
> which periodically generates a message every second on debug
> kernels.

Sounds reasonable to me. Consider the whole patchset acked.

-- 
Cyril Hrubis
chrubis@suse.cz

[LTP] [PATCH 3/3] kmsg01: use lower timeout for test_read_block()

[Jan Stancek]

----- Original Message -----
> Hi!
> > Test is currently expecting that read will block for ~5 seconds.
> > This is a problem for busy systems, where there are many messages
> > periodically generated. One example is ie31200_edac module,
> > which periodically generates a message every second on debug
> > kernels.
> 
> Sounds reasonable to me. Consider the whole patchset acked.

Pushed.

Regards,
Jan