root / tea4cups / trunk / tea4cups @ 632

Revision 632, 41.5 kB (checked in by jerome, 19 years ago)

Now decodes integers and enums in the IPP messages

  • Property svn:executable set to *
  • Property svn:keywords set to Author Date Id Rev
Line 
1#! /usr/bin/env python
2# -*- coding: ISO-8859-15 -*-
3
4# Tea4CUPS : Tee for CUPS
5#
6# (c) 2005 Jerome Alet <alet@librelogiciel.com>
7# This program is free software; you can redistribute it and/or modify
8# it under the terms of the GNU General Public License as published by
9# the Free Software Foundation; either version 2 of the License, or
10# (at your option) any later version.
11#
12# This program is distributed in the hope that it will be useful,
13# but WITHOUT ANY WARRANTY; without even the implied warranty of
14# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15# GNU General Public License for more details.
16#
17# You should have received a copy of the GNU General Public License
18# along with this program; if not, write to the Free Software
19# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307, USA.
20#
21# $Id$
22#
23#
24
25import sys
26import os
27import pwd
28import popen2
29import errno
30import md5
31import cStringIO
32import shlex
33import tempfile
34import ConfigParser
35import select
36import signal
37import time
38from struct import unpack
39
40version = "2.12alpha_unofficial"
41
42class TeeError(Exception):
43    """Base exception for Tea4CUPS related stuff."""
44    def __init__(self, message = ""):
45        self.message = message
46        Exception.__init__(self, message)
47    def __repr__(self):
48        return self.message
49    __str__ = __repr__
50   
51class ConfigError(TeeError) :   
52    """Configuration related exceptions."""
53    pass 
54   
55class IPPError(TeeError) :   
56    """IPP related exceptions."""
57    pass 
58   
59class Popen4ForCUPS(popen2.Popen4) :
60    """Our own class to execute real backends.
61   
62       Their first argument is different from their path so using
63       native popen2.Popen3 would not be feasible.
64    """
65    def __init__(self, cmd, bufsize=-1, arg0=None) :
66        self.arg0 = arg0
67        popen2.Popen4.__init__(self, cmd, bufsize)
68       
69    def _run_child(self, cmd):
70        try :
71            MAXFD = os.sysconf("SC_OPEN_MAX")
72        except (AttributeError, ValueError) :   
73            MAXFD = 256
74        for i in range(3, MAXFD) : 
75            try:
76                os.close(i)
77            except OSError:
78                pass
79        try:
80            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
81        finally:
82            os._exit(1)
83   
84# Some IPP constants   
85OPERATION_ATTRIBUTES_TAG = 0x01
86JOB_ATTRIBUTES_TAG = 0x02
87END_OF_ATTRIBUTES_TAG = 0x03
88PRINTER_ATTRIBUTES_TAG = 0x04
89UNSUPPORTED_ATTRIBUTES_TAG = 0x05
90
91class IPPMessage :
92    """A class for IPP message files."""
93    def __init__(self, data, debug=0) :
94        """Initializes an IPP Message object."""
95        self.debug = debug
96        self.data = data
97        self.operation_attributes = {}
98        self.job_attributes = {}
99        self.printer_attributes = {}
100        self.tags = [ None ] * 256      # by default all tags reserved
101       
102        # Delimiter tags
103        self.tags[0x01] = "operation-attributes-tag"
104        self.tags[0x02] = "job-attributes-tag"
105        self.tags[0x03] = "end-of-attributes-tag"
106        self.tags[0x04] = "printer-attributes-tag"
107        self.tags[0x05] = "unsupported-attributes-tag"
108       
109        # out of band values
110        self.tags[0x10] = "unsupported"
111        self.tags[0x11] = "reserved-for-future-default"
112        self.tags[0x12] = "unknown"
113        self.tags[0x13] = "no-value"
114       
115        # integer values
116        self.tags[0x20] = "generic-integer"
117        self.tags[0x21] = "integer"
118        self.tags[0x22] = "boolean"
119        self.tags[0x23] = "enum"
120       
121        # octetString
122        self.tags[0x30] = "octetString-with-an-unspecified-format"
123        self.tags[0x31] = "dateTime"
124        self.tags[0x32] = "resolution"
125        self.tags[0x33] = "rangeOfInteger"
126        self.tags[0x34] = "reserved-for-collection"
127        self.tags[0x35] = "textWithLanguage"
128        self.tags[0x36] = "nameWithLanguage"
129       
130        # character strings
131        self.tags[0x20] = "generic-character-string"
132        self.tags[0x41] = "textWithoutLanguage"
133        self.tags[0x42] = "nameWithoutLanguage"
134        # self.tags[0x43] = "reserved"
135        self.tags[0x44] = "keyword"
136        self.tags[0x45] = "uri"
137        self.tags[0x46] = "uriScheme"
138        self.tags[0x47] = "charset"
139        self.tags[0x48] = "naturalLanguage"
140        self.tags[0x49] = "mimeMediaType"
141       
142        # now parses the IPP message
143        self.parse()
144       
145    def parseTag(self) :   
146        """Extracts information from an IPP tag."""
147        pos = self.position
148        valuetag = self.tags[ord(self.data[pos])]
149        pos += 1
150        posend = pos2 = pos + 2
151        namelength = unpack(">H", self.data[pos:pos2])[0]
152        if not namelength :
153            name = self._curname
154        else :   
155            posend += namelength
156            self._curname = name = self.data[pos2:posend]
157        pos2 = posend + 2
158        valuelength = unpack(">H", self.data[posend:pos2])[0]
159        posend = pos2 + valuelength
160        value = self.data[pos2:posend]
161        if valuetag in ("integer", "enum") :
162            value = unpack(">I", value)
163        oldval = self._curdict.setdefault(name, [])
164        oldval.append((valuetag, value))
165        self.printInfo("%s(%s) %s" % (name, valuetag, value))
166        return posend - self.position
167       
168    def operation_attributes_tag(self) : 
169        """Indicates that the parser enters into an operation-attributes-tag group."""
170        self.printInfo("Start of operation_attributes_tag")
171        self._curdict = self.operation_attributes
172        return self.parseTag()
173       
174    def job_attributes_tag(self) : 
175        """Indicates that the parser enters into an operation-attributes-tag group."""
176        self.printInfo("Start of job_attributes_tag")
177        self._curdict = self.job_attributes
178        return self.parseTag()
179       
180    def printer_attributes_tag(self) : 
181        """Indicates that the parser enters into an operation-attributes-tag group."""
182        self.printInfo("Start of printer_attributes_tag")
183        self._curdict = self.printer_attributes
184        return self.parseTag()
185       
186    def printInfo(self, msg) :   
187        """Prints a debug message."""
188        if self.debug :
189            sys.stderr.write("%s\n" % msg)
190            sys.stderr.flush()
191           
192    def parse(self) :
193        """Parses an IPP Message.
194       
195           NB : Only a subset of RFC2910 is implemented.
196           We are only interested in textual informations for now anyway.
197        """
198        self._curname = None
199        self._curdict = None
200        self.version = "%s.%s" % (ord(self.data[0]), ord(self.data[1]))
201        self.operation_id = "0x%04x" % unpack(">H", self.data[2:4])[0]
202        self.request_id = "0x%08x" % unpack(">I", self.data[4:8])[0]
203        self.position = 8
204        try :
205            tag = ord(self.data[self.position])
206            while tag != END_OF_ATTRIBUTES_TAG :
207                self.position += 1
208                name = self.tags[tag]
209                if name is not None :
210                    func = getattr(self, name.replace("-", "_"), None)
211                    if func is not None :
212                        self.position += func()
213                        if ord(self.data[self.position]) > UNSUPPORTED_ATTRIBUTES_TAG :
214                            self.position -= 1
215                            continue
216                tag = ord(self.data[self.position])
217        except IndexError :
218            raise IPPError, "Unexpected end of IPP message."
219           
220        # Now transform all one-element lists into single values
221        for attrtype in ("operation", "job", "printer") :
222            attrdict = getattr(self, "%s_attributes" % attrtype)
223            for (key, value) in attrdict.items() :
224                if len(value) == 1 :
225                    attrdict[key] = value[0]
226           
227class FakeConfig :   
228    """Fakes a configuration file parser."""
229    def get(self, section, option, raw=0) :
230        """Fakes the retrieval of an option."""
231        raise ConfigError, "Invalid configuration file : no option %s in section [%s]" % (option, section)
232       
233class CupsBackend :
234    """Base class for tools with no database access."""
235    def __init__(self) :
236        """Initializes the CUPS backend wrapper."""
237        signal.signal(signal.SIGTERM, signal.SIG_IGN)
238        signal.signal(signal.SIGPIPE, signal.SIG_IGN)
239        self.MyName = "Tea4CUPS"
240        self.myname = "tea4cups"
241        self.pid = os.getpid()
242       
243    def readConfig(self) :   
244        """Reads the configuration file."""
245        confdir = os.environ.get("CUPS_SERVERROOT", ".") 
246        self.conffile = os.path.join(confdir, "%s.conf" % self.myname)
247        if os.path.isfile(self.conffile) :
248            self.config = ConfigParser.ConfigParser()
249            self.config.read([self.conffile])
250            self.debug = self.isTrue(self.getGlobalOption("debug", ignore=1))
251        else :   
252            self.config = FakeConfig()
253            self.debug = 1      # no config, so force debug mode !
254           
255    def logInfo(self, message, level="info") :       
256        """Logs a message to CUPS' error_log file."""
257        sys.stderr.write("%s: %s v%s (PID %i) : %s\n" % (level.upper(), self.MyName, version, os.getpid(), message))
258        sys.stderr.flush()
259       
260    def logDebug(self, message) :   
261        """Logs something to debug output if debug is enabled."""
262        if self.debug :
263            self.logInfo(message, level="debug")
264       
265    def isTrue(self, option) :       
266        """Returns 1 if option is set to true, else 0."""
267        if (option is not None) and (option.upper().strip() in ['Y', 'YES', '1', 'ON', 'T', 'TRUE']) :
268            return 1
269        else :   
270            return 0
271                       
272    def getGlobalOption(self, option, ignore=0) :   
273        """Returns an option from the global section, or raises a ConfigError if ignore is not set, else returns None."""
274        try :
275            return self.config.get("global", option, raw=1)
276        except (ConfigParser.NoSectionError, ConfigParser.NoOptionError) :   
277            if not ignore :
278                raise ConfigError, "Option %s not found in section global of %s" % (option, self.conffile)
279               
280    def getPrintQueueOption(self, printqueuename, option, ignore=0) :   
281        """Returns an option from the printer section, or the global section, or raises a ConfigError."""
282        globaloption = self.getGlobalOption(option, ignore=1)
283        try :
284            return self.config.get(printqueuename, option, raw=1)
285        except (ConfigParser.NoSectionError, ConfigParser.NoOptionError) :   
286            if globaloption is not None :
287                return globaloption
288            elif not ignore :
289                raise ConfigError, "Option %s not found in section [%s] of %s" % (option, printqueuename, self.conffile)
290               
291    def enumBranches(self, printqueuename, branchtype="tee") :
292        """Returns the list of branchtypes branches for a particular section's."""
293        branchbasename = "%s_" % branchtype.lower()
294        try :
295            # globalbranches = [ (k, v) for (k, v) in self.config.items("global") if k.startswith(branchbasename) ]
296            globalbranches = [ (k, self.config.get("global", k)) for k in self.config.options("global") if k.startswith(branchbasename) ]
297        except ConfigParser.NoSectionError, msg :   
298            raise ConfigError, "Invalid configuration file : %s" % msg
299        try :
300            # sectionbranches = [ (k, v) for (k, v) in self.config.items(printqueuename) if k.startswith(branchbasename) ]
301            sectionbranches = [ (k, self.config.get(printqueuename, k)) for k in self.config.options(printqueuename) if k.startswith(branchbasename) ]
302        except ConfigParser.NoSectionError, msg :   
303            self.logInfo("No section for print queue %s : %s" % (printqueuename, msg))
304            sectionbranches = []
305        branches = {}
306        for (k, v) in globalbranches :
307            value = v.strip()
308            if value :
309                branches[k] = value
310        for (k, v) in sectionbranches :   
311            value = v.strip()
312            if value :
313                branches[k] = value # overwrite any global option or set a new value
314            else :   
315                del branches[k] # empty value disables a global option
316        return branches
317       
318    def discoverOtherBackends(self) :   
319        """Discovers the other CUPS backends.
320       
321           Executes each existing backend in turn in device enumeration mode.
322           Returns the list of available backends.
323        """
324        # Unfortunately this method can't output any debug information
325        # to stdout or stderr, else CUPS considers that the device is
326        # not available.
327        available = []
328        (directory, myname) = os.path.split(sys.argv[0])
329        if not directory :
330            directory = "./"
331        tmpdir = tempfile.gettempdir()
332        lockfilename = os.path.join(tmpdir, "%s..LCK" % myname)
333        if os.path.exists(lockfilename) :
334            lockfile = open(lockfilename, "r")
335            pid = int(lockfile.read())
336            lockfile.close()
337            try :
338                # see if the pid contained in the lock file is still running
339                os.kill(pid, 0)
340            except OSError, e :   
341                if e.errno != errno.EPERM :
342                    # process doesn't exist anymore
343                    os.remove(lockfilename)
344           
345        if not os.path.exists(lockfilename) :
346            lockfile = open(lockfilename, "w")
347            lockfile.write("%i" % self.pid)
348            lockfile.close()
349            allbackends = [ os.path.join(directory, b) \
350                                for b in os.listdir(directory) 
351                                    if os.access(os.path.join(directory, b), os.X_OK) \
352                                        and (b != myname)] 
353            for backend in allbackends :                           
354                answer = os.popen(backend, "r")
355                try :
356                    devices = [line.strip() for line in answer.readlines()]
357                except :   
358                    devices = []
359                status = answer.close()
360                if status is None :
361                    for d in devices :
362                        # each line is of the form :
363                        # 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
364                        # so we have to decompose it carefully
365                        fdevice = cStringIO.StringIO(d)
366                        tokenizer = shlex.shlex(fdevice)
367                        tokenizer.wordchars = tokenizer.wordchars + \
368                                                        r".:,?!~/\_$*-+={}[]()#"
369                        arguments = []
370                        while 1 :
371                            token = tokenizer.get_token()
372                            if token :
373                                arguments.append(token)
374                            else :
375                                break
376                        fdevice.close()
377                        try :
378                            (devicetype, device, name, fullname) = arguments
379                        except ValueError :   
380                            pass    # ignore this 'bizarre' device
381                        else :   
382                            if name.startswith('"') and name.endswith('"') :
383                                name = name[1:-1]
384                            if fullname.startswith('"') and fullname.endswith('"') :
385                                fullname = fullname[1:-1]
386                            available.append('%s %s:%s "%s+%s" "%s managed %s"' \
387                                                 % (devicetype, self.myname, device, self.MyName, name, self.MyName, fullname))
388            os.remove(lockfilename)
389        available.append('direct %s:// "%s+Nothing" "%s managed Virtual Printer"' \
390                             % (self.myname, self.MyName, self.MyName))
391        return available
392                       
393    def initBackend(self) :   
394        """Initializes the backend's attributes."""
395        # check that the DEVICE_URI environment variable's value is
396        # prefixed with self.myname otherwise don't touch it.
397        # If this is the case, we have to remove the prefix from
398        # the environment before launching the real backend
399        muststartwith = "%s:" % self.myname
400        device_uri = os.environ.get("DEVICE_URI", "")
401        if device_uri.startswith(muststartwith) :
402            fulldevice_uri = device_uri[:]
403            device_uri = fulldevice_uri[len(muststartwith):]
404            for i in range(2) :
405                if device_uri.startswith("/") : 
406                    device_uri = device_uri[1:]
407        try :
408            (backend, destination) = device_uri.split(":", 1) 
409        except ValueError :   
410            if not device_uri :
411                self.logDebug("Not attached to an existing print queue.")
412                backend = ""
413            else :   
414                raise TeeError, "Invalid DEVICE_URI : %s\n" % device_uri
415       
416        self.JobId = sys.argv[1].strip()
417        self.UserName = sys.argv[2].strip() or pwd.getpwuid(os.geteuid())[0] # use CUPS' user when printing test pages from CUPS' web interface
418        self.Title = sys.argv[3].strip()
419        self.Copies = int(sys.argv[4].strip())
420        self.Options = sys.argv[5].strip()
421        if len(sys.argv) == 7 :
422            self.InputFile = sys.argv[6] # read job's datas from file
423        else :   
424            self.InputFile = None        # read job's datas from stdin
425           
426        self.RealBackend = backend
427        self.DeviceURI = device_uri
428        self.PrinterName = os.environ.get("PRINTER", "")
429        self.Directory = self.getPrintQueueOption(self.PrinterName, "directory")
430        self.DataFile = os.path.join(self.Directory, "%s-%s-%s-%s" % (self.myname, self.PrinterName, self.UserName, self.JobId))
431        (ippfilename, ippmessage) = self.parseIPPMessageFile()
432        self.ControlFile = ippfilename
433        (chtype, self.ClientHost) = ippmessage.operation_attributes.get("job-originating-host-name", \
434                                          ippmessage.job_attributes.get("job-originating-host-name", (None, None)))
435        (jbtype, self.JobBilling) = ippmessage.job_attributes.get("job-billing", (None, None))
436           
437    def getCupsConfigDirectives(self, directives=[]) :
438        """Retrieves some CUPS directives from its configuration file.
439       
440           Returns a mapping with lowercased directives as keys and
441           their setting as values.
442        """
443        dirvalues = {} 
444        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
445        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
446        try :
447            conffile = open(cupsdconf, "r")
448        except IOError :   
449            raise TeeError, "Unable to open %s" % cupsdconf
450        else :   
451            for line in conffile.readlines() :
452                linecopy = line.strip().lower()
453                for di in [d.lower() for d in directives] :
454                    if linecopy.startswith("%s " % di) :
455                        try :
456                            val = line.split()[1]
457                        except :   
458                            pass # ignore errors, we take the last value in any case.
459                        else :   
460                            dirvalues[di] = val
461            conffile.close()           
462        return dirvalues       
463           
464    def parseIPPMessageFile(self) :       
465        """Parses the IPP message file and returns a tuple (filename, parsedvalue)."""
466        cupsdconf = self.getCupsConfigDirectives(["RequestRoot"])
467        requestroot = cupsdconf.get("requestroot", "/var/spool/cups")
468        if (len(self.JobId) < 5) and self.JobId.isdigit() :
469            ippmessagefile = "c%05i" % int(self.JobId)
470        else :   
471            ippmessagefile = "c%s" % self.JobId
472        ippmessagefile = os.path.join(requestroot, ippmessagefile)
473        ippmessage = {}
474        try :
475            ippdatafile = open(ippmessagefile)
476        except :   
477            self.logInfo("Unable to open IPP message file %s" % ippmessagefile, "warn")
478        else :   
479            self.logDebug("Parsing of IPP message file %s begins." % ippmessagefile)
480            try :
481                ippmessage = IPPMessage(ippdatafile.read())
482            except IPPError, msg :   
483                self.logInfo("Error while parsing %s : %s" % (ippmessagefile, msg), "warn")
484            else :   
485                self.logDebug("Parsing of IPP message file %s ends." % ippmessagefile)
486            ippdatafile.close()
487        return (ippmessagefile, ippmessage)
488               
489    def exportAttributes(self) :   
490        """Exports our backend's attributes to the environment."""
491        os.environ["DEVICE_URI"] = self.DeviceURI       # WARNING !
492        os.environ["TEAPRINTERNAME"] = self.PrinterName
493        os.environ["TEADIRECTORY"] = self.Directory
494        os.environ["TEADATAFILE"] = self.DataFile
495        os.environ["TEAJOBSIZE"] = str(self.JobSize)
496        os.environ["TEAMD5SUM"] = self.JobMD5Sum
497        os.environ["TEACLIENTHOST"] = self.ClientHost or ""
498        os.environ["TEAJOBID"] = self.JobId
499        os.environ["TEAUSERNAME"] = self.UserName
500        os.environ["TEATITLE"] = self.Title
501        os.environ["TEACOPIES"] = str(self.Copies)
502        os.environ["TEAOPTIONS"] = self.Options
503        os.environ["TEAINPUTFILE"] = self.InputFile or ""
504        os.environ["TEABILLING"] = self.JobBilling or ""
505        os.environ["TEACONTROLFILE"] = self.ControlFile
506       
507    def saveDatasAndCheckSum(self) :
508        """Saves the input datas into a static file."""
509        self.logDebug("Duplicating data stream into %s" % self.DataFile)
510        mustclose = 0
511        if self.InputFile is not None :
512            infile = open(self.InputFile, "rb")
513            mustclose = 1
514        else :   
515            infile = sys.stdin
516        CHUNK = 64*1024         # read 64 Kb at a time
517        dummy = 0
518        sizeread = 0
519        checksum = md5.new()
520        outfile = open(self.DataFile, "wb")   
521        while 1 :
522            data = infile.read(CHUNK) 
523            if not data :
524                break
525            sizeread += len(data)   
526            outfile.write(data)
527            checksum.update(data)   
528            if not (dummy % 32) : # Only display every 2 Mb
529                self.logDebug("%s bytes saved..." % sizeread)
530            dummy += 1   
531        outfile.close()
532        if mustclose :   
533            infile.close()
534        self.JobSize = sizeread   
535        self.JobMD5Sum = checksum.hexdigest()
536        self.logDebug("Job %s is %s bytes long." % (self.JobId, self.JobSize))
537        self.logDebug("Job %s MD5 sum is %s" % (self.JobId, self.JobMD5Sum))
538
539    def cleanUp(self) :
540        """Cleans up the place."""
541        if not self.isTrue(self.getPrintQueueOption(self.PrinterName, "keepfiles", ignore=1)) :
542            os.remove(self.DataFile)
543           
544    def sigtermHandler(self, signum, frame) :
545        """Sets an attribute whenever SIGTERM is received."""
546        self.gotSigTerm = 1
547        self.logInfo("SIGTERM received for Job %s." % self.JobId)
548       
549    def runBranches(self) :         
550        """Launches each hook or tee defined for the current print queue."""
551        exitcode = 0
552        self.isCancelled = 0    # did a prehook cancel the print job ?
553        self.gotSigTerm = 0
554        signal.signal(signal.SIGTERM, self.sigtermHandler)
555        serialize = self.isTrue(self.getPrintQueueOption(self.PrinterName, "serialize", ignore=1))
556        for branchtype in ["prehook", "tee", "posthook"] :
557            branches = self.enumBranches(self.PrinterName, branchtype)
558            status = self.runCommands(branchtype, branches, serialize)
559            if status :
560                if branchtype != "posthook" :
561                    exitcode = status
562                else :   
563                    # we just ignore error in posthooks
564                    self.logInfo("An error occured during the execution of posthooks.", "warn")
565            if (branchtype == "prehook") and self.isCancelled :
566                break # We don't want to execute tees or posthooks in this case
567        signal.signal(signal.SIGTERM, signal.SIG_IGN)
568        if not exitcode :
569            self.logInfo("OK")
570        else :   
571            self.logInfo("An error occured, please check CUPS' error_log file.")
572        return exitcode
573       
574    def runCommands(self, btype, branches, serialize) :   
575        """Runs the commands for a particular branch type."""
576        exitcode = 0 
577        btype = btype.lower()
578        btypetitle = btype.title()
579        branchlist = branches.keys()   
580        branchlist.sort()
581        if serialize :
582            self.logDebug("Begin serialized %ss" % btypetitle)
583            if (btype == "tee") and self.RealBackend :
584                self.logDebug("Launching original backend %s for printer %s" % (self.RealBackend, self.PrinterName))
585                retcode = self.runOriginalBackend()
586                if os.WIFEXITED(retcode) :
587                    retcode = os.WEXITSTATUS(retcode)
588                os.environ["TEASTATUS"] = str(retcode)
589                exitcode = retcode
590            for branch in branchlist :
591                command = branches[branch]
592                if self.gotSigTerm :
593                    break
594                self.logDebug("Launching %s : %s" % (branch, command))
595                retcode = os.system(command)
596                self.logDebug("Exit code for %s %s on printer %s is %s" % (btype, branch, self.PrinterName, retcode))
597                if os.WIFEXITED(retcode) :
598                    retcode = os.WEXITSTATUS(retcode)
599                if retcode :   
600                    if (btype == "prehook") and (retcode == 255) : # -1
601                        self.logInfo("Job %s cancelled by prehook %s" % (self.JobId, branch))
602                        self.isCancelled = 1
603                    else :   
604                        self.logInfo("%s %s on printer %s didn't exit successfully." % (btypetitle, branch, self.PrinterName), "error")
605                        exitcode = 1
606            self.logDebug("End serialized %ss" % btypetitle)
607        else :       
608            self.logDebug("Begin forked %ss" % btypetitle)
609            pids = {}
610            if (btype == "tee") and self.RealBackend :
611                branches["Original backend"] = None     # Fakes a tee to launch one more child
612                branchlist = ["Original backend"] + branchlist
613            for branch in branchlist :
614                command = branches[branch]
615                if self.gotSigTerm :
616                    break
617                pid = os.fork()
618                if pid :
619                    pids[branch] = pid
620                else :   
621                    if branch == "Original backend" :
622                        self.logDebug("Launching original backend %s for printer %s" % (self.RealBackend, self.PrinterName))
623                        sys.exit(self.runOriginalBackend())
624                    else :
625                        self.logDebug("Launching %s : %s" % (branch, command))
626                        retcode = os.system(command)
627                        if os.WIFEXITED(retcode) :
628                            retcode = os.WEXITSTATUS(retcode)
629                        else :   
630                            retcode = -1
631                        sys.exit(retcode)
632            for (branch, pid) in pids.items() :
633                (childpid, retcode) = os.waitpid(pid, 0)
634                self.logDebug("Exit code for %s %s (PID %s) on printer %s is %s" % (btype, branch, childpid, self.PrinterName, retcode))
635                if os.WIFEXITED(retcode) :
636                    retcode = os.WEXITSTATUS(retcode)
637                if retcode :   
638                    if (btype == "prehook") and (retcode == 255) : # -1
639                        self.logInfo("Job %s cancelled by prehook %s" % (self.JobId, branch))
640                        self.isCancelled = 1
641                    else :   
642                        self.logInfo("%s %s (PID %s) on printer %s didn't exit successfully." % (btypetitle, branch, childpid, self.PrinterName), "error")
643                        exitcode = 1
644                if branch == "Original backend" :   
645                    os.environ["TEASTATUS"] = str(retcode)
646            self.logDebug("End forked %ss" % btypetitle)
647        return exitcode
648       
649    def unregisterFileNo(self, pollobj, fileno) :               
650        """Removes a file handle from the polling object."""
651        try :
652            pollobj.unregister(fileno)
653        except KeyError :   
654            self.logInfo("File number %s unregistered twice from polling object, ignored." % fileno, "warn")
655        except :   
656            self.logDebug("Error while unregistering file number %s from polling object." % fileno)
657        else :   
658            self.logDebug("File number %s unregistered from polling object." % fileno)
659           
660    def formatFileEvent(self, fd, mask) :       
661        """Formats file debug info."""
662        maskval = []
663        if mask & select.POLLIN :
664            maskval.append("POLLIN")
665        if mask & select.POLLOUT :
666            maskval.append("POLLOUT")
667        if mask & select.POLLPRI :
668            maskval.append("POLLPRI")
669        if mask & select.POLLERR :
670            maskval.append("POLLERR")
671        if mask & select.POLLHUP :
672            maskval.append("POLLHUP")
673        if mask & select.POLLNVAL :
674            maskval.append("POLLNVAL")
675        return "%s (%s)" % (fd, " | ".join(maskval))
676       
677    def runOriginalBackend(self) :   
678        """Launches the original backend."""
679        originalbackend = os.path.join(os.path.split(sys.argv[0])[0], self.RealBackend)
680        arguments = sys.argv
681        self.logDebug("Starting original backend %s with args %s" % (originalbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + arguments[1:])])))
682        subprocess = Popen4ForCUPS([originalbackend] + arguments[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
683       
684        # Save file descriptors, we will need them later.
685        stderrfno = sys.stderr.fileno()
686        fromcfno = subprocess.fromchild.fileno()
687        tocfno = subprocess.tochild.fileno()
688       
689        # We will have to be careful when dealing with I/O
690        # So we use a poll object to know when to read or write
691        pollster = select.poll()
692        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
693        pollster.register(stderrfno, select.POLLOUT)
694        pollster.register(tocfno, select.POLLOUT)
695       
696        # Initialize our buffers
697        indata = ""
698        outdata = ""
699        endinput = endoutput = 0
700        inputclosed = outputclosed = 0
701        totaltochild = totalfromcups = 0
702        totalfromchild = totaltocups = 0
703       
704        if self.InputFile is None :
705           # this is not a real file, we read the job's data
706            # from our temporary file which is a copy of stdin
707            inf = open(self.DataFile, "rb")
708            infno = inf.fileno()
709            pollster.register(infno, select.POLLIN | select.POLLPRI)
710        else :   
711            # job's data is in a file, no need to pass the data
712            # to the original backend
713            self.logDebug("Job's data is in %s" % self.InputFile)
714            infno = None
715            endinput = 1
716       
717        self.logDebug("Entering streams polling loop...")
718        MEGABYTE = 1024*1024
719        killed = 0
720        status = -1
721        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
722            # First check if original backend is still alive
723            status = subprocess.poll()
724           
725            # Now if we got SIGTERM, we have
726            # to kill -TERM the original backend
727            if self.gotSigTerm and not killed :
728                try :
729                    os.kill(subprocess.pid, signal.SIGTERM)
730                except OSError, msg : # ignore but logs if process was already killed.
731                    self.logDebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg))
732                else :   
733                    self.logInfo(_("SIGTERM was sent to original backend %s (PID %s)") % (originalbackend, subprocess.pid))
734                    killed = 1
735           
736            # In any case, deal with any remaining I/O
737            try :
738                availablefds = pollster.poll(5000)
739            except select.error, msg :   
740                self.logDebug("Interrupted poll : %s" % msg)
741                availablefds = []
742            if not availablefds :
743                self.logDebug("Nothing to do, sleeping a bit...")
744                time.sleep(0.01) # give some time to the system
745            else :
746                for (fd, mask) in availablefds :
747                    try :
748                        if mask & select.POLLOUT :
749                            # We can write
750                            if fd == tocfno :
751                                if indata :
752                                    try :
753                                        nbwritten = os.write(fd, indata)   
754                                    except (OSError, IOError), msg :   
755                                        self.logDebug("Error while writing to original backend's stdin %s : %s" % (fd, msg))
756                                    else :   
757                                        if len(indata) != nbwritten :
758                                            self.logDebug("Short write to original backend's input !")
759                                        totaltochild += nbwritten   
760                                        self.logDebug("%s bytes sent to original backend so far..." % totaltochild)
761                                        indata = indata[nbwritten:]
762                                else :       
763                                    self.logDebug("No data to send to original backend yet, sleeping a bit...")
764                                    time.sleep(0.01)
765                                   
766                                if endinput :   
767                                    self.unregisterFileNo(pollster, tocfno)       
768                                    self.logDebug("Closing original backend's stdin.")
769                                    os.close(tocfno)
770                                    inputclosed = 1
771                            elif fd == stderrfno :
772                                if outdata :
773                                    try :
774                                        nbwritten = os.write(fd, outdata)
775                                    except (OSError, IOError), msg :   
776                                        self.logDebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
777                                    else :
778                                        if len(outdata) != nbwritten :
779                                            self.logDebug("Short write to stderr (CUPS) !")
780                                        totaltocups += nbwritten   
781                                        self.logDebug("%s bytes sent back to CUPS so far..." % totaltocups)
782                                        outdata = outdata[nbwritten:]
783                                else :       
784                                    # self.logDebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
785                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
786                                   
787                                if endoutput :   
788                                    self.unregisterFileNo(pollster, stderrfno)       
789                                    outputclosed = 1
790                            else :   
791                                self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
792                                time.sleep(0.01)
793                               
794                        if mask & (select.POLLIN | select.POLLPRI) :     
795                            # We have something to read
796                            try :
797                                data = os.read(fd, MEGABYTE)
798                            except (IOError, OSError), msg :   
799                                self.logDebug("Error while reading file %s : %s" % (fd, msg))
800                            else :
801                                if fd == infno :
802                                    if not data :    # If yes, then no more input data
803                                        self.unregisterFileNo(pollster, infno)
804                                        self.logDebug("Input data ends.")
805                                        endinput = 1 # this happens with real files.
806                                    else :   
807                                        indata += data
808                                        totalfromcups += len(data)
809                                        self.logDebug("%s bytes read from CUPS so far..." % totalfromcups)
810                                elif fd == fromcfno :
811                                    if not data :
812                                        self.logDebug("No back channel data to read from original backend yet, sleeping a bit...")
813                                        time.sleep(0.01)
814                                    else :
815                                        outdata += data
816                                        totalfromchild += len(data)
817                                        self.logDebug("%s bytes read from original backend so far..." % totalfromchild)
818                                else :   
819                                    self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
820                                    time.sleep(0.01)
821                                   
822                        if mask & (select.POLLHUP | select.POLLERR) :
823                            # Treat POLLERR as an EOF.
824                            # Some standard I/O stream has no more datas
825                            self.unregisterFileNo(pollster, fd)
826                            if fd == infno :
827                                # Here we are in the case where the input file is stdin.
828                                # which has no more data to be read.
829                                self.logDebug("Input data ends.")
830                                endinput = 1
831                            elif fd == fromcfno :   
832                                # We are no more interested in this file descriptor       
833                                self.logDebug("Closing original backend's stdout+stderr.")
834                                os.close(fromcfno)
835                                endoutput = 1
836                            else :   
837                                self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
838                                time.sleep(0.01)
839                               
840                        if mask & select.POLLNVAL :       
841                            self.logDebug("File %s was closed. Unregistering from polling object." % fd)
842                            self.unregisterFileNo(pollster, fd)
843                    except IOError, msg :           
844                        self.logDebug("Got an IOError : %s" % msg) # we got signalled during an I/O
845               
846        # We must close the original backend's input stream
847        if killed and not inputclosed :
848            self.logDebug("Forcing close of original backend's stdin.")
849            os.close(tocfno)
850       
851        self.logDebug("Exiting streams polling loop...")
852       
853        self.logDebug("input data's final length : %s" % len(indata))
854        self.logDebug("back-channel data's final length : %s" % len(outdata))
855       
856        self.logDebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups)
857        self.logDebug("Total bytes sent to original backend (job's datas) : %s" % totaltochild)
858       
859        self.logDebug("Total bytes read from original backend (back-channel datas) : %s" % totalfromchild)
860        self.logDebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups)
861       
862        # Check exit code of original CUPS backend.   
863        if status == -1 :
864            # we exited the loop before the original backend exited
865            # now we have to wait for it to finish and get its status
866            self.logDebug("Waiting for original backend to exit...")
867            try :
868                status = subprocess.wait()
869            except OSError : # already dead : TODO : detect when abnormal
870                status = 0
871        if os.WIFEXITED(status) :
872            return os.WEXITSTATUS(status)
873        elif not killed :   
874            self.logInfo("CUPS backend %s died abnormally." % originalbackend, "error")
875            return -1
876        else :   
877            return 1
878       
879if __name__ == "__main__" :   
880    # This is a CUPS backend, we should act and die like a CUPS backend
881    wrapper = CupsBackend()
882    if len(sys.argv) == 1 :
883        print "\n".join(wrapper.discoverOtherBackends())
884        sys.exit(0)               
885    elif len(sys.argv) not in (6, 7) :   
886        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n"\
887                              % sys.argv[0])
888        sys.exit(1)
889    else :   
890        try :
891            wrapper.readConfig()
892            wrapper.initBackend()
893            wrapper.saveDatasAndCheckSum()
894            wrapper.exportAttributes()
895            retcode = wrapper.runBranches()
896            wrapper.cleanUp()
897        except SystemExit, e :   
898            retcode = e.code
899        except :   
900            import traceback
901            lines = []
902            for line in traceback.format_exception(*sys.exc_info()) :
903                lines.extend([l for l in line.split("\n") if l])
904            msg = "ERROR: ".join(["%s (PID %s) : %s\n" % (wrapper.MyName, wrapper.pid, l) for l in (["ERROR: Tea4CUPS v%s" % version] + lines)])
905            sys.stderr.write(msg)
906            sys.stderr.flush()
907            retcode = 1
908        sys.exit(retcode)
Note: See TracBrowser for help on using the browser.