support: Print timestamps in timeout handler

This is sometimes useful to determine if a test truly got stuck, or if
it was making progress (logging information to standard output) and
was merely slow to finish.
This commit is contained in:
Florian Weimer 2018-11-19 15:35:03 +01:00
parent c75772e3f0
commit 35e3fbc451
2 changed files with 35 additions and 0 deletions

View File

@ -1,3 +1,10 @@
2018-11-19 Florian Weimer <fweimer@redhat.com>
support: Print timestamps in timeout handler.
* support/support_test_main.c (print_timestamp): New function.
(signal_handler): Use it to print the termination time and the
time of the last write to standard output.
2018-11-16 Zack Weinberg <zackw@panix.com>
Gabriel F. T. Gomes <gabriel@inconstante.eti.br>

View File

@ -30,6 +30,7 @@
#include <string.h>
#include <sys/param.h>
#include <sys/resource.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <time.h>
@ -86,6 +87,19 @@ static pid_t test_pid;
/* The cleanup handler passed to test_main. */
static void (*cleanup_function) (void);
static void
print_timestamp (const char *what, struct timeval tv)
{
struct tm tm;
if (gmtime_r (&tv.tv_sec, &tm) == NULL)
printf ("%s: %lld.%06d\n",
what, (long long int) tv.tv_sec, (int) tv.tv_usec);
else
printf ("%s: %04d-%02d-%02dT%02d:%02d:%02d.%06d\n",
what, 1900 + tm.tm_year, tm.tm_mon + 1, tm.tm_mday,
tm.tm_hour, tm.tm_min, tm.tm_sec, (int) tv.tv_usec);
}
/* Timeout handler. We kill the child and exit with an error. */
static void
__attribute__ ((noreturn))
@ -94,6 +108,13 @@ signal_handler (int sig)
int killed;
int status;
/* Do this first to avoid further interference from the
subprocess. */
struct timeval now;
bool now_available = gettimeofday (&now, NULL) == 0;
struct stat64 st;
bool st_available = fstat64 (STDOUT_FILENO, &st) == 0 && st.st_mtime != 0;
assert (test_pid > 1);
/* Kill the whole process group. */
kill (-test_pid, SIGKILL);
@ -144,6 +165,13 @@ signal_handler (int sig)
printf ("Timed out: killed the child process but it exited %d\n",
WEXITSTATUS (status));
if (now_available)
print_timestamp ("Termination time", now);
if (st_available)
print_timestamp ("Last write to standard output",
(struct timeval) { st.st_mtim.tv_sec,
st.st_mtim.tv_nsec / 1000 });
/* Exit with an error. */
exit (1);
}