Wednesday, February 4, 2009

AppEngine dev_appserver logging

For some weird reason I cannot debug on dev_appserver. My breakpoints are simply ignored. So I placed logging code in troublesome places. By default, dev_appserver sets the root logger level to INFO. If run with -d option, it's DEBUG, and it logs all environment for every request. I tried to set the root level to WARNING or higher, but it was either ignored or made logger totally silent. So the best option I found is to leave the root level to INFO and to use module loggers for application-specific DEBUG messages. In the __main__ function I added the following lines:
logger=logging.getLogger("my")
logger.setLevel(logging.DEBUG)
Every module has to get its own logger like this:
# module engine.py
import logging

logger=logging.getLogger("my.engine")
Because of the dot separator my.engine logger inherits the configuration of my logger, so DEBUG messages are printed on the console.

I also did not find the correct way to add handlers to my logger, because if I change the logger initialization like this:

logger=logging.getLogger("my")
logger.setLevel(logging.DEBUG)
ch=logging.StreamHandler()
logger.addHandler(ch)
It adds a new handler for every request, so each message is printed many times. Of course, it's possible to remove the handler after run_wsgi_app call, but it looked weird to add and immediately remove the handler every time. If you know a better way to configure logging with dev_appengine, please let me know.

No comments: