Make no-compile test deterministic

tools/nocompile_driver.py

 #!/usr/bin/env python
 # Copyright (c) 2011 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 """Implements a simple "negative compile" test for C++ on linux.
 
 Sometimes a C++ API needs to ensure that various usages cannot compile. To
 enable unittesting of these assertions, we use this python script to
 invoke gcc on a source file and assert that compilation fails.
 
 For more info, see:
   http://dev.chromium.org/developers/testing/no-compile-tests
 """
 
 import StringIO
 import ast
-import locale
 import os
 import re
 import select
 import shlex
 import subprocess
 import sys
 import time
 
 
 # Matches lines that start with #if and have the substring TEST in the
@@ skipping 30 matching lines @@
 RESULT_FILE_HEADER = """
 // This file is generated by the no compile test from:
 //   %s
 
 #include "base/logging.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 """
 
 
-# The GUnit test function to output on a successful test completion.
-SUCCESS_GUNIT_TEMPLATE = """
-TEST(%s, %s) {
-  LOG(INFO) << "Took %f secs. Started at %f, ended at %f";
-}
+# The log message on a test completion.
+LOG_TEMPLATE = """
+TEST(%s, %s) took %f secs. Started at %f, ended at %f.
 """
 
-# The GUnit test function to output for a disabled test.
-DISABLED_GUNIT_TEMPLATE = """
+# The GUnit test function to output for a successful or disabled test.

[dcheng, 2017/01/19 05:36:22]

Nit: probably OK to just remove "successful or disabled" because this just means
any test.

[wychen, 2017/01/19 15:43:57]

But failed tests wouldn't use this template.

+GUNIT_TEMPLATE = """
 TEST(%s, %s) { }
 """
 
 
 # Timeout constants.
 NCTEST_TERMINATE_TIMEOUT_SEC = 60
 NCTEST_KILL_TIMEOUT_SEC = NCTEST_TERMINATE_TIMEOUT_SEC + 2
 BUSY_LOOP_MAX_TIME_SEC = NCTEST_KILL_TIMEOUT_SEC * 2
 
 
@@ skipping 146 matching lines @@
           'name': name,
           'suite_name': config['suite_name'],
           'terminate_timeout': now + NCTEST_TERMINATE_TIMEOUT_SEC,
           'kill_timeout': now + NCTEST_KILL_TIMEOUT_SEC,
           'started_at': now,
           'aborted_at': 0,
           'finished_at': 0,
           'expectations': expectations}
 
 
-def PassTest(resultfile, test):
+def PassTest(resultfile, resultlog, test):
   """Logs the result of a test started by StartTest(), or a disabled test
   configuration.
 
   Args:
     resultfile: File object for .cc file that results are written to.
+    resultlog: File object for the log file.
     test: An instance of the dictionary returned by StartTest(), a
           configuration from ExtractTestConfigs().
   """
+  resultfile.write(GUNIT_TEMPLATE % (
+      test['suite_name'], test['name']))
+
   # The 'started_at' key is only added if a test has been started.
   if 'started_at' in test:
-    resultfile.write(SUCCESS_GUNIT_TEMPLATE % (
+    resultlog.write(LOG_TEMPLATE % (
         test['suite_name'], test['name'],
         test['finished_at'] - test['started_at'],
         test['started_at'], test['finished_at']))
-  else:
-    resultfile.write(DISABLED_GUNIT_TEMPLATE % (
-        test['suite_name'], test['name']))
 
 
 def FailTest(resultfile, test, error, stdout=None, stderr=None):
   """Logs the result of a test started by StartTest()
 
   Args:
     resultfile: File object for .cc file that results are written to.
     test: An instance of the dictionary returned by StartTest()
     error: The printable reason for the failure.
     stdout: The test's output to stdout.
     stderr: The test's output to stderr.
   """
   resultfile.write('#error "%s Failed: %s"\n' % (test['name'], error))
   resultfile.write('#error "compile line: %s"\n' % test['cmdline'])
   if stdout and len(stdout) != 0:
     resultfile.write('#error "%s stdout:"\n' % test['name'])
     for line in stdout.split('\n'):
       resultfile.write('#error "  %s:"\n' % line)
 
   if stderr and len(stderr) != 0:
     resultfile.write('#error "%s stderr:"\n' % test['name'])
     for line in stderr.split('\n'):
       resultfile.write('#error "  %s"\n' % line)
   resultfile.write('\n')
 
 
-def WriteStats(resultfile, suite_name, timings):
-  """Logs the peformance timings for each stage of the script into a fake test.
+def WriteStats(resultlog, suite_name, timings):
+  """Logs the peformance timings for each stage of the script.
 
   Args:
-    resultfile: File object for .cc file that results are written to.
+    resultlog: File object for the log file.
     suite_name: The name of the GUnit suite this test belongs to.
     timings: Dictionary with timestamps for each stage of the script run.
   """
-  stats_template = ("Started %f, Ended %f, Total %fs, Extract %fs, "
-                    "Compile %fs, Process %fs")
+  stats_template = """
+TEST(%s): Started %f, Ended %f, Total %fs, Extract %fs, Compile %fs, Process %fs
+"""
   total_secs = timings['results_processed'] - timings['started']
   extract_secs = timings['extract_done'] - timings['started']
   compile_secs = timings['compile_done'] - timings['extract_done']
   process_secs = timings['results_processed'] - timings['compile_done']
-  resultfile.write('TEST(%s, Stats) { LOG(INFO) << "%s"; }\n' % (
-      suite_name, stats_template % (
-          timings['started'], timings['results_processed'], total_secs,
-          extract_secs, compile_secs, process_secs)))
+  resultlog.write(stats_template % (
+      suite_name, timings['started'], timings['results_processed'], total_secs,
+      extract_secs, compile_secs, process_secs))
 
 
-def ProcessTestResult(resultfile, test):
+def ProcessTestResult(resultfile, resultlog, test):
   """Interprets and logs the result of a test started by StartTest()
 
   Args:
     resultfile: File object for .cc file that results are written to.
+    resultlog: File object for the log file.
     test: The dictionary from StartTest() to process.
   """
   # Snap a copy of stdout and stderr into the test dictionary immediately
   # cause we can only call this once on the Popen object, and lots of stuff
   # below will want access to it.
   proc = test['proc']
   (stdout, stderr) = proc.communicate()
 
   if test['aborted_at'] != 0:
     FailTest(resultfile, test, "Compile timed out. Started %f ended %f." %
              (test['started_at'], test['aborted_at']))
     return
 
   if proc.poll() == 0:
     # Handle failure due to successful compile.
     FailTest(resultfile, test,
              'Unexpected successful compilation.',
              stdout, stderr)
     return
   else:
     # Check the output has the right expectations.  If there are no
     # expectations, then we just consider the output "matched" by default.
     if len(test['expectations']) == 0:
-      PassTest(resultfile, test)
+      PassTest(resultfile, resultlog, test)
       return
 
     # Otherwise test against all expectations.
     for regexp in test['expectations']:
       if (regexp.search(stdout) is not None or
           regexp.search(stderr) is not None):
-        PassTest(resultfile, test)
+        PassTest(resultfile, resultlog, test)
         return
     expectation_str = ', '.join(
         ["r'%s'" % regexp.pattern for regexp in test['expectations']])
     FailTest(resultfile, test,
              'Expectations [%s] did not match output.' % expectation_str,
              stdout, stderr)
     return
 
 
-def CompleteAtLeastOneTest(resultfile, executing_tests):
+def CompleteAtLeastOneTest(executing_tests):
   """Blocks until at least one task is removed from executing_tests.
 
   This function removes completed tests from executing_tests, logging failures
   and output.  If no tests can be removed, it will enter a poll-loop until one
   test finishes or times out.  On a timeout, this function is responsible for
   terminating the process in the appropriate fashion.
 
   Args:
     executing_tests: A dict mapping a string containing the test name to the
                      test dict return from StartTest().
 
   Returns:
     A list of tests that have finished.
   """
   finished_tests = []
   busy_loop_timeout = time.time() + BUSY_LOOP_MAX_TIME_SEC
   while len(finished_tests) == 0:
     # If we don't make progress for too long, assume the code is just dead.
     assert busy_loop_timeout > time.time()
 
     # Select on the output pipes.
     read_set = []
     for test in executing_tests.values():
       read_set.extend([test['proc'].stderr, test['proc'].stdout])
-    result = select.select(read_set, [], read_set, NCTEST_TERMINATE_TIMEOUT_SEC)
+    select.select(read_set, [], read_set, NCTEST_TERMINATE_TIMEOUT_SEC)
 
     # Now attempt to process results.
     now = time.time()
     for test in executing_tests.values():
       proc = test['proc']
       if proc.poll() is not None:
         test['finished_at'] = now
         finished_tests.append(test)
       elif test['terminate_timeout'] < now:
         proc.terminate()
@@ skipping 29 matching lines @@
 
   # Convert filename from underscores to CamelCase.
   words = os.path.splitext(os.path.basename(sourcefile_path))[0].split('_')
   words = [w.capitalize() for w in words]
   suite_name = 'NoCompile' + ''.join(words)
 
   test_configs = ExtractTestConfigs(sourcefile_path, suite_name)
   timings['extract_done'] = time.time()
 
   resultfile = StringIO.StringIO()
+  resultlog = StringIO.StringIO()
   resultfile.write(RESULT_FILE_HEADER % sourcefile_path)
 
   # Run the no-compile tests, but ensure we do not run more than |parallelism|
   # tests at once.
   timings['header_written'] = time.time()
   executing_tests = {}
   finished_tests = []
 
   test = StartTest(
       sourcefile_path,
       cflags + ' -MMD -MF %s.d -MT %s' % (resultfile_path, resultfile_path),
       { 'name': 'NCTEST_SANITY',
         'suite_name': suite_name,
         'expectations': None,
       })
   executing_tests[test['name']] = test
 
   for config in test_configs:
     # CompleteAtLeastOneTest blocks until at least one test finishes. Thus, this
     # acts as a semaphore.  We cannot use threads + a real semaphore because
     # subprocess forks, which can cause all sorts of hilarity with threads.
     if len(executing_tests) >= parallelism:
-      finished_tests.extend(CompleteAtLeastOneTest(resultfile, executing_tests))
+      finished_tests.extend(CompleteAtLeastOneTest(executing_tests))
 
     if config['name'].startswith('DISABLED_'):
-      PassTest(resultfile, config)
+      PassTest(resultfile, resultlog, config)
     else:
       test = StartTest(sourcefile_path, cflags, config)
       assert test['name'] not in executing_tests
       executing_tests[test['name']] = test
 
   # If there are no more test to start, we still need to drain the running
   # ones.
   while len(executing_tests) > 0:
-    finished_tests.extend(CompleteAtLeastOneTest(resultfile, executing_tests))
+    finished_tests.extend(CompleteAtLeastOneTest(executing_tests))
   timings['compile_done'] = time.time()
 
   for test in finished_tests:
     if test['name'] == 'NCTEST_SANITY':
       _, stderr = test['proc'].communicate()
       return_code = test['proc'].poll()
       if return_code != 0:
         sys.stderr.write(stderr)
       continue
-    ProcessTestResult(resultfile, test)
+    ProcessTestResult(resultfile, resultlog, test)
   timings['results_processed'] = time.time()
 
-  WriteStats(resultfile, suite_name, timings)
+  WriteStats(resultlog, suite_name, timings)
 
+  with open(resultfile_path + '.log', 'w') as fd:
+    fd.write(resultlog.getvalue())
   if return_code == 0:
     with open(resultfile_path, 'w') as fd:
       fd.write(resultfile.getvalue())
 
   resultfile.close()
   sys.exit(return_code)
 
 
 if __name__ == '__main__':
   main()