[build-script] Log CMake Bootstrap build time

Include the CMake bootstrap time in the build-script build times.
We're including everything else. Would be good to determine how much
time we can save by caching a new enough pre-built CMake in the builder
images.

Importing the log_time_in_scope exposes a cyclic dependency cycle
between the `swift_build_support` and `build_swift` python modules in
such a way that the tests fail due to re-importing parts of build_swift:

```
ImportError: Failed to import test module: tests.build_swift.test_migration
Traceback (most recent call last):
  File "/usr/lib/python3.8/unittest/loader.py", line 436, in _find_test_path
    module = self._get_module_from_name(name)
  File "/usr/lib/python3.8/unittest/loader.py", line 377, in _get_module_from_name
    __import__(name)
  File "/home/build-user/swift/utils/build_swift/tests/build_swift/test_migration.py", line 14, in <module>
    from build_swift import migration
  File "/home/build-user/swift/utils/build_swift/build_swift/migration.py", line 18, in <module>
    from swift_build_support.swift_build_support.targets import \
  File "/home/build-user/swift/utils/swift_build_support/swift_build_support/targets.py", line 15, in <module>
    from . import cmake
  File "/home/build-user/swift/utils/swift_build_support/swift_build_support/cmake.py", line 26, in <module>
    from swift_build_support.swift_build_support.utils import log_time_in_scope
  File "/home/build-user/swift/utils/swift_build_support/swift_build_support/utils.py", line 20, in <module>
    from build_swift.build_swift.constants import SWIFT_BUILD_ROOT
ModuleNotFoundError: No module named 'build_swift.build_swift'
```

I've put the import of log_time_in_scope into the function definition
to ensure that build_swift has been fully loaded by the time we need
log_time_in_scope, ensuring that there is order between the two pieces.

Python caches the imported module, so if we accidentally re-import the
log_time_in_scope, nothing actually changes.

This re-orders the instantiation of the BuildScriptInvocation object so
that it comes before the creation of the CMake path. This ensures that
BuildScriptInvocation() does not delete the build log after logging the
CMake bootstrap time. This is fine because the toolchain and arguments
are reference types, so updating the CMake path in both of those will be
reflected in the copy taken in the BuildScriptInvocation() object.

Author: etcwilde

utils/build-script

@@ -695,6 +695,12 @@ def main_normal():
     if args.cmake is not None:
         toolchain.cmake = args.cmake
 
+    # Preprocess the arguments to apply defaults.
+    apply_default_arguments(toolchain, args)
+
+    # Create the build script invocation.
+    invocation = build_script_invocation.BuildScriptInvocation(toolchain, args)
+
     cmake = CMake(args=args, toolchain=toolchain)
     # Check the CMake version is sufficient on Linux and build from source
     # if not.
@@ -703,9 +709,6 @@ def main_normal():
         toolchain.cmake = cmake_path
         args.cmake = cmake_path
 
-    # Preprocess the arguments to apply defaults.
-    apply_default_arguments(toolchain, args)
-
     # Validate the arguments.
     validate_arguments(toolchain, args)
 
@@ -716,9 +719,6 @@ def main_normal():
         # Capture the output because we don't want to see the stats.
         shell.capture([toolchain.sccache, "--show-stats"])
 
-    # Create the build script invocation.
-    invocation = build_script_invocation.BuildScriptInvocation(toolchain, args)
-
     # Sanitize the runtime environment.
     initialize_runtime_environment()
 

utils/swift_build_support/swift_build_support/cmake.py

@@ -267,14 +267,18 @@ def build_cmake(self, source_root, build_root):
         if not os.path.isdir(cmake_build_dir):
             os.makedirs(cmake_build_dir)
 
-        cwd = os.getcwd()
-        os.chdir(cmake_build_dir)
-        build_jobs = self.args.build_jobs or multiprocessing.cpu_count()
-        shell.call_without_sleeping([cmake_bootstrap, '--no-qt-gui',
-                                     '--parallel=%s' % build_jobs, '--',
-                                     '-DCMAKE_USE_OPENSSL=OFF'], echo=True)
-        shell.call_without_sleeping(['make', '-j%s' % build_jobs],
-                                    echo=True)
+        print("--- Bootstrap Local CMake ---", flush=True)
+        from swift_build_support.swift_build_support.utils \
+            import log_time_in_scope
+        with log_time_in_scope("Bootstrap Local CMake"):
+            cwd = os.getcwd()
+            os.chdir(cmake_build_dir)
+            build_jobs = self.args.build_jobs or multiprocessing.cpu_count()
+            shell.call_without_sleeping([cmake_bootstrap, '--no-qt-gui',
+                                         '--parallel=%s' % build_jobs, '--',
+                                         '-DCMAKE_USE_OPENSSL=OFF'], echo=True)
+            shell.call_without_sleeping(['make', '-j%s' % build_jobs],
+                                        echo=True)
         os.chdir(cwd)
         return os.path.join(cmake_build_dir, 'bin', 'cmake')