print, logging, upstart

2013-02-09 02:59:05 -0500

Originally posted on tumblr

Decided recently that using print directly instead of python logging was a minor instance of "coding when I should be using"; likewise daemonizing/restarting code shouldn't be done by hand either, so I finally figured out how to actually use upstart "user configs". (Together they made a good set of things to experiment with while the net was offline due to the northeast blizzard.)

Turns out that both of them were mostly straightforward, except for one impossible/undocumented step. Even on ubuntu, it's impossible to start user scripts explicitly (though you can trigger them on events, which almost counts) because these lines are missing from /etc/dbus-1/system.d/Upstart.conf:

    <allow send_destination="com.ubuntu.Upstart"
       send_interface="com.ubuntu.Upstart0_6.Job"
       send_type="method_call" send_member="Start" />
    <allow send_destination="com.ubuntu.Upstart"
       send_interface="com.ubuntu.Upstart0_6.Job"
       send_type="method_call" send_member="Stop" />

(Similar lines are needed for restart/reload.) I haven't studied the security implications (they don't matter for the machines I'm using this on, but they might matter for your machine) since I haven't checked if these lines are missing from Quantal, and if they are, what bug report I should file. (Filing bug reports instead of kludging around things is another kind of long term vs. short term tradeoff, but that's the subject for a later "codes well with others" post.)

Python logging has a similar "missing chunk of magic". To be fair, if all you're trying to do is code more cleanly, and have easy to use instrumentation for later, logging.basicConfig and changing your print calls to logging.warn with explicit format strings is enough. However, much of what I write should run as services (under upstart, see above) and should actually syslog... and that's supposed to be easy to do with logging. In the past, I've just used syslog directly, and now that I dig into it, I see why: in order to use logging with syslog, you need

    syslog_tag = "%s[%d]: " % (os.path.basename(sys.argv[0]), os.getpid())
    logging.basicConfig(level=logging.DEBUG)
    syshandler = SysLogHandler(address="/dev/log")
    sysformatter = logging.Formatter(syslog_tag + "%(message)s")
    syshandler.setFormatter(sysformatter)
    logging.getLogger().addHandler(syshandler)

Turns out that since SysLogHandler doesn't use openlog (because when it logging was written, the syslog module apparently wasn't threadsafe) so you have to cook up your own process name/pid tagging. Then, even though /dev/log is pretty much the only way to access syslog in the past decade, the default is still UDP to port 514, so you have to override that as well. Once you drop in this 6-line blob, you can use logging in the normal fashion - figuring out a way to folded into one helper that gets pushed upstream would be nice.