Debugging: Console Output and Upstart Scripts

Question

How do you send the output of an upstart script to a terminal so to find tracebacks in python code? It's taking me for ever to do things without trace-backs that used to take just a second. I'm having to place several file write calls to track down errors. What took second to find before with a traceback is turning in to several minutes minutes. This is miserable. This has been going on for a few weeks now and I'm sick of it. would some speak up on this please. I feel like I'm using assembly without a debugger again.

Answer 1

If you use Upstart 1.4 or newer, put console log into your Upstart job and all the output to stdout/stderr will end up to /var/log/upstart/<job>.log. Then you can do tail -f /var/log/upstart/<job>.log & to have the output appear in terminal.

Answer 2

There's a whole section on debugging techniques in the Upstart Cookbook. The easiest thing you could do is add --debug to your kernel arguments, which will increase upstart's verbosity and dump everything to syslog. Yes, debugging is complex, it's a reflection of the net complexity required to create a parallelized init system. I'm sure there's room for improvement.

Answer 3

When I write a python daemon I catch all the exceptions and throw then to the log file. I not only use for debug, but in production too. I have a a small script that I run every morning that looks for something upsetting in the logs.

It also helps in keeping the daemon running, of course.

Some sample code (I remove the not interesting parts):

import logging

if __name__ == "__main__":
    logging.basicConfig(level=logging.INFO,
                    format='%(asctime)s %(levelname)s %(message)s',
                    filename=LOG_FILE,
                    filemode='w')
    logging.info("Sincrod inicializado")
    if not DEBUG:
        daemonize()
    while True:
        try:
            actua()
        except:
            logging.error(sys.exc_info())
        if (datetime.datetime.now().hour > NOITE_EMPEZA\
         and datetime.datetime.now().hour < NOITE_REMATA):
            time.sleep(INTERVALO_NOITE)
        else:
            time.sleep(INTERVALO_DIA)

Where actua() is the real daemon (it writes to log too). Note that I also have a DEBUG variable in a settings file, when it's True, I don't fork the daemon so it's executes on the console.

Daemons

Daemons are the unix equivalent to windows services. They are processes that run in the background independent from other processes. That means that their father is usually init, and that they are detached from any tty. As they are independent, there is no predefined place to put their output.

There are lots of python libraries and snippets to make a daemon, in the above example I use my own function, that combines some ideas from Steinar Knutsens and Jeff Kunces versions. It's as simple as possible, note that I fork twice.

def daemonize():
    """Forks this process creating a daemon and killing the original one"""
    if (not os.fork()):
        # get our own session and fixup std[in,out,err]
        os.setsid()
        sys.stdin.close()
        sys.stdout = NullDevice()
        sys.stderr = NullDevice()
        if (not os.fork()):
            # hang around till adopted by init
            ppid = os.getppid()
            while (ppid != 1):
                time.sleep(0.5)
                ppid = os.getppid()
        else:
            # time for child to die
            os._exit(0)
    else:
        # wait for child to die and then bail
        os.wait()
        sys.exit()