Skip to content
Jeff Davis edited this page Jan 4, 2012 · 1 revision

Timing and Tuning

Because there were strict timeout rules for the contest I spent time measuring and tuning performance, it's also a great way to spot implementation issues and limitations in the language. I used gotest and gopprof extensively for lower level optimization; the article on profiling Go is a great introduction to doing that so I won't cover that here.

Another key method I use it to collect timing data at a higher level to do functional analysis. That data was collected per turn, output at the end of the run, and then analyzed both per game and in aggregate. I looked at the scaling behavior of the different components and for any interesting anomalies.

I kept a Turn number as a global and maintained a "timing stack" with the functions TPush(tag), TPop() and TPopn(n). TPush(tag) initiated timing for tag. If the tag started with '@' or '+' the data was tracked over all turns and written to a CSV file at program termination while all other tags were ephemeral and timing data was simply written to stderr; '@' was used for tracking things which in production could be ignored while '+' was used for instances where the timing data was actually used to budget during real play. TPopn(n) was used for timing inner loop processing such as combat resolution where it would record the number of permutations evaluated so compute times could be forecast for different scenario counts.

The CSV's were written in melted form for easy plotting using ggplot2, the fantastic graphing and visualization toolkit developed for R by Hadley Wickham. I would then produce statistics on the per turn timings for various functions such as the symmetry analysis, pathfinding, combat, etc. I would then calculate a collection of metrics such as the scaling as a function of number of ants, new tiles, number of combat partitions, combat partition size, etc. It was also important to look for outliers and try to reduce the variance in times. In particular there are some maps with large numbers of false symmetries which required many symmetry map validations. It turned out that I invalidating a minhash which it produced an invalid mapping mitigated that a great deal.

Example of the typical distribution of times for symmetry checking Symmetry Timing Typical And the maps with a lot of false symmetry Symmetry false positives

Combat resolution times Combat resolution timing

GC Timing GC Times One of the reasons I was so comfortable using Go was that the garbage collection was smooth with low variance on time taken. That might have been partly due to how I allocated memory but I think it's also typical given the algorithm they use. I did experiment with explicit GC calls but it seemed unnecessary.

Clone this wiki locally