add misc/dump-timing.py too, to visualize the timeline

.gitignore

@@ -56,3 +56,4 @@ docs/_build/
 target/
 /twistd.pid
 /relay.sqlite
+/misc/node_modules/

misc/dump-timing.py

@@ -0,0 +1,95 @@
+# To use the web() option, you should do:
+# * cd misc
+# * npm install vis zepto
+
+from __future__ import print_function
+import os, sys, time, json
+
+
+streams = sys.argv[1:]
+num_streams = len(streams)
+labels = dict([(num, " "*num + "[%d]" % (num+1) + " "*(num_streams-1-num))
+               for num in range(num_streams)])
+timeline = []
+groups_out = []
+for which,fn in enumerate(streams):
+    with open(fn, "rb") as f:
+        for (start, finish, what, start_d, finish_d) in json.load(f):
+            timeline.append( (start, finish, which, what, start_d, finish_d) )
+    print("%s is %s" % (labels[which], fn))
+    groups_out.append({"id": which, "content": fn,
+                       "className": "group-%d" % which})
+
+
+timeline.sort(key=lambda row: row[0])
+first = timeline[0][0]
+print("started at %s" % time.ctime(start))
+viz_out = []
+for num, (start, finish, which, what, start_d, finish_d) in enumerate(timeline):
+    delta = start - first
+    delta_s = "%.6f" % delta
+    start_d_str = ", ".join(["%s=%s" % (name, start_d[name])
+                             for name in sorted(start_d)])
+    finish_d_str = ", ".join(["%s=%s" % (name, finish_d[name])
+                              for name in sorted(finish_d)])
+    details_str = start_d_str
+    if finish_d_str:
+        details_str += "/" + finish_d_str
+    finish_str = ""
+    if finish is not None:
+        finish_str = " +%.6f" % (finish - start)
+    print("%9s: %s %s %s%s" % (delta_s, labels[which], what, details_str,
+                               finish_str))
+    viz_start = start*1000
+    viz_end = None if finish is None else finish*1000
+    viz_type = "range" if finish else "point"
+    if what == "wormhole started" or what == "wormhole":
+        viz_type = "background"
+    viz_content = '<span title="%s">%s</span>' % (details_str or "(No details)",
+                                                  what) # sigh
+    viz_className = "item-group-%d" % which
+    if "waiting" in start_d:
+        viz_className += " wait-%s" % start_d["waiting"]
+    viz_out.append({"id": num, "start": viz_start, "end": viz_end,
+                    "group": which, "content": viz_content,
+                    "className": viz_className, # or style:
+                    "type": viz_type,
+                    })
+
+here = os.path.dirname(__file__)
+web_root = os.path.join(here, "web")
+vis_root = os.path.join(here, "node_modules", "vis", "dist")
+zepto_root = os.path.join(here, "node_modules", "zepto")
+if not os.path.isdir(vis_root) or not os.path.isdir(zepto_root):
+    print("Cannot find 'vis' and 'zepto' in misc/node_modules/")
+    print("Please run 'npm install vis zepto' from the misc/ directory.")
+    sys.exit(1)
+
+def web():
+    # set up a server that serves web/ at the root, plus a /data.json built
+    # from {timeline}. Quit when it fetches /done .
+    from twisted.web import resource, static, server
+    from twisted.internet import reactor, endpoints
+    ep = endpoints.serverFromString(reactor, "tcp:8066:interface=127.0.0.1")
+    root = static.File(web_root)
+    data_json = {"items": viz_out, "groups": groups_out}
+    data = json.dumps(data_json).encode("utf-8")
+    root.putChild("data.json", static.Data(data, "application/json"))
+    root.putChild("vis", static.File(vis_root))
+    root.putChild("zepto", static.File(zepto_root))
+    class Shutdown(resource.Resource):
+        def render_GET(self, request):
+            print("timeline ready, server shutting down")
+            reactor.stop()
+            return "shutting down"
+    root.putChild("done", Shutdown())
+    site = server.Site(root)
+    ep.listen(site)
+    import webbrowser
+    def launch_browser():
+        webbrowser.open("http://localhost:%d/timeline.html" % 8066)
+        print("browser opened, waiting for shutdown")
+    reactor.callLater(0, launch_browser)
+    reactor.run()
+web()
+

misc/web/timeline.css

@@ -0,0 +1,20 @@
+
+div.item-group-0 {
+    background-color: #fcc;
+}
+
+div.item-group-1 {
+    background-color: #cfc;
+}
+
+div.item-group-2 {
+    background-color: #ccf;
+}
+
+div.wait-user {
+    background-color: #ccc;
+}
+
+.vis-item .vis-item-overflow {
+    overflow: visible;
+}

misc/web/timeline.html

@@ -0,0 +1,21 @@
+<html>
+<head>
+<meta charset="utf-8">
+<title>Timeline Visualizer</title>
+<script src="vis/vis.min.js"></script>
+<script src="zepto/zepto.min.js"></script>
+<link href="vis/vis.min.css" rel="stylesheet" type="text/css" />
+<link href="timeline.css" rel="stylesheet" type="text/css" />
+</head>
+
+<body>
+<h1>Wormhole Timeline</h1>
+
+<div id="viz"></div>
+<br>
+<div id="cursor_date"></div>
+<div id="cursor_time"></div>
+
+<script src="timeline.js"></script>
+
+</body> </html>

misc/web/timeline.js

@@ -0,0 +1,45 @@
+var vis, $; // hush
+
+var container = document.getElementById("viz");
+var options = {editable: false,
+               showCurrentTime: false,
+               snap: null,
+               order: function(a,b) { return a.id - b.id; }
+              };
+var timeline = new vis.Timeline(container, options);
+
+$.getJSON("data.json", function(data) {
+    timeline.setData({groups: new vis.DataSet(data.groups),
+                      items: new vis.DataSet(data.items)});
+    var start = data.items[0].start;
+    var end = data.items[data.items.length-1].start;
+    var span = end - start;
+    timeline.setWindow(start - (span/10), end + (span/10));
+    //timeline.fit(); // doesn't leave space on the ends
+    timeline.setOptions({min: start - (span/10),
+                         max: end + (span/10),
+                         zoomMin: 50,
+                         zoomMax: 1.2*span});
+    var bar = timeline.addCustomTime(start, "cursor");
+    timeline.on("timechange", update_cursor);
+    update_cursor({time: new Date(start)});
+    timeline.on("doubleClick", zoom);
+    $.get("done", function(_) {});
+});
+
+function zoom(properties) {
+    var target = properties.time.valueOf();
+    var w = timeline.getWindow();
+    var span = w.end - w.start;
+    var new_span = span / 2;
+    var new_start = target - new_span/2;
+    var new_end = target + new_span/2;
+    timeline.setWindow(new_start, new_end, {animation: true});
+}
+
+function update_cursor(properties) {
+    var t = properties.time;
+    document.getElementById("cursor_date").innerText = t;
+    var m = vis.moment(t);
+    document.getElementById("cursor_time").innerText = m.format("ss.SSSSSS");
+}