[igt-dev] [PATCH i-g-t v2 2/7] lib/igt_core: Send logs to runner with comms

Petri Latvala petri.latvala at intel.com
Mon Oct 31 10:24:29 UTC 2022


If the runner has opened a socket to talk to it, use it for sending
logs and other messages.

Signed-off-by: Petri Latvala <petri.latvala at intel.com>
Cc: Arkadiusz Hiler <arek at hiler.eu>
Acked-by: Kamil Konieczny <kamil.konieczny at linux.intel.com>
---
 lib/igt_core.c | 177 ++++++++++++++++++++++++++++++++++++-------------
 1 file changed, 132 insertions(+), 45 deletions(-)

diff --git a/lib/igt_core.c b/lib/igt_core.c
index aad7b6d8..3941c528 100644
--- a/lib/igt_core.c
+++ b/lib/igt_core.c
@@ -76,6 +76,7 @@
 #include "igt_list.h"
 #include "igt_device_scan.h"
 #include "igt_thread.h"
+#include "runnercomms.h"
 
 #define UNW_LOCAL_ONLY
 #include <libunwind.h>
@@ -456,6 +457,84 @@ static void _igt_log_buffer_reset(void)
 	pthread_mutex_unlock(&log_buffer_mutex);
 }
 
+__attribute__((format(printf, 2, 3)))
+static void _log_line_fprintf(FILE* stream, const char *format, ...)
+{
+	va_list ap;
+	char *str;
+
+	va_start(ap, format);
+
+	if (runner_connected()) {
+		vasprintf(&str, format, ap);
+		send_to_runner(runnerpacket_log(fileno(stream), str));
+		free(str);
+	} else {
+		vfprintf(stream, format, ap);
+	}
+}
+
+enum _subtest_type {
+      _SUBTEST_TYPE_NORMAL,
+      _SUBTEST_TYPE_DYNAMIC,
+};
+
+static void _subtest_result_message(enum _subtest_type subtest_type,
+				    const char *name,
+				    const char *result,
+				    double timeelapsed)
+{
+	char timestr[32];
+
+	snprintf(timestr, sizeof(timestr), "%.3f", timeelapsed);
+
+	if (runner_connected()) {
+		if (subtest_type == _SUBTEST_TYPE_NORMAL)
+			send_to_runner(runnerpacket_subtest_result(name, result, timestr, NULL));
+		else
+			send_to_runner(runnerpacket_dynamic_subtest_result(name, result, timestr, NULL));
+
+		return;
+	}
+
+	printf("%s%s %s: %s (%ss)%s\n",
+	       (!__igt_plain_output) ? "\x1b[1m" : "",
+	       subtest_type == _SUBTEST_TYPE_NORMAL ? "Subtest" : "Dynamic subtest",
+	       name,
+	       result,
+	       timestr,
+	       (!__igt_plain_output) ? "\x1b[0m" : "");
+	fflush(stdout);
+	if (stderr_needs_sentinel)
+		fprintf(stderr, "%s %s: %s (%ss)\n",
+			subtest_type == _SUBTEST_TYPE_NORMAL ? "Subtest" : "Dynamic subtest",
+			name,
+			result,
+			timestr);
+}
+
+static void _subtest_starting_message(enum _subtest_type subtest_type,
+				      const char *name)
+{
+	if (runner_connected()) {
+		if (subtest_type == _SUBTEST_TYPE_NORMAL)
+			send_to_runner(runnerpacket_subtest_start(name));
+		else
+			send_to_runner(runnerpacket_dynamic_subtest_start(name));
+
+		return;
+	}
+
+	igt_info("Starting %s: %s\n",
+		 subtest_type == _SUBTEST_TYPE_NORMAL ? "subtest" : "dynamic subtest",
+		 name);
+	fflush(stdout);
+	if (stderr_needs_sentinel)
+		fprintf(stderr, "Starting %s: %s\n",
+			subtest_type == _SUBTEST_TYPE_NORMAL ? "subtest" : "dynamic subtest",
+			name);
+}
+
 static void _igt_log_buffer_dump(void)
 {
 	uint8_t i;
@@ -478,31 +557,31 @@ static void _igt_log_buffer_dump(void)
 	}
 
 	if (in_dynamic_subtest)
-		fprintf(stderr, "Dynamic subtest %s failed.\n", in_dynamic_subtest);
+		_log_line_fprintf(stderr, "Dynamic subtest %s failed.\n", in_dynamic_subtest);
 	else if (in_subtest)
-		fprintf(stderr, "Subtest %s failed.\n", in_subtest);
+		_log_line_fprintf(stderr, "Subtest %s failed.\n", in_subtest);
 	else
-		fprintf(stderr, "Test %s failed.\n", command_str);
+		_log_line_fprintf(stderr, "Test %s failed.\n", command_str);
 
 	if (log_buffer.start == log_buffer.end) {
-		fprintf(stderr, "No log.\n");
+		_log_line_fprintf(stderr, "No log.\n");
 		return;
 	}
 
 	pthread_mutex_lock(&log_buffer_mutex);
-	fprintf(stderr, "**** DEBUG ****\n");
+	_log_line_fprintf(stderr, "**** DEBUG ****\n");
 
 	i = log_buffer.start;
 	do {
 		char *last_line = log_buffer.entries[i];
-		fprintf(stderr, "%s", last_line);
+		_log_line_fprintf(stderr, "%s", last_line);
 		i++;
 	} while (i != log_buffer.start && i != log_buffer.end);
 
 	/* reset the buffer */
 	log_buffer.start = log_buffer.end = 0;
 
-	fprintf(stderr, "****  END  ****\n");
+	_log_line_fprintf(stderr, "****  END  ****\n");
 	pthread_mutex_unlock(&log_buffer_mutex);
 }
 
@@ -763,9 +842,19 @@ static void print_version(void)
 
 	uname(&uts);
 
-	igt_info("IGT-Version: %s-%s (%s) (%s: %s %s)\n", PACKAGE_VERSION,
-		 IGT_GIT_SHA1, TARGET_CPU_PLATFORM,
-		 uts.sysname, uts.release, uts.machine);
+	if (runner_connected()) {
+		char versionstr[256];
+
+		snprintf(versionstr, sizeof(versionstr),
+			 "IGT-Version: %s-%s (%s) (%s: %s %s)\n", PACKAGE_VERSION,
+			 IGT_GIT_SHA1, TARGET_CPU_PLATFORM,
+			 uts.sysname, uts.release, uts.machine);
+		send_to_runner(runnerpacket_versionstring(versionstr));
+	} else {
+		igt_info("IGT-Version: %s-%s (%s) (%s: %s %s)\n", PACKAGE_VERSION,
+			 IGT_GIT_SHA1, TARGET_CPU_PLATFORM,
+			 uts.sysname, uts.release, uts.machine);
+	}
 }
 
 static void print_usage(const char *help_str, bool output_on_stderr)
@@ -937,6 +1026,11 @@ static void common_init_env(void)
 	if (env) {
 		igt_rc_device = strdup(env);
 	}
+
+	env = getenv("IGT_RUNNER_SOCKET_FD");
+	if (env) {
+		set_runner_socket(atoi(env));
+	}
 }
 
 static int common_init(int *argc, char **argv,
@@ -1329,24 +1423,15 @@ bool __igt_run_subtest(const char *subtest_name, const char *file, const int lin
 
 
 	if (skip_subtests_henceforth) {
-		printf("%sSubtest %s: %s%s\n",
-		       (!__igt_plain_output) ? "\x1b[1m" : "", subtest_name,
-		       skip_subtests_henceforth == SKIP ?
-		       "SKIP" : "FAIL", (!__igt_plain_output) ? "\x1b[0m" : "");
-		fflush(stdout);
-		if (stderr_needs_sentinel)
-			fprintf(stderr, "Subtest %s: %s\n", subtest_name,
-				skip_subtests_henceforth == SKIP ?
-				"SKIP" : "FAIL");
+		_subtest_result_message(_SUBTEST_TYPE_NORMAL, subtest_name,
+					skip_subtests_henceforth == SKIP ? "SKIP" : "FAIL",
+					0.0);
 		return false;
 	}
 
 	igt_kmsg(KMSG_INFO "%s: starting subtest %s\n",
 		 command_str, subtest_name);
-	igt_info("Starting subtest: %s\n", subtest_name);
-	fflush(stdout);
-	if (stderr_needs_sentinel)
-		fprintf(stderr, "Starting subtest: %s\n", subtest_name);
+	_subtest_starting_message(_SUBTEST_TYPE_NORMAL, subtest_name);
 
 	_igt_log_buffer_reset();
 	igt_thread_clear_fail_state();
@@ -1374,10 +1459,7 @@ bool __igt_run_dynamic_subtest(const char *dynamic_subtest_name)
 
 	igt_kmsg(KMSG_INFO "%s: starting dynamic subtest %s\n",
 		 command_str, dynamic_subtest_name);
-	igt_info("Starting dynamic subtest: %s\n", dynamic_subtest_name);
-	fflush(stdout);
-	if (stderr_needs_sentinel)
-		fprintf(stderr, "Starting dynamic subtest: %s\n", dynamic_subtest_name);
+	_subtest_starting_message(_SUBTEST_TYPE_DYNAMIC, dynamic_subtest_name);
 
 	_igt_log_buffer_reset();
 	igt_thread_clear_fail_state();
@@ -1456,23 +1538,16 @@ bool __igt_enter_dynamic_container(void)
 __noreturn static void exit_subtest(const char *result)
 {
 	struct timespec now;
-	const char *subtest_text = in_dynamic_subtest ? "Dynamic subtest" : "Subtest";
 	const char **subtest_name = in_dynamic_subtest ? &in_dynamic_subtest : &in_subtest;
 	struct timespec *thentime = in_dynamic_subtest ? &dynamic_subtest_time : &subtest_time;
 	jmp_buf *jmptarget = in_dynamic_subtest ? &igt_dynamic_jmpbuf : &igt_subtest_jmpbuf;
 
 	igt_gettime(&now);
 
-	igt_info("%s%s %s: %s (%.3fs)%s\n",
-		 (!__igt_plain_output) ? "\x1b[1m" : "",
-		 subtest_text, *subtest_name, result,
-		 igt_time_elapsed(thentime, &now),
-		 (!__igt_plain_output) ? "\x1b[0m" : "");
-	fflush(stdout);
-	if (stderr_needs_sentinel)
-		fprintf(stderr, "%s %s: %s (%.3fs)\n",
-			subtest_text, *subtest_name,
-			result, igt_time_elapsed(thentime, &now));
+	_subtest_result_message(in_dynamic_subtest ? _SUBTEST_TYPE_DYNAMIC : _SUBTEST_TYPE_NORMAL,
+				*subtest_name,
+				result,
+				igt_time_elapsed(thentime, &now));
 
 	igt_terminate_spins();
 
@@ -1539,7 +1614,15 @@ void igt_skip(const char *f, ...)
 
 	if (!igt_only_list_subtests()) {
 		va_start(args, f);
-		vprintf(f, args);
+		if (runner_connected()) {
+			char *str;
+
+			vasprintf(&str, f, args);
+			send_to_runner(runnerpacket_log(STDOUT_FILENO, str));
+			free(str);
+		} else {
+			vprintf(f, args);
+		}
 		va_end(args);
 	}
 
@@ -1827,7 +1910,10 @@ static bool running_under_gdb(void)
 
 static void __write_stderr(const char *str, size_t len)
 {
-	igt_ignore_warn(write(STDERR_FILENO, str, len));
+	if (runner_connected())
+		log_to_runner_sig_safe(str, len);
+	else
+		igt_ignore_warn(write(STDERR_FILENO, str, len));
 }
 
 static void write_stderr(const char *str)
@@ -1840,7 +1926,10 @@ static const char hex[] = "0123456789abcdef";
 static void
 xputch(int c)
 {
-	igt_ignore_warn(write(STDERR_FILENO, (const void *) &c, 1));
+	if (runner_connected())
+		log_to_runner_sig_safe((const void *) &c, 1);
+	else
+		igt_ignore_warn(write(STDERR_FILENO, (const void *) &c, 1));
 }
 
 static int
@@ -2849,11 +2938,9 @@ void igt_vlog(const char *domain, enum igt_log_level level, const char *format,
 	/* prepend all except information messages with process, domain and log
 	 * level information */
 	if (level != IGT_LOG_INFO) {
-		fwrite(formatted_line, sizeof(char), strlen(formatted_line),
-		       file);
+		_log_line_fprintf(file, "%s", formatted_line);
 	} else {
-		fwrite(thread_id, sizeof(char), strlen(thread_id), file);
-		fwrite(line, sizeof(char), strlen(line), file);
+		_log_line_fprintf(file, "%s%s", thread_id, line);
 	}
 
 	pthread_mutex_unlock(&print_mutex);
-- 
2.30.2



More information about the igt-dev mailing list