Chomping at Chandler

I contributed to the Chandler migration testing we were doing today and ran across a happy surprise. The idea of the exercise was to migrate data from Chandler 0.6alpha4 to the latest checkpoint build. In the course of this, I exported my calendars both as .ics files and via sharing on the server.

When I loaded up the latest chandler, I first connected to the server and made sure I could see all my calendars, which I could, and then I imported one of the .ics files. Lo and behold, it noticed that I already had the same items from the server and merged the items as they were read in. I ended up not with two copies of every item, but instead, each item was referenced by two calendars. (I had renamed the calendar before importing the .ics file to see if it would create a collection with the same name - and it did).

I was quite pleased at this bit of smarts, as you can tell!

This was sent to the chandler-dev list and I wanted to have a nicely-formatter version handy.

---

Profiling Chandler is tricky because there are lots of moving parts. Here are a few tips and tricks that come to mind:

1. To compare numbers, always use the same data. Recreating your repository everytime changes the data in subtle ways because you get new UUIDs everytime and the order of things, random in mappings, is conditioned by the hash of their keys, very often UUIDs. Instead, load and prepare your data, backup the repository and always restore it when re-running the testcase.

   rc -r ~/Desktop/__repository__.001 (or whatever your path may be)

2. Preload all items, that way the vaguaries of item loading are out of the way, unless that’s what you’re interested in. Running check() loads all items into the UI view.

   rc -r ~/Desktop/__repository__.001 --undo check

   –undo check runs check() and undoes bogus versions until check() passes at startup time. If check() passes right away, as I’d expect from a clean restore, –undo will undo nothing and you will have started your chandler will all items pre-loaded.

3. The -P flag using the perf tests produces profiles that crash hotshot (at least, for me, on my Mac). Also, with -P you cannot be sure how much of the perf test cruft you’re profiling along with it. Know what you’re measuring, and add the profiling hook yourself.

   Find the block of code or call you’re interested in and wrap it with a prof.runcall() call, creating a local function for the block of code if need be. For example, to profile import, I just change ImportExport.py around line 267 as follows:

   import hotshot
prof = hotshot.Profile(’import.log’)
collection = prof.runcall(importICalendarFile, fullpath,
        self.view, coll, filterAttributes, activity, None, logger)
prof.close()

   Then process the resulting import.log file with the hotshot APIs as is done, for example, in my t82.py file included below. Really, how to process the hotshot output is up to you, whatever works best for the kind of output you’re looking for. t82.py, when run the first time on a .log file, produces a .stats file from it which is vastly faster to reload. This is can be a huge timesaver when profiling things like a large import, for example.
4. Remove commit() calls. Currently, our code includes commits() in less than ideal places and this has the effect of slowing things down considerably. commit() is an expensive operation that we’d like to do *between* user actions instead of *during* user actions. Measuring it during a user action is pointless unless it is critical to the action.

   For example, the criticality of calling commit() at the end of CalendarCanvas.CreateEmptyEvent() is dubious. John has offered to review all such commit calls and remove them if possible, leaving it to the user event that started the action to do the commit, if needed.

5. Instead of only looking at the amount of time spent doing things, consider how many times they’re done. Currently, I sense that there are a lot of perf gains to be made in the app by doing things less instead of faster. Why are we loading 41 images when creating an event in the calendar, for example ? This leads to the next point.
6. The app loads things lazily. Items are loaded lazily. Images are loaded lazily. If you see 41 images loaded, the next thing is to profile creating a second event instead. Indeed, the calendar doesn’t load 41 images the second time. Run the action multiple times so that all the init cases are out of the way. But, we’re still calling MenusAndToolbars.appendDynamicBlocks 336 times nonetheless… something to look into there even if we’re only spending 0.007s there, the fact it’s called that often may lead you onto something where significant time is spent overall.
7. When communicating about profiles, don’t send the .log files around, they can be huge. Use a .stats file instead. As said before, the t82.py file below creates a .stats file from a .log file whenever it is invoked with a .log file. Don’t send a text version out either, the .stats file can be opened with hotshot APIs and queried in various ways to look for callers, callees, different sort orders, etc, etc. The Stats class has several interesting APIs to poke around a .stats file: docs.python.org/lib/profile-stats.html

That’s all I can think of for now. See my t82.py script below.

Andi..

---

import os
import hotshot, hotshot.stats, pstats

def cum(stats, length=50):
    stats.sort_stats('cum')
    stats.print_stats(length)

def calls(stats, length=50):
    stats.sort_stats('time', 'calls')
    stats.print_stats(length)

def show(file, call='cum', length=50):
    if file.endswith('stats'):
        stats = pstats.Stats(file)
    else:
        stats = hotshot.stats.load(file)
        stats.strip_dirs()
        stats.dump_stats('.'.join((os.path.splitext(file)[0], 'stats')))
    if call == 'cum':
        cum(stats, int(length))
    elif call == 'tot':
        calls(stats, int(length))
    else:
        stats.sort_stats(call)
        stats.print_stats(int(length))

    return stats

if __name__ == "__main__":
    from sys import argv
    show(*argv[1:])

i’m failing two functional tests:

TestTriageSectioning crashes on quit
TestRemoveFromTrashOnImport fails with this report:
  SUITE ChandlerFunctionalTestSuite FAILED
    TEST TestRemoveFromTrashOnImport failed
      ACTION Check_ItemInCollection (On collection search)
        REPORT (On collection search)

Now to check the unit tests…

After I complained about problems with gdb in IRC, Andi told me that a recent Apple update to the OS has caused gdb to break, and that the workaround is to symlink the required libraries in some dyld-searched place, like /usr/local/lib, which is where i’ve been putting my symlinks.

The only external mention I can see via google is in a Macintouch post about Security Update 2006-004 (search for “gdb” - there is only one posting that mentions it). But the error reported is exactly the same kind as I am seeing.

All fine and good while I was working on Chandler alpha 3 code, but now I can’t get even useful dyld errors when I try to run straight Chandler trunk:

dyld: Library not loaded: /Users/builder/tinderbuild/external/debug/Library/Frameworks/Python.framework/Versions/2.4/Python
  Referenced from: /Users/rae/work/osaf/chandler/chandler/debug/Library/Frameworks/Python.framework/Versions/2.4/Resources/Python.app/Contents/MacOS/Python
  Reason: no suitable image found. Did find:
/Users/rae/lib/Python: not a file


Program received signal SIGTRAP, Trace/breakpoint trap.
0×8fe061c4 in __dyld__ZN4dyld5_mainEPK11mach_headeriPPKcS5_S5_ ()
(gdb)

Without a list of missing libraries, it’s hard to stick in the symlinks.

Hm, now that I think about it, perhaps new symbols are showing up in the libraries I symlinked already, since they were symlinked to the alpha 3 libs. Those libraries aren’t really supposed to change at all, … but hey, maybe they did? When I first did the symlinking, I thought I would have to write a tool that would swap the symlinks amongst the permuations of debug/release and alpha3/trunk, but Andi assured me the libraries were pretty static.

Hm, I will have to check it out.

Well, I’ve turned off spell checking, so no more crashes. However, still no search bar!

The control is created and is getting called on occasion (e.g. to get its size when the window changes size). It’s just not visible.

One thing I had to do to the control before adding it to the toolbar was to remove it from its superview. When the control was created its “Window” was set to be the Chandler window. However, the toolbar API doc specifically says that the control should be created with a NULL Window parent. I thought the best I could do (since I have no control over how the control is created) was to call HIViewRemoveFromSuperview() on it. From the debugger, I could tell it certainly set the control’s window to NULL, so I think it’s the right thing to do.

However, whenever I do a dump of the control, I now see that its “Visible” value is always “no”. And indeed, it is not shown at all. I’ve added code to explicitly make the control visible, but it makes no difference.

So tomorrow I’m going to look into trying things like putting another (non-text) control in the toolbar and see if it’s another text-field-specific thing. I’ll just put a button in or something.

*sigh

I seem to have all the code working correctly, but Chandler crashes on startup.

You can see the stack traces here in both C++ and Python. It’s weird, as if it’s failing when it tries to start up a Cocoa runtime environment. Very frustrating too, because it’s the last thing that stands in the way of the search bar on Mac OS. :-/

I “filled in” the code for embedding any arbitrary control in a toolbar on the Mac. It’s a little tricky, because I was unable to pass the toolbar item down through the code as user data or a refcon or what have you. So instead, I use a static fifo (a C++ queue) to make the pointer available at the lowest level.

It’s a little frustrating becuase it *looks* like you can pass arbitrary data all the way down, however the OS seems to parse the data because it crashes if I try to do it. It may be that I need to wrap the pointer in a CFDataRef or something. But for now the static fifo is doing the job just fine.

Given /Applications/Chandler0.7.app:

cd /Applications/Chandler0.7.app/Contents/Resources/Library/Frameworks/Python.framework/Versions
sudo rm -rf Current
ln -s 2.4 Current

That’s it.

In all Mac frameworks, “Current” is a symlink to the actual directory.

I am hoping there are other space savers to find. My first attempt at using symlinks for multiple dylib’s with the same size failed.

Ah well.

When I committed my new Markup Bar code yesterday, I had to disable any functional tests that interacted with the Markup Bar, since the whole way it works is different now. What follows is something of a rambling that is intended to help me keep things straight about who inherits from whom, and why.

Before, The Markup Bar used wx.Toolbar and its attendant wx.ToolbarItems, but now it’s a simple ControlBlocks.ContentItemDetail, which is a ContainerBlocks.BoxContainer, which is a Block.RectangularChild.

On the wx side, ContainerBlocks.BoxContainer uses a ContainerBlocks.wxBoxContainer, which is a Block.wxRectangularChild with extra logic for handling foreground colours and layout. Hm, maybe one of my problems with the buttons is that they don’t inherit from this class? Food for thought..

Now Block.wxRectangularChild is just a wx.Panel, so it doesn’t have all the methods that wx.Toolbar does for pressing buttons and such. I have to somehow search through the child blocks of the Markup Bar and find them by name. Then I have to send them events that make them think they are being pressed.

I played around in PyCrust inside Chandler last night for a while, trying to manually do this with App_ns.markupbar, but it seems to be a BlockProxy and has no children through whom I could search at all. I suspect this is the nature of its “proxy”ness, so I will have to talk to John about how exactly BlockProxy’s work.

I think once I have a handle on the children of the Markup Bar i will be able to send them the required event to press themselves, and the functional tests willbe restored to their full good health.

One thing I am wondering about though, is how the performance tests are faring? I think they manipulate the Markup Bar as well, but I didn’t see any red in the tinderbox last night. Perhaps they are not run automatically? I should ask Bear, but maybe he will just answer here in a comment.

If you are a Mac and you are feeling adventurous, you can download Chandler_osx_0.7alpha2.dev-r10378-rae.dmg [56.2 MB], which is a build I did with my changes. I haven’t checked it in because I want to check for sure to see if it has had a negative impact on Chandler’s speed. It feels like it has.

Also, it doesn’t quite work correctly. :-/

Feel free to download it and try it out. Let me know what your experiences with it are like. Well, aside from the crashes I described in my last posting, of course.

I published the dmg file on my DreamHost account, so downloads should be quite zippy. Feel free to leave comments about the speed, as I’m curious bout how zippy it is in fact.

I now have the new markup bar buttons up and rendering correctly, complete with rollover. However, when I click on any of the buttons, the app crashes. It looks like the wxPython class wx.lib.buttons.GenBitmapButton cannot handle “self”’s C++ class being deleted in the middle of OnLeftUp().

Here are some pictures (you can also just view the Flickr set):

My very first successful rendering of buttons.

Up until this point I was having a lot of problems with Python’s handling of __init() methods and their parameters. Specifically, keyword parameters vs positional ones vs default-value parameters (are they keywords? Are they positional? I think the answer to both questions is “yes”!).

As you can see, the buttons are way too big. But still, I wanted to try a rollover to see if it worked…

Rollover works!

.. and it id! Nice.

I fixed the size problem and also the read-only icon to be the right bitmap, and got this:

Now that looks more like it!

Note the button background is all white. That might be a symptom of using ContainerBlocks.BoxContainer as the parent block for the buttons.

I had to try rolling over the buttons (I already knew clicking would cause a crash), so here are the other buttons rolled over one-by-one..

rolling over contact

rolling over task

rolling over event

rolling over private

So what happens when you click? First all the buttons disappear, which I assume is a normal part of switching how things look:

What happens when you click Then the app crashes with this stack trace:

Traceback (most recent call last):
  File “/Users/rae/work/osaf/chandler/chandler/release/Library/Frameworks/Python.framework/Versions/2.4/lib/python2.4/site-packages/wx/lib/buttons.py”, line 315, in OnLeftUp
      self.Refresh()
File “/Users/rae/work/osaf/chandler/chandler/release/Library/Frameworks/Python.framework/Versions/2.4/lib/python2.4/site-packages/wx/_core.py”, line 12815, in __getattr__
      raise PyDeadObjectError(self.attrStr % self._name)
wx._core.PyDeadObjectError: The C++ part of the wxChandlerMultiStateButton object has been deleted, attribute access no longer allowed.
release/RunChandler: line 13: 1838 Bus error $CHANDLERBIN/release/RunPython -O $CHANDLERHOME/Chandler.py “$@”

The code in buttons.py”, line 315 looks like this:

   def OnLeftUp(self, event):
       if not self.IsEnabled() or not self.HasCapture():
           return
       if self.HasCapture():
           self.ReleaseMouse()
           # if the button was down when the mouse was released…
           if not self.up:
               self.Notify()
           self.up = True
           self.Refresh()
           event.Skip()

the crash happens in the second-last line. The C++ button is gone, so it cannot refresh.

So.. on with the show!