7

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?

11
  • 1
    Could you please elaborate on how do you do such tracing plots in Chrome/Chromium? They are awesome.
    – juliohm
    May 12, 2014 at 9:33
  • 2
    You basically generate your traces and dump them in a specific JSON format. I wrote a bit about that here.
    – matthias
    May 12, 2014 at 10:16
  • 2
    Since you already have some python coding experience, I think the easiest way would be to write a python script which loads your JSON file and outputs tikz commands to draw the result. If you want a more specific answer, you can provide a sample JSON file and some hints about the expected output
    – JLDiaz
    May 31, 2014 at 14:38
  • I thought about that too. However, this means I would need to recreate all the nice things pgfplots provides: axes, grids, ticks etc.
    – matthias
    May 31, 2014 at 15:21
  • 1
    If you know it, could you please decode ts (timestamp)? In your file the last entry is "ts": 487442.9702758789. Even if it contains milliseconds, where is the beginning and duration or the ending of the process? If it is a time difference multiplied by 1000*1000 (according to your website), how we can get the beginning of the process? It must be stored in tid then (?).
    – Malipivo
    Jun 3, 2014 at 20:10

1 Answer 1

9
+50

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:

Result

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:

Final

1
  • 3
    I just wanted to say WOW.
    – Bordaigorl
    Jun 4, 2014 at 17:31

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.