Arc Forumnew | comments | leaders | submitlogin
Arc profiler in rainbow: preliminary results
8 points by conanite 5484 days ago | discuss
I wrote this profiler to prove that 'pr was inefficient, but I may have proved nothing at all. Here is my test scenario:

  running news.arc
  /newest shows 30 plain text-story items (not url-stories)
  start profiler, and load /newest 10 times
  stop profiler, consult report
The report shows that 'pr is invoked 25040 times, 'pr calls map1, and 'map1 ends up calling 'disp 33150 times. And 'map1 conses together all the return values of disp, and that result is promptly discarded by 'pr.

So an implementation of 'pr that used a non-consing equivalent of 'map1 would result in 33150 fewer invocations of 'cons - 330510 instead of 363660. Which looks good (10% fewer conses!), until you realise 33K conses represent about 0.5% of the execution time for the profiled scenario. Probably below the average error in a benchmark test. Hence, nothing of significance proven about 'pr.

Still, rainbow's profiler has come a long way: it generates a navigable html report, shows caller and callee invocation counts, and merges profile data from multiple threads into a single report. I've put an example report up here: http://home.conandalton.net/profile-report.html (it's the report for the scenario I described)

To run this scenario, do something like this:

  arc> (thread (nsv))
  ; stuff about listening on a port
  arc> (profiling-on)
  t
  ; switch to your preferred browser and hammer the server for a bit, then come back and
  arc> (profiling-off)
  ; uses (system "open #(file)") to open the report in a browser
  ; (works on my mac, you might need to open the file manually)
  nil
It's not perfect yet, but it's useful enough to learn about how your arc program is really behaving - even if you're targeting scheme and not rainbow (the timings are probably different, but the invocation counts should be correct)