runner: Handle outputs before checking for timeout

1/3

---
 runner/executor.c | 72 +++++++++++++++++++++++------------------------
 1 file changed, 36 insertions(+), 36 deletions(-)
index 72e45b65..28b8a443 100644
@@ -828,42 +828,6 @@ static int monitor_output(pid_t child,
 
 		igt_gettime(&time_now);
 
-		timeout_reason = need_to_timeout(settings, killed, tainted(&taints),
-						 igt_time_elapsed(&time_last_activity, &time_now),
-						 igt_time_elapsed(&time_last_subtest, &time_now),
-						 igt_time_elapsed(&time_killed, &time_now));
-
-		if (timeout_reason) {
-			if (killed == SIGKILL) {
-				/* Nothing that can be done, really. Let's tell the caller we want to abort. */
-
-				if (settings->log_level >= LOG_LEVEL_NORMAL) {
-					errf("Child refuses to die, tainted 0x%lx. Aborting.\n",
-					     taints);
-					if (kill(child, 0) && errno == ESRCH)
-						errf("The test process no longer exists, "
-						     "but we didn't get informed of its demise...\n");
-				}
-
-				close_watchdogs(settings);
-				free(outbuf);
-				close(outfd);
-				close(errfd);
-				close(kmsgfd);
-				return -1;
-			}
-
-			if (settings->log_level >= LOG_LEVEL_NORMAL) {
-				outf("%s", timeout_reason);
-				fflush(stdout);
-			}
-
-			killed = next_kill_signal(killed);
-			if (!kill_child(killed, child))
-				return -1;
-			time_killed = time_now;
-		}
-
 		/* TODO: Refactor these handlers to their own functions */
 		if (outfd >= 0 && FD_ISSET(outfd, &set)) {
 			char *newline;

@@ -1072,6 +1036,42 @@ static int monitor_output(pid_t child,
 			child = 0;
 			sigfd = -1; /* we are dying, no signal handling for now */
 		}
+
+		timeout_reason = need_to_timeout(settings, killed, tainted(&taints),
+						 igt_time_elapsed(&time_last_activity, &time_now),
+						 igt_time_elapsed(&time_last_subtest, &time_now),
+						 igt_time_elapsed(&time_killed, &time_now));
+
+		if (timeout_reason) {
+			if (killed == SIGKILL) {
+				/* Nothing that can be done, really. Let's tell the caller we want to abort. */
+
+				if (settings->log_level >= LOG_LEVEL_NORMAL) {
+					errf("Child refuses to die, tainted 0x%lx. Aborting.\n",
+					     taints);
+					if (kill(child, 0) && errno == ESRCH)
+						errf("The test process no longer exists, "
+						     "but we didn't get informed of its demise...\n");
+				}
+
+				close_watchdogs(settings);
+				free(outbuf);
+				close(outfd);
+				close(errfd);
+				close(kmsgfd);
+				return -1;
+			}
+
+			if (settings->log_level >= LOG_LEVEL_NORMAL) {
+				outf("%s", timeout_reason);
+				fflush(stdout);
+			}
+
+			killed = next_kill_signal(killed);
+			if (!kill_child(killed, child))
+				return -1;
+			time_killed = time_now;
+		}
 	}
 
 	dump_dmesg(kmsgfd, outputs[_F_DMESG]);

2.20.1

_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
---
 runner/executor.c | 4 ++++
 1 file changed, 4 insertions(+)
index 28b8a443..790f99db 100644
@@ -1054,6 +1054,10 @@ static int monitor_output(pid_t child,
 						     "but we didn't get informed of its demise...\n");
 				}
 
+				dump_dmesg(kmsgfd, outputs[_F_DMESG]);
+				if (settings->sync)
+					fdatasync(outputs[_F_DMESG]);
+
 				close_watchdogs(settings);
 				free(outbuf);
 				close(outfd);

2.20.1

_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
---
 runner/executor.c | 66 ++++++++++++++++++++++++-----------------------
 1 file changed, 34 insertions(+), 32 deletions(-)
index 790f99db..c4b99115 100644
@@ -537,7 +537,7 @@ void close_outputs(int *fds)
 	}
 }
 
-static void dump_dmesg(int kmsgfd, int outfd)
+static int dump_dmesg(int kmsgfd, int outfd)
 {
 	/*
 	 * Write kernel messages to the log file until we reach

@@ -546,29 +546,31 @@ static void dump_dmesg(int kmsgfd, int outfd)
 	 * message to match against, or stop when we reach EAGAIN.
 	 */
 
-	int comparefd = open("/dev/kmsg", O_RDONLY | O_NONBLOCK);
+	int comparefd;
 	unsigned flags;
 	unsigned long long seq, cmpseq, usec;
 	char cont;
 	char buf[2048];
 	ssize_t r;
 
-	if (comparefd < 0)
-		return;
-	lseek(comparefd, 0, SEEK_END);
+	if (kmsgfd < 0)
+		return 0;
 
-	if (fcntl(kmsgfd, F_SETFL, O_NONBLOCK)) {
-		close(comparefd);
-		return;
+	comparefd = open("/dev/kmsg", O_RDONLY | O_NONBLOCK);
+	if (comparefd < 0) {
+		errf("Error opening another fd for /dev/kmsg\n");
+		return -1;
 	}
+	lseek(comparefd, 0, SEEK_END);
 
 	while (1) {
 		if (comparefd >= 0) {
 			r = read(comparefd, buf, sizeof(buf) - 1);
 			if (r < 0) {
 				if (errno != EAGAIN && errno != EPIPE) {
+					errf("Warning: Error reading kmsg comparison record: %m\n");
 					close(comparefd);
-					return;
+					return 0;
 				}
 			} else {
 				buf[r] = '\0';

@@ -582,16 +584,21 @@ static void dump_dmesg(int kmsgfd, int outfd)
 		}
 
 		r = read(kmsgfd, buf, sizeof(buf));
-		if (r <= 0) {
-			if (errno == EPIPE)
+		if (r < 0) {
+			if (errno == EPIPE) {
+				errf("Warning: kernel log ringbuffer underflow, some records lost.\n");
+				continue;
+			} else if (errno == EINVAL) {
+				errf("Warning: Buffer too small for kernel log record, record lost.\n");
 				continue;
+			} else if (errno != EAGAIN) {
+				errf("Error reading from kmsg: %m\n");
+				return errno;
+			}
 
-			/*
-			 * If EAGAIN, we're done. If some other error,
-			 * we can't do anything anyway.
-			 */
+			/* EAGAIN, so we're done dumping */
 			close(comparefd);
-			return;
+			return 0;
 		}
 
 		write(outfd, buf, r);

@@ -604,7 +611,7 @@ static void dump_dmesg(int kmsgfd, int outfd)
 			 * enough.
 			 */
 			if (seq >= cmpseq)
-				return;
+				return 0;
 		}
 	}
 }

@@ -939,22 +946,17 @@ static int monitor_output(pid_t child,
 		}
 
 		if (kmsgfd >= 0 && FD_ISSET(kmsgfd, &set)) {
+			int dmesgstatus;
+
 			time_last_activity = time_now;
 
-			s = read(kmsgfd, buf, sizeof(buf));
-			if (s < 0) {
-				if (errno != EPIPE && errno != EINVAL) {
-					errf("Error reading from kmsg, stopping monitoring: %m\n");
-					close(kmsgfd);
-					kmsgfd = -1;
-				} else if (errno == EINVAL) {
-					errf("Warning: Buffer too small for kernel log record, record lost.\n");
-				}
-			} else {
-				write(outputs[_F_DMESG], buf, s);
-				if (settings->sync) {
-					fdatasync(outputs[_F_DMESG]);
-				}
+			dmesgstatus = dump_dmesg(kmsgfd, outputs[_F_DMESG]);
+			if (settings->sync)
+				fdatasync(outputs[_F_DMESG]);
+
+			if (dmesgstatus) {
+				close(kmsgfd);
+				kmsgfd = -1;
 			}
 		}
 

@@ -1256,7 +1258,7 @@ static int execute_next_entry(struct execute_state *state,
 		goto out_pipe;
 	}
 
-	if ((kmsgfd = open("/dev/kmsg", O_RDONLY | O_CLOEXEC)) < 0) {
+	if ((kmsgfd = open("/dev/kmsg", O_RDONLY | O_CLOEXEC | O_NONBLOCK)) < 0) {
 		errf("Warning: Cannot open /dev/kmsg\n");
 	} else {
 		/* TODO: Checking of abort conditions in pre-execute dmesg */

2.20.1

_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev

runner: Handle outputs before checking for timeout

Petri Latvala

Petri Latvala

Petri Latvala

Chris Wilson

Patchwork

Patchwork

Patchwork

Patchwork