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

@@ -279,7 +279,9 @@ Options
          "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 @@ Options
        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 @@ Options
      ``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

@@ -340,6 +340,9 @@ void cmMakefile::PrintCommandTrace(const cmListFileFunction& lff) const
       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

@@ -46,6 +46,7 @@ required_traces = [
     {
         'args': msg_args,
         'cmd': 'message',
+        'frame': 3 if expand else 2
     },
 ]
 
@@ -59,14 +60,17 @@ with open(trace_file, 'r') as fp:
 
     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