kmsg01: set/restore console log level
PATCH 1/3 kmsg01: set/restore console log level
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
--- testcases/kernel/logging/kmsg/kmsg01.c | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+)
testcases/kernel/logging/kmsg/kmsg01.c +19 -0
@@ -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"
Signature · 1 line
1.8.3.1
PATCH 2/3 kmsg01: specify read timeout in usec
--- testcases/kernel/logging/kmsg/kmsg01.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-)
testcases/kernel/logging/kmsg/kmsg01.c +8 -8
@@ -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 ]);
Signature · 1 line
1.8.3.1
PATCH 3/3 kmsg01: use lower timeout for test_read_block()
In reply to Jan StancekTest 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.
--- testcases/kernel/logging/kmsg/kmsg01.c | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-)
testcases/kernel/logging/kmsg/kmsg01.c +2 -3
@@ -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
Signature · 1 line
1.8.3.1
PATCH 3/3 kmsg01: use lower timeout for test_read_block()
Hi!
Quoted 5 lines
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_edacmodule, which periodically generates a message every second on debug kernels.
Sounds reasonable to me. Consider the whole patchset acked.
Signature · 2 lines
Cyril Hrubis [email protected]
PATCH 3/3 kmsg01: use lower timeout for test_read_block()
----- Original Message -----
Quoted 8 lines
Hi!
Quoted 5 lines
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_edacmodule, which periodically generates a message every second on debug kernels.Sounds reasonable to me. Consider the whole patchset acked.
Pushed.
Regards,
Jan
PATCH 1/3 kmsg01: set/restore console log level
In reply to Jan StancekHi!
Looks good.
Signature · 2 lines
Cyril Hrubis [email protected]