How can I visualize program traces with TikZ?

Question

To analyze multi-threaded program behaviour, I generate traces of code execution. Now, the chrome browser allows me to visualize it in a nice way:

I'd like to include a visualization like these in my TeX documents. My question is thus: is there something similar available with TikZ or pgfplots that I missed so far?

Answer 1

Here is a solution using LuaLaTeX.

First of all, a preprocessing has to be done to your JSON data, because the field tid contains integers too large for lua, which are then stored as floating point numbers, with an internal rounding which makes impossible to reconstruct the original integer.

I think that those field (tid) should be stored indeed as a JSON string. You can change your python script which generates the JSON and store it as string. Probably the Chrome visualizer will still work. Meanwhile, I processed your data with the following python script:

import json
import sys
if len(sys.argv)<3:
    print "Usage: %s input.json output.json" % sys.argv[0]
    sys.exit()
_in = open(sys.argv[1])
data = json.loads(_in.read())
_in.close()
for t in data["traceEvents"]:
    t["tid"] = str(t["tid"])
_out = open(sys.argv[2], "w")
_out.write(json.dumps(data))
_out.close()

Using this script and the example JSON you provided I produced the following JSON as input for my experiment (saved as trace.json):

{"traceEvents": [{"name": "foo", "pid": 11403, "ts": 463.9625549316406, "cat": "f", "tid": "140094068987648", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 24585.962295532227, "cat": "f", "tid": "140094060594944", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 32024.860382080078, "cat": "f", "tid": "140093981456128", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 45877.933502197266, "cat": "f", "tid": "140093973063424", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 70307.01637268066, "cat": "f", "tid": "140093964670720", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 84609.9853515625, "cat": "f", "tid": "140093956278016", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 93953.84788513184, "cat": "f", "tid": "140093947885312", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 94250.91743469238, "cat": "f", "tid": "140093964670720", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 99001.88446044922, "cat": "f", "tid": "140093964670720", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 111577.03399658203, "cat": "f", "tid": "140093939492608", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 126761.91329956055, "cat": "f", "tid": "140093947885312", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 131937.98065185547, "cat": "f", "tid": "140093947885312", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 137961.86447143555, "cat": "f", "tid": "140094068987648", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 146477.93769836426, "cat": "f", "tid": "140094068987648", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 168772.93586730957, "cat": "f", "tid": "140093931099904", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 171284.91401672363, "cat": "f", "tid": "140093947885312", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 190065.86074829102, "cat": "f", "tid": "140093947885312", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 200531.9595336914, "cat": "f", "tid": "140093377476352", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 203018.9037322998, "cat": "f", "tid": "140093939492608", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 205718.0404663086, "cat": "f", "tid": "140093956278016", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 224355.93605041504, "cat": "f", "tid": "140093956278016", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 239644.05059814453, "cat": "f", "tid": "140093931099904", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 244351.86386108398, "cat": "f", "tid": "140093973063424", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 246371.03080749512, "cat": "f", "tid": "140093973063424", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 248718.9769744873, "cat": "f", "tid": "140093931099904", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 250808.9542388916, "cat": "f", "tid": "140094060594944", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 261550.9033203125, "cat": "f", "tid": "140093964670720", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 271960.973739624, "cat": "f", "tid": "140093964670720", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 277998.9242553711, "cat": "f", "tid": "140093981456128", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 285593.98651123047, "cat": "f", "tid": "140093981456128", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 295259.952545166, "cat": "f", "tid": "140094060594944", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 296828.9852142334, "cat": "f", "tid": "140093939492608", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 309973.00148010254, "cat": "f", "tid": "140093973063424", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 310663.93852233887, "cat": "f", "tid": "140093377476352", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 314920.90225219727, "cat": "f", "tid": "140093377476352", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 328592.06199645996, "cat": "f", "tid": "140093973063424", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 330901.8611907959, "cat": "f", "tid": "140094068987648", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 342347.8603363037, "cat": "f", "tid": "140093377476352", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 353376.8653869629, "cat": "f", "tid": "140093377476352", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 374196.05255126953, "cat": "f", "tid": "140093973063424", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 376448.8697052002, "cat": "f", "tid": "140093973063424", "ph": "B"}, {"name": "foo", "pid": 11403, "ts": 414726.97257995605, "cat": "f", "tid": "140093973063424", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 421860.933303833, "cat": "f", "tid": "140093964670720", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 422044.9924468994, "cat": "f", "tid": "140094060594944", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 422374.01008605957, "cat": "f", "tid": "140093947885312", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 425405.97915649414, "cat": "f", "tid": "140093956278016", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 452973.8426208496, "cat": "f", "tid": "140093377476352", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 466531.99195861816, "cat": "f", "tid": "140093939492608", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 478200.91247558594, "cat": "f", "tid": "140093981456128", "ph": "E"}, {"name": "foo", "pid": 11403, "ts": 487442.9702758789, "cat": "f", "tid": "140093931099904", "ph": "E"}]}

The structure of this JSON is an array of events, and for each event the following fields are stored (I give a short description of how I interpreted them and used in the diagram):

• name: It is the name (of the process?) to be shown in each bar of the diagram
• tid: It is the thread identifier, to be shown at the left of the diagram. There is one row in the diagram per tid. Those have to be strings, as said above
• pid: It is the PID (of the process to which the thread belongs, I assume). This info is not used in the diagram. It is 11403 for all the events in this example.
• cat: Some kind of "category", not shown in the diagram. It is f for all the events in this example.
• ts: it is a timestamp relative to some unknown time origin. Those timestamps have to be scaled down (divided by 100) to accomodate them to units manageable y tex/tikz. The luatex code takes care of this.
• ph: It contains a single letter "B" or "E", which I assume means "Begin" or "End", and thus indicates if the current event is the beginning or the ending of a thread execution. My code draws solid rectangles between one "B" and next "E" events for the same tid.

Indeed, in my code I do not check if the "B" and "E" events are properly sequenced. I assume that the first event of a thread is always of type "B", and after a "B" event, the next event for the same thread is always of type "E". It looks a reasonable assumption, and it holds for the example data.

Now to the code.

Main tex file (test.tex)

\documentclass{article}
\usepackage[margin=1cm]{geometry}
\usepackage{tikz}
\usepackage{traces}  % <-- See later
\usetikzlibrary{calc}

\begin{document}
\tikzset{
  tid/.style = {    % Style for the column of "tid" at the left of the diagram
     anchor=south west, 
     fill=blue!10, 
     text width=3cm, 
     minimum height=6mm,
  },
  trace/.style = {  % Style for each "bar" in the diagram
     draw=blue!50!black!40, 
     fill=cyan!70!black!60,
  },
  label name/.style = {  % Style for the name appearing in each bar
     font=\small\sffamily,
  },
}

\begin{tikzpicture}[x=0.03mm, y=6mm]  % Note the scale, it is important!
   \plotTraceFromJSON{trace.json}     % The name of the file containing the trace
   % That's all!
\end{tikzpicture}
\end{document}

The result

After processing with lualatex test.tex the resulting pdf is:

This result can be further embellished using tikz, since the command \plotTraceFromJson not only drawn the diagram, but also defined some node names which can be used as reference to add grids or annotations. See more at the end.

The latex style file (traces.sty)

This is very minimalistic. It only loads the lua code, and defines a latex command to invoke it:

% This is file traces.sty
\directlua{dofile("luatrace.lua")}
\newcommand{\plotTraceFromJSON}[1]{
  \directlua{plotDiagram("#1")}
}

The lua code (luatrace.lua)

Finally, the lua code reads the JSON, parses it to internal lua variables, processes it in order to group all the events pertaining to the same tid in a ordered array of pairs (begin, end) of executions, and uses the processed data to generate a series of tikz commands which draw the above graph.

This code requires another library called JSON.lua, which can be downloaded here. The complete file is only 29K, so I wonder if I could paste it here, just in case the provided link dies in the future...

-- This is file luatrace.lua
JSON = dofile("JSON.lua")  -- This is required, see above

local function parseJson(file)
    local f = assert(io.open(file, "r"))
    local json_txt = f:read("*all")
    f:close()
    local v= JSON:decode(json_txt)
    return (v.traceEvents)
end

local function process(data)
    local threads = {}
    for i = 1,#data do
        tid = data[i].tid
        if (threads[tid]==nil) then
            -- Create new
            threads[tid] = {name   = data[i].name,
                            pid      = data[i].pid,
                            events = {} }
        end
        table.insert(threads[tid].events, {data[i].ts,data[i].ph})
    end
    return(threads)
end

function plotDiagram(file)
    local v = parseJson(file)
    local t = process(v)

    -- Ensure ordering of the tid
    local aux = {}
    for tid,v in pairs(t) do table.insert(aux,tid) end
    table.sort(aux)

    local y = 0
    local counter = 0
    for i,tid in ipairs(aux) do
        v = t[tid]
        tex.print(string.format("\\node[tid] at (0, %f) (tid%s) {%s};",y, counter, tid))
        tex.print(string.format("\\fill[trace]  (tid%s.south east) ++(0, 0) ",counter))
        y = y-1
        counter = counter + 1
        for j = 1, #v.events-1, 2 do
            start = v.events[j][2]
            ending = v.events[j+1][3]
            tex.print(string.format(" +(%f, 0) rectangle +(%f,0.8) node[label name, midway] {%s} ", start/100, ending/100, v.name ))
        end
        tex.print(";")
    end
end

Further embellishments

After the diagram is produced, some node names are available, named tid0, tid1, etc.. Those are the nodes which contain the tid of each thread, and thus can be used as references to draw horizontal lines in a grid.

Also, vertical lines can be drawn using the same time units than the diagram (but remembering that lua scaled all of them to 1/100).

The following code shows an example of this kind of post-processing:

\documentclass{article}
\usepackage{tikz}
\usepackage{traces}
\usetikzlibrary{calc}
\usepackage[margin=1cm]{geometry}

\pgfdeclarelayer{background}
\pgfsetlayers{background,main}

\begin{document}
\tikzset{
  tid/.style = {
     anchor=south west, 
     fill=blue!10, 
     text width=3cm, 
     minimum height=6mm,
     font=\ttfamily
  },
  trace/.style = {
     draw=blue!50!black!40, 
     fill=cyan!70!black!60,
  },
  label name/.style = {
     font=\small\sffamily,
  },
}
\begin{tikzpicture}[x=0.03mm, y=6mm]
% Plot the diagram

\plotTraceFromJSON{trace.json}

% Add background grid or other embellishments
\coordinate (right border) at (current bounding box.east);
\coordinate (left border) at (tid0.east);
\coordinate (bottom border) at (current bounding box.south);
\coordinate (top border) at (current bounding box.north);
\begin{pgfonlayer}{background}
\foreach \y in {0,2,...,9} {
    \fill[black!10] (tid\y.south-|left border) rectangle ($(tid\y.south-|right border)+(0,0.8)$);
}
\foreach \x in {1, 2, ..., 4} {
    \draw[black!60] ($(bottom border-|left border)+(1000*\x,-0.3)$) -- ($(top border-|left border) +(1000*\x,0.3)$) node[above] {0.\x s};
    \draw[black!20] ($(bottom border-|left border)+(1000*\x+500,-0.3)$) -- ($(top border-|left border) +(1000*\x+500,0.3)$);
}
\end{pgfonlayer}

\end{tikzpicture}
\end{document}

And this is the result: