commit c829f0cfcaa4753743fde1900091e1233c41350b
author Frank Winklmeier <frank.winklmeier@cern.ch> Mon Jan 20 10:42:50 2020 +0100
committer Brad King <brad.king@kitware.com> Wed Jan 22 09:58:52 2020 -0500
tree 319fee9604ee4f5f4c6a006855b5d055f5b81a68
parent 5e38b8f608fee599494aadd0d4b5ed9366843bda

trace: Add time and stack level to JSON output format

Add the timestamp and stack depth of the function call to the JSON trace
output format. This information can be useful for cmake profiling and
call stack inspection (see e.g. https://github.com/volo-zyko/cmake-profile-stats).

Improve unit test to allow for varying set of keys to check in trace lines.

Help/manual/cmake.1.rst

diff --git a/Help/manual/cmake.1.rst b/Help/manual/cmake.1.rst
index 4315f0a..44b1f2f 100644
--- a/Help/manual/cmake.1.rst
+++ b/Help/manual/cmake.1.rst
@@ -279,7 +279,9 @@
          "file": "/full/path/to/the/CMake/file.txt",
          "line": 0,
          "cmd": "add_executable",
-         "args": ["foo", "bar"]
+         "args": ["foo", "bar"],
+         "time": 1579512535.9687231,
+         "frame": 2
        }
 
      The members are:
@@ -288,8 +290,8 @@
        The full path to the CMake source file where the function
        was called.
 
-      ``line``
-       The line in `file` of the function call.
+     ``line``
+       The line in ``file`` of the function call.
 
      ``cmd``
        The name of the function that was called.
@@ -297,6 +299,12 @@
      ``args``
        A string list of all function parameters.
 
+     ``time``
+       Timestamp (seconds since epoch) of the function call.
+
+     ``frame``
+       Stack frame depth of the function that was called.
+
      Additionally, the first JSON document outputted contains the
      ``version`` key for the current major and minor version of the
 

Source/cmMakefile.cxx

diff --git a/Source/cmMakefile.cxx b/Source/cmMakefile.cxx
index dc741d3..1d1e895 100644
--- a/Source/cmMakefile.cxx
+++ b/Source/cmMakefile.cxx
@@ -340,6 +340,9 @@
       for (std::string const& arg : args) {
         val["args"].append(arg);
       }
+      val["time"] = cmSystemTools::GetTime();
+      val["frame"] =
+        static_cast<std::uint64_t>(this->ExecutionStatusStack.size());
       msg << Json::writeString(builder, val);
 #endif
       break;

Tests/RunCMake/CommandLine/trace-json-v1-check.py

diff --git a/Tests/RunCMake/CommandLine/trace-json-v1-check.py b/Tests/RunCMake/CommandLine/trace-json-v1-check.py
index 14febaf..e617b76 100755
--- a/Tests/RunCMake/CommandLine/trace-json-v1-check.py
+++ b/Tests/RunCMake/CommandLine/trace-json-v1-check.py
@@ -46,6 +46,7 @@
     {
         'args': msg_args,
         'cmd': 'message',
+        'frame': 3 if expand else 2
     },
 ]
 
@@ -59,14 +60,17 @@
 
     for i in fp.readlines():
         line = json.loads(i)
-        assert sorted(line.keys()) == ['args', 'cmd', 'file', 'line']
+        assert sorted(line.keys()) == ['args', 'cmd', 'file', 'frame', 'line', 'time']
         assert isinstance(line['args'], list)
         assert isinstance(line['cmd'], unicode)
         assert isinstance(line['file'], unicode)
+        assert isinstance(line['frame'], int)
         assert isinstance(line['line'], int)
+        assert isinstance(line['time'], float)
 
         for j in required_traces:
-            if j['cmd'] == line['cmd'] and j['args'] == line['args']:
-                j['found'] = True
+            # Compare the subset of required keys with line
+            if {k: line[k] for k in j} == j:
+                required_traces.remove(j)
 
-assert all([x.get('found', False) == True for x in required_traces])
+assert not required_traces