[LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[Jan Stancek]

If system continues to produce log entries, test_read_block()
may never end, because it won't reach EOF neither timeout.

This has been observed with x38_edac in debug kernel, where
this module keeps producing periodic log entries.

The test already has a timeout on single read, this patch
adds overall timeout for all reads combined to not cross
over specified value. This should prevent testcase from
running in infinite loop in case log entries are generated
periodically / indefinitely.

It also adds seek to end of kmsg for block/nonblock read tests
as it is not necessary to go through whole content entry by entry.

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

diff --git a/testcases/kernel/logging/kmsg/kmsg01.c b/testcases/kernel/logging/kmsg/kmsg01.c
index 4e24298..4307947 100644
--- a/testcases/kernel/logging/kmsg/kmsg01.c
+++ b/testcases/kernel/logging/kmsg/kmsg01.c
@@ -52,7 +52,8 @@
 #define NUM_READ_MSGS 3
 #define NUM_READ_RETRY 10
 #define NUM_OVERWRITE_MSGS 1024
-#define READ_TIMEOUT 5
+#define SINGLE_READ_TIMEOUT 2
+#define READ_TIMEOUT_MS (30*1000)
 
 char *TCID = "kmsg01";
 static void setup(void);
@@ -196,11 +197,12 @@ static int timed_read(int fd, int timeout_sec)
  *    -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, int timeout_ms)
 {
 	int child, status, ret = 0;
 	int pipefd[2];
 	char msg[MAX_MSGSIZE];
+	long long elapsed_ms = 0;
 
 	if (pipe(pipefd) != 0)
 		tst_brkm(TBROK|TERRNO, cleanup, "pipe failed");
@@ -231,11 +233,22 @@ static int timed_read_kmsg(int fd, int timeout_sec)
 	SAFE_CLOSE(cleanup, pipefd[1]);
 
 	/* parent reads pipe until it reaches eof or until read times out */
+	tst_timer_start(CLOCK_MONOTONIC);
 	do {
-		TEST(timed_read(pipefd[0], timeout_sec));
-	} while (TEST_RETURN > 0);
+		TEST(timed_read(pipefd[0], SINGLE_READ_TIMEOUT));
+		tst_timer_stop();
+		elapsed_ms = tst_timer_elapsed_ms();
+	} while (TEST_RETURN > 0 && elapsed_ms < timeout_ms);
 	SAFE_CLOSE(cleanup, pipefd[0]);
 
+	if (elapsed_ms >= timeout_ms) {
+		/* this is not necessarily error, kernel or user-space
+		 * process may generate messages at higher rate than what
+		 * we would consider as 'blocked', see SINGLE_READ_TIMEOUT */
+		tst_resm(TWARN, "reads taking too long, giving up");
+		TEST_RETURN = -2;
+	}
+
 	/* child is blocked, kill it */
 	if (TEST_RETURN == -2)
 		kill(child, SIGTERM);
@@ -261,7 +274,12 @@ static void test_read_nonblock(void)
 	if (fd < 0)
 		tst_brkm(TBROK|TERRNO, cleanup, "failed to open /dev/kmsg");
 
-	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
+	if (lseek(fd, 0, SEEK_END) == -1)
+		tst_resm(TFAIL|TERRNO, "SEEK_END 0 failed");
+
+	/* /dev/kmsg opened with O_NONBLOCK will return EAGAIN when
+	 * no more records are available */
+	TEST(timed_read_kmsg(fd, READ_TIMEOUT_MS));
 	if (TEST_RETURN == -1 && TEST_ERRNO == EAGAIN)
 		tst_resm(TPASS, "non-block read returned EAGAIN");
 	else
@@ -279,7 +297,12 @@ static void test_read_block(void)
 	if (fd < 0)
 		tst_brkm(TBROK|TERRNO, cleanup, "failed to open /dev/kmsg");
 
-	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
+	if (lseek(fd, 0, SEEK_END) == -1)
+		tst_resm(TFAIL|TERRNO, "SEEK_END 0 failed");
+
+	/* /dev/kmsg opened without O_NONBLOCK will block on read when
+	 * no more records are available */
+	TEST(timed_read_kmsg(fd, READ_TIMEOUT_MS));
 	if (TEST_RETURN == -2)
 		tst_resm(TPASS, "read blocked");
 	else
@@ -582,6 +605,7 @@ static void setup(void)
 	if (tst_kvercmp(3, 5, 0) < 0)
 		tst_brkm(TCONF, NULL, "This test requires kernel"
 			" >= 3.5.0");
+	tst_timer_check(CLOCK_MONOTONIC);
 	srand(getpid());
 	TEST_PAUSE;
 }
-- 
1.8.3.1


------------------------------------------------------------------------------
_______________________________________________
Ltp-list mailing list
Ltp-list@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ltp-list

Re: [LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[Cyril Hrubis]

Hi!
> diff --git a/testcases/kernel/logging/kmsg/kmsg01.c b/testcases/kernel/logging/kmsg/kmsg01.c
> index 4e24298..4307947 100644
> --- a/testcases/kernel/logging/kmsg/kmsg01.c
> +++ b/testcases/kernel/logging/kmsg/kmsg01.c
> @@ -52,7 +52,8 @@
>  #define NUM_READ_MSGS 3
>  #define NUM_READ_RETRY 10
>  #define NUM_OVERWRITE_MSGS 1024
> -#define READ_TIMEOUT 5
> +#define SINGLE_READ_TIMEOUT 2
> +#define READ_TIMEOUT_MS (30*1000)
>  
>  char *TCID = "kmsg01";
>  static void setup(void);
> @@ -196,11 +197,12 @@ static int timed_read(int fd, int timeout_sec)
>   *    -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, int timeout_ms)
>  {
>  	int child, status, ret = 0;
>  	int pipefd[2];
>  	char msg[MAX_MSGSIZE];
> +	long long elapsed_ms = 0;
>  
>  	if (pipe(pipefd) != 0)
>  		tst_brkm(TBROK|TERRNO, cleanup, "pipe failed");
> @@ -231,11 +233,22 @@ static int timed_read_kmsg(int fd, int timeout_sec)
>  	SAFE_CLOSE(cleanup, pipefd[1]);
>  
>  	/* parent reads pipe until it reaches eof or until read times out */
> +	tst_timer_start(CLOCK_MONOTONIC);
>  	do {
> -		TEST(timed_read(pipefd[0], timeout_sec));
> -	} while (TEST_RETURN > 0);
> +		TEST(timed_read(pipefd[0], SINGLE_READ_TIMEOUT));
> +		tst_timer_stop();
> +		elapsed_ms = tst_timer_elapsed_ms();
> +	} while (TEST_RETURN > 0 && elapsed_ms < timeout_ms);
>  	SAFE_CLOSE(cleanup, pipefd[0]);
>  
> +	if (elapsed_ms >= timeout_ms) {
> +		/* this is not necessarily error, kernel or user-space
> +		 * process may generate messages at higher rate than what
> +		 * we would consider as 'blocked', see SINGLE_READ_TIMEOUT */
> +		tst_resm(TWARN, "reads taking too long, giving up");
> +		TEST_RETURN = -2;
> +	}

Maybe this is worth of new return value, since this means that we
timeouted while waiting for timeout.

Apart from that the logic looks fine. The test could be probably cleaned
by using checkpoints instead of pipe and the function used to propagate
exit value from child, but that is probably worth of separate patch.

>  	/* child is blocked, kill it */
>  	if (TEST_RETURN == -2)
>  		kill(child, SIGTERM);
> @@ -261,7 +274,12 @@ static void test_read_nonblock(void)
>  	if (fd < 0)
>  		tst_brkm(TBROK|TERRNO, cleanup, "failed to open /dev/kmsg");
>  
> -	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
> +	if (lseek(fd, 0, SEEK_END) == -1)
> +		tst_resm(TFAIL|TERRNO, "SEEK_END 0 failed");
> +
> +	/* /dev/kmsg opened with O_NONBLOCK will return EAGAIN when
> +	 * no more records are available */
> +	TEST(timed_read_kmsg(fd, READ_TIMEOUT_MS));
>  	if (TEST_RETURN == -1 && TEST_ERRNO == EAGAIN)
>  		tst_resm(TPASS, "non-block read returned EAGAIN");
>  	else
> @@ -279,7 +297,12 @@ static void test_read_block(void)
>  	if (fd < 0)
>  		tst_brkm(TBROK|TERRNO, cleanup, "failed to open /dev/kmsg");
>  
> -	TEST(timed_read_kmsg(fd, READ_TIMEOUT));
> +	if (lseek(fd, 0, SEEK_END) == -1)
> +		tst_resm(TFAIL|TERRNO, "SEEK_END 0 failed");
> +
> +	/* /dev/kmsg opened without O_NONBLOCK will block on read when
> +	 * no more records are available */
> +	TEST(timed_read_kmsg(fd, READ_TIMEOUT_MS));

As far as I can se the timed_read_kmsg() is used only from these two
functions, why don't we add the lseek() there instead?

-- 
Cyril Hrubis
chrubis@suse.cz

------------------------------------------------------------------------------
Monitor 25 network devices or servers for free with OpManager!
OpManager is web-based network management software that monitors 
network devices and physical & virtual servers, alerts via email & sms 
for fault. Monitor 25 devices for free with no restriction. Download now
http://ad.doubleclick.net/ddm/clk/292181274;119417398;o
_______________________________________________
Ltp-list mailing list
Ltp-list@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ltp-list

Re: [LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[Cyril Hrubis]

Hi!
> > Apart from that the logic looks fine. The test could be probably cleaned
> > by using checkpoints instead of pipe and the function used to propagate
> > exit value from child, but that is probably worth of separate patch.
> 
> Checkpoint alone doesn't seem to be enough to tell difference between:
> - child has read one record and will continue reading
> - child read has reached eof and will now exit
> 
> while parent does:
> do {
>   ret = tst_checkpoint_wait()
> } while (ret == 0)
> 
> I could map some shared memory for such flag, but I'm thinking if I can't just
> use tst_futexes to store such flag. In that case, it would likely be
> needed to handle EWOULDBLOCK in tst_checkpoint_wait and restart wait.

Or we can pass down to the child what is expected result, make it print
the PASS/FAIL and then just record the child status in the parent.

-- 
Cyril Hrubis
chrubis@suse.cz

------------------------------------------------------------------------------
Monitor 25 network devices or servers for free with OpManager!
OpManager is web-based network management software that monitors 
network devices and physical & virtual servers, alerts via email & sms 
for fault. Monitor 25 devices for free with no restriction. Download now
http://ad.doubleclick.net/ddm/clk/292181274;119417398;o
_______________________________________________
Ltp-list mailing list
Ltp-list@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ltp-list

Re: [LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[Cyril Hrubis]

Hi!
> > Or we can pass down to the child what is expected result, make it print
> > the PASS/FAIL and then just record the child status in the parent.
> 
> One of expected results is that read blocks, child can't do much else after that.

Sorry, I got confused and though that child used timed_read() in this
case. (I will get back to the previous email now)

-- 
Cyril Hrubis
chrubis@suse.cz

------------------------------------------------------------------------------
Monitor 25 network devices or servers for free with OpManager!
OpManager is web-based network management software that monitors 
network devices and physical & virtual servers, alerts via email & sms 
for fault. Monitor 25 devices for free with no restriction. Download now
http://ad.doubleclick.net/ddm/clk/292181274;119417398;o
_______________________________________________
Ltp-list mailing list
Ltp-list@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ltp-list

Re: [LTP] [PATCH] kmsg01: avoid infinite run in test_read_block()

[Cyril Hrubis]

Hi!
> > Apart from that the logic looks fine. The test could be probably cleaned
> > by using checkpoints instead of pipe and the function used to propagate
> > exit value from child, but that is probably worth of separate patch.
> 
> Checkpoint alone doesn't seem to be enough to tell difference between:
> - child has read one record and will continue reading
> - child read has reached eof and will now exit
> 
> while parent does:
> do {
>   ret = tst_checkpoint_wait()
> } while (ret == 0)
> 
> I could map some shared memory for such flag, but I'm thinking if I can't just
> use tst_futexes to store such flag. In that case, it would likely be
> needed to handle EWOULDBLOCK in tst_checkpoint_wait and restart wait.

Hmm, we can change the tst_checkpoint library to allocate two uint32_t
per id (even would be for futex and odd for the propagated value) and
add parameters to propagate 32bit integer value from
tst_checkpoint_wake() to tst_checkpoint_wait(). That way we would avoid
the need for changing the futex related code at all (the only change
would be id -> 2 * id). Given that we allocate whole page we can waste
half of the checkpoint pairs without any problems.

-- 
Cyril Hrubis
chrubis@suse.cz

------------------------------------------------------------------------------
Monitor 25 network devices or servers for free with OpManager!
OpManager is web-based network management software that monitors 
network devices and physical & virtual servers, alerts via email & sms 
for fault. Monitor 25 devices for free with no restriction. Download now
http://ad.doubleclick.net/ddm/clk/292181274;119417398;o
_______________________________________________
Ltp-list mailing list
Ltp-list@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ltp-list