Display more timestamps when profiling ninja

When running setup with `--profile-self` option,
there are currently no logs after "Found ninja...". However, there are
still some lengthy processes for generating targets and ninja.build.

This add more log entries, when profiling, only for the purpose of
displaying the timestamps of the different steps in ninja generation.

3 files changed, 14 insertions, 0 deletions

diff --git a/mesonbuild/backend/ninjabackend.py b/mesonbuild/backend/ninjabackend.py
index 1786fef..9c347d7 100644
--- a/mesonbuild/backend/ninjabackend.py
+++ b/mesonbuild/backend/ninjabackend.py
@@ -628,11 +628,15 @@ class NinjaBackend(backends.Backend):
 
             for t in ProgressBar(self.build.get_targets().values(), desc='Generating targets'):
                 self.generate_target(t)
+            mlog.log_timestamp("Targets generated")
             self.add_build_comment(NinjaComment('Test rules'))
             self.generate_tests()
+            mlog.log_timestamp("Tests generated")
             self.add_build_comment(NinjaComment('Install rules'))
             self.generate_install()
+            mlog.log_timestamp("Install generated")
             self.generate_dist()
+            mlog.log_timestamp("Dist generated")
             key = OptionKey('b_coverage')
             if (key in self.environment.coredata.options and
                     self.environment.coredata.options[key].value):
@@ -640,12 +644,14 @@ class NinjaBackend(backends.Backend):
                 if gcovr_exe or (lcov_exe and genhtml_exe):
                     self.add_build_comment(NinjaComment('Coverage rules'))
                     self.generate_coverage_rules(gcovr_exe, gcovr_version)
+                    mlog.log_timestamp("Coverage rules generated")
                 else:
                     # FIXME: since we explicitly opted in, should this be an error?
                     # The docs just say these targets will be created "if possible".
                     mlog.warning('Need gcovr or lcov/genhtml to generate any coverage reports')
             self.add_build_comment(NinjaComment('Suffix'))
             self.generate_utils()
+            mlog.log_timestamp("Utils generated")
             self.generate_ending()
 
             self.write_rules(outfile)
@@ -1363,6 +1369,7 @@ class NinjaBackend(backends.Backend):
     def write_builds(self, outfile):
         for b in ProgressBar(self.build_elements, desc='Writing build.ninja'):
             b.write(outfile)
+        mlog.log_timestamp("build.ninja generated")
 
     def generate_phony(self):
         self.add_build_comment(NinjaComment('Phony build target, always out of date'))
diff --git a/mesonbuild/mlog.py b/mesonbuild/mlog.py
index 3c95ee8..b431428 100644
--- a/mesonbuild/mlog.py
+++ b/mesonbuild/mlog.py
@@ -276,6 +276,10 @@ class _Logger:
         else:
             self._log(*args, is_error=is_error, nested=nested, sep=sep, end=end)
 
+    def log_timestamp(self, *args: TV_Loggable) -> None:
+        if self.log_timestamp_start:
+            self.log(*args)
+
     def _log_once(self, *args: TV_Loggable, is_error: bool = False,
                   nested: bool = True, sep: T.Optional[str] = None,
                   end: T.Optional[str] = None) -> None:
@@ -419,6 +423,7 @@ get_log_dir = _logger.get_log_dir
 get_warning_count = _logger.get_warning_count
 initialize = _logger.initialize
 log = _logger.log
+log_timestamp = _logger.log_timestamp
 nested = _logger.nested
 nested_warnings = _logger.nested_warnings
 no_logging = _logger.no_logging
diff --git a/mesonbuild/msetup.py b/mesonbuild/msetup.py
index 61d66f2..e6c1220 100644
--- a/mesonbuild/msetup.py
+++ b/mesonbuild/msetup.py
@@ -293,6 +293,8 @@ class MesonApp:
                 with open(fname, 'w', encoding='utf-8') as f:
                     json.dump(data, f)
 
+                mlog.log("meson setup completed")  # Display timestamp
+
         except Exception as e:
             mintro.write_meson_info_file(b, [e])
             if cdf is not None: