Running Python script as upstart service shows different time output

Question

I have a python script that is essentially a small socket server that does some simple network tasks for me, and I started running it as an upstart service to keep track of it and manage whether or not it was running. To log information, I am using Python's built in logging module. When running as an Upstart service, I noticed a small problem: All of the time calls come out in GMT. When running it on its own(either ./scriptname.py or python scriptname.py) it uses local time, and Python is aware of the local time. The system time is set correctly, and I only see this behavior when running as an upstart service. Does anyone know why this would happen and how I could fix it?

EDIT: Relevant code: I have a helper class, conveniently called helper, that contains some oft used functions (I know it needs to be better organized, but it was thrown together fairly quickly). Most notably this function that I use to set up my logger:

class helper:
    log_format = '%(asctime)-25s %(name)-25s %(levelname)-12s %(message)s'

    @staticmethod
    def createLogger(name):
        rotatingFile = logging.handlers.RotatingFileHandler('/var/log/myLog.log', maxBytes=1048576, backupCount=5)
        rotatingFile.setLevel(logging.DEBUG)
        formatter = logging.Formatter(helper.log_format)
        formatter.time = localtime()
        rotatingFile.setFormatter(formatter)
        log = logging.getLogger(name)
        log.setLevel(logging.DEBUG)
        logging.basicConfig(format=helper.log_format, level=logging.DEBUG)
        if not log.handlers:
            log.addHandler(rotatingFile)
        return log

And it gets used like this in one of my classes:

class MyClass:

    def __init__(self):
        self._log = helper.createLogger('LogName')
        self._log.info('Some relevant info')

    _log = None

It's all pretty straightforward use of the python internal logging tools. I added the formatter.time = localtime() after I started noticing this problem, but before I realized that it only happened when run as a service. It didn't help.

Here is my (very basic) upstart config that I got from a tutorial:

description "Blah blah"
author  "My Name <My Email>"

start on runlevel [234]
stop on runlevel [0156]

exec /path/to/script.py

respawn

Answer 1

Inspect your script's environment under upstart. localtime() takes timezone information from TZ/TZDIR//etc/localtime, 'GMT' being the hard-coded default (see time/tzset.c in glibc sources) . The environment may be chrooted or otherwise restricted and your TZ specification might not work.

As a quick check, you can use strace -o <outfile> -ff start <jobname> to see whether python reads the correct timezone file at startup.

Answer 2

So, I think I finally discovered the issue. I needed to set the TZ env var but I wasn't doing it right before. Adding env TZ=/usr/share/zoneinfo/US/Central to my upstart config corrected it. Thanks for the help everyone!