root / tea4cups / trunk / tea4cups @ 639

#! /usr/bin/env python
# -*- coding: ISO-8859-15 -*-

# Tea4CUPS : Tee for CUPS
#
# (c) 2005 Jerome Alet <alet@librelogiciel.com>
# (c) 2005 Peter Stuge <stuge-tea4cups@cdy.org>
# This program 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.
#
# This program 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 this program; if not, write to the Free Software
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307, USA.
#
# $Id$
#
#

import sys
import os
import pwd
import popen2
import errno
import md5
import cStringIO
import shlex
import tempfile
import ConfigParser
import select
import signal
import time
from struct import unpack

version = "2.12alpha3_unofficial"

class TeeError(Exception):
    """Base exception for Tea4CUPS related stuff."""
    def __init__(self, message = ""):
        self.message = message
        Exception.__init__(self, message)
    def __repr__(self):
        return self.message
    __str__ = __repr__
    
class ConfigError(TeeError) :    
    """Configuration related exceptions."""
    pass 
    
class IPPError(TeeError) :    
    """IPP related exceptions."""
    pass 
    
class Popen4ForCUPS(popen2.Popen4) :
    """Our own class to execute real backends.
    
       Their first argument is different from their path so using
       native popen2.Popen3 would not be feasible.
    """
    def __init__(self, cmd, bufsize=-1, arg0=None) :
        self.arg0 = arg0
        popen2.Popen4.__init__(self, cmd, bufsize)
        
    def _run_child(self, cmd):
        try :
            MAXFD = os.sysconf("SC_OPEN_MAX")
        except (AttributeError, ValueError) :    
            MAXFD = 256
        for i in range(3, MAXFD) : 
            try:
                os.close(i)
            except OSError:
                pass
        try:
            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
        finally:
            os._exit(1)
    
# Some IPP constants    
OPERATION_ATTRIBUTES_TAG = 0x01
JOB_ATTRIBUTES_TAG = 0x02
END_OF_ATTRIBUTES_TAG = 0x03
PRINTER_ATTRIBUTES_TAG = 0x04
UNSUPPORTED_ATTRIBUTES_TAG = 0x05

class IPPMessage :
    """A class for IPP message files.
    
       Usage :
       
         fp = open("/var/spool/cups/c00001", "rb")
         message = IPPMessage(fp.read())
         fp.close()
         print "IPP version : %s" % message.version
         print "IPP operation Id : %s" % message.operation_id
         print "IPP request Id : %s" % message.request_id
         for attrtype in ("operation", "job", "printer", "unsupported") :
             attrdict = getattr(message, "%s_attributes" % attrtype)
             if attrdict :
                 print "%s attributes :" % attrtype.title()
                 for key in attrdict.keys() :
                     print "  %s : %s" % (key, attrdict[key])
    """
    attributes_types = ("operation", "job", "printer", "unsupported")
    def __init__(self, data, debug=0) :
        """Initializes and parses IPP Message object.
        
           Parameters :
           
             data : the IPP Message's content.
             debug : a boolean value to output debug info on stderr.
        """
        self.debug = debug
        self.data = data
        for attrtype in self.attributes_types :
            setattr(self, "%s_attributes" % attrtype, {})
        self.tags = [ None ] * 256      # by default all tags reserved
        
        # Delimiter tags
        self.tags[OPERATION_ATTRIBUTES_TAG] = "operation-attributes-tag"
        self.tags[JOB_ATTRIBUTES_TAG] = "job-attributes-tag"
        self.tags[END_OF_ATTRIBUTES_TAG] = "end-of-attributes-tag"
        self.tags[PRINTER_ATTRIBUTES_TAG] = "printer-attributes-tag"
        self.tags[UNSUPPORTED_ATTRIBUTES_TAG] = "unsupported-attributes-tag"
        
        # out of band values
        self.tags[0x10] = "unsupported"
        self.tags[0x11] = "reserved-for-future-default"
        self.tags[0x12] = "unknown"
        self.tags[0x13] = "no-value"
        
        # integer values
        self.tags[0x20] = "generic-integer"
        self.tags[0x21] = "integer"
        self.tags[0x22] = "boolean"
        self.tags[0x23] = "enum"
        
        # octetString
        self.tags[0x30] = "octetString-with-an-unspecified-format"
        self.tags[0x31] = "dateTime"
        self.tags[0x32] = "resolution"
        self.tags[0x33] = "rangeOfInteger"
        self.tags[0x34] = "reserved-for-collection"
        self.tags[0x35] = "textWithLanguage"
        self.tags[0x36] = "nameWithLanguage"
        
        # character strings
        self.tags[0x20] = "generic-character-string"
        self.tags[0x41] = "textWithoutLanguage"
        self.tags[0x42] = "nameWithoutLanguage"
        # self.tags[0x43] = "reserved"
        self.tags[0x44] = "keyword"
        self.tags[0x45] = "uri"
        self.tags[0x46] = "uriScheme"
        self.tags[0x47] = "charset"
        self.tags[0x48] = "naturalLanguage"
        self.tags[0x49] = "mimeMediaType"
        
        # now parses the IPP message
        self.parse()
        
    def printInfo(self, msg) :    
        """Prints a debug message."""
        if self.debug :
            sys.stderr.write("%s\n" % msg)
            sys.stderr.flush()
            
    def parseTag(self) :    
        """Extracts information from an IPP tag."""
        pos = self.position
        tagtype = self.tags[ord(self.data[pos])]
        pos += 1
        posend = pos2 = pos + 2
        namelength = unpack(">H", self.data[pos:pos2])[0]
        if not namelength :
            name = self._curname
        else :    
            posend += namelength
            self._curname = name = self.data[pos2:posend]
        pos2 = posend + 2
        valuelength = unpack(">H", self.data[posend:pos2])[0]
        posend = pos2 + valuelength
        value = self.data[pos2:posend]
        if tagtype in ("integer", "enum") :
            value = unpack(">I", value)[0]
        oldval = self._curdict.setdefault(name, [])
        oldval.append((tagtype, value))
        self.printInfo("%s(%s) %s" % (name, tagtype, value))
        return posend - self.position
        
    def operation_attributes_tag(self) : 
        """Indicates that the parser enters into an operation-attributes-tag group."""
        self.printInfo("Start of operation_attributes_tag")
        self._curdict = self.operation_attributes
        return self.parseTag()
        
    def job_attributes_tag(self) : 
        """Indicates that the parser enters into a job-attributes-tag group."""
        self.printInfo("Start of job_attributes_tag")
        self._curdict = self.job_attributes
        return self.parseTag()
        
    def printer_attributes_tag(self) : 
        """Indicates that the parser enters into a printer-attributes-tag group."""
        self.printInfo("Start of printer_attributes_tag")
        self._curdict = self.printer_attributes
        return self.parseTag()
        
    def unsupported_attributes_tag(self) : 
        """Indicates that the parser enters into an unsupported-attributes-tag group."""
        self.printInfo("Start of unsupported_attributes_tag")
        self._curdict = self.unsupported_attributes
        return self.parseTag()
        
    def parse(self) :
        """Parses an IPP Message.
        
           NB : Only a subset of RFC2910 is implemented.
        """
        self._curname = None
        self._curdict = None
        self.version = "%s.%s" % (ord(self.data[0]), ord(self.data[1]))
        self.operation_id = "0x%04x" % unpack(">H", self.data[2:4])[0]
        self.request_id = "0x%08x" % unpack(">I", self.data[4:8])[0]
        self.position = 8
        try :
            tag = ord(self.data[self.position])
            while tag != END_OF_ATTRIBUTES_TAG :
                self.position += 1
                name = self.tags[tag]
                if name is not None :
                    func = getattr(self, name.replace("-", "_"), None)
                    if func is not None :
                        self.position += func()
                        if ord(self.data[self.position]) > UNSUPPORTED_ATTRIBUTES_TAG :
                            self.position -= 1
                            continue
                tag = ord(self.data[self.position])
        except IndexError :
            raise IPPError, "Unexpected end of IPP message."
            
        # Now transform all one-element lists into single values
        for attrtype in self.attributes_types :
            attrdict = getattr(self, "%s_attributes" % attrtype)
            for (key, value) in attrdict.items() :
                if len(value) == 1 :
                    attrdict[key] = value[0]
                    
class FakeConfig :    
    """Fakes a configuration file parser."""
    def get(self, section, option, raw=0) :
        """Fakes the retrieval of an option."""
        raise ConfigError, "Invalid configuration file : no option %s in section [%s]" % (option, section)
        
class CupsBackend :
    """Base class for tools with no database access."""
    def __init__(self) :
        """Initializes the CUPS backend wrapper."""
        signal.signal(signal.SIGTERM, signal.SIG_IGN)
        signal.signal(signal.SIGPIPE, signal.SIG_IGN)
        self.MyName = "Tea4CUPS"
        self.myname = "tea4cups"
        self.pid = os.getpid()
        
    def readConfig(self) :    
        """Reads the configuration file."""
        confdir = os.environ.get("CUPS_SERVERROOT", ".") 
        self.conffile = os.path.join(confdir, "%s.conf" % self.myname)
        if os.path.isfile(self.conffile) :
            self.config = ConfigParser.ConfigParser()
            self.config.read([self.conffile])
            self.debug = self.isTrue(self.getGlobalOption("debug", ignore=1))
        else :    
            self.config = FakeConfig()
            self.debug = 1      # no config, so force debug mode !
            
    def logInfo(self, message, level="info") :        
        """Logs a message to CUPS' error_log file."""
        sys.stderr.write("%s: %s v%s (PID %i) : %s\n" % (level.upper(), self.MyName, version, os.getpid(), message))
        sys.stderr.flush()
        
    def logDebug(self, message) :    
        """Logs something to debug output if debug is enabled."""
        if self.debug :
            self.logInfo(message, level="debug")
        
    def isTrue(self, option) :        
        """Returns 1 if option is set to true, else 0."""
        if (option is not None) and (option.upper().strip() in ['Y', 'YES', '1', 'ON', 'T', 'TRUE']) :
            return 1
        else :    
            return 0
                        
    def getGlobalOption(self, option, ignore=0) :    
        """Returns an option from the global section, or raises a ConfigError if ignore is not set, else returns None."""
        try :
            return self.config.get("global", option, raw=1)
        except (ConfigParser.NoSectionError, ConfigParser.NoOptionError) :    
            if not ignore :
                raise ConfigError, "Option %s not found in section global of %s" % (option, self.conffile)
                
    def getPrintQueueOption(self, printqueuename, option, ignore=0) :    
        """Returns an option from the printer section, or the global section, or raises a ConfigError."""
        globaloption = self.getGlobalOption(option, ignore=1)
        try :
            return self.config.get(printqueuename, option, raw=1)
        except (ConfigParser.NoSectionError, ConfigParser.NoOptionError) :    
            if globaloption is not None :
                return globaloption
            elif not ignore :
                raise ConfigError, "Option %s not found in section [%s] of %s" % (option, printqueuename, self.conffile)
                
    def enumBranches(self, printqueuename, branchtype="tee") :
        """Returns the list of branchtypes branches for a particular section's."""
        branchbasename = "%s_" % branchtype.lower()
        try :
            globalbranches = [ (k, self.config.get("global", k)) for k in self.config.options("global") if k.startswith(branchbasename) ]
        except ConfigParser.NoSectionError, msg :    
            raise ConfigError, "Invalid configuration file : %s" % msg
        try :
            sectionbranches = [ (k, self.config.get(printqueuename, k)) for k in self.config.options(printqueuename) if k.startswith(branchbasename) ]
        except ConfigParser.NoSectionError, msg :    
            self.logInfo("No section for print queue %s : %s" % (printqueuename, msg))
            sectionbranches = []
        branches = {}
        for (k, v) in globalbranches :
            value = v.strip()
            if value :
                branches[k] = value
        for (k, v) in sectionbranches :    
            value = v.strip()
            if value :
                branches[k] = value # overwrite any global option or set a new value
            else :    
                del branches[k] # empty value disables a global option
        return branches
        
    def discoverOtherBackends(self) :    
        """Discovers the other CUPS backends.
        
           Executes each existing backend in turn in device enumeration mode.
           Returns the list of available backends.
        """
        # Unfortunately this method can't output any debug information
        # to stdout or stderr, else CUPS considers that the device is
        # not available.
        available = []
        (directory, myname) = os.path.split(sys.argv[0])
        if not directory :
            directory = "./"
        tmpdir = tempfile.gettempdir()
        lockfilename = os.path.join(tmpdir, "%s..LCK" % myname)
        if os.path.exists(lockfilename) :
            lockfile = open(lockfilename, "r")
            pid = int(lockfile.read())
            lockfile.close()
            try :
                # see if the pid contained in the lock file is still running
                os.kill(pid, 0)
            except OSError, e :    
                if e.errno != errno.EPERM :
                    # process doesn't exist anymore
                    os.remove(lockfilename)
            
        if not os.path.exists(lockfilename) :
            lockfile = open(lockfilename, "w")
            lockfile.write("%i" % self.pid)
            lockfile.close()
            allbackends = [ os.path.join(directory, b) \
                                for b in os.listdir(directory) 
                                    if os.access(os.path.join(directory, b), os.X_OK) \
                                        and (b != myname)] 
            for backend in allbackends :                            
                answer = os.popen(backend, "r")
                try :
                    devices = [line.strip() for line in answer.readlines()]
                except :    
                    devices = []
                status = answer.close()
                if status is None :
                    for d in devices :
                        # each line is of the form : 
                        # 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
                        # so we have to decompose it carefully
                        fdevice = cStringIO.StringIO(d)
                        tokenizer = shlex.shlex(fdevice)
                        tokenizer.wordchars = tokenizer.wordchars + \
                                                        r".:,?!~/\_$*-+={}[]()#"
                        arguments = []
                        while 1 :
                            token = tokenizer.get_token()
                            if token :
                                arguments.append(token)
                            else :
                                break
                        fdevice.close()
                        try :
                            (devicetype, device, name, fullname) = arguments
                        except ValueError :    
                            pass    # ignore this 'bizarre' device
                        else :    
                            if name.startswith('"') and name.endswith('"') :
                                name = name[1:-1]
                            if fullname.startswith('"') and fullname.endswith('"') :
                                fullname = fullname[1:-1]
                            available.append('%s %s:%s "%s+%s" "%s managed %s"' \
                                                 % (devicetype, self.myname, device, self.MyName, name, self.MyName, fullname))
            os.remove(lockfilename)
        available.append('direct %s:// "%s+Nothing" "%s managed Virtual Printer"' \
                             % (self.myname, self.MyName, self.MyName))
        return available
                        
    def initBackend(self) :    
        """Initializes the backend's attributes."""
        # check that the DEVICE_URI environment variable's value is 
        # prefixed with self.myname otherwise don't touch it.
        # If this is the case, we have to remove the prefix from 
        # the environment before launching the real backend 
        muststartwith = "%s:" % self.myname
        device_uri = os.environ.get("DEVICE_URI", "")
        if device_uri.startswith(muststartwith) :
            fulldevice_uri = device_uri[:]
            device_uri = fulldevice_uri[len(muststartwith):]
            for i in range(2) :
                if device_uri.startswith("/") :  
                    device_uri = device_uri[1:]
        try :
            (backend, destination) = device_uri.split(":", 1) 
        except ValueError :    
            if not device_uri :
                self.logDebug("Not attached to an existing print queue.")
                backend = ""
            else :    
                raise TeeError, "Invalid DEVICE_URI : %s\n" % device_uri
        
        self.JobId = sys.argv[1].strip()
        self.UserName = sys.argv[2].strip() or pwd.getpwuid(os.geteuid())[0] # use CUPS' user when printing test pages from CUPS' web interface
        self.Title = sys.argv[3].strip()
        self.Copies = int(sys.argv[4].strip())
        self.Options = sys.argv[5].strip()
        if len(sys.argv) == 7 :
            self.InputFile = sys.argv[6] # read job's datas from file
        else :    
            self.InputFile = None        # read job's datas from stdin
            
        self.RealBackend = backend
        self.DeviceURI = device_uri
        self.PrinterName = os.environ.get("PRINTER", "")
        self.Directory = self.getPrintQueueOption(self.PrinterName, "directory")
        self.DataFile = os.path.join(self.Directory, "%s-%s-%s-%s" % (self.myname, self.PrinterName, self.UserName, self.JobId))
        (ippfilename, ippmessage) = self.parseIPPMessageFile()
        self.ControlFile = ippfilename
        (chtype, self.ClientHost) = ippmessage.operation_attributes.get("job-originating-host-name", \
                                          ippmessage.job_attributes.get("job-originating-host-name", (None, None)))
        (jbtype, self.JobBilling) = ippmessage.job_attributes.get("job-billing", (None, None))
            
    def getCupsConfigDirectives(self, directives=[]) :
        """Retrieves some CUPS directives from its configuration file.
        
           Returns a mapping with lowercased directives as keys and 
           their setting as values.
        """
        dirvalues = {} 
        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
        try :
            conffile = open(cupsdconf, "r")
        except IOError :    
            raise TeeError, "Unable to open %s" % cupsdconf
        else :    
            for line in conffile.readlines() :
                linecopy = line.strip().lower()
                for di in [d.lower() for d in directives] :
                    if linecopy.startswith("%s " % di) :
                        try :
                            val = line.split()[1]
                        except :    
                            pass # ignore errors, we take the last value in any case.
                        else :    
                            dirvalues[di] = val
            conffile.close()            
        return dirvalues       
            
    def parseIPPMessageFile(self) :        
        """Parses the IPP message file and returns a tuple (filename, parsedvalue)."""
        cupsdconf = self.getCupsConfigDirectives(["RequestRoot"])
        requestroot = cupsdconf.get("requestroot", "/var/spool/cups")
        if (len(self.JobId) < 5) and self.JobId.isdigit() :
            ippmessagefile = "c%05i" % int(self.JobId)
        else :    
            ippmessagefile = "c%s" % self.JobId
        ippmessagefile = os.path.join(requestroot, ippmessagefile)
        ippmessage = {}
        try :
            ippdatafile = open(ippmessagefile)
        except :    
            self.logInfo("Unable to open IPP message file %s" % ippmessagefile, "warn")
        else :    
            self.logDebug("Parsing of IPP message file %s begins." % ippmessagefile)
            try :
                ippmessage = IPPMessage(ippdatafile.read())
            except IPPError, msg :    
                self.logInfo("Error while parsing %s : %s" % (ippmessagefile, msg), "warn")
            else :    
                self.logDebug("Parsing of IPP message file %s ends." % ippmessagefile)
            ippdatafile.close()
        return (ippmessagefile, ippmessage)
                
    def exportAttributes(self) :    
        """Exports our backend's attributes to the environment."""
        os.environ["DEVICE_URI"] = self.DeviceURI       # WARNING !
        os.environ["TEAPRINTERNAME"] = self.PrinterName
        os.environ["TEADIRECTORY"] = self.Directory
        os.environ["TEADATAFILE"] = self.DataFile
        os.environ["TEAJOBSIZE"] = str(self.JobSize)
        os.environ["TEAMD5SUM"] = self.JobMD5Sum
        os.environ["TEACLIENTHOST"] = self.ClientHost or ""
        os.environ["TEAJOBID"] = self.JobId
        os.environ["TEAUSERNAME"] = self.UserName
        os.environ["TEATITLE"] = self.Title
        os.environ["TEACOPIES"] = str(self.Copies)
        os.environ["TEAOPTIONS"] = self.Options
        os.environ["TEAINPUTFILE"] = self.InputFile or ""
        os.environ["TEABILLING"] = self.JobBilling or ""
        os.environ["TEACONTROLFILE"] = self.ControlFile
        
    def saveDatasAndCheckSum(self) :
        """Saves the input datas into a static file."""
        self.logDebug("Duplicating data stream into %s" % self.DataFile)
        mustclose = 0
        if self.InputFile is not None :
            infile = open(self.InputFile, "rb")
            mustclose = 1
        else :    
            infile = sys.stdin
        CHUNK = 64*1024         # read 64 Kb at a time
        dummy = 0
        sizeread = 0
        checksum = md5.new()
        outfile = open(self.DataFile, "wb")    
        while 1 :
            data = infile.read(CHUNK) 
            if not data :
                break
            sizeread += len(data)    
            outfile.write(data)
            checksum.update(data)    
            if not (dummy % 32) : # Only display every 2 Mb
                self.logDebug("%s bytes saved..." % sizeread)
            dummy += 1    
        outfile.close()
        if mustclose :    
            infile.close()
        self.JobSize = sizeread    
        self.JobMD5Sum = checksum.hexdigest()
        self.logDebug("Job %s is %s bytes long." % (self.JobId, self.JobSize))
        self.logDebug("Job %s MD5 sum is %s" % (self.JobId, self.JobMD5Sum))

    def cleanUp(self) :
        """Cleans up the place."""
        if not self.isTrue(self.getPrintQueueOption(self.PrinterName, "keepfiles", ignore=1)) :
            os.remove(self.DataFile)
            
    def sigtermHandler(self, signum, frame) :
        """Sets an attribute whenever SIGTERM is received."""
        self.gotSigTerm = 1
        self.logInfo("SIGTERM received for Job %s." % self.JobId)
        
    def runBranches(self) :         
        """Launches each hook or tee defined for the current print queue."""
        exitcode = 0
        self.isCancelled = 0    # did a prehook cancel the print job ?
        self.gotSigTerm = 0
        signal.signal(signal.SIGTERM, self.sigtermHandler)
        serialize = self.isTrue(self.getPrintQueueOption(self.PrinterName, "serialize", ignore=1))
        self.pipes = { 0: os.pipe() }
        for branchtype in ["prehook", "tee", "posthook"] :
            if branchtype == "posthook" :
                os.close(self.pipes[0][1])
            branches = self.enumBranches(self.PrinterName, branchtype)
            for b in branches :
                bname = b.split("_", 1)[1]
                if branchtype != "posthook" and bname not in self.pipes :
                    self.pipes[bname] = os.pipe()
                else :
                    if bname in self.pipes :
                        os.close(self.pipes[bname][1])
            status = self.runCommands(branchtype, branches, serialize)
            if status :
                if branchtype != "posthook" :
                    exitcode = status
                else :    
                    # we just ignore error in posthooks
                    self.logInfo("An error occured during the execution of posthooks.", "warn")
            if (branchtype == "prehook") and self.isCancelled :
                break # We don't want to execute tees or posthooks in this case
        signal.signal(signal.SIGTERM, signal.SIG_IGN)
        for p in self.pipes :
            os.close(self.pipes[p][0])
            try :
                os.close(self.pipes[p][1])
            except OSError :
                pass
        if not exitcode :
            self.logInfo("OK")
        else :    
            self.logInfo("An error occured, please check CUPS' error_log file.")
        return exitcode
        
    def stdioRedirSystem(self, cmd, stdin=0, stdout=1) :
        """Launches a command with stdio redirected."""
        # Code contributed by Peter Stuge on May 23rd and June 7th 2005
        pid = os.fork()
        if pid == 0 :
            if stdin != 0 :
                os.dup2(stdin, 0)
                os.close(stdin)
            if stdout != 1 :
                os.dup2(stdout, 1)
                os.close(stdout)
            try :
                os.execl("/bin/sh", "sh", "-c", cmd)
            except OSError , msg :
                self.logDebug("execl() failed: %s" % msg)
            os._exit(1)
        return os.waitpid(pid, 0)[1]
        
    def runCommand(self, branch, command) :
        """Runs a particular branch command."""
        # Code contributed by Peter Stuge on June 7th 2005
        self.logDebug("Launching %s : %s" % (branch, command))
        btype, bname = branch.split("_", 1)
        if bname not in self.pipes :
          bname = 0
        if btype != "posthook" :
            return self.stdioRedirSystem(command, 0, self.pipes[bname][1])
        else :
            return self.stdioRedirSystem(command, self.pipes[bname][0])

    def runCommands(self, btype, branches, serialize) :    
        """Runs the commands for a particular branch type."""
        exitcode = 0 
        btype = btype.lower()
        btypetitle = btype.title()
        branchlist = branches.keys()    
        branchlist.sort()
        if serialize :
            self.logDebug("Begin serialized %ss" % btypetitle)
            if (btype == "tee") and self.RealBackend :
                self.logDebug("Launching original backend %s for printer %s" % (self.RealBackend, self.PrinterName))
                retcode = self.runOriginalBackend()
                if os.WIFEXITED(retcode) :
                    retcode = os.WEXITSTATUS(retcode)
                os.environ["TEASTATUS"] = str(retcode)
                exitcode = retcode
            for branch in branchlist :
                command = branches[branch]
                if self.gotSigTerm :
                    break
                retcode = self.runCommand(branch, command)
                self.logDebug("Exit code for %s %s on printer %s is %s" % (btype, branch, self.PrinterName, retcode))
                if os.WIFEXITED(retcode) :
                    retcode = os.WEXITSTATUS(retcode)
                if retcode :    
                    if (btype == "prehook") and (retcode == 255) : # -1
                        self.logInfo("Job %s cancelled by prehook %s" % (self.JobId, branch))
                        self.isCancelled = 1
                    else :    
                        self.logInfo("%s %s on printer %s didn't exit successfully." % (btypetitle, branch, self.PrinterName), "error")
                        exitcode = 1
            self.logDebug("End serialized %ss" % btypetitle)
        else :        
            self.logDebug("Begin forked %ss" % btypetitle)
            pids = {}
            if (btype == "tee") and self.RealBackend :
                branches["Original backend"] = None     # Fakes a tee to launch one more child
                branchlist = ["Original backend"] + branchlist
            for branch in branchlist :
                command = branches[branch]
                if self.gotSigTerm :
                    break
                pid = os.fork()
                if pid :
                    pids[branch] = pid
                else :    
                    if branch == "Original backend" :
                        self.logDebug("Launching original backend %s for printer %s" % (self.RealBackend, self.PrinterName))
                        sys.exit(self.runOriginalBackend())
                    else :
                        retcode = self.runCommand(branch, command)
                        if os.WIFEXITED(retcode) :
                            retcode = os.WEXITSTATUS(retcode)
                        else :    
                            retcode = -1
                        sys.exit(retcode)
            for (branch, pid) in pids.items() :
                (childpid, retcode) = os.waitpid(pid, 0)
                self.logDebug("Exit code for %s %s (PID %s) on printer %s is %s" % (btype, branch, childpid, self.PrinterName, retcode))
                if os.WIFEXITED(retcode) :
                    retcode = os.WEXITSTATUS(retcode)
                if retcode :    
                    if (btype == "prehook") and (retcode == 255) : # -1
                        self.logInfo("Job %s cancelled by prehook %s" % (self.JobId, branch))
                        self.isCancelled = 1
                    else :    
                        self.logInfo("%s %s (PID %s) on printer %s didn't exit successfully." % (btypetitle, branch, childpid, self.PrinterName), "error")
                        exitcode = 1
                if branch == "Original backend" :    
                    os.environ["TEASTATUS"] = str(retcode)
            self.logDebug("End forked %ss" % btypetitle)
        return exitcode
        
    def unregisterFileNo(self, pollobj, fileno) :                
        """Removes a file handle from the polling object."""
        try :
            pollobj.unregister(fileno)
        except KeyError :    
            self.logInfo("File number %s unregistered twice from polling object, ignored." % fileno, "warn")
        except :    
            self.logDebug("Error while unregistering file number %s from polling object." % fileno)
        else :    
            self.logDebug("File number %s unregistered from polling object." % fileno)
            
    def formatFileEvent(self, fd, mask) :        
        """Formats file debug info."""
        maskval = []
        if mask & select.POLLIN :
            maskval.append("POLLIN")
        if mask & select.POLLOUT :
            maskval.append("POLLOUT")
        if mask & select.POLLPRI :
            maskval.append("POLLPRI")
        if mask & select.POLLERR :
            maskval.append("POLLERR")
        if mask & select.POLLHUP :
            maskval.append("POLLHUP")
        if mask & select.POLLNVAL :
            maskval.append("POLLNVAL")
        return "%s (%s)" % (fd, " | ".join(maskval))
        
    def runOriginalBackend(self) :    
        """Launches the original backend."""
        originalbackend = os.path.join(os.path.split(sys.argv[0])[0], self.RealBackend)
        arguments = sys.argv
        self.logDebug("Starting original backend %s with args %s" % (originalbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + arguments[1:])])))
        subprocess = Popen4ForCUPS([originalbackend] + arguments[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
        
        # Save file descriptors, we will need them later.
        stderrfno = sys.stderr.fileno()
        fromcfno = subprocess.fromchild.fileno()
        tocfno = subprocess.tochild.fileno()
        
        # We will have to be careful when dealing with I/O 
        # So we use a poll object to know when to read or write
        pollster = select.poll()
        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
        pollster.register(stderrfno, select.POLLOUT)
        pollster.register(tocfno, select.POLLOUT)
        
        # Initialize our buffers
        indata = ""
        outdata = ""
        endinput = endoutput = 0
        inputclosed = outputclosed = 0
        totaltochild = totalfromcups = 0
        totalfromchild = totaltocups = 0
        
        if self.InputFile is None :
           # this is not a real file, we read the job's data
            # from our temporary file which is a copy of stdin 
            inf = open(self.DataFile, "rb")
            infno = inf.fileno()
            pollster.register(infno, select.POLLIN | select.POLLPRI)
        else :    
            # job's data is in a file, no need to pass the data
            # to the original backend
            self.logDebug("Job's data is in %s" % self.InputFile)
            infno = None
            endinput = 1
        
        self.logDebug("Entering streams polling loop...")
        MEGABYTE = 1024*1024
        killed = 0
        status = -1
        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
            # First check if original backend is still alive
            status = subprocess.poll()
            
            # Now if we got SIGTERM, we have 
            # to kill -TERM the original backend
            if self.gotSigTerm and not killed :
                try :
                    os.kill(subprocess.pid, signal.SIGTERM)
                except OSError, msg : # ignore but logs if process was already killed.
                    self.logDebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg))
                else :    
                    self.logInfo(_("SIGTERM was sent to original backend %s (PID %s)") % (originalbackend, subprocess.pid))
                    killed = 1
            
            # In any case, deal with any remaining I/O
            try :
                availablefds = pollster.poll(5000)
            except select.error, msg :    
                self.logDebug("Interrupted poll : %s" % msg)
                availablefds = []
            if not availablefds :
                self.logDebug("Nothing to do, sleeping a bit...")
                time.sleep(0.01) # give some time to the system
            else :
                for (fd, mask) in availablefds :
                    try :
                        if mask & select.POLLOUT :
                            # We can write
                            if fd == tocfno :
                                if indata :
                                    try :
                                        nbwritten = os.write(fd, indata)    
                                    except (OSError, IOError), msg :    
                                        self.logDebug("Error while writing to original backend's stdin %s : %s" % (fd, msg))
                                    else :    
                                        if len(indata) != nbwritten :
                                            self.logDebug("Short write to original backend's input !")
                                        totaltochild += nbwritten    
                                        self.logDebug("%s bytes sent to original backend so far..." % totaltochild)
                                        indata = indata[nbwritten:]
                                else :        
                                    self.logDebug("No data to send to original backend yet, sleeping a bit...")
                                    time.sleep(0.01)
                                    
                                if endinput :    
                                    self.unregisterFileNo(pollster, tocfno)        
                                    self.logDebug("Closing original backend's stdin.")
                                    os.close(tocfno)
                                    inputclosed = 1
                            elif fd == stderrfno :
                                if outdata :
                                    try :
                                        nbwritten = os.write(fd, outdata)
                                    except (OSError, IOError), msg :    
                                        self.logDebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
                                    else :
                                        if len(outdata) != nbwritten :
                                            self.logDebug("Short write to stderr (CUPS) !")
                                        totaltocups += nbwritten    
                                        self.logDebug("%s bytes sent back to CUPS so far..." % totaltocups)
                                        outdata = outdata[nbwritten:]
                                else :        
                                    # self.logDebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
                                    
                                if endoutput :    
                                    self.unregisterFileNo(pollster, stderrfno)        
                                    outputclosed = 1
                            else :    
                                self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
                                time.sleep(0.01)
                                
                        if mask & (select.POLLIN | select.POLLPRI) :     
                            # We have something to read
                            try :
                                data = os.read(fd, MEGABYTE)
                            except (IOError, OSError), msg :    
                                self.logDebug("Error while reading file %s : %s" % (fd, msg))
                            else :
                                if fd == infno :
                                    if not data :    # If yes, then no more input data
                                        self.unregisterFileNo(pollster, infno)
                                        self.logDebug("Input data ends.")
                                        endinput = 1 # this happens with real files.
                                    else :    
                                        indata += data
                                        totalfromcups += len(data)
                                        self.logDebug("%s bytes read from CUPS so far..." % totalfromcups)
                                elif fd == fromcfno :
                                    if not data :
                                        self.logDebug("No back channel data to read from original backend yet, sleeping a bit...")
                                        time.sleep(0.01)
                                    else :
                                        outdata += data
                                        totalfromchild += len(data)
                                        self.logDebug("%s bytes read from original backend so far..." % totalfromchild)
                                else :    
                                    self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
                                    time.sleep(0.01)
                                    
                        if mask & (select.POLLHUP | select.POLLERR) :
                            # Treat POLLERR as an EOF.
                            # Some standard I/O stream has no more datas
                            self.unregisterFileNo(pollster, fd)
                            if fd == infno :
                                # Here we are in the case where the input file is stdin.
                                # which has no more data to be read.
                                self.logDebug("Input data ends.")
                                endinput = 1
                            elif fd == fromcfno :    
                                # We are no more interested in this file descriptor        
                                self.logDebug("Closing original backend's stdout+stderr.")
                                os.close(fromcfno)
                                endoutput = 1
                            else :    
                                self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
                                time.sleep(0.01)
                                
                        if mask & select.POLLNVAL :        
                            self.logDebug("File %s was closed. Unregistering from polling object." % fd)
                            self.unregisterFileNo(pollster, fd)
                    except IOError, msg :            
                        self.logDebug("Got an IOError : %s" % msg) # we got signalled during an I/O
                
        # We must close the original backend's input stream
        if killed and not inputclosed :
            self.logDebug("Forcing close of original backend's stdin.")
            os.close(tocfno)
        
        self.logDebug("Exiting streams polling loop...")
        
        self.logDebug("input data's final length : %s" % len(indata))
        self.logDebug("back-channel data's final length : %s" % len(outdata))
        
        self.logDebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups)
        self.logDebug("Total bytes sent to original backend (job's datas) : %s" % totaltochild)
        
        self.logDebug("Total bytes read from original backend (back-channel datas) : %s" % totalfromchild)
        self.logDebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups)
        
        # Check exit code of original CUPS backend.    
        if status == -1 :
            # we exited the loop before the original backend exited
            # now we have to wait for it to finish and get its status
            self.logDebug("Waiting for original backend to exit...")
            try :
                status = subprocess.wait()
            except OSError : # already dead : TODO : detect when abnormal
                status = 0
        if os.WIFEXITED(status) :
            return os.WEXITSTATUS(status)
        elif not killed :    
            self.logInfo("CUPS backend %s died abnormally." % originalbackend, "error")
            return -1
        else :    
            return 1
        
if __name__ == "__main__" :    
    # This is a CUPS backend, we should act and die like a CUPS backend
    wrapper = CupsBackend()
    if len(sys.argv) == 1 :
        print "\n".join(wrapper.discoverOtherBackends())
        sys.exit(0)                
    elif len(sys.argv) not in (6, 7) :    
        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n"\
                              % sys.argv[0])
        sys.exit(1)
    else :    
        try :
            wrapper.readConfig()
            wrapper.initBackend()
            wrapper.saveDatasAndCheckSum()
            wrapper.exportAttributes()
            retcode = wrapper.runBranches()
            wrapper.cleanUp()
        except SystemExit, e :    
            retcode = e.code
        except :    
            import traceback
            lines = []
            for line in traceback.format_exception(*sys.exc_info()) :
                lines.extend([l for l in line.split("\n") if l])
            msg = "ERROR: ".join(["%s (PID %s) : %s\n" % (wrapper.MyName, wrapper.pid, l) for l in (["ERROR: Tea4CUPS v%s" % version] + lines)])
            sys.stderr.write(msg)
            sys.stderr.flush()
            retcode = 1
        sys.exit(retcode)