Flush C stdio streams upon process termination
authorReid Kleckner <reid@kleckner.net>
Thu, 5 Jun 2014 00:13:43 +0000 (00:13 +0000)
committerReid Kleckner <reid@kleckner.net>
Thu, 5 Jun 2014 00:13:43 +0000 (00:13 +0000)
Due to what can only be described as a CRT bug, stdout and amazingly
even stderr are not always flushed upon process termination, especially
when the system is under high threading pressure.  I have found two
repros for this:

1) In lib\Support\Threading.cpp, change sys::Mutex to an
std::recursive_mutex and run check-clang.  Usually between 30 and 40
tests will fail.

2) Add OutputDebugStrings in code that runs during static initialization
and static shutdown.  This will sometimes generate similar failures.

After a substantial amount of troubleshooting and debugging, I found
that I could reproduce this from the command line without running
check-clang.  Simply make the mutex change described in #1, then
manually run the following command many times by running it once, then
pressing Up -> Enter very quickly:

D:\src\llvm\build\vs2013\Debug\bin\c-index-test.EXE -cursor-at=D:\src\llvm\tools\clang\test\Index\targeted-preamble.h:2:15 D:\src\llvm\tools\clang\test\Index\targeted-cursor.c -include D:\src\llvm\build\vs2013\tools\clang\test\Index\Output\targeted-cursor.c.tmp.h -Xclang -error-on-deserialized-decl=NestedVar1      -Xclang -error-on-deserialized-decl=TopVar    | D:\src\llvm\build\vs2013\Debug\bin\FileCheck.EXE D:\src\llvm\tools\clang\test\Index\targeted-cursor.c -check-prefix=PREAMBLE-CURSOR1

Sporadically they will fail, and attaching a debugger to a failed
instance indicates that stdin of FileCheck.exe is empty.

Note that due to the repro in #2, we can rule out a bug in the STL's
mutex implementation, and instead conclude that this is a real flake in
the windows test harness.

Test Plan:
Without patch: Ran check-clang 10 times and saw over 30 Unexpected failures on every run.
With patch: Ran check-clang 10 times and saw 0 unexpected failures across all runs.

Reviewers: rnk

Differential Revision: http://reviews.llvm.org/D4021

Patch by Zachary Turner!

llvm-svn: 210225

clang/tools/c-arcmt-test/c-arcmt-test.c
clang/tools/c-index-test/c-index-test.c

index 56a4132..60faed0 100644 (file)
@@ -97,14 +97,20 @@ typedef struct thread_info {
 void thread_runner(void *client_data_v) {
   thread_info *client_data = client_data_v;
   client_data->result = carcmttest_main(client_data->argc, client_data->argv);
-#ifdef __CYGWIN__
-  fflush(stdout);  /* stdout is not flushed on Cygwin. */
-#endif
+}
+
+static void flush_atexit(void) {
+  // stdout, and surprisingly even stderr, are not always flushed on process
+  // and thread exit, particularly when the system is under heavy load.
+  fflush(stdout);
+  fflush(stderr);
 }
 
 int main(int argc, const char **argv) {
   thread_info client_data;
 
+  atexit(flush_atexit);
+
 #if defined(_WIN32)
   if (getenv("LIBCLANG_LOGGING") == NULL)
     putenv("LIBCLANG_LOGGING=1");
index 1d5cb14..576f3c4 100644 (file)
@@ -4116,14 +4116,20 @@ typedef struct thread_info {
 void thread_runner(void *client_data_v) {
   thread_info *client_data = client_data_v;
   client_data->result = cindextest_main(client_data->argc, client_data->argv);
-#ifdef __CYGWIN__
-  fflush(stdout);  /* stdout is not flushed on Cygwin. */
-#endif
+}
+
+static void flush_atexit(void) {
+  // stdout, and surprisingly even stderr, are not always flushed on process
+  // and thread exit, particularly when the system is under heavy load.
+  fflush(stdout);
+  fflush(stderr);
 }
 
 int main(int argc, const char **argv) {
   thread_info client_data;
 
+  atexit(flush_atexit);
+
 #ifdef CLANG_HAVE_LIBXML
   LIBXML_TEST_VERSION
 #endif