Page MenuHomePhabricator

Flush output streams upon process termination
ClosedPublic

Authored by zturner on Jun 4 2014, 1:04 PM.

Details

Summary

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.

Diff Detail

Event Timeline

zturner updated this revision to Diff 10100.Jun 4 2014, 1:04 PM
zturner retitled this revision from to Flush output streams upon process termination.
zturner updated this object.
zturner edited the test plan for this revision. (Show Details)
zturner added a reviewer: rnk.
zturner added subscribers: Unknown Object (MLST), scottmg.

Did you file an upstream bug?

rnk edited edge metadata.Jun 4 2014, 2:58 PM

That's interesting. I think we avoid this problem for most of our binaries
because they use llvm::raw_ostream. It looks like this is only a problem
for C code that has to use C stdio. I think we never write to C stdio from
other atexit handlers, so I think this should work fine.

I also wonder if this was the true cause of http://llvm.org/PR19744.

@thakis: Done. https://connect.microsoft.com/VisualStudio/feedback/details/888893/stdout-and-stderr-are-not-necessarily-flushed-upon-clean-process-exit
@rnk: Interesting. I am incllined to say that yes, that is definitely the same bug.

I think even if we do write to c stdio handlers from other atexit handlers, it should still be fine. Calls to atexit() handlers are serialized, so worst case scenario some *additional* data that was already not getting flushed, still doesn't get flushed. It's still better than the current flakiness in all cases.

Also, I've confirmed with at least 2 other windows engineers that they have experienced both stderr and stdout not flushing on process termination, so apparently this is a "known issue".

Note that I do not even have Cygwin installed, much less on the path.

@rnk: If you're good with this, can you commit it?

rnk accepted this revision.Jun 4 2014, 5:21 PM
rnk edited edge metadata.

lgtm. It seems harmless to work around this problem in MSVCRT stdio in some C test binaries.

This revision is now accepted and ready to land.Jun 4 2014, 5:21 PM
edward-san closed this revision.EditedJun 9 2014, 10:29 AM
edward-san added a subscriber: edward-san.

Closing. It was applied in r210225 by rnk.