Tuesday, November 30, 2010

Python tips from the Google AI Challenge

I did a few things during the AI contest that made my life easier. Some may be obvious to most people, but I hope they are useful to someone.

Also, a cleaned up version of my bot is at bitbucket.

Logging

Python's logging facility is very useful. Here, I only used it to log to a file, overwriting the file each time. This is something that simple functions could do, but why write them if they are built in? Maybe in another language where extra libraries must be used for logging, writing my own would have made more sense.

The bots cannot write to files on the contest server. During the previous contest, I used logging during my local testing, and commented out the logging setup when I submitted my code. This time around, I wrote my bot so that if it is not given any arguments, the way it will be called on the contest server, it doesn't log. With arguments, it uses the first argument as the logfile name.

Here is where that code lives in my bot:

if __name__ == '__main__':
  try:
    import psyco
    psyco.full()
  except ImportError:
    pass

  try:
    argv = sys.argv[1:]
    if len(argv) > 0:
      logging.basicConfig(filename=argv[0],
                          level=logging.DEBUG,
                          filemode="w")
    main(turn_time)
  except KeyboardInterrupt:
    print 'ctrl-c, leaving ...'
  except EOFError:
    logging.debug("end of input")
  except:
    logging.exception('Crash')

The EOFError was needed for to make local testing cleaner. Someone on the forums posted the logging.exception tip, which is great for seeing the exception information in the log file.

Timeouts

The contest server uses one second timeouts per turn. My bot had logic to try to avoid timing out, although it is not very strict. Testing locally, sometimes I wanted to see if the bot was having problems just because it was too slow, so I would tell it to run for five seconds and see if it worked better. This never helped, but it seemed like a good idea.

Also, when replaying parts of games that I had lost, I would run with logging on. With logging on, the bot took longer, and might not do the same thing it had done in the game. So, I would let it take longer than a second to see what it was thinking.

Replays

One of the greatest things about this contest is that the games are all based on text. That means we could theoretically write bots in any language that does I/O. (Practically, the admins have limited resources, and can only set up a reasonable number of languages). Also, it means that the state of the game is represented by a string. If we have that string, we can see what our bot is doing. So, fairly early in the contest, I wrote some code to parse the compressed game state available on the web visualizer and from the local game engine. The code wrote out a file with the game state at every turn. Given that, I could easily rerun my bot on a given move.

As an aside, my bot was stateless between moves. It did not carry any information from one move to the next. Given that, I could more easily debug what my bot was doing on a single turn.

So, with the replay information, and logging, I was able to tweak the logic of my bot, and find several bugs.

I have to admit... I don't use debuggers very often. I like writing small functions that don't rely on state elsewhere in the code. Given that, and some logging, I find that I can usually debug pretty quickly. Oh, and I prefer languages with interactive shells, so I don't have to recompile to try different things when testing my code.

But, sometimes debuggers are the right tool. In my case, I had some very ugly code, and logging was not cutting it. I couldn't figure out why it was in the state it was in. So, pdb to the rescue.

The main loop of my bot is here.

def main(turn_time=0.8):
  turn = 0
  while(True):
    map_data = []
    turn += 1
    while True:
      current_line = raw_input()
      if len(current_line) >= 2 and current_line.startswith("go"):
        start_time = time.time()
        end_time = start_time + turn_time
        s = "\n".join(map_data)
        logging.debug("turn %d\n%s\ngo\n", turn, s)
        main_do_turn(map_data, turn, end_time)
        break

      else:
        map_data.append(current_line)

The code reads from stdin until it sees the "go" string. Then, it bundles up all of those lines and calls main_do_turn, which is the function that calculates my move for a given turn.

To debug this in the debugger, I wrote another Python script that looked like this.

import MyBot
import time
import logging
import pdb
import sys

def go(filename):
    s = open(filename).readlines()
    logging.basicConfig(filename="bot.log",
                        level=logging.DEBUG,
                        filemode="w")

    logging.debug('test')
    MyBot.main_do_turn(s, 1, time.time() + 9e99)


pdb.run('go("test.txt")')

This script set up my logging for me, set the timeout really big, and started my bot in the debugger.

Something similar could be done in the debugger of any language, as long as the bot has a function that can handle a single turn.

No comments: