python-lunch 0.4.0-1 / usr / bin / lunch-slave

#!/usr/bin/python
# -*- coding: utf-8 -*-
#
# Lunch
# Copyright (C) 2009 Société des arts technologiques (SAT)
# http://www.sat.qc.ca
# All rights reserved.
#
# This file is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
# the Free Software Foundation, either version 2 of the License, or
# (at your option) any later version.
#
# Lunch is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with Lunch.  If not, see <http://www.gnu.org/licenses/>.
"""
The lunch-slave script is an interactive process launcher. 

It that can only launch a single process.
This file is a stand-alone script. It does not depend on any library, except Twisted and the standard Python modules.
"""
#FIXME: still need to edit this version string by hand
__version__ = "0.4.0"

DESCRIPTION = "The lunch slave utility is an interactive process launcher. It is intended to be run by the lunch master process through an encrypted SSH connection. It launches a single process at a time and allows to specify its environment and to log its standard output and error to a file. Launch it, type \"help\" and press enter to know more about how it works."

#TODO: allow to launch more than one process.
#TODO: spend more time looking at twisted.runner.procmon 

import os
import sys
import time
import logging
import textwrap

from twisted.internet import protocol
from twisted.internet import task
from twisted.internet import error
from twisted.internet import reactor
from twisted.internet import stdio
from twisted.protocols import basic
from twisted.python import procutils

# Those constants are redefined here to avoid the need to import the lunch module.
STATE_STARTING = "STARTING"
STATE_RUNNING = "RUNNING" # success
STATE_STOPPING = "STOPPING"
STATE_STOPPED = "STOPPED" # success

class SlaveError(Exception):
    """
    Raised by the Slave
    """
    pass

def call_callbacks(callbacks, *args, **kwargs):
    """
    Calls each callable in the list of callbacks with the arguments and keyword-arguments provided.

    Simplified implementation of the signal-slot pattern.
    """
    for c in callbacks:
        c(*args, **kwargs)

class ChildProcess(protocol.ProcessProtocol):
    """
    Process managed by a lunch-slave.
 
    Its stdout and stderr streams are logged to a file.    
    """
    def __init__(self, slave):
        """
        @param slave: Slave instance.
        """
        self.slave = slave

    def connectionMade(self):
        """
        Called once the process is started.
        """
        self.slave._on_connection_made()

    def outReceived(self, data):
        """
        Called when text is received from the managed process stdout
        Twisted will not splitlines, it gives an arbitrary amount of
        data at a time. 

        Here, we make sure our slave manager only gets one line at a time.
        """
        for line in data.splitlines():
            if line != "":
                self.slave._stdout_file.write(line + "\n")
                self.slave.must_flush_stdout_file = True
                if self.slave._num_lines_received == 0:
                    if ": not found" in line:
                        self.slave.on_command_not_found()
                self.slave._num_lines_received += 1

    def errReceived(self, data):
        """
        Called when text is received from the managed process stderr
        """
        for line in data.splitlines().strip():
            if line != "":
                self.slave._stdout_file.write(line + "\n")
                if self.slave._num_lines_received == 0:
                    if ": not found" in line:
                        self.slave.on_command_not_found()
                self.slave.must_flush_stdout_file = True
                self.slave._num_lines_received += 1

    def processEnded(self, reason):
        """
        Called when the child process has exited.
        status is probably a twisted.internet.error.ProcessTerminated
        "A process has ended with a probable error condition: process ended by signal 1"
        
        This is called when all the file descriptors associated with the child 
        process have been closed and the process has been reaped. This means it 
        is the last callback which will be made onto a ProcessProtocol. 
        The status parameter has the same meaning as it does for processExited.
        """
        exit_code = reason.value.exitCode
        if exit_code is None:
            exit_code = reason.value.signal
        self.slave._on_process_ended(exit_code)
    
    def inConnectionLost(self, data):
        #self.slave.log("stdin pipe has closed." + str(data))
        pass
        
    def outConnectionLost(self, data):
        #self.slave.log("stdout pipe has closed." + str(data))
        pass
        
    def errConnectionLost(self, data):
        #self.slave.log("stderr pipe has closed." + str(data))
        pass

    def processExited(self, reason):
        """
        This is called when the child process has been reaped, and receives 
        information about the process' exit status. The status is passed in the form 
        of a Failure instance, created with a .value that either holds a ProcessDone 
        object if the process terminated normally (it died of natural causes instead 
        of receiving a signal, and if the exit code was 0), or a ProcessTerminated 
        object (with an .exitCode attribute) if something went wrong.
        """
        self.slave.log("process has exited " + str(reason.value))
    
class Slave(object):
    """
    Slave that manages a process. 
    
    The command, identifier and env can be set after object creation.
    """
    def __init__(self, command=None, identifier=None, env=None):
        """
        @param command: Shell string. The first item is the name of the name of the executable.
        @param identifier: Any string. Used as a file name, so avoid spaces and exotic characters.
        """
        self.flush_log_file_every = 0.1
        self._num_lines_received = 0
        self._process_transport = None
        self._child_process = None
        self._time_child_started = None
        self._child_running_time = None
        self._stdout_file = None
        self.must_flush_stdout_file = False
        self.child_state = STATE_STOPPED
        self.io_protocol = None # this attribute is set directly to the SlaveIO instance once created.
        self.command = command # string
        self.options = {
            "clear-old-logs": True,
            "delay_kill": 8.0, # seconds # TODO: use the attr of the lunch.commands.Command
            }
        self.identifier = identifier # title
        self.env = {} # environment variables for the child process
        if env is not None:
            self.env.update(env)
        self.log_dir = os.path.join(os.getcwd(), "lunch_log")
        self.pid = None
        self.log_callbacks = []
        if self.identifier is None:
            self.identifier = "default"
        self.log_level = logging.DEBUG
        self._delayed_kill = None # DelayedCall instance
        self._flush_task = task.LoopingCall(self._looping_call_flush_log_files)
        self._flush_task.start(self.flush_log_file_every, now=False)
    
    def _before_shutdown(self):
        """
        Called before twisted's reactor shutdown.
        to make sure that the process is dead before quitting.
        """
        if self.child_state in [STATE_STARTING, STATE_RUNNING, STATE_STOPPING]:
            msg = "Child still %s. Stopping it before shutdown." % (self.child_state)
            self.log(msg)
            self.stop()

    def _looping_call_flush_log_files(self):
        if self.must_flush_stdout_file:
            if not self._stdout_file.closed:
                self._stdout_file.flush()
            self.must_flush_stdout_file = False

    def on_command_not_found(self):
        self.io_protocol.send_not_found()

    def is_alive(self):
        """
        Checks if the child is alive.
        """
        #TODO Use this
        if self.child_state == STATE_RUNNING:
            proc = self._process_transport
            try:
                proc.signalProcess(0)
            except (OSError, error.ProcessExitedAlready):
                msg = "Lost process %s. Error sending it an empty signal." % (self.identifier)
                self.io_protocol.send_error(msg)
                return False
            else:
                return True
        else:
            return False
    
    def start_child(self):
        """
        Starts the child process
        """
        if self.child_state in [STATE_RUNNING, STATE_STARTING]:
            msg = "Child is already %s. Cannot start it." % (self.child_state)
            self.io_protocol.send_error(msg)
            return
        elif self.child_state == STATE_STOPPING:
            msg = "Child is %s. Please try again to start it when it will be stopped." % (self.child_state)
            self.io_protocol.send_error(msg)
            # TODO: The Master should try again later.
            return
        if self.command is None or self.command.strip() == "":
            msg = "You must provide a command to be run."
            self.io_protocol.send_error(msg)
            return
        #else:
        #    # find full path to executable
        #    words = self.command.strip().split(" ")
        #    executable_name = words[0]
        #    try:
        #        full_exec_path = procutils.which(executable_name)[0]
        #        #self.command[0] = procutils.which(self.command[0])[0]
        #    except IndexError:
        #        msg = "Could not find path of executable %s." % (executable_name)
        #        self.io_protocol.send_error(msg)
        #        return
        # create log dir
        if not os.path.exists(self.log_dir):
            try:
                os.makedirs(self.log_dir)
            except OSError, e:
                self.io_protocol.send_error("Could not create log directory %s." % (self.log_dir))
                return
            else:
                self.log("Created directory %s" % (self.log_dir))
        # remove old log file
        stdout_file_name = os.path.join(self.log_dir, "child-%s.log" % (self.identifier))
        if self.options["clear-old-logs"]:
            try:
                os.remove(stdout_file_name) # cleans it up from last time we ran it. TAKE CARE !
            except OSError, e:
                self.log("Error erasing old stdout file %s." % (stdout_file_name), logging.ERROR)
        # open log file in write mode.
        try:
            self._stdout_file = file(stdout_file_name, "w") 
        except OSError, e:
            self.io_protocol.send_error("Could not open log file %s in write mode." % (stdout_file_name))
            return
        else:
            # close, chmod and re-open it:
            self._stdout_file.close()
            os.chmod(stdout_file_name, 0600)
            self._stdout_file = file(stdout_file_name, "a")
            self.log("Writing %s child's output to %s" % (self.identifier, stdout_file_name))
        self.log("Slave %s will run command %s" % (self.identifier, str(self.command)))
        self._child_process = ChildProcess(self)
        proc_path = self.command[0]
        args = self.command
        environ = {}
        #for key in ['HOME', 'DISPLAY', 'PATH']: # passing a few env vars
        #    if os.environ.has_key(key):
        #        environ[key] = os.environ[key]
        # let's pass it all the environment variables.
        environ.update(os.environ)
        for key, val in self.env.iteritems():
            environ[key] = val
        self.set_child_state(STATE_STARTING)
        #self.log("Identifier: %s" % (self.identifier))
        #self.log("Environment variables: %s" % (str(environ)))
        #self._process_transport = reactor.spawnProcess(self._child_process, proc_path, args, environ, usePTY=True)
        shell = "/bin/sh"
        if os.path.exists("/bin/bash"):
            shell = "/bin/bash"
        self._time_child_started = time.time()
        self._num_lines_received = 0
        self._process_transport = reactor.spawnProcess(self._child_process, shell, [shell, "-c", "exec %s" % (self.command)], environ, usePTY=True)
        self.pid = self._process_transport.pid
        self.log("Spawned child %s with pid %s." % (self.identifier, self.pid))
        self.io_protocol.send_child_pid(self.pid)
    
    def _on_connection_made(self):
        if not STATE_STARTING:
            self.log("Connection made even if we were not starting the child process.", logging.ERROR)
        self.set_child_state(STATE_RUNNING)
    
    def stop(self):
        """
        Stops the child process
        """
        def _later_check(self, pid):
            if self.pid == pid:
                if self.child_state in [STATE_STOPPING]:
                    self.io_protocol.send_error("Child process not dead.")
                    self.stop() # KILL
                elif self.child_state in [STATE_STOPPED]:
                    msg = "Successfully killed process after least than the %f seconds. State is %s." % (self.options["delay_kill"], self.child_state)
                    self.log(msg)
            self._delayed_kill = None
        
        # TODO: do callLater calls to check if the process is still running or not.
        #see twisted.internet.process._BaseProcess.reapProcess
        signal_to_send = None
        if self.child_state in [STATE_RUNNING, STATE_STARTING]:
            self.set_child_state(STATE_STOPPING)
            self.log('Will stop the child process using SIGINT.')
            signal_to_send = 2 # Used to be 15 #"TERM"
            # closing files handles in _on_process_ended
            self._delayed_kill = reactor.callLater(self.options["delay_kill"], _later_check, self, self.pid) # XXX important.
        elif self.child_state == STATE_STOPPING:
            self.log('Will stop the child process using SIGKILL since it\'s not dead.')
            signal_to_send = 9 #"KILL"
            # _on_process_ended will probably be called, this time.
        else: # STOPPED
            msg = "The child process is already stopped."
            self.set_child_state(STATE_STOPPED)
            self.io_protocol.send_error(msg)
            return
        if signal_to_send is not None:
            try:
                self._process_transport.signalProcess(signal_to_send)
            except OSError, e:
                msg = "Error sending signal %s to the child process. %s" % (signal_to_send, e)
                self.io_protocol.send_error(msg)
            except error.ProcessExitedAlready:
                #if signal_to_send == "TERM":
                msg = "The child process had already exited while trying to send signal %s." % (signal_to_send)
                self.io_protocol.send_error(msg)
            #TODO: later, make sure it is correctly killed.

    def log(self, msg, level=logging.DEBUG):
        """
        Sends some logging string to the Master. 
        (through stdout)
        """
        if level >= self.log_level:
            call_callbacks(self.log_callbacks, msg, level)

    def _on_process_ended(self, exit_code):
        self._child_running_time = time.time() - self._time_child_started
        if self.child_state == STATE_STOPPING:
            self.log('Child process exited as expected.')
            if self._delayed_kill is not None:
                if self._delayed_kill.active:
                    self._delayed_kill.cancel()
                self._delayed_kill = None
        elif self.child_state == STATE_STARTING:
            self.log('Child process exited while trying to start it.')
        elif self.child_state == STATE_RUNNING:
            if exit_code == 0:
                self.log('Child process exited.')
            else:
                self.log('Child process exited with error.')
        self._process_transport.loseConnection() # close file handles
        self.log("Child exitted with %s" % (exit_code), logging.INFO)
        self.io_protocol.send_retval(exit_code)
        self.set_child_state(STATE_STOPPED)
        self.log("Closing slave's process stdout file.")
        self._stdout_file.close()
        
    def set_child_state(self, new_state):
        """
        Handles state changes.
        """
        if self.child_state != new_state:
            if new_state == STATE_STOPPED:
                self.log("Child lived for %s seconds." % (self._child_running_time))
                self.io_protocol.send_state(new_state, self._child_running_time)
            else:
                self.io_protocol.send_state(new_state)
            self.log("child state: %s" % (new_state))
        else:
            self.log("State is same as before: %s" % (new_state))
        self.child_state = new_state
        
class SlaveIO(basic.LineReceiver):
    """
    Interactive commands for the slave using its standard input and output.
    """
    delimiter = '\n' # unix terminal style newlines. remove this line
                     # for use with Telnet
    _COMMAND_PREFIX = "recv"
    log_keys = {
        logging.DEBUG: "DEBUG",
        logging.INFO: "INFO",
        logging.WARNING: "WARNING",
        logging.CRITICAL: "CRITICAL",
        logging.ERROR: "ERROR",
        }
    
    def __init__(self, slave):
        self.slave = slave
        slave.io_protocol = self
    
    def connectionMade(self):
        self.send_message("Welcome to the lunch-slave console. Type 'help' for help.")
        if self._on_log not in self.slave.log_callbacks:
            self.slave.log_callbacks.append(self._on_log)
        self.send_ready()
    
    def send_not_found(self):
        self.sendLine("not_found %s" % (self.slave.command))
    
    def send_ready(self):
        self.sendLine("ready")
    
    def send_child_pid(self, pid):
        self.sendLine("child_pid %s" % (pid))
    
    def send_retval(self, exit_code):
        self.sendLine("retval %s" % (exit_code))

    def _on_log(self, msg, level=logging.INFO):
        self.send_log(msg, level)

    def lineReceived(self, line):
        """
        Commands are in the form "command arg"
        Answers are in the form "key message"
        """
        if line == "": 
            return
        # Parse the command
        try:
            key = line.split(" ")[0].lower()
            mess = line[len(key) + 1:]
        except IndexError, e:
            self.send_log("Index error parsing command-line. %s" % (e), logging.ERROR)
        
        # Dispatch the command to the appropriate method.  Note that all you
        # need to do to implement a new command is add another recv_* method.
        try:
            method = getattr(self, 'recv_' + key)
        except AttributeError, e:
            self.send_error('%s no such command.')
        else:
            method(mess)

    def recv_help(self, line):
        """
        help [command]: List commands, or show help on the given command.
        """
        args = line.split()
        # If there is an argument, shows its method's __docstring__
        if len(args) == 1:
            command = args[0]
            method_name = self._COMMAND_PREFIX + "_" + command
            if hasattr(self, method_name):
                doc = getattr(self, method_name).__doc__.strip()
                MAX_LINE_WIDTH = 70
                for line in doc.splitlines():
                    if line != "":
                        for line2 in textwrap.wrap(line, MAX_LINE_WIDTH):
                            self.send_message("(help) " + line.strip())
            else:
                self.send_log("(help) No such command: %s" % (command), logging.ERROR)
        else:
            commands = [cmd[len(self._COMMAND_PREFIX) + 1:] for cmd in dir(self) if cmd.startswith(self._COMMAND_PREFIX)]
            self.send_message("(help) Valid commands: %s" %  (" ".join(commands)))

    def send_state(self, child_state, child_running_time=None):
        # TODO: could be more verbose - it's the child state, not the lunch-slave state.
        if child_running_time is not None:
            self.sendLine("%s %s %s" % ("state", child_state, child_running_time))
        else:
            self.sendLine("%s %s" % ("state", child_state))
    
    def recv_quit(self, line):
        """
        quit: Quits this session
        """
        if self.slave.child_state == STATE_RUNNING:
            self.send_log("The lunch-slave is still running. Need to stop it.") # XXX
            self.slave.stop()
        self.send_bye()
        self.transport.loseConnection() # close this process' stdin and stdout

    def send_bye(self):
        """
        Confirms that we will stop this lunch-slave.
        """
        self.sendLine('%s Exiting lunch-slave.' % ("bye"))

    def recv_logdir(self, line):
        """
        logdir: sets the log directory
        """
        words = line.split() # TODO: do not split it, use bash !
        if len(words) == 0:
            self.send_error("No log dir specified.")
            return
        dir_name = words[0]
        if not os.path.exists(dir_name):
            try:
                os.makedirs(dir_name)
            except OSError, e:
                self.send_error("Directory %s does not exist and could not create it. %s" % (dir_name, e))
                return
        self.slave.log_dir = dir_name
        self.send_ok()
        
    #def recv_set(self, name, value=None):
    #    """set: Sets a configuration value. Usage: set <name> <value>"""
    #    if hasattr(self.slave, name):
    #        _type = type(getattr(self.slave, name))
    #        try:
    #            setattr(self.slave, _type(value))
    #        except ValueError, e:
    #            self.send_error("Bad type for %s. \"%s\" is not a valid %s." % (name, value, _type.__name__))
    
    def recv_do(self, line):
        """
        do: sets the shell command to be run.
        """
        li = line.split() # TODO: do not split it, use bash !
        if len(li) == 0:
            self.send_error("Cannot use an empty command.")
            return
        self.send_message("Using %s as a command to run." % (line))
        self.slave.command = line.strip()
        self.send_ok()

    def recv_env(self, line):
        """
        env: Sets the env vars for the process. 
        Must be in a string of key=value separated by spaces.
        """
        args = line.split()
        for key_val in args:
            try:
                k, v = key_val.split("=")
            except ValueError:
                self.send_error("%s %s" % ("Wrong env key-value pair:", key_val))
            else:
                self.send_log("Setting env var $%s=%s." % (k, v), logging.DEBUG)
                self.slave.env[k] = v

    def send_ok(self):
        self.sendLine("ok")

    def recv_run(self, line):
        """
        run: Starts the process.
        """
        self.slave.start_child()
    
    def recv_stop(self, line):
        """
        stop: Stops the process.
        """
        self.slave.stop()
    
    def recv_opt(self, line):
        """
        opt: sets an option. 
        Usage: opt <key> <value> 
        Use 0 or 1 for boolean options.
        """
        words = line.split()
        try:
            k = words[0]
            v = words[1]
        except IndexError, e:
            self.send_error("Wrong number of arguments.")
            return
        if not self.slave.options.has_key(k):
            self.send_error("No such option: %s" % (k))
            return
        current = self.slave.options[k]
        cast = type(current)
        try:
            if cast is bool:
                self.slave.options[k] = bool(int(v))
            else:
                self.slave.options[k] = cast(v)
            self.send_ok()
            return
        except ValueError, e:
            self.send_error("Wrong type of value %s for option %s." % (v, k))
            return
        # else ok?

    def recv_opts(self, line):
        """
        opt: lists options. 
        """
        self.send_message("Options: %s" % (self.slave.options))

    def recv_ping(self, line):
        """
        ping: Answers with "pong"
        """
        #TODO : check if slave process is running
        self.send_pong()

    def send_error(self, msg):
        self.sendLine("%s %s" % ("error", msg))
    
    def send_message(self, msg):
        self.sendLine("%s %s" % ("msg", msg))

    def send_pong(self):
        self.sendLine("pong")

    def send_log(self, msg, level=logging.DEBUG):
        key = self.log_keys[level]
        self.sendLine("%s %s %s" % ("log", key, msg))

    def recv_status(self, line):
        """
        status: ask the lunch-slave to print the state of the child process.
        """
        self.send_status()

    def send_status(self):
        self.sendLine("%s %s" % ("status", self.slave.child_state))

    def connectionLost(self, reason):
        # stop the reactor, only because this is meant to be run in Stdio.
        try:
            self.slave.log_callbacks.remove(self._on_log) # XXX !
        except ValueError, e:
            pass
        if self.slave.child_state != STATE_STOPPED:
            try:
                self.slave.stop()
            except SlaveError, e:
                self.send_error("%s" % (e))
        if reactor.running != 0:
            reactor.stop()

def run_slave():
    """
    Runs the slave application.
    """
    from optparse import OptionParser
    parser = OptionParser(usage="%prog [options]", version="%prog " + __version__, description=DESCRIPTION)
    parser.add_option("-i", "--id", type="string", help="Identifier of this lunch slave.")
    (options, args) = parser.parse_args()
    kwargs = {}
    if options.id:
        kwargs["identifier"] = options.id
    slave = Slave(**kwargs)
    reactor.addSystemEventTrigger("before", "shutdown", slave._before_shutdown) #to make sure that the process is dead before quitting.
    slave_io = SlaveIO(slave)
    stdio.StandardIO(slave_io)
    try:
        reactor.run()
    except KeyboardInterrupt:
        reactor.stop()

if __name__ == "__main__":
    run_slave()