History

perf scripts python: exported-sql-viewer.py: Add call tree

Add a new report to display a call tree. The Call Tree report is very similar to the Context-Sensitive Call Graph, but the data is not aggregated. Also the 'Count' column, which would be always 1, is replaced by the 'Call Time'. Committer testing: $ cat simple-retpoline.c /* https://lkml.kernel.org/r/20190109091835.5570-6-adrian.hunter@intel.com $ gcc -ggdb3 -Wall -Wextra -O2 -o simple-retpoline simple-retpoline.c $ objdump -d simple-retpoline */ __attribute__((noinline)) int bar(void) { return -1; } int foo(void) { return bar() + 1; } __attribute__((indirect_branch("thunk"))) int main() { int (*volatile fn)(void) = foo; fn(); return fn(); } $ $ perf record -o simple-retpoline.perf.data -e intel_pt/cyc/u ./simple-retpoline $ perf script -i simple-retpoline.perf.data --itrace=be -s ~acme/libexec/perf-core/scripts/python/export-to-sqlite.py simple-retpoline.db branches calls $ python ~acme/libexec/perf-core/scripts/python/exported-sql-viewer.py simple-retpoline.db And in the GUI select: "Reports" "Call Tree" Call Path | Object | Call Time (ns) | Time (ns) | Time (%) | Branch Count | Brach Count (%) | > simple-retpolin > PID:TID > _start ld-2.28.so 2193855505777 156267 100.0 10602 100.0 unknown unknown 2193855506010 2276 1.5 1 0.0 > _dl_start ld-2.28.so 2193855508286 137047 87.7 10088 95.2 > _dl_init ld-2.28.so 2193855645444 9142 5.9 326 3.1 > _start simple-retpoline 2193855654587 7457 4.8 182 1.7 > __libc_start_main <SNIP> <SNIP> > main simple-retpoline 2193855657493 32 0.5 12 6.7 > foo simple-retpoline 2193855657493 14 43.8 5 41.7 <SNIP>

Adrian Hunter committed 7 years ago

Commit ae8b8871 parent 254c0d81 file · +186 −9Browse files

Showing the changes to tools/perf/scripts/python/exported-sql-viewer.py (1 of 1 file). Show all

Unified · Split

tools/perf/scripts/python/exported-sql-viewer.py+186−9
@@ -688,6 +688,150 @@ class CallGraphModel(CallGraphModelBase): · 687 unmodified lines
688688 ids.insert(0, query.value(1))
689689 return ids
690690
691+# Call tree data model level 2+ item base
692+
693+class CallTreeLevelTwoPlusItemBase(CallGraphLevelItemBase):
694+
695+ def __init__(self, glb, row, comm_id, thread_id, calls_id, time, branch_count, parent_item):
696+ super(CallTreeLevelTwoPlusItemBase, self).__init__(glb, row, parent_item)
697+ self.comm_id = comm_id
698+ self.thread_id = thread_id
699+ self.calls_id = calls_id
700+ self.branch_count = branch_count
701+ self.time = time
702+
703+ def Select(self):
704+ self.query_done = True;
705+ if self.calls_id == 0:
706+ comm_thread = " AND comm_id = " + str(self.comm_id) + " AND thread_id = " + str(self.thread_id)
707+ else:
708+ comm_thread = ""
709+ query = QSqlQuery(self.glb.db)
710+ QueryExec(query, "SELECT calls.id, name, short_name, call_time, return_time - call_time, branch_count"
711+ " FROM calls"
712+ " INNER JOIN call_paths ON calls.call_path_id = call_paths.id"
713+ " INNER JOIN symbols ON call_paths.symbol_id = symbols.id"
714+ " INNER JOIN dsos ON symbols.dso_id = dsos.id"
715+ " WHERE calls.parent_id = " + str(self.calls_id) + comm_thread +
716+ " ORDER BY call_time, calls.id")
717+ while query.next():
718+ child_item = CallTreeLevelThreeItem(self.glb, self.child_count, self.comm_id, self.thread_id, query.value(0), query.value(1), query.value(2), query.value(3), int(query.value(4)), int(query.value(5)), self)
719+ self.child_items.append(child_item)
720+ self.child_count += 1
721+
722+# Call tree data model level three item
723+
724+class CallTreeLevelThreeItem(CallTreeLevelTwoPlusItemBase):
725+
726+ def __init__(self, glb, row, comm_id, thread_id, calls_id, name, dso, count, time, branch_count, parent_item):
727+ super(CallTreeLevelThreeItem, self).__init__(glb, row, comm_id, thread_id, calls_id, time, branch_count, parent_item)
728+ dso = dsoname(dso)
729+ self.data = [ name, dso, str(count), str(time), PercentToOneDP(time, parent_item.time), str(branch_count), PercentToOneDP(branch_count, parent_item.branch_count) ]
730+ self.dbid = calls_id
731+
732+# Call tree data model level two item
733+
734+class CallTreeLevelTwoItem(CallTreeLevelTwoPlusItemBase):
735+
736+ def __init__(self, glb, row, comm_id, thread_id, pid, tid, parent_item):
737+ super(CallTreeLevelTwoItem, self).__init__(glb, row, comm_id, thread_id, 0, 0, 0, parent_item)
738+ self.data = [str(pid) + ":" + str(tid), "", "", "", "", "", ""]
739+ self.dbid = thread_id
740+
741+ def Select(self):
742+ super(CallTreeLevelTwoItem, self).Select()
743+ for child_item in self.child_items:
744+ self.time += child_item.time
745+ self.branch_count += child_item.branch_count
746+ for child_item in self.child_items:
747+ child_item.data[4] = PercentToOneDP(child_item.time, self.time)
748+ child_item.data[6] = PercentToOneDP(child_item.branch_count, self.branch_count)
749+
750+# Call tree data model level one item
751+
752+class CallTreeLevelOneItem(CallGraphLevelItemBase):
753+
754+ def __init__(self, glb, row, comm_id, comm, parent_item):
755+ super(CallTreeLevelOneItem, self).__init__(glb, row, parent_item)
756+ self.data = [comm, "", "", "", "", "", ""]
757+ self.dbid = comm_id
758+
759+ def Select(self):
760+ self.query_done = True;
761+ query = QSqlQuery(self.glb.db)
762+ QueryExec(query, "SELECT thread_id, pid, tid"
763+ " FROM comm_threads"
764+ " INNER JOIN threads ON thread_id = threads.id"
765+ " WHERE comm_id = " + str(self.dbid))
766+ while query.next():
767+ child_item = CallTreeLevelTwoItem(self.glb, self.child_count, self.dbid, query.value(0), query.value(1), query.value(2), self)
768+ self.child_items.append(child_item)
769+ self.child_count += 1
770+
771+# Call tree data model root item
772+
773+class CallTreeRootItem(CallGraphLevelItemBase):
774+
775+ def __init__(self, glb):
776+ super(CallTreeRootItem, self).__init__(glb, 0, None)
777+ self.dbid = 0
778+ self.query_done = True;
779+ query = QSqlQuery(glb.db)
780+ QueryExec(query, "SELECT id, comm FROM comms")
781+ while query.next():
782+ if not query.value(0):
783+ continue
784+ child_item = CallTreeLevelOneItem(glb, self.child_count, query.value(0), query.value(1), self)
785+ self.child_items.append(child_item)
786+ self.child_count += 1
787+
788+# Call Tree data model
789+
790+class CallTreeModel(CallGraphModelBase):
791+
792+ def __init__(self, glb, parent=None):
793+ super(CallTreeModel, self).__init__(glb, parent)
794+
795+ def GetRoot(self):
796+ return CallTreeRootItem(self.glb)
797+
798+ def columnCount(self, parent=None):
799+ return 7
800+
801+ def columnHeader(self, column):
802+ headers = ["Call Path", "Object", "Call Time", "Time (ns) ", "Time (%) ", "Branch Count ", "Branch Count (%) "]
803+ return headers[column]
804+
805+ def columnAlignment(self, column):
806+ alignment = [ Qt.AlignLeft, Qt.AlignLeft, Qt.AlignRight, Qt.AlignRight, Qt.AlignRight, Qt.AlignRight, Qt.AlignRight ]
807+ return alignment[column]
808+
809+ def DoFindSelect(self, query, match):
810+ QueryExec(query, "SELECT calls.id, comm_id, thread_id"
811+ " FROM calls"
812+ " INNER JOIN call_paths ON calls.call_path_id = call_paths.id"
813+ " INNER JOIN symbols ON call_paths.symbol_id = symbols.id"
814+ " WHERE symbols.name" + match +
815+ " ORDER BY comm_id, thread_id, call_time, calls.id")
816+
817+ def FindPath(self, query):
818+ # Turn the query result into a list of ids that the tree view can walk
819+ # to open the tree at the right place.
820+ ids = []
821+ parent_id = query.value(0)
822+ while parent_id:
823+ ids.insert(0, parent_id)
824+ q2 = QSqlQuery(self.glb.db)
825+ QueryExec(q2, "SELECT parent_id"
826+ " FROM calls"
827+ " WHERE id = " + str(parent_id))
828+ if not q2.next():
829+ break
830+ parent_id = q2.value(0)
831+ ids.insert(0, query.value(2))
832+ ids.insert(0, query.value(1))
833+ return ids
834+
691835 # Vertical widget layout
692836
693837 class VBox():
@@ -772,6 +916,29 @@ class CallGraphWindow(TreeWindowBase): · 78 unmodified lines
772916
773917 AddSubWindow(glb.mainwindow.mdi_area, self, "Context-Sensitive Call Graph")
774918
919+# Call tree window
920+
921+class CallTreeWindow(TreeWindowBase):
922+
923+ def __init__(self, glb, parent=None):
924+ super(CallTreeWindow, self).__init__(parent)
925+
926+ self.model = LookupCreateModel("Call Tree", lambda x=glb: CallTreeModel(x))
927+
928+ self.view = QTreeView()
929+ self.view.setModel(self.model)
930+
931+ for c, w in ((0, 230), (1, 100), (2, 100), (3, 70), (4, 70), (5, 100)):
932+ self.view.setColumnWidth(c, w)
933+
934+ self.find_bar = FindBar(self, self)
935+
936+ self.vbox = VBox(self.view, self.find_bar.Widget())
937+
938+ self.setWidget(self.vbox.Widget())
939+
940+ AddSubWindow(glb.mainwindow.mdi_area, self, "Call Tree")
941+
775942 # Child data item finder
776943
777944 class ChildDataItemFinder():
@@ -1890,10 +2057,10 @@ def GetEventList(db): · 1112 unmodified lines
18902057
18912058 # Is a table selectable
18922059
1893−def IsSelectable(db, table):
2060+def IsSelectable(db, table, sql = ""):
18942061 query = QSqlQuery(db)
18952062 try:
1896− QueryExec(query, "SELECT * FROM " + table + " LIMIT 1")
2063+ QueryExec(query, "SELECT * FROM " + table + " " + sql + " LIMIT 1")
18972064 except:
18982065 return False
18992066 return True
@@ -2302,9 +2469,10 @@ p.c2 { · 402 unmodified lines
23022469 </style>
23032470 <p class=c1><a href=#reports>1. Reports</a></p>
23042471 <p class=c2><a href=#callgraph>1.1 Context-Sensitive Call Graph</a></p>
2305−<p class=c2><a href=#allbranches>1.2 All branches</a></p>
2306−<p class=c2><a href=#selectedbranches>1.3 Selected branches</a></p>
2307−<p class=c2><a href=#topcallsbyelapsedtime>1.4 Top calls by elapsed time</a></p>
2472+<p class=c2><a href=#calltree>1.2 Call Tree</a></p>
2473+<p class=c2><a href=#allbranches>1.3 All branches</a></p>
2474+<p class=c2><a href=#selectedbranches>1.4 Selected branches</a></p>
2475+<p class=c2><a href=#topcallsbyelapsedtime>1.5 Top calls by elapsed time</a></p>
23082476 <p class=c1><a href=#tables>2. Tables</a></p>
23092477 <h1 id=reports>1. Reports</h1>
23102478 <h2 id=callgraph>1.1 Context-Sensitive Call Graph</h2>
@@ -2340,7 +2508,10 @@ v- ls · 29 unmodified lines
23402508 <h3>Find</h3>
23412509 Ctrl-F displays a Find bar which finds function names by either an exact match or a pattern match.
23422510 The pattern matching symbols are ? for any character and * for zero or more characters.
2343−<h2 id=allbranches>1.2 All branches</h2>
2511+<h2 id=calltree>1.2 Call Tree</h2>
2512+The Call Tree report is very similar to the Context-Sensitive Call Graph, but the data is not aggregated.
2513+Also the 'Count' column, which would be always 1, is replaced by the 'Call Time'.
2514+<h2 id=allbranches>1.3 All branches</h2>
23442515 The All branches report displays all branches in chronological order.
23452516 Not all data is fetched immediately. More records can be fetched using the Fetch bar provided.
23462517 <h3>Disassembly</h3>
@@ -2366,10 +2537,10 @@ sudo ldconfig · 19 unmodified lines
23662537 Ctrl-F displays a Find bar which finds substrings by either an exact match or a regular expression match.
23672538 Refer to Python documentation for the regular expression syntax.
23682539 All columns are searched, but only currently fetched rows are searched.
2369−<h2 id=selectedbranches>1.3 Selected branches</h2>
2540+<h2 id=selectedbranches>1.4 Selected branches</h2>
23702541 This is the same as the <a href=#allbranches>All branches</a> report but with the data reduced
23712542 by various selection criteria. A dialog box displays available criteria which are AND'ed together.
2372−<h3>1.3.1 Time ranges</h3>
2543+<h3>1.4.1 Time ranges</h3>
23732544 The time ranges hint text shows the total time range. Relative time ranges can also be entered in
23742545 ms, us or ns. Also, negative values are relative to the end of trace. Examples:
23752546 <pre>
@@ -2380,7 +2551,7 @@ ms, us or ns. Also, negative values are relative to the end of trace. Examples: · 4 unmodified lines
23802551 -10ms- The last 10ms
23812552 </pre>
23822553 N.B. Due to the granularity of timestamps, there could be no branches in any given time range.
2383−<h2 id=topcallsbyelapsedtime>1.4 Top calls by elapsed time</h2>
2554+<h2 id=topcallsbyelapsedtime>1.5 Top calls by elapsed time</h2>
23842555 The Top calls by elapsed time report displays calls in descending order of time elapsed between when the function was called and when it returned.
23852556 The data is reduced by various selection criteria. A dialog box displays available criteria which are AND'ed together.
23862557 If not all data is fetched, a Fetch bar is provided. Ctrl-F displays a Find bar.
@@ -2516,6 +2687,9 @@ class MainWindow(QMainWindow): · 129 unmodified lines
25162687 if IsSelectable(glb.db, "calls"):
25172688 reports_menu.addAction(CreateAction("Context-Sensitive Call &Graph", "Create a new window containing a context-sensitive call graph", self.NewCallGraph, self))
25182689
2690+ if IsSelectable(glb.db, "calls", "WHERE parent_id >= 0"):
2691+ reports_menu.addAction(CreateAction("Call &Tree", "Create a new window containing a call tree", self.NewCallTree, self))
2692+
25192693 self.EventMenu(GetEventList(glb.db), reports_menu)
25202694
25212695 if IsSelectable(glb.db, "calls"):
@@ -2576,6 +2750,9 @@ class MainWindow(QMainWindow): · 54 unmodified lines
25762750 def NewCallGraph(self):
25772751 CallGraphWindow(self.glb, self)
25782752
2753+ def NewCallTree(self):
2754+ CallTreeWindow(self.glb, self)
2755+
25792756 def NewTopCalls(self):
25802757 dialog = TopCallsDialog(self.glb, self)
25812758 ret = dialog.exec_()