[lldb][trace] Add a basic function call dump [3] - Add a JSON dumper
authorWalter Erquinigo <wallace@fb.com>
Sun, 16 Oct 2022 01:52:22 +0000 (18:52 -0700)
committerWalter Erquinigo <wallace@fb.com>
Tue, 18 Oct 2022 20:57:53 +0000 (13:57 -0700)
The JSON dumper is very minimalistic. It pretty much only shows the
delimiting instruction IDs of every segment, so that further queries to
the SBCursor can be used to make sense of the data. It's main purpose is
to be serialized somewhat cheaply.

I also renamed untracedSegment to untracedPrefixSegment, in case in the
future we add an untracedSuffixSegment. In any case, this new name is
more explicit, which I like.

Differential Revision: https://reviews.llvm.org/D136034

lldb/include/lldb/Target/TraceDumper.h
lldb/source/Commands/CommandObjectThread.cpp
lldb/source/Target/TraceDumper.cpp
lldb/test/API/commands/trace/TestTraceDumpFunctionCalls.py

index bcbe8e5..59f8878 100644 (file)
@@ -92,10 +92,10 @@ public:
   ///   In terms of implementation details, as segment can be represented with
   ///   the beginning and ending instruction IDs from the instruction trace.
   ///
-  ///  UntracedSegment:
+  ///  UntracedPrefixSegment:
   ///   It might happen that we didn't trace the beginning of a function and we
   ///   saw it for the first time as part of a return. As a way to signal these
-  ///   cases, we have a placeholder UntracedSegment class that completes the
+  ///   cases, we have a placeholder UntracedPrefixSegment class that completes the
   ///   callgraph.
   ///
   ///  Example:
@@ -119,7 +119,7 @@ public:
   ///
   ///   Notice that we changed the instruction ids because this is a new trace.
   ///   Here, in order to have a somewhat complete tree with good traversal
-  ///   capabilities, we can create an UntracedSegment to signal the portion of
+  ///   capabilities, we can create an UntracedPrefixSegment to signal the portion of
   ///   main() that we didn't trace. We don't know if this segment was in fact
   ///   multiple segments with many function calls. We'll never know. The
   ///   resulting tree looks like the following:
@@ -131,7 +131,7 @@ public:
   ///   And in pseudo-code:
   ///
   ///     FunctionCall [
-  ///       UntracedSegment {
+  ///       UntracedPrefixSegment {
   ///         symbol: main()
   ///         nestedCall: FunctionCall [ # this untraced segment has a nested
   ///         call
@@ -289,20 +289,20 @@ public:
       FunctionCall &m_owning_call;
     };
 
-    class UntracedSegment {
+    class UntracedPrefixSegment {
     public:
       /// Note: Untraced segments can only exist if have also seen a traced
       /// segment of the same function call. Thus, we can use those traced
       /// segments if we want symbol information and such.
 
-      UntracedSegment(FunctionCallUP &&nested_call)
+      UntracedPrefixSegment(FunctionCallUP &&nested_call)
           : m_nested_call(std::move(nested_call)) {}
 
       const FunctionCall &GetNestedCall() const;
 
     private:
-      UntracedSegment(const UntracedSegment &) = delete;
-      UntracedSegment &operator=(UntracedSegment const &);
+      UntracedPrefixSegment(const UntracedPrefixSegment &) = delete;
+      UntracedPrefixSegment &operator=(UntracedPrefixSegment const &);
       FunctionCallUP m_nested_call;
     };
 
@@ -346,11 +346,11 @@ public:
 
     /// Create an untraced segment for this call that jumps to the provided
     /// nested call.
-    void SetUntracedSegment(FunctionCallUP &&nested_call);
+    void SetUntracedPrefixSegment(FunctionCallUP &&nested_call);
 
     /// \return
-    ///   A optional to the untraced segment of this call.
-    const llvm::Optional<UntracedSegment> &GetUntracedSegment() const;
+    ///   A optional to the untraced prefix segment of this call.
+    const llvm::Optional<UntracedPrefixSegment> &GetUntracedPrefixSegment() const;
 
     /// \return
     ///   A pointer to the parent call. It may be \b nullptr.
@@ -360,7 +360,7 @@ public:
 
   private:
     /// An optional untraced segment that precedes all the traced segments.
-    llvm::Optional<UntracedSegment> m_untraced_segment;
+    llvm::Optional<UntracedPrefixSegment> m_untraced_prefix_segment;
     /// The traced segments in order. We used a deque to prevent moving these
     /// objects when appending to the list, which would happen with vector.
     std::deque<TracedSegment> m_traced_segments;
@@ -384,8 +384,8 @@ public:
     virtual void TraceItem(const TraceItem &item) = 0;
 
     /// Dump a function call forest.
-    virtual void FunctionCallForest(const std::vector<FunctionCallUP> &forest) {
-    }
+    virtual void
+    FunctionCallForest(const std::vector<FunctionCallUP> &forest) = 0;
   };
 
   /// Create a instruction dumper for the cursor.
index f7a571d..414acfb 100644 (file)
@@ -2132,6 +2132,7 @@ public:
         break;
       }
       case 'J': {
+        m_dumper_options.json = true;
         m_dumper_options.pretty_print_json = true;
         break;
       }
@@ -2198,8 +2199,7 @@ protected:
     llvm::Optional<StreamFile> out_file;
     if (m_options.m_output_file) {
       out_file.emplace(m_options.m_output_file->GetPath().c_str(),
-                       File::eOpenOptionWriteOnly | File::eOpenOptionCanCreate,
-                       lldb::eFilePermissionsFileDefault);
+                       File::eOpenOptionWriteOnly | File::eOpenOptionCanCreate);
     }
 
     m_options.m_dumper_options.forwards = true;
@@ -2395,8 +2395,7 @@ protected:
     llvm::Optional<StreamFile> out_file;
     if (m_options.m_output_file) {
       out_file.emplace(m_options.m_output_file->GetPath().c_str(),
-                       File::eOpenOptionWriteOnly | File::eOpenOptionCanCreate,
-                       lldb::eFilePermissionsFileDefault);
+                       File::eOpenOptionWriteOnly | File::eOpenOptionCanCreate);
     }
 
     if (m_options.m_continue && !m_last_id) {
index 2dbcb49..7a5214d 100644 (file)
@@ -247,13 +247,13 @@ private:
   }
 
   void DumpFunctionCallTree(const TraceDumper::FunctionCall &function_call) {
-    if (function_call.GetUntracedSegment()) {
+    if (function_call.GetUntracedPrefixSegment()) {
       m_s.Indent();
       DumpUntracedContext(function_call);
       m_s << "\n";
 
       m_s.IndentMore();
-      DumpFunctionCallTree(function_call.GetUntracedSegment()->GetNestedCall());
+      DumpFunctionCallTree(function_call.GetUntracedPrefixSegment()->GetNestedCall());
       m_s.IndentLess();
     }
 
@@ -314,6 +314,43 @@ public:
 
   ~OutputWriterJSON() { m_j.arrayEnd(); }
 
+  void FunctionCallForest(
+      const std::vector<TraceDumper::FunctionCallUP> &forest) override {
+    for (size_t i = 0; i < forest.size(); i++) {
+      m_j.object([&] { DumpFunctionCallTree(*forest[i]); });
+    }
+  }
+
+  void DumpFunctionCallTree(const TraceDumper::FunctionCall &function_call) {
+    if (function_call.GetUntracedPrefixSegment()) {
+      m_j.attributeObject("untracedPrefixSegment", [&] {
+        m_j.attributeObject("nestedCall", [&] {
+          DumpFunctionCallTree(
+              function_call.GetUntracedPrefixSegment()->GetNestedCall());
+        });
+      });
+    }
+
+    if (!function_call.GetTracedSegments().empty()) {
+      m_j.attributeArray("tracedSegments", [&] {
+        for (const TraceDumper::FunctionCall::TracedSegment &segment :
+             function_call.GetTracedSegments()) {
+          m_j.object([&] {
+            m_j.attribute("firstInstructionId",
+                          std::to_string(segment.GetFirstInstructionID()));
+            m_j.attribute("lastInstructionId",
+                          std::to_string(segment.GetLastInstructionID()));
+            segment.IfNestedCall(
+                [&](const TraceDumper::FunctionCall &nested_call) {
+                  m_j.attributeObject(
+                      "nestedCall", [&] { DumpFunctionCallTree(nested_call); });
+                });
+          });
+        }
+      });
+    }
+  }
+
   void DumpEvent(const TraceDumper::TraceItem &item) {
     m_j.attribute("event", TraceCursor::EventKindToString(*item.event));
     switch (*item.event) {
@@ -597,7 +634,7 @@ TraceDumper::FunctionCall::TracedSegment::GetLastInstructionSymbolInfo() const {
 }
 
 const TraceDumper::FunctionCall &
-TraceDumper::FunctionCall::UntracedSegment::GetNestedCall() const {
+TraceDumper::FunctionCall::UntracedPrefixSegment::GetNestedCall() const {
   return *m_nested_call;
 }
 
@@ -631,14 +668,14 @@ TraceDumper::FunctionCall::GetLastTracedSegment() {
   return m_traced_segments.back();
 }
 
-const Optional<TraceDumper::FunctionCall::UntracedSegment> &
-TraceDumper::FunctionCall::GetUntracedSegment() const {
-  return m_untraced_segment;
+const Optional<TraceDumper::FunctionCall::UntracedPrefixSegment> &
+TraceDumper::FunctionCall::GetUntracedPrefixSegment() const {
+  return m_untraced_prefix_segment;
 }
 
-void TraceDumper::FunctionCall::SetUntracedSegment(
+void TraceDumper::FunctionCall::SetUntracedPrefixSegment(
     TraceDumper::FunctionCallUP &&nested_call) {
-  m_untraced_segment.emplace(std::move(nested_call));
+  m_untraced_prefix_segment.emplace(std::move(nested_call));
 }
 
 TraceDumper::FunctionCall *TraceDumper::FunctionCall::GetParentCall() const {
@@ -694,8 +731,8 @@ static TraceDumper::FunctionCall &AppendReturnedInstructionToFunctionCallForest(
   // one that will contain the new instruction in its first traced segment.
   TraceDumper::FunctionCallUP new_root =
       std::make_unique<TraceDumper::FunctionCall>(cursor_sp, symbol_info);
-  // This new root will own the previous root through an untraced segment.
-  new_root->SetUntracedSegment(std::move(roots.back()));
+  // This new root will own the previous root through an untraced prefix segment.
+  new_root->SetUntracedPrefixSegment(std::move(roots.back()));
   roots.pop_back();
   // We update the roots container to point to the new root
   roots.emplace_back(std::move(new_root));
index 70f8edb..d37920b 100644 (file)
@@ -10,8 +10,20 @@ class TestTraceDumpInfo(TraceIntelPTTestCaseBase):
       self.expect("thread trace dump function-calls 2",
         error=True, substrs=['error: no thread with index: "2"'])
 
-      # We don't support yet JSON
-      self.expect("thread trace dump function-calls 1 -j", substrs=['[]'])
+      self.expect("thread trace dump function-calls 1 -j",
+        substrs=['[{"tracedSegments":[{"firstInstructionId":"1","lastInstructionId":"22"}]}]'])
+
+      self.expect("thread trace dump function-calls 1 -J",
+        substrs=['''[
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "1",
+        "lastInstructionId": "22"
+      }
+    ]
+  }
+]'''])
 
       # We test first some code without function call
       self.expect("thread trace dump function-calls 1",
@@ -34,6 +46,26 @@ m.out`foo() + 65 at multi_thread.cpp:12:21 to 12:21  [4, 19524]
 [call tree #1]
 <tracing errors>  [19532, 19532]'''])
 
+      self.expect("thread trace dump function-calls 2 -J",
+        substrs=['''[
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "4",
+        "lastInstructionId": "19524"
+      }
+    ]
+  },
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "19532",
+        "lastInstructionId": "19532"
+      }
+    ]
+  }
+]'''])
+
       self.expect("thread trace dump function-calls 3",
         substrs=['''thread #3: tid = 3497497
 
@@ -43,6 +75,26 @@ m.out`bar() + 30 at multi_thread.cpp:19:3 to 20:6  [5, 61831]
 [call tree #1]
 <tracing errors>  [61834, 61834]'''])
 
+      self.expect("thread trace dump function-calls 3 -J",
+        substrs=['''[
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "5",
+        "lastInstructionId": "61831"
+      }
+    ]
+  },
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "61834",
+        "lastInstructionId": "61834"
+      }
+    ]
+  }
+]'''])
+
     def testInlineFunctionCalls(self):
       self.expect("file " + os.path.join(self.getSourceDir(), "inline-function", "a.out"))
       self.expect("b main") # we'll trace from the beginning of main
@@ -58,6 +110,42 @@ a.out`main + 8 at inline.cpp:15:7 to 16:14  [1, 5]
   a.out`foo(int) + 49 at inline.cpp:9:15 to 12:1  [22, 26]
 a.out`main + 25 at inline.cpp:16:14 to 16:14  [27, 27]'''])
 
+      self.expect("thread trace dump function-calls -J",
+        substrs=['''[
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "1",
+        "lastInstructionId": "5",
+        "nestedCall": {
+          "tracedSegments": [
+            {
+              "firstInstructionId": "6",
+              "lastInstructionId": "13",
+              "nestedCall": {
+                "tracedSegments": [
+                  {
+                    "firstInstructionId": "14",
+                    "lastInstructionId": "21"
+                  }
+                ]
+              }
+            },
+            {
+              "firstInstructionId": "22",
+              "lastInstructionId": "26"
+            }
+          ]
+        }
+      },
+      {
+        "firstInstructionId": "27",
+        "lastInstructionId": "27"
+      }
+    ]
+  }
+]'''])
+
     def testIncompleteInlineFunctionCalls(self):
       self.expect("file " + os.path.join(self.getSourceDir(), "inline-function", "a.out"))
       self.expect("b 4") # we'll trace from the middle of the inline method
@@ -73,6 +161,38 @@ a.out`main
   a.out`foo(int) + 49 at inline.cpp:9:15 to 12:1  [6, 10]
 a.out`main + 25 at inline.cpp:16:14 to 16:14  [11, 11]'''])
 
+      self.expect("thread trace dump function-calls -J",
+        substrs=['''[
+  {
+    "untracedPrefixSegment": {
+      "nestedCall": {
+        "untracedPrefixSegment": {
+          "nestedCall": {
+            "tracedSegments": [
+              {
+                "firstInstructionId": "1",
+                "lastInstructionId": "5"
+              }
+            ]
+          }
+        },
+        "tracedSegments": [
+          {
+            "firstInstructionId": "6",
+            "lastInstructionId": "10"
+          }
+        ]
+      }
+    },
+    "tracedSegments": [
+      {
+        "firstInstructionId": "11",
+        "lastInstructionId": "11"
+      }
+    ]
+  }
+]'''])
+
     def testMultifileFunctionCalls(self):
       # This test is extremely important because it first calls the method foo() which requires going through the dynamic linking.
       # You'll see the entry "a.out`symbol stub for: foo()" which will invoke the ld linker, which will in turn find the actual foo
@@ -107,3 +227,99 @@ a.out`main + 55 at main.cpp:14 to 16:0  [21, 25]
         libbar.so`bar() at bar.cpp:1 to 4:0  [32, 40]
     libfoo.so`foo() + 13 at foo.cpp:4 to 6:0  [41, 48]
 a.out`main + 68 at main.cpp:16 to 16:0  [49, 51]'''])
+
+      self.expect("thread trace dump function-calls -J",
+        substrs=['''[
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "1",
+        "lastInstructionId": "1",
+        "nestedCall": {
+          "tracedSegments": [
+            {
+              "firstInstructionId": "3",
+              "lastInstructionId": "5",
+              "nestedCall": {
+                "tracedSegments": [
+                  {
+                    "firstInstructionId": "6",
+                    "lastInstructionId": "7"
+                  }
+                ]
+              }
+            }
+          ]
+        }
+      }
+    ]
+  },
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "8",
+        "lastInstructionId": "8"
+      }
+    ]
+  },
+  {
+    "tracedSegments": [
+      {
+        "firstInstructionId": "10",
+        "lastInstructionId": "14",
+        "nestedCall": {
+          "tracedSegments": [
+            {
+              "firstInstructionId": "16",
+              "lastInstructionId": "20"
+            }
+          ]
+        }
+      },
+      {
+        "firstInstructionId": "21",
+        "lastInstructionId": "25",
+        "nestedCall": {
+          "tracedSegments": [
+            {
+              "firstInstructionId": "26",
+              "lastInstructionId": "26",
+              "nestedCall": {
+                "tracedSegments": [
+                  {
+                    "firstInstructionId": "27",
+                    "lastInstructionId": "30",
+                    "nestedCall": {
+                      "tracedSegments": [
+                        {
+                          "firstInstructionId": "31",
+                          "lastInstructionId": "31",
+                          "nestedCall": {
+                            "tracedSegments": [
+                              {
+                                "firstInstructionId": "32",
+                                "lastInstructionId": "40"
+                              }
+                            ]
+                          }
+                        }
+                      ]
+                    }
+                  },
+                  {
+                    "firstInstructionId": "41",
+                    "lastInstructionId": "48"
+                  }
+                ]
+              }
+            }
+          ]
+        }
+      },
+      {
+        "firstInstructionId": "49",
+        "lastInstructionId": "51"
+      }
+    ]
+  }
+]'''])