root / pykota / trunk / bin / cupspykota @ 2389

Revision 2389, 39.0 kB (checked in by jerome, 19 years ago)

Added a debug message.
Changed version.

  • Property svn:eol-style set to native
  • Property svn:executable set to *
  • Property svn:keywords set to Author Date Id Revision
RevLine 
[1177]1#! /usr/bin/env python
2# -*- coding: ISO-8859-15 -*-
3
4# CUPSPyKota accounting backend
5#
6# PyKota - Print Quotas for CUPS and LPRng
7#
[2028]8# (c) 2003, 2004, 2005 Jerome Alet <alet@librelogiciel.com>
[1177]9# This program is free software; you can redistribute it and/or modify
10# it under the terms of the GNU General Public License as published by
11# the Free Software Foundation; either version 2 of the License, or
12# (at your option) any later version.
13#
14# This program is distributed in the hope that it will be useful,
15# but WITHOUT ANY WARRANTY; without even the implied warranty of
16# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
17# GNU General Public License for more details.
18#
19# You should have received a copy of the GNU General Public License
20# along with this program; if not, write to the Free Software
[2303]21# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
[1177]22#
23# $Id$
24#
[2066]25#
[1177]26
27import sys
28import os
[2164]29import errno
30import tempfile
[1182]31import popen2
[1178]32import cStringIO
33import shlex
[1182]34import select
35import signal
[1291]36import time
[1177]37
[1546]38from pykota.tool import PyKotaFilterOrBackend, PyKotaToolError, crashed
[1177]39from pykota.config import PyKotaConfigError
40from pykota.storage import PyKotaStorageError
[1196]41from pykota.accounter import PyKotaAccounterError
[2313]42from pykota.ipp import IPPRequest, IPPError
[1271]43   
[1478]44class PyKotaPopen4(popen2.Popen4) :
[1182]45    """Our own class to execute real backends.
46   
47       Their first argument is different from their path so using
48       native popen2.Popen3 would not be feasible.
49    """
[1478]50    def __init__(self, cmd, bufsize=-1, arg0=None) :
[1182]51        self.arg0 = arg0
[1478]52        popen2.Popen4.__init__(self, cmd, bufsize)
[1182]53       
54    def _run_child(self, cmd):
[1704]55        try :
56            MAXFD = os.sysconf("SC_OPEN_MAX")
57        except (AttributeError, ValueError) :   
58            MAXFD = 256
59        for i in range(3, MAXFD) : 
[1182]60            try:
61                os.close(i)
62            except OSError:
63                pass
64        try:
65            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
66        finally:
67            os._exit(1)
68   
[1271]69class PyKotaBackend(PyKotaFilterOrBackend) :       
70    """A class for the pykota backend."""
71    def acceptJob(self) :       
72        """Returns the appropriate exit code to tell CUPS all is OK."""
73        return 0
74           
75    def removeJob(self) :           
76        """Returns the appropriate exit code to let CUPS think all is OK.
[1177]77       
[1271]78           Returning 0 (success) prevents CUPS from stopping the print queue.
79        """   
80        return 0
[1222]81       
[2060]82    def genBanner(self, bannerfileorcommand) :
83        """Reads a banner or generates one through an external command.
84       
85           Returns the banner's content in a format which MUST be accepted
86           by the printer.
87        """
88        if bannerfileorcommand :
89            banner = "" # no banner by default
90            if os.access(bannerfileorcommand, os.X_OK) or not os.path.isfile(bannerfileorcommand) :
91                self.logdebug("Launching %s to generate a banner." % bannerfileorcommand)
92                child = popen2.Popen3(bannerfileorcommand, capturestderr=1)
93                banner = child.fromchild.read()
94                child.tochild.close()
95                child.childerr.close()
96                child.fromchild.close()
97                status = child.wait()
98                if os.WIFEXITED(status) :
99                    status = os.WEXITSTATUS(status)
100                self.printInfo(_("Banner generator %s exit code is %s") % (bannerfileorcommand, str(status)))
101            else :
102                self.logdebug("Using %s as the banner." % bannerfileorcommand)
103                try :
104                    fh = open(bannerfileorcommand, 'r')
105                except IOError, msg :   
106                    self.printInfo("Impossible to open %s : %s" % (bannerfileorcommand, msg), "error")
107                else :   
108                    banner = fh.read()
109                    fh.close()
110            if banner :       
111                return cStringIO.StringIO(banner)
112   
113    def startingBanner(self, printername) :
114        """Retrieves a starting banner for current printer and returns its content."""
115        self.logdebug("Retrieving starting banner...")
116        return self.genBanner(self.config.getStartingBanner(printername))
117   
118    def endingBanner(self, printername) :
119        """Retrieves an ending banner for current printer and returns its content."""
120        self.logdebug("Retrieving ending banner...")
121        return self.genBanner(self.config.getEndingBanner(printername))
122       
[1901]123    def getCupsConfigDirectives(self, directives=[]) :
[1902]124        """Retrieves some CUPS directives from its configuration file.
125       
126           Returns a mapping with lowercased directives as keys and
127           their setting as values.
128        """
[1901]129        dirvalues = {} 
[1502]130        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
131        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
132        try :
133            conffile = open(cupsdconf, "r")
134        except IOError :   
[1503]135            self.logdebug("Unable to open %s" % cupsdconf)
[1502]136        else :   
137            for line in conffile.readlines() :
138                linecopy = line.strip().lower()
[1901]139                for di in [d.lower() for d in directives] :
140                    if linecopy.startswith("%s " % di) :
141                        try :
142                            val = line.split()[1]
143                        except :   
144                            pass # ignore errors, we take the last value in any case.
145                        else :   
146                            dirvalues[di] = val
[1502]147            conffile.close()           
[1901]148        return dirvalues       
[1502]149           
[2217]150    def getJobInfosFromPageLog(self, cupsconfig, printername, username, jobid) :
151        """Retrieves the job-originating-hostname and job-billing attributes from the CUPS page_log file if possible."""
[1901]152        pagelogpath = cupsconfig.get("pagelog", "/var/log/cups/page_log")
153        self.logdebug("Trying to extract job-originating-host-name from %s" % pagelogpath)
[1502]154        try :
155            pagelog = open(pagelogpath, "r")
156        except IOError :   
[1503]157            self.logdebug("Unable to open %s" % pagelogpath)
[2217]158            return (None, None) # no page log or can't read it, originating hostname unknown yet
[1502]159        else :   
160            # TODO : read backward so we could take first value seen
161            # TODO : here we read forward so we must take the last value seen
[1819]162            prefix = ("%s %s %s " % (printername, username, jobid)).lower()
[1502]163            matchingline = None
164            while 1 :
165                line = pagelog.readline()
166                if not line :
167                    break
168                else :
169                    line = line.strip()
[1530]170                    if line.lower().startswith(prefix) :   
[1502]171                        matchingline = line # no break, because we read forward
172            pagelog.close()       
173            if matchingline is None :
[1606]174                self.logdebug("No matching line found in %s" % pagelogpath)
[2217]175                return (None, None) # correct line not found, job-originating-host-name unknown
[1502]176            else :   
[2217]177                (jobbilling, hostname) = matchingline.split()[-2:]
178                if jobbilling == "-" :
179                    jobbilling = ""
180                return (jobbilling, hostname)   
[1502]181               
[1271]182    def doWork(self, policy, printer, user, userpquota) :   
183        """Most of the work is done here."""
184        # Two different values possible for policy here :
185        # ALLOW means : Either printer, user or user print quota doesn't exist,
186        #               but the job should be allowed anyway.
187        # OK means : Both printer, user and user print quota exist, job should
188        #            be allowed if current user is allowed to print on this printer
189        if policy == "OK" :
[1372]190            # exports user information with initial values
191            self.exportUserInfo(userpquota)
192           
[1901]193            # tries to extract job-originating-host-name and other information
[2177]194            self.regainPriv()
[1901]195            cupsdconf = self.getCupsConfigDirectives(["PageLog", "RequestRoot"])
196            requestroot = cupsdconf.get("requestroot", "/var/spool/cups")
197            if (len(self.jobid) < 5) and self.jobid.isdigit() :
198                ippmessagefile = "c%05i" % int(self.jobid)
199            else :   
200                ippmessagefile = "c%s" % self.jobid
201            ippmessagefile = os.path.join(requestroot, ippmessagefile)
202            ippmessage = {}
203            try :
204                ippdatafile = open(ippmessagefile)
205            except :   
206                self.printInfo("Unable to open IPP message file %s" % ippmessagefile, "warn")
207            else :   
208                self.logdebug("Parsing of IPP message file %s begins." % ippmessagefile)
[1902]209                try :
[2313]210                    ippmessage = IPPRequest(ippdatafile.read())
[2311]211                    ippmessage.parse()
212                except IPPError, msg :   
[1902]213                    self.printInfo("Error while parsing %s : %s" % (ippmessagefile, msg), "warn")
214                else :   
215                    self.logdebug("Parsing of IPP message file %s ends." % ippmessagefile)
[1901]216                ippdatafile.close()
[2007]217            self.dropPriv()   
[2254]218           
219            try :
220                (chtype, clienthost) = ippmessage.operation_attributes.get("job-originating-host-name", \
221                                          ippmessage.job_attributes.get("job-originating-host-name", (None, None)))
[2388]222                (jbtype, bcode) = ippmessage.job_attributes.get("job-billing", (None, None))
[2254]223            except AttributeError :   
224                clienthost = None
[2388]225                bcode = None
[2217]226            if clienthost is None :
[2388]227                (bcode, clienthost) = self.getJobInfosFromPageLog(cupsdconf, printer.Name, user.Name, self.jobid)
[1503]228            self.logdebug("Client Hostname : %s" % (clienthost or "Unknown"))   
[2388]229            self.logdebug("Billing Code : %s" % (bcode or "None"))   
[2254]230           
[2239]231            os.environ["PYKOTAJOBORIGINATINGHOSTNAME"] = str(clienthost or "")
[2388]232            os.environ["PYKOTAJOBBILLING"] = str(bcode or "")
[1502]233           
[1375]234            # enters first phase
[1517]235            os.environ["PYKOTAPHASE"] = "BEFORE"
[1375]236           
[2060]237            # precomputes the job's price
238            self.softwareJobPrice = userpquota.computeJobPrice(self.softwareJobSize)
[1517]239            os.environ["PYKOTAPRECOMPUTEDJOBPRICE"] = str(self.softwareJobPrice)
[2060]240            self.logdebug("Precomputed job's size is %s pages, price is %s units" % (self.softwareJobSize, self.softwareJobPrice))
[1519]241           
[2308]242            denyduplicates = self.config.getDenyDuplicates(printer.Name)
[1519]243            if not self.jobSizeBytes :
[2066]244                # if no data to pass to real backend, probably a filter
245                # higher in the chain failed because of a misconfiguration.
246                # we deny the job in this case (nothing to print anyway)
[1820]247                self.printMoreInfo(user, printer, _("Job contains no data. Printing is denied."), "warn")
[1519]248                action = "DENY"
[2308]249            elif denyduplicates \
[2066]250                 and printer.LastJob.Exists \
251                 and (printer.LastJob.UserName == user.Name) \
252                 and (printer.LastJob.JobMD5Sum == self.checksum) :
[2314]253                # TODO : use the current user's last job instead of 
254                # TODO : the current printer's last job. This would be
255                # TODO : better but requires an additional database query
256                # TODO : with SQL, and is much more complex with the
257                # TODO : actual LDAP schema. Maybe this is not very
258                # TODO : important, because usually dupes are rapidly sucessive.
[2308]259                if denyduplicates == 1 :
260                    self.printMoreInfo(user, printer, _("Job is a duplicate. Printing is denied."), "warn")
261                    action = "DENY"
262                else :   
263                    self.logdebug("Launching subprocess [%s] to see if dupes should be allowed or not." % denyduplicates)
264                    fanswer = os.popen(denyduplicates, "r")
265                    action = fanswer.read().strip().upper()
266                    fanswer.close()
267                    if action == "DENY" :     
268                        self.printMoreInfo(user, printer, _("Job is a duplicate. Printing is denied by subprocess."), "warn")
269                    else :   
270                        self.printMoreInfo(user, printer, _("Job is a duplicate. Printing is allowed by subprocess."), "warn")
[2388]271                        action = self.warnUserPQuota(userpquota)
[1606]272            else :   
273                # checks the user's quota
274                action = self.warnUserPQuota(userpquota)
[1519]275           
[2388]276            # Now handle the billing code
277            if bcode is not None :
[2389]278                self.logdebug("Checking billing code [%s]." % bcode)
[2388]279                billingcode = self.storage.getBillingCode(bcode)
280                if billingcode.Exists :
281                    self.logdebug("Billing code [%s] exists in database." % bcode)
282                else :
283                    msg = "Unknown billing code [%s] : " % bcode
284                    (newaction, script) = self.config.getUnknownBillingCode(printer.Name)
285                    if newaction == "CREATE" :
286                        self.logdebug(msg + "will be created.")
287                        billingcode = self.storage.addBillingCode(bcode)
288                        if billingcode.Exists :
289                            self.logdebug(msg + "has been created.")
290                        else :   
291                            self.printInfo(msg + "couldn't be created.", "error")
292                    else :   
293                        self.logdebug(msg + "job will be denied.")
294                        action = newaction
295                        if script is not None : 
296                            self.logdebug(msg + "launching subprocess [%s] to notify user." % script)
297                            os.system(script)
298            else :   
299                billingcode = None
300           
[1372]301            # exports some new environment variables
[1517]302            os.environ["PYKOTAACTION"] = action
[1372]303           
304            # launches the pre hook
305            self.prehook(userpquota)
[1918]306
307            # saves the size of banners which have to be accounted for
308            # this is needed in the case of software accounting
309            bannersize = 0
[1372]310           
[1918]311            # handle starting banner pages before accounting
312            accountbanner = self.config.getAccountBanner(printer.Name)
313            if accountbanner in ["ENDING", "NONE"] :
[2066]314                if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) :
[2054]315                    self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn")
316                else :
317                    if action == 'DENY' :
[2066]318                        self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name))
319                        userpquota.incDenyBannerCounter() # increments the warning counter
[2054]320                        self.exportUserInfo(userpquota)
321                    banner = self.startingBanner(printer.Name)
322                    if banner :
323                        self.logdebug("Printing starting banner before accounting begins.")
324                        self.handleData(banner)
[1918]325 
[1820]326            self.printMoreInfo(user, printer, _("Job accounting begins."))
[1624]327            self.accounter.beginJob(printer)
[1918]328           
329            # handle starting banner pages during accounting
330            if accountbanner in ["STARTING", "BOTH"] :
[2066]331                if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) :
[2054]332                    self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn")
333                else :
334                    if action == 'DENY' :
[2066]335                        self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name))
336                        userpquota.incDenyBannerCounter() # increments the warning counter
[2054]337                        self.exportUserInfo(userpquota)
338                    banner = self.startingBanner(printer.Name)
339                    if banner :
340                        self.logdebug("Printing starting banner during accounting.")
341                        self.handleData(banner)
342                        if self.accounter.isSoftware :
343                            bannersize += 1 # TODO : fix this by passing the banner's content through PDLAnalyzer
[1280]344        else :   
345            action = "ALLOW"
[1517]346            os.environ["PYKOTAACTION"] = action
[1271]347           
348        # pass the job's data to the real backend   
[1280]349        if action in ["ALLOW", "WARN"] :
[1291]350            if self.gotSigTerm :
[1280]351                retcode = self.removeJob()
352            else :   
353                retcode = self.handleData()       
354        else :       
[1271]355            retcode = self.removeJob()
356       
357        if policy == "OK" :       
[1374]358            # indicate phase change
[1517]359            os.environ["PYKOTAPHASE"] = "AFTER"
[1374]360           
[1918]361            # handle ending banner pages during accounting
362            if accountbanner in ["ENDING", "BOTH"] :
[2066]363                if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) :
[2054]364                    self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn")
365                else :
366                    if action == 'DENY' :
[2066]367                        self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name))
368                        userpquota.incDenyBannerCounter() # increments the warning counter
[2054]369                        self.exportUserInfo(userpquota)
370                    banner = self.endingBanner(printer.Name)
371                    if banner :
372                        self.logdebug("Printing ending banner during accounting.")
373                        self.handleData(banner)
374                        if self.accounter.isSoftware :
375                            bannersize += 1 # TODO : fix this by passing the banner's content through PDLAnalyzer
[1918]376 
[1271]377            # stops accounting.
[1624]378            self.accounter.endJob(printer)
[1820]379            self.printMoreInfo(user, printer, _("Job accounting ends."))
[1271]380               
381            # retrieve the job size   
[1321]382            if action == "DENY" :
383                jobsize = 0
[1820]384                self.printMoreInfo(user, printer, _("Job size forced to 0 because printing is denied."))
[1321]385            else :   
[2066]386                userpquota.resetDenyBannerCounter()
[2007]387                jobsize = self.accounter.getJobSize(printer)
[1974]388                if self.softwareJobSize and (jobsize != self.softwareJobSize) :
389                    self.printInfo(_("Beware : computed job size (%s) != precomputed job size (%s)") % (jobsize, self.softwareJobSize), "error")
[2062]390                    (limit, replacement) = self.config.getTrustJobSize(printer.Name)
391                    if limit is None :
392                        self.printInfo(_("The job size will be trusted anyway according to the 'trustjobsize' directive"), "warn")
393                    else :
394                        if jobsize <= limit :
395                            self.printInfo(_("The job size will be trusted because it is inferior to the 'trustjobsize' directive's limit %s") % limit, "warn")
396                        else :
397                            self.printInfo(_("The job size will be modified according to the 'trustjobsize' directive : %s") % replacement, "warn")
398                            if replacement == "PRECOMPUTED" :
399                                jobsize = self.softwareJobSize
400                            else :   
401                                jobsize = replacement
[2007]402                jobsize += bannersize   
[1820]403            self.printMoreInfo(user, printer, _("Job size : %i") % jobsize)
[1271]404           
405            # update the quota for the current user on this printer
[1606]406            self.printInfo(_("Updating user %s's quota on printer %s") % (user.Name, printer.Name))
[1285]407            jobprice = userpquota.increasePagesUsage(jobsize)
[1271]408           
409            # adds the current job to history   
[2057]410            printer.addJobToHistory(self.jobid, user, self.accounter.getLastPageCounter(), \
411                                    action, jobsize, jobprice, self.preserveinputfile, \
412                                    self.title, self.copies, self.options, clienthost, \
[2388]413                                    self.jobSizeBytes, self.checksum, None, bcode)
[1820]414            self.printMoreInfo(user, printer, _("Job added to history."))
[1271]415           
[2388]416            if billingcode and billingcode.Exists :
417                billingcode.consume(jobsize, jobprice)
418                self.printMoreInfo(user, printer, _("Billing code %s was updated.") % billingcode.BillingCode)
419               
[1372]420            # exports some new environment variables
[1517]421            os.environ["PYKOTAJOBSIZE"] = str(jobsize)
422            os.environ["PYKOTAJOBPRICE"] = str(jobprice)
[1372]423           
[1517]424            # then re-export user information with new value
[1372]425            self.exportUserInfo(userpquota)
426           
[1923]427            # handle ending banner pages after accounting ends
428            if accountbanner in ["STARTING", "NONE"] :
[2066]429                if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) :
[2054]430                    self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn")
431                else :
432                    if action == 'DENY' :
[2066]433                        self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name))
434                        userpquota.incDenyBannerCounter() # increments the warning counter
[2054]435                        self.exportUserInfo(userpquota)
436                    banner = self.endingBanner(printer.Name)
437                    if banner :
438                        self.logdebug("Printing ending banner after accounting ends.")
439                        self.handleData(banner)
440                       
[1372]441            # Launches the post hook
442            self.posthook(userpquota)
443           
[1271]444        return retcode   
[1478]445               
[1458]446    def unregisterFileNo(self, pollobj, fileno) :               
447        """Removes a file handle from the polling object."""
448        try :
449            pollobj.unregister(fileno)
450        except KeyError :   
[1584]451            self.printInfo(_("File number %s unregistered twice from polling object, ignored.") % fileno, "warn")
[1494]452        except :   
453            self.logdebug("Error while unregistering file number %s from polling object." % fileno)
[1458]454        else :   
455            self.logdebug("File number %s unregistered from polling object." % fileno)
456           
[1495]457    def formatFileEvent(self, fd, mask) :       
[1478]458        """Formats file debug info."""
[1495]459        maskval = []
460        if mask & select.POLLIN :
461            maskval.append("POLLIN")
462        if mask & select.POLLOUT :
463            maskval.append("POLLOUT")
464        if mask & select.POLLPRI :
465            maskval.append("POLLPRI")
466        if mask & select.POLLERR :
467            maskval.append("POLLERR")
468        if mask & select.POLLHUP :
469            maskval.append("POLLHUP")
470        if mask & select.POLLNVAL :
471            maskval.append("POLLNVAL")
472        return "%s (%s)" % (fd, " | ".join(maskval))
[1478]473       
[1918]474    def handleData(self, filehandle=None) :
[1271]475        """Pass the job's data to the real backend."""
[1222]476        # Find the real backend pathname   
[1271]477        realbackend = os.path.join(os.path.split(sys.argv[0])[0], self.originalbackend)
[1222]478       
479        # And launch it
[1923]480        if filehandle is None :
481            arguments = sys.argv
482        else :   
483            # Here we absolutely WANT to remove any filename from the command line !
484            arguments = [ "Fake this because we are printing a banner" ] + sys.argv[1:6]
[2006]485           
486        self.regainPriv()   
487       
[1924]488        self.logdebug("Starting real backend %s with args %s" % (realbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + arguments[1:])])))
489        subprocess = PyKotaPopen4([realbackend] + arguments[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
[1222]490       
491        # Save file descriptors, we will need them later.
492        stderrfno = sys.stderr.fileno()
493        fromcfno = subprocess.fromchild.fileno()
[1494]494        tocfno = subprocess.tochild.fileno()
[1222]495       
496        # We will have to be careful when dealing with I/O
497        # So we use a poll object to know when to read or write
498        pollster = select.poll()
499        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
[1494]500        pollster.register(stderrfno, select.POLLOUT)
501        pollster.register(tocfno, select.POLLOUT)
[1222]502       
[1494]503        # Initialize our buffers
504        indata = ""
505        outdata = ""
506        endinput = endoutput = 0
507        inputclosed = outputclosed = 0
[1897]508        totaltochild = totalfromcups = 0
509        totalfromchild = totaltocups = 0
[1494]510       
[1918]511        if filehandle is None:
512            if self.preserveinputfile is None :
513               # this is not a real file, we read the job's data
514                # from our temporary file which is a copy of stdin
515                infno = self.jobdatastream.fileno()
516                self.jobdatastream.seek(0)
517                pollster.register(infno, select.POLLIN | select.POLLPRI)
518            else :   
519                # job's data is in a file, no need to pass the data
520                # to the real backend
521                self.logdebug("Job's data is in %s" % self.preserveinputfile)
522                infno = None
523                endinput = 1
524        else:
525            self.logdebug("Printing data passed from filehandle")
526            indata = filehandle.read()
[1494]527            infno = None
528            endinput = 1
[1918]529            filehandle.close()
[1494]530       
[1606]531        self.logdebug("Entering streams polling loop...")
[1495]532        MEGABYTE = 1024*1024
[1494]533        killed = 0
534        status = -1
[1495]535        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
[1494]536            # First check if original backend is still alive
537            status = subprocess.poll()
538           
539            # Now if we got SIGTERM, we have
540            # to kill -TERM the original backend
541            if self.gotSigTerm and not killed :
542                try :
[1222]543                    os.kill(subprocess.pid, signal.SIGTERM)
[1495]544                except OSError, msg : # ignore but logs if process was already killed.
[1514]545                    self.logdebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg))
[1495]546                else :   
[1606]547                    self.printInfo(_("SIGTERM was sent to real backend %s (pid: %s)") % (realbackend, subprocess.pid))
[1291]548                    killed = 1
[1494]549           
550            # In any case, deal with any remaining I/O
[1498]551            try :
552                availablefds = pollster.poll(5000)
553            except select.error, msg :   
554                self.logdebug("Interrupted poll : %s" % msg)
555                availablefds = []
[1495]556            if not availablefds :
[1606]557                self.logdebug("Nothing to do, sleeping a bit...")
[1495]558                time.sleep(0.01) # give some time to the system
559            else :
560                for (fd, mask) in availablefds :
561                    # self.logdebug(self.formatFileEvent(fd, mask))
562                    try :
563                        if mask & select.POLLOUT :
564                            # We can write
565                            if fd == tocfno :
566                                if indata :
567                                    try :
[1897]568                                        nbwritten = os.write(fd, indata)   
[1515]569                                    except (OSError, IOError), msg :   
[1495]570                                        self.logdebug("Error while writing to real backend's stdin %s : %s" % (fd, msg))
571                                    else :   
[1897]572                                        if len(indata) != nbwritten :
573                                            self.logdebug("Short write to real backend's input !")
574                                        totaltochild += nbwritten   
575                                        self.logdebug("%s bytes sent to real backend so far..." % totaltochild)
576                                        indata = indata[nbwritten:]
[1498]577                                else :       
[1606]578                                    self.logdebug("No data to send to real backend yet, sleeping a bit...")
[1498]579                                    time.sleep(0.01)
580                                   
[1495]581                                if endinput :   
582                                    self.unregisterFileNo(pollster, tocfno)       
[1606]583                                    self.logdebug("Closing real backend's stdin.")
[1495]584                                    os.close(tocfno)
585                                    inputclosed = 1
586                            elif fd == stderrfno :
587                                if outdata :
588                                    try :
[1897]589                                        nbwritten = os.write(fd, outdata)
[1515]590                                    except (OSError, IOError), msg :   
[1495]591                                        self.logdebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
592                                    else :
[1897]593                                        if len(outdata) != nbwritten :
594                                            self.logdebug("Short write to stderr (CUPS) !")
595                                        totaltocups += nbwritten   
596                                        self.logdebug("%s bytes sent back to CUPS so far..." % totaltocups)
597                                        outdata = outdata[nbwritten:]
[1498]598                                else :       
599                                    # self.logdebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
600                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
601                                   
[1495]602                                if endoutput :   
603                                    self.unregisterFileNo(pollster, stderrfno)       
604                                    outputclosed = 1
[1498]605                            else :   
606                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
607                                time.sleep(0.01)
608                               
[1495]609                        if mask & (select.POLLIN | select.POLLPRI) :     
610                            # We have something to read
611                            try :
612                                data = os.read(fd, MEGABYTE)
613                            except (IOError, OSError), msg :   
614                                self.logdebug("Error while reading file %s : %s" % (fd, msg))
615                            else :
616                                if fd == infno :
617                                    if not data :    # If yes, then no more input data
618                                        self.unregisterFileNo(pollster, infno)
[1606]619                                        self.logdebug("Input data ends.")
[1495]620                                        endinput = 1 # this happens with real files.
[1498]621                                    else :   
622                                        indata += data
[1897]623                                        totalfromcups += len(data)
624                                        self.logdebug("%s bytes read from CUPS so far..." % totalfromcups)
[1495]625                                elif fd == fromcfno :
[1498]626                                    if not data :
[1606]627                                        self.logdebug("No back channel data to read from real backend yet, sleeping a bit...")
[1498]628                                        time.sleep(0.01)
629                                    else :
630                                        outdata += data
[1897]631                                        totalfromchild += len(data)
632                                        self.logdebug("%s bytes read from real backend so far..." % totalfromchild)
[1498]633                                else :   
634                                    self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
635                                    time.sleep(0.01)
636                                   
[1495]637                        if mask & (select.POLLHUP | select.POLLERR) :
638                            # Treat POLLERR as an EOF.
639                            # Some standard I/O stream has no more datas
640                            self.unregisterFileNo(pollster, fd)
[1494]641                            if fd == infno :
[1495]642                                # Here we are in the case where the input file is stdin.
643                                # which has no more data to be read.
[1606]644                                self.logdebug("Input data ends.")
[1495]645                                endinput = 1
646                            elif fd == fromcfno :   
647                                # We are no more interested in this file descriptor       
[1606]648                                self.logdebug("Closing real backend's stdout+stderr.")
[1495]649                                os.close(fromcfno)
650                                endoutput = 1
[1498]651                            else :   
652                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
653                                time.sleep(0.01)
[1495]654                               
655                        if mask & select.POLLNVAL :       
[1606]656                            self.logdebug("File %s was closed. Unregistering from polling object." % fd)
[1495]657                            self.unregisterFileNo(pollster, fd)
658                    except IOError, msg :           
659                        self.logdebug("Got an IOError : %s" % msg) # we got signalled during an I/O
[1191]660               
[1494]661        # We must close the real backend's input stream
662        if killed and not inputclosed :
[1606]663            self.logdebug("Forcing close of real backend's stdin.")
[1494]664            os.close(tocfno)
665       
[1606]666        self.logdebug("Exiting streams polling loop...")
[1492]667       
[1897]668        self.logdebug("input data's final length : %s" % len(indata))
669        self.logdebug("back-channel data's final length : %s" % len(outdata))
670       
671        self.logdebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups)
672        self.logdebug("Total bytes sent to real backend (job's datas) : %s" % totaltochild)
673       
674        self.logdebug("Total bytes read from real backend (back-channel datas) : %s" % totalfromchild)
675        self.logdebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups)
676       
[1494]677        # Check exit code of original CUPS backend.   
678        if status == -1 :
679            # we exited the loop before the real backend exited
680            # now we have to wait for it to finish and get its status
[1606]681            self.logdebug("Waiting for real backend to exit...")
[1494]682            try :
683                status = subprocess.wait()
[2054]684            except OSError : # already dead : TODO : detect when abnormal
[1494]685                status = 0
[1222]686        if os.WIFEXITED(status) :
687            retcode = os.WEXITSTATUS(status)
[1291]688        elif not killed :   
[1606]689            self.sendBackChannelData(_("CUPS backend %s died abnormally.") % realbackend, "error")
[1222]690            retcode = -1
[1291]691        else :   
692            retcode = self.removeJob()
[2006]693           
694        self.dropPriv()   
695       
[1271]696        return retcode   
[1222]697   
[1177]698if __name__ == "__main__" :   
699    # This is a CUPS backend, we should act and die like a CUPS backend
[1542]700    retcode = 0
[1177]701    if len(sys.argv) == 1 :
[1178]702        (directory, myname) = os.path.split(sys.argv[0])
[2164]703        tmpdir = tempfile.gettempdir()
704        lockfilename = os.path.join(tmpdir, "%s..LCK" % myname)
705        if os.path.exists(lockfilename) :
706            # there's already a lockfile, see if still used
707            lockfile = open(lockfilename, "r")
708            pid = int(lockfile.read())
709            lockfile.close()
[1178]710            try :
[2164]711                # see if the pid contained in the lock file is still running
712                os.kill(pid, 0)
713            except OSError, e :   
714                if e.errno != errno.EPERM :
715                    # process doesn't exist anymore, remove the lock
716                    os.remove(lockfilename)
717           
718        if not os.path.exists(lockfilename) :
719            lockfile = open(lockfilename, "w")
720            lockfile.write("%i" % os.getpid())
721            lockfile.close()
722            # we will execute each existing backend in device enumeration mode
723            # and generate their PyKota accounting counterpart
[2165]724            allbackends = [ os.path.join(directory, b) \
725                                for b in os.listdir(directory) 
726                                    if os.access(os.path.join(directory, b), os.X_OK) \
727                                        and (b != myname)] 
728            for backend in allbackends :                           
[2164]729                answer = os.popen(backend, "r")
730                try :
731                    devices = [line.strip() for line in answer.readlines()]
732                except :   
733                    devices = []
734                status = answer.close()
735                if status is None :
736                    for d in devices :
737                        # each line is of the form : 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
738                        # so we have to decompose it carefully
739                        fdevice = cStringIO.StringIO("%s" % d)
740                        tokenizer = shlex.shlex(fdevice)
741                        tokenizer.wordchars = tokenizer.wordchars + r".:,?!~/\_$*-+={}[]()#"
742                        arguments = []
743                        while 1 :
744                            token = tokenizer.get_token()
745                            if token :
746                                arguments.append(token)
747                            else :
748                                break
749                        fdevice.close()
750                        try :
751                            (devicetype, device, name, fullname) = arguments
752                        except ValueError :   
753                            pass    # ignore this 'bizarre' device
754                        else :   
755                            if name.startswith('"') and name.endswith('"') :
756                                name = name[1:-1]
757                            if fullname.startswith('"') and fullname.endswith('"') :
758                                fullname = fullname[1:-1]
759                            print '%s cupspykota:%s "PyKota+%s" "PyKota managed %s"' % (devicetype, device, name, fullname)
760            os.remove(lockfilename)
[1542]761        retcode = 0               
[1177]762    elif len(sys.argv) not in (6, 7) :   
763        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n" % sys.argv[0])
764        retcode = 1
765    else :   
766        try :
[2210]767            # Initializes the backend
768            kotabackend = PyKotaBackend()   
769            kotabackend.deferredInit()
770            retcode = kotabackend.mainWork()
771            kotabackend.storage.close()
772            kotabackend.closeJobDataStream()   
773        except SystemExit :   
774            retcode = -1
[1513]775        except :
[1517]776            try :
777                kotabackend.crashed("cupspykota backend failed")
778            except :   
[1542]779                crashed("cupspykota backend failed")
780            retcode = 1   
[1177]781       
782    sys.exit(retcode)   
Note: See TracBrowser for help on using the browser.