d8307d
commit 35e3fbc4512c880fccb35b8e3abd132d4be18480
d8307d
Author: Florian Weimer <fweimer@redhat.com>
d8307d
Date:   Mon Nov 19 15:35:03 2018 +0100
d8307d
d8307d
    support: Print timestamps in timeout handler
d8307d
    
d8307d
    This is sometimes useful to determine if a test truly got stuck, or if
d8307d
    it was making progress (logging information to standard output) and
d8307d
    was merely slow to finish.
d8307d
d8307d
diff --git a/support/support_test_main.c b/support/support_test_main.c
d8307d
index 23429779aca85613..fa3c2e06dee5ae0f 100644
d8307d
--- a/support/support_test_main.c
d8307d
+++ b/support/support_test_main.c
d8307d
@@ -30,6 +30,7 @@
d8307d
 #include <string.h>
d8307d
 #include <sys/param.h>
d8307d
 #include <sys/resource.h>
d8307d
+#include <sys/time.h>
d8307d
 #include <sys/types.h>
d8307d
 #include <sys/wait.h>
d8307d
 #include <time.h>
d8307d
@@ -86,6 +87,19 @@ static pid_t test_pid;
d8307d
 /* The cleanup handler passed to test_main.  */
d8307d
 static void (*cleanup_function) (void);
d8307d
 
d8307d
+static void
d8307d
+print_timestamp (const char *what, struct timeval tv)
d8307d
+{
d8307d
+  struct tm tm;
d8307d
+  if (gmtime_r (&tv.tv_sec, &tm) == NULL)
d8307d
+    printf ("%s: %lld.%06d\n",
d8307d
+            what, (long long int) tv.tv_sec, (int) tv.tv_usec);
d8307d
+  else
d8307d
+    printf ("%s: %04d-%02d-%02dT%02d:%02d:%02d.%06d\n",
d8307d
+            what, 1900 + tm.tm_year, tm.tm_mon + 1, tm.tm_mday,
d8307d
+            tm.tm_hour, tm.tm_min, tm.tm_sec, (int) tv.tv_usec);
d8307d
+}
d8307d
+
d8307d
 /* Timeout handler.  We kill the child and exit with an error.  */
d8307d
 static void
d8307d
 __attribute__ ((noreturn))
d8307d
@@ -94,6 +108,13 @@ signal_handler (int sig)
d8307d
   int killed;
d8307d
   int status;
d8307d
 
d8307d
+  /* Do this first to avoid further interference from the
d8307d
+     subprocess.  */
d8307d
+  struct timeval now;
d8307d
+  bool now_available = gettimeofday (&now, NULL) == 0;
d8307d
+  struct stat64 st;
d8307d
+  bool st_available = fstat64 (STDOUT_FILENO, &st) == 0 && st.st_mtime != 0;
d8307d
+
d8307d
   assert (test_pid > 1);
d8307d
   /* Kill the whole process group.  */
d8307d
   kill (-test_pid, SIGKILL);
d8307d
@@ -144,6 +165,13 @@ signal_handler (int sig)
d8307d
     printf ("Timed out: killed the child process but it exited %d\n",
d8307d
             WEXITSTATUS (status));
d8307d
 
d8307d
+  if (now_available)
d8307d
+    print_timestamp ("Termination time", now);
d8307d
+  if (st_available)
d8307d
+    print_timestamp ("Last write to standard output",
d8307d
+                     (struct timeval) { st.st_mtim.tv_sec,
d8307d
+                         st.st_mtim.tv_nsec / 1000 });
d8307d
+
d8307d
   /* Exit with an error.  */
d8307d
   exit (1);
d8307d
 }