Why is cron catching Python's logging events a

Question

I've got a very simple test setup with cron and a Python script that uses the logging module, and cron is behaving oddly when it encounters a logging event.

crontab

* * * * * ~/test.py >> ~/test.log

~/test.py

#!/usr/bin/env python

import logging
logging.basicConfig(level=logging.DEBUG)

print 'Properly printed, to file'
logging.debug("Does not get printed, get's e-mailed as an error")
print 'Still running, though'

~/test.log

After a cron run, the log is populated with these two messages:

Properly printed, to file
Still running, though

cron Error E-mail

Also after a cron run, I get a notification that I have new mail:

From tomcat6@local  Thu May 23 16:35:01 2013
Date: Thu, 23 May 2013 16:35:01 -0700
From: root@local (Cron Daemon)
To: tomcat6@local
Subject: Cron <tomcat6@local> ~/test.py >> ~/test.log
Content-Type: text/plain; charset=UTF-8
Auto-Submitted: auto-generated
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/usr/local/tomcat6>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=tomcat6>
X-Cron-Env: <USER=tomcat6>

DEBUG:root:Does not get printed, get's e-mailed as an error

It looks like it's not an explicit error, otherwise the final, 'Still running...', message would not be printed to ~/test.log, right?

Why are cron and or logging doing this, and is there a workaround?

Answer 1

The default configuration set by basicConfig() logs messages to stderr, and cron interprets any output to the stderr filehandle as email-worthy; you are, after all, not redirecting it.

See the logging.basicConfig() documentation:

Does basic configuration for the logging system by creating a StreamHandler with a default Formatter and adding it to the root logger,

and the StreamHandler docs:

If stream is specified, the instance will use it for logging output; otherwise, sys.stderr will be used.

The work-around is to not set up a stream handler, or pick a different stream, or to pick a filename to log to:

logging.basicConfig(level=logging.DEBUG, filename='/some/file/to/log/to')

or

logging.basicConfig(level=logging.DEBUG, stream=sys.stdout)

By logging to stdout you write logging information to the same output stream as print() does.

Another work-around is to redirect stderr to stdout:

* * * * * ~/test.py >> ~/test.log 2&>1