From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 77319 invoked by alias); 19 Nov 2018 15:18:01 -0000 Mailing-List: contact libc-stable-help@sourceware.org; run by ezmlm Precedence: bulk List-Post: List-Help: List-Subscribe: List-Archive: Sender: libc-stable-owner@sourceware.org Received: (qmail 77238 invoked by uid 89); 19 Nov 2018 15:18:01 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Checked: by ClamAV 0.100.2 on sourceware.org X-Virus-Found: No X-Spam-SWARE-Status: No, score=-24.9 required=5.0 tests=BAYES_00,GIT_PATCH_0,GIT_PATCH_1,GIT_PATCH_2,GIT_PATCH_3,SPF_HELO_PASS,UNSUBSCRIBE_BODY autolearn=ham version=3.3.2 spammy=interference, 1900, Timeout, logging X-Spam-Status: No, score=-24.9 required=5.0 tests=BAYES_00,GIT_PATCH_0,GIT_PATCH_1,GIT_PATCH_2,GIT_PATCH_3,SPF_HELO_PASS,UNSUBSCRIBE_BODY autolearn=ham version=3.3.2 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on sourceware.org X-Spam-Level: X-HELO: mx1.redhat.com Received: from mx1.redhat.com (HELO mx1.redhat.com) (209.132.183.28) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with ESMTP; Mon, 19 Nov 2018 15:17:59 +0000 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.phx2.redhat.com [10.5.11.14]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id C04DD88313 for ; Mon, 19 Nov 2018 15:17:58 +0000 (UTC) Received: from oldenburg.str.redhat.com (ovpn-117-57.ams2.redhat.com [10.36.117.57]) by smtp.corp.redhat.com (Postfix) with ESMTP id 8CDD968B0C for ; Mon, 19 Nov 2018 15:17:58 +0000 (UTC) Received: by oldenburg.str.redhat.com (Postfix, from userid 1000) id 6CB6D4399457D; Mon, 19 Nov 2018 16:17:52 +0100 (CET) Date: Mon, 01 Jan 2018 00:00:00 -0000 To: libc-stable@sourceware.org Subject: [2.28 COMMITTED] support: Print timestamps in timeout handler User-Agent: Heirloom mailx 12.5 7/5/10 MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit Message-Id: <20181119151752.6CB6D4399457D@oldenburg.str.redhat.com> From: fweimer@redhat.com (Florian Weimer) X-Scanned-By: MIMEDefang 2.79 on 10.5.11.14 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.28]); Mon, 19 Nov 2018 15:17:58 +0000 (UTC) X-IsSubscribed: yes X-SW-Source: 2018-11/txt/msg00025.txt.bz2 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. (cherry picked from commit 35e3fbc4512c880fccb35b8e3abd132d4be18480) 2018-11-19 Florian Weimer 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. diff --git a/support/support_test_main.c b/support/support_test_main.c index 23429779ac..fa3c2e06de 100644 --- a/support/support_test_main.c +++ b/support/support_test_main.c @@ -30,6 +30,7 @@ #include #include #include +#include #include #include #include @@ -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); }