diff --git a/scripts/graph_tracer.py b/scripts/graph_tracer.py
index ba6b62389c..c5fcd7ae29 100644
--- a/scripts/graph_tracer.py
+++ b/scripts/graph_tracer.py
@@ -1,5 +1,16 @@
import fileinput
import pydot
+import sys
+import itertools
+import json
+
+
+def pairwise(iterable):
+ "s -> (s0,s1), (s1,s2), (s2, s3), ..."
+ a, b = itertools.tee(iterable)
+ next(b, None)
+ return itertools.izip(a, b)
+
nodes = {}
edges = set()
@@ -7,38 +18,51 @@ edges = set()
graph = pydot.Dot(graph_name="call_graph", graph_type="digraph")
names = {}
-times = {}
-deferreds = {}
+starts = {}
+ends = {}
+deferreds = set()
+deferreds_map = {}
deferred_edges = set()
root_id = None
for line in fileinput.input():
+ line = line.strip()
try:
if " calls " in line:
start, end = line.split(" calls ")
start, end = start.strip(), end.strip()
edges.add((start, end))
- print start, end
+ # print start, end
if " named " in line:
node_id, name = line.split(" named ")
names[node_id.strip()] = name.strip()
- if name.strip() == "Deferred synapse.rest.client.v1.room.RoomSendEventRestServlet.on_PUT":
+ if name.strip() == "synapse.rest.client.v1.room.RoomSendEventRestServlet.on_PUT":
root_id = node_id
if " in " in line:
node_id, d = line.split(" in ")
- deferreds[node_id.strip()] = d.strip()
- if " time " in line:
- node_id, ms = line.split(" time ")
- times[node_id.strip()] = int(ms.strip())
+ deferreds_map[node_id.strip()] = d.strip()
+ if " is deferred" in line:
+ node_id, _ = line.split(" is deferred")
+ deferreds.add(node_id)
+ if " start " in line:
+ node_id, ms = line.split(" start ")
+ starts[node_id.strip()] = int(ms.strip())
+ if " end " in line:
+ node_id, ms = line.split(" end ")
+ ends[node_id.strip()] = int(ms.strip())
if " waits on " in line:
start, end = line.split(" waits on ")
start, end = start.strip(), end.strip()
deferred_edges.add((start, end))
- print start, end
+ # print start, end
except Exception as e:
- print "failed %s to parse '%s'" % (e.message, line)
+ sys.stderr.write("failed %s to parse '%s'\n" % (e.message, line))
+
+if not root_id:
+ sys.stderr.write("Could not find root")
+ sys.exit(1)
# deferreds_root = set(deferreds.values())
@@ -59,8 +83,8 @@ for line in fileinput.input():
# tree = deferred_tree.setdefault(d, {})
# populate(d, tree)
-print deferred_edges
-print root_id
+# print deferred_edges
+# print root_id
def is_in_deferred(d):
while True:
@@ -74,16 +98,77 @@ def is_in_deferred(d):
else:
return False
+
+def walk_graph(d):
+ res = [d]
+ while d != root_id:
+ for start, end in edges:
+ if d == end:
+ d = start
+ res.append(d)
+ break
+ else:
+ return res
+ return res
+
+
+def make_tree_el(node_id):
+ return {
+ "id": node_id,
+ "name": names[node_id],
+ "children": [],
+ "start": starts[node_id],
+ "end": ends[node_id],
+ "size": ends[node_id] - starts[node_id],
+ }
+
+tree = make_tree_el(root_id)
+
+tree_index = {
+ root_id: tree,
+}
+
+
+viz_out = {
+ "nodes": [],
+ "edges": [],
+}
+
for node_id, name in names.items():
# if times.get(node_id, 100) < 5:
# continue
+ walk = walk_graph(node_id)
+ # print walk
+ if root_id not in walk:
+ continue
+
if node_id in deferreds:
- if not is_in_deferred(deferreds[node_id]):
- continue
- else:
if not is_in_deferred(node_id):
continue
+ elif node_id in deferreds_map:
+ if not is_in_deferred(deferreds_map[node_id]):
+ continue
+
+ walk_names = [
+ names[w].split("synapse.", 1)[1] for w in walk
+ ]
+
+ for child, parent in reversed(list(pairwise(walk))):
+ if parent in tree_index and child not in tree_index:
+ el = make_tree_el(child)
+ tree_index[parent]["children"].append(el)
+ tree_index[child] = el
+
+ # print "-".join(reversed(["end"] + walk_names)) + ", " + str(ends[node_id] - starts[node_id])
+ # print "%d,%s,%s,%s" % (len(walk), walk_names[0], starts[node_id], ends[node_id])
+
+ viz_out["nodes"].append({
+ "id": node_id,
+ "label": names[node_id].split("synapse.", 1)[1],
+ "value": ends[node_id] - starts[node_id],
+ "level": len(walk),
+ })
node = pydot.Node(node_id, label=name)
@@ -98,18 +183,30 @@ for node_id, name in names.items():
# print node_id
+# for el in tree_index.values():
+# el["children"].sort(key=lambda e: e["start"])
+#
+# print json.dumps(tree)
+
for parent, child in edges:
if child not in nodes:
- print child, "not a node"
+ # sys.stderr.write(child + " not a node\n")
continue
if parent not in nodes:
- print parent, "not a node"
+ # sys.stderr.write(parent + " not a node\n")
continue
+ viz_out["edges"].append({
+ "from": parent,
+ "to": child,
+ "value": ends[child] - starts[child],
+ })
+
edge = pydot.Edge(nodes[parent], nodes[child])
graph.add_edge(edge)
+print json.dumps(viz_out)
file_prefix = "call_graph_out"
graph.write('%s.dot' % file_prefix, format='raw', prog='dot')
diff --git a/synapse/util/traceutil.py b/synapse/util/traceutil.py
index e313912801..1aca33298e 100644
--- a/synapse/util/traceutil.py
+++ b/synapse/util/traceutil.py
@@ -29,6 +29,7 @@ class Tracer(object):
self.next_id = 1
+ self.deferred_frames = {}
self.deferred_to_current_frames = {}
def process(self, frame, event, arg):
@@ -44,11 +45,16 @@ class Tracer(object):
trace_id = self.get_next_id()
deferred.syn_trace_defer_id = trace_id
logger.info(
- "%s named Deferred %s",
+ "%s named %s",
trace_id,
self.get_name_for_frame(generator.gi_frame)
)
+ logger.info(
+ "%s is deferred",
+ trace_id,
+ )
+
logger.info("%s start %d", trace_id, int(time.time() * 1000))
def do(res):
|
