root / tea4cups / trunk / tea4cups @ 631

Revision 631, 41.4 kB (checked in by jerome, 19 years ago)

Improved the IPP parser

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