Monthly Archives: September 2007

python-dev mailman archive thread-arc visualizations

Posted on by

What’s new? Mailman archive processing! Bezier segmenting for more accurate arcs (thank you Luc Masonobe)! Pseudo-thread-arcs! (Actual thread arcs as visible on the whoa-awesome-but-why-aren’t-you-released-software ReMail project would seem to more practically squash ridiculously-large arcs and of course leverage the other side.)

python-dev-july-2007-threadarc-assembled.png

  • Node colors are per-author. The middle bottom thread demonstrates the need for a smarter distinct color logic, as I’m pretty confident that thread isn’t the result of one person with multiple personalities.
  • Nodes are sequenced time-wise from left-to-right with uniform (pixel-based) spacing. I tried placing them by time, but things clump up pretty uselessly. Non-linear time scaling is on my list.
  • Arc colors are based on the subject, whereas reconstruction is based on the headers. As such, arc colors in a thread may change if someone changes the subject.
  • Arc width is constant, though I was entertaining varying it based on the amount of new content in each e-mail. Of course, there’s always knobs to tweak.

Please note that the above image is actually the result of re-arranging the contents of two separate images; the layout currently used just stacks them all vertically with a (dynamic) uniform spacing. For this reason, the rightmost threads are actually from a separate run where I set the ‘chaos’ filter with a much higher bar. Oh, and those are threads from the July 2007 python-dev archive, although without labeling you have no reason to believe me.

python-dev-2007-threadarc-chaos200.png

And this is the result of sucking up January-July 2007, filtering on threads with a ‘chaos’ greater than 200. (‘chaos’ being an arbitrary and arguably incorrect term for the total distance of all nodes from their parent (less one). So a thread where every message is just a response to the one that chronologically preceded it will have a chaos of 0. A thread where every message is a response to the message before the one that chronologically preceded it will have a chaos of (n – 2) where n is the number of messages. Apply algebra, rinse, and repeat.

I’m going to try and get this going with Thunderbird reasonably soon, but it might take longer than I’d hope. Thunderbird w/pyxpcom didn’t build clean on my amd64-arch laptop, chronicle-recorder’s valgrind crashes on amd64, and the like means some busywork on the horizon.

A step sideways

Posted on by

This seemed like a better idea in my head:

when others ask why, I clearly am not even listening.

What is it? It’s a variant on the blog visualization below from this post, but using crescent/lune slices instead and with no sustain (aka, if there’s no data point, we don’t draw anything). It self-normalizes so that the maximum value range takes up a full 180 degrees. It does not bother to account for the loss of area when apportioning the slices, though it could. I doubt that would make up for the perceptual issues anyway.

older and maybe better

The good news is that the visualization motivated me to properly abstract the previously inane special-cased implementations for rings/curves to a path-based implementation like reasonable people would expect. (Refactoring still to be done.)

In other news, I’ve changed up the revision control for my chronicle-recorder patches after it became clear my stacked git approach was not going to cleanly allow concurrent development on my new laptop. The new way is a bunch of bzr branches; the ‘rev control’ page link on the left is the authority on what is what.

Chronicle-Recorder Graph/Ring Visualization! Hooray!

Posted on by

Thanks to new and improved time management skills (and a holiday weekend doesn’t hurt), I’ve got a chronicle-recorder visualization going on via chroniquery:

visichron.py trace vfancy -f smain

Above, we have the visualization run against the ‘fancy’ program seen in the previous chroniquery posts (with one caveat, addressed later). What does it mean?

  • The circular nodes are functions in the executed program. In this case, we start from ‘smain’ and pull in all the subroutines that we detect.
  • The edges between nodes indicate that a function call occurred between the two functions sometime during the execution; it could be once, it could be many times. The color of the edge is a slightly more saturated version of the color of the node that performed the call. If they call each other, only one color wins.
  • The rings around the outside of each node indicate when it was called, specifically:
    • The ring starts and stops based on the chronicle-query timestamp. Like on a clock, time starts at due north and flows around clock-wise, with the last smidge of time just before we reach due north again.  This has its ups and downs. The reason we are using ‘smain’ instead of ‘main’ is that when we used the untouched main, the first “new” ended up taking up most of our timestamp space. So I turned main into smain and had a new main that takes the memory allocator start-up cost hit and then calls smain.
    • The thickness of the ring indicates the depth of the call-stack at the time. The thickest ring corresponds to the outermost function, the thinnest ring to the innermost function. This results in a nice nesting effect for recursive functions, even if it’s more of an ‘indirect’ recursion.
    • The color of each ring slice is based on the control flow taken during the function call. (I think this is awesome, hence the bolding.) Now, I’m making it sound fancier than it is; as a hackish first pass, we simply determine the coverage of all the instructions executed during that function call. A more clever implementation might do something when iteration is detected. A better implementation would probably move the analysis into the chronicle-query core where information on the basic blocks under execution should be available. Specific examples you can look at above:
      • print_list: The outermost calls are aqua-green because their boolean arguments are true. The ‘middle’ calls are light green because their boolean arguments are false. The fina, innermost calls are orange-ish because they are the terminal case of the linked-list traversal where we realize we have a NULL pointer and should bail without calling printf. They are also really tiny because no printf means basically no timestamps for the function.
      • nuke: Four calls are made to nuke; the first and third times (light blue) we are asking to remove something that is not there, the second and fourth times (purple) we are asking to remove something that is. I have no idea why the third removal is so tiny; either I have a bug somewhere or using the timestamps is far more foolish than I thought.

Besides the obvious shout-out to chronicle-recorder, pygraphviz and graphviz power the graph layout. Now, a good question would be whether this actually works on something more complex? Could it be? Well, you can probably see the next picture as you’re reading this, so we’ll cut this rhetorical parade short.

visichron.py trace chronicle-query -f load_all_mmapped_objects

Besides the obvious font issues, this actually looks pretty nice. But what does it tell us? Honestly, the full traversal here is excessive. All we care about is the center node, load_all_mmapped_objects, and load_dwarf2_for (due north and a teeny bit east of the center node). If we look at the calls to load_dwarf2_for, we can see that two of them have different control-flow coverages. Those happen to be the times debug symbols could not be found (which is my problem I want to debug). The first one is for ld-2.6.1.so (I’m looking at the textual output of chronisole for the same command), and the second one is for /usr/bin/python2.5. The second one should definitely not fail, because it should find the symbols in /usr/lib/debug, but it does.

Unfortunately, the trail sorta stops cold there with a bug in either chronicle-query or in chroniquery (possibly cribbed from chronomancer). load_dwarf2_for should be calling dwarf2_load, but we don’t see it. I don’t know why, but I haven’t actually looked into it either. Rest assured that a much more awesome graph awaits me in the future!

Because there’s too much text and not enough pictures, I’ll also throw in the output of the ring visualization test which uses a stepped tick-count (1 per function call) to show how things could look if we went with an artificial time base…

ring visualization example

Bzr repositories for both can be found at http://www.visophyte.org/rev_control/bzr/.

Hooray for dwarf location lists!

Posted on by

chronisole-trace-fancy-main-working.png

I resolved the time-stamp issues from last time. Arguments are now happy because we move to the time-stamp corresponding to when the function’s prologue had completed. The booleans were wrong because they were copied to locals during the prologue, which is where the argument list referenced them. Things like this are much easier to diagnose thanks to support of disassembly prints-outs via the diStorm64 disassembler, although I may move to using libdisassemble in the future since it is pure python and presumably provides (or can be more easily coerced to provide) a richer set of info about the disassembly.