root / pykota / trunk / bin / cupspykota @ 1897

Revision 1897, 33.0 kB (checked in by jalet, 20 years ago)

Added many debug messages.
Added some code to prevent short writes.

  • 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#
[1257]8# (c) 2003-2004 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
21# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307, USA.
22#
23# $Id$
24#
25# $Log$
[1897]26# Revision 1.75  2004/11/01 15:45:25  jalet
27# Added many debug messages.
28# Added some code to prevent short writes.
29#
[1820]30# Revision 1.74  2004/10/13 20:51:27  jalet
31# Made debugging levels be the same in cupspykota and lprngpykota.
32# Now outputs more information in informational messages : user, printer, jobid
33#
[1819]34# Revision 1.73  2004/10/13 16:56:45  jalet
35# Added a space to the pattern to differentiate jobs which id begins with
36# the same digits, like jobs 87 and 879 for example : if printed by same
37# user on same printer, but from a different host this could have broken
38# the result. (In reality this couldn't happen because 879 would be the
39# last line to match anyway because of job ordering, but we never know
40# if the page_log file gets corrupt somewhat)
41#
[1713]42# Revision 1.72  2004/09/13 16:02:44  jalet
43# Added fix for incorrect job's size when hardware accounting fails
44#
[1704]45# Revision 1.71  2004/09/06 17:05:06  jalet
46# Fix for autodetection of SC_OPEN_MAX
47#
[1643]48# Revision 1.70  2004/07/26 09:20:27  jalet
49# Unneeded module
50#
[1624]51# Revision 1.69  2004/07/22 22:41:47  jalet
52# Hardware accounting for LPRng should be OK now. UNTESTED.
53#
[1606]54# Revision 1.68  2004/07/20 22:19:44  jalet
55# Sanitized a bit + use of gettext
56#
[1600]57# Revision 1.67  2004/07/16 12:22:45  jalet
58# LPRng support early version
59#
[1584]60# Revision 1.66  2004/07/01 19:56:25  jalet
61# Better dispatching of error messages
62#
[1562]63# Revision 1.65  2004/06/22 09:31:17  jalet
64# Always send some debug info to CUPS' back channel stream (stderr) as
65# informationnal messages.
66#
[1546]67# Revision 1.64  2004/06/18 13:34:46  jalet
68# Now all tracebacks include PyKota's version number
69#
[1542]70# Revision 1.63  2004/06/17 13:26:50  jalet
71# Better exception handling code
72#
[1541]73# Revision 1.62  2004/06/16 20:56:34  jalet
74# Smarter initialisation code
75#
[1530]76# Revision 1.61  2004/06/08 09:00:04  jalet
77# Fixed problem when username was passed in uppercase from Samba and we
78# tried to find correct line in CUPS page_log to extract the hostname.
79#
[1520]80# Revision 1.60  2004/06/03 23:14:08  jalet
81# Now stores the job's size in bytes in the database.
82# Preliminary work on payments storage : database schemas are OK now,
83# but no code to store payments yet.
84# Removed schema picture, not relevant anymore.
85#
[1519]86# Revision 1.59  2004/06/03 22:12:53  jalet
87# Now denies empty jobs
88#
[1517]89# Revision 1.58  2004/06/03 21:50:33  jalet
90# Improved error logging.
91# crashrecipient directive added.
92# Now exports the job's size in bytes too.
93#
[1515]94# Revision 1.57  2004/06/02 22:18:07  jalet
95# I think the bug when cancelling jobs should be fixed right now
96#
[1514]97# Revision 1.56  2004/06/02 21:50:56  jalet
98# Moved the sigterm capturing elsewhere
99#
[1513]100# Revision 1.55  2004/06/02 14:25:07  jalet
101# Should correctly capture ALL errors now
102#
[1503]103# Revision 1.54  2004/05/26 16:44:48  jalet
104# Now logs something when client hostname can't be extracted
105#
[1502]106# Revision 1.53  2004/05/26 14:49:35  jalet
107# First try at saving the job-originating-hostname in the database
108#
[1499]109# Revision 1.52  2004/05/25 09:15:13  jalet
110# accounter.py : old code deleted
111# the rest : now exports PYKOTAPRECOMPUTEDJOBSIZE and PYKOTAPRECOMPUTEDJOBPRICE
112#
[1498]113# Revision 1.51  2004/05/25 08:31:16  jalet
114# Heavy CPU usage seems to be fixed at least !
115#
[1497]116# Revision 1.50  2004/05/25 05:17:50  jalet
117# Now precomputes the job's size only if current printer's enforcement
118# is "STRICT"
119#
[1495]120# Revision 1.49  2004/05/24 22:45:48  jalet
121# New 'enforcement' directive added
122# Polling loop improvements
123#
[1494]124# Revision 1.48  2004/05/24 14:36:24  jalet
125# Revert to old polling loop. Will need optimisations
126#
[1493]127# Revision 1.47  2004/05/24 11:59:46  jalet
128# More robust (?) code
129#
[1492]130# Revision 1.46  2004/05/21 22:02:51  jalet
131# Preliminary work on pre-accounting
132#
[1484]133# Revision 1.45  2004/05/19 07:15:32  jalet
134# Could the 'misterious' bug in my loop be finally fixed ???
135#
[1483]136# Revision 1.44  2004/05/18 14:48:47  jalet
137# Big code changes to completely remove the need for "requester" directives,
138# jsut use "hardware(... your previous requester directive's content ...)"
139#
[1478]140# Revision 1.43  2004/05/17 11:46:05  jalet
141# First try at cupspykota's main loop rewrite
142#
[1467]143# Revision 1.42  2004/05/10 11:22:28  jalet
144# Typo
145#
[1466]146# Revision 1.41  2004/05/10 10:07:30  jalet
147# Catches OSError while reading
148#
[1465]149# Revision 1.40  2004/05/10 09:29:48  jalet
150# Should be more robust if we receive a SIGTERM during an I/O operation
151#
[1458]152# Revision 1.39  2004/05/07 14:44:53  jalet
153# Fix for file handles unregistered twice from the polling object
154#
[1433]155# Revision 1.38  2004/04/09 22:24:46  jalet
156# Began work on correct handling of child processes when jobs are cancelled by
157# the user. Especially important when an external requester is running for a
158# long time.
159#
[1411]160# Revision 1.37  2004/03/18 19:11:25  jalet
161# Fix for raw jobs in cupspykota
162#
[1410]163# Revision 1.36  2004/03/18 14:03:18  jalet
164# Added fsync() calls
165#
[1405]166# Revision 1.35  2004/03/16 12:05:01  jalet
167# Small fix for new waitprinter.sh : when job was denied, would wait forever
168# for printer being in printing mode.
169#
[1400]170# Revision 1.34  2004/03/15 10:47:56  jalet
171# This time the traceback formatting should be correct !
172#
[1391]173# Revision 1.33  2004/03/05 12:46:07  jalet
174# Improve tracebacks
175#
[1390]176# Revision 1.32  2004/03/05 12:31:35  jalet
177# Now should output full traceback when crashing
178#
[1375]179# Revision 1.31  2004/03/01 14:35:56  jalet
180# PYKOTAPHASE wasn't set soon enough at the start of the job
181#
[1374]182# Revision 1.30  2004/03/01 14:34:15  jalet
183# PYKOTAPHASE wasn't set at the right time at the end of data transmission
184# to underlying layer (real backend)
185#
[1372]186# Revision 1.29  2004/03/01 11:23:25  jalet
187# Pre and Post hooks to external commands are available in the cupspykota
188# backend. Forthe pykota filter they will be implemented real soon now.
189#
[1365]190# Revision 1.28  2004/02/26 14:18:07  jalet
191# Should fix the remaining bugs wrt printers groups and users groups.
192#
[1335]193# Revision 1.27  2004/02/04 23:41:27  jalet
194# Should fix the incorrect "backend died abnormally" problem.
195#
[1321]196# Revision 1.26  2004/01/30 16:35:03  jalet
197# Fixes stupid software accounting bug in CUPS backend
198#
[1302]199# Revision 1.25  2004/01/16 17:51:46  jalet
200# Fuck Fuck Fuck !!!
201#
[1291]202# Revision 1.24  2004/01/14 15:52:01  jalet
203# Small fix for job cancelling code.
204#
[1289]205# Revision 1.23  2004/01/13 10:48:28  jalet
206# Small streams polling loop modification.
207#
[1285]208# Revision 1.22  2004/01/12 22:43:40  jalet
209# New formula to compute a job's price
210#
[1280]211# Revision 1.21  2004/01/12 18:17:36  jalet
212# Denied jobs weren't stored into the history anymore, this is now fixed.
213#
[1271]214# Revision 1.20  2004/01/11 23:22:42  jalet
215# Major code refactoring, it's way cleaner, and now allows automated addition
216# of printers on first print.
217#
[1257]218# Revision 1.19  2004/01/08 14:10:32  jalet
219# Copyright year changed.
220#
[1256]221# Revision 1.18  2004/01/07 16:16:32  jalet
222# Better debugging information
223#
[1240]224# Revision 1.17  2003/12/27 16:49:25  uid67467
225# Should be ok now.
226#
227# Revision 1.17  2003/12/06 08:54:29  jalet
228# Code simplifications.
229# Added many debugging messages.
230#
[1222]231# Revision 1.16  2003/11/26 20:43:29  jalet
232# Inadvertantly introduced a bug, which is fixed.
233#
[1221]234# Revision 1.15  2003/11/26 19:17:35  jalet
235# Printing on a printer not present in the Quota Storage now results
236# in the job being stopped or cancelled depending on the system.
237#
[1210]238# Revision 1.14  2003/11/25 13:25:45  jalet
239# Boolean problem with old Python, replaced with 0
240#
[1203]241# Revision 1.13  2003/11/23 19:01:35  jalet
242# Job price added to history
243#
[1200]244# Revision 1.12  2003/11/21 14:28:43  jalet
245# More complete job history.
246#
[1196]247# Revision 1.11  2003/11/19 23:19:35  jalet
248# Code refactoring work.
249# Explicit redirection to /dev/null has to be set in external policy now, just
250# like in external mailto.
251#
[1191]252# Revision 1.10  2003/11/18 17:54:24  jalet
253# SIGTERMs are now transmitted to original backends.
254#
[1190]255# Revision 1.9  2003/11/18 14:11:07  jalet
256# Small fix for bizarre urls
257#
[1186]258# Revision 1.8  2003/11/15 14:26:44  jalet
259# General improvements to the documentation.
260# Email address changed in sample configuration file, because
261# I receive low quota messages almost every day...
262#
[1185]263# Revision 1.7  2003/11/14 22:05:12  jalet
264# New CUPS backend fully functionnal.
265# Old CUPS configuration method is now officially deprecated.
266#
[1184]267# Revision 1.6  2003/11/14 20:13:11  jalet
268# We exit the loop too soon.
269#
[1183]270# Revision 1.5  2003/11/14 18:31:27  jalet
271# Not perfect, but seems to work with the poll() loop.
272#
[1182]273# Revision 1.4  2003/11/14 17:04:15  jalet
274# More (untested) work on the CUPS backend.
275#
[1180]276# Revision 1.3  2003/11/12 23:27:44  jalet
277# More work on new backend. This commit may be unstable.
278#
[1178]279# Revision 1.2  2003/11/12 09:33:34  jalet
280# New CUPS backend supports device enumeration
281#
[1177]282# Revision 1.1  2003/11/08 16:05:31  jalet
283# CUPS backend added for people to experiment.
284#
285#
286#
287
288import sys
289import os
[1182]290import popen2
[1178]291import cStringIO
292import shlex
[1182]293import select
294import signal
[1291]295import time
[1177]296
[1546]297from pykota.tool import PyKotaFilterOrBackend, PyKotaToolError, crashed
[1177]298from pykota.config import PyKotaConfigError
299from pykota.storage import PyKotaStorageError
[1196]300from pykota.accounter import PyKotaAccounterError
[1271]301   
[1478]302class PyKotaPopen4(popen2.Popen4) :
[1182]303    """Our own class to execute real backends.
304   
305       Their first argument is different from their path so using
306       native popen2.Popen3 would not be feasible.
307    """
[1478]308    def __init__(self, cmd, bufsize=-1, arg0=None) :
[1182]309        self.arg0 = arg0
[1478]310        popen2.Popen4.__init__(self, cmd, bufsize)
[1182]311       
312    def _run_child(self, cmd):
[1704]313        try :
314            MAXFD = os.sysconf("SC_OPEN_MAX")
315        except (AttributeError, ValueError) :   
316            MAXFD = 256
317        for i in range(3, MAXFD) : 
[1182]318            try:
319                os.close(i)
320            except OSError:
321                pass
322        try:
323            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
324        finally:
325            os._exit(1)
326   
[1271]327class PyKotaBackend(PyKotaFilterOrBackend) :       
328    """A class for the pykota backend."""
329    def acceptJob(self) :       
330        """Returns the appropriate exit code to tell CUPS all is OK."""
331        return 0
332           
333    def removeJob(self) :           
334        """Returns the appropriate exit code to let CUPS think all is OK.
[1177]335       
[1271]336           Returning 0 (success) prevents CUPS from stopping the print queue.
337        """   
338        return 0
[1222]339       
[1502]340    def getPageLogLocation(self) :
341        """Retrieves CUPS' page_log file location."""
342        location = None
343        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
344        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
345        try :
346            conffile = open(cupsdconf, "r")
347        except IOError :   
[1503]348            self.logdebug("Unable to open %s" % cupsdconf)
[1502]349            return # file doesn't exist or can't be read
350        else :   
351            for line in conffile.readlines() :
352                linecopy = line.strip().lower()
353                if linecopy.startswith("pagelog ") :
354                    try :
355                        location = line.split()[1]
356                    except :   
357                        pass # ignore errors, we take the last value in any case.
358            conffile.close()           
359            return location           
360           
361    def getJobOriginatingHostname(self, printername, username, jobid) :
362        """Retrieves the job-originating-hostname from the CUPS page_log file if possible."""
363        pagelogpath = self.getPageLogLocation() or "/var/log/cups/page_log"
364        try :
365            pagelog = open(pagelogpath, "r")
366        except IOError :   
[1503]367            self.logdebug("Unable to open %s" % pagelogpath)
[1502]368            return # no page log or can't read it, originating hostname unknown yet
369        else :   
370            # TODO : read backward so we could take first value seen
371            # TODO : here we read forward so we must take the last value seen
[1819]372            prefix = ("%s %s %s " % (printername, username, jobid)).lower()
[1502]373            matchingline = None
374            while 1 :
375                line = pagelog.readline()
376                if not line :
377                    break
378                else :
379                    line = line.strip()
[1530]380                    if line.lower().startswith(prefix) :   
[1502]381                        matchingline = line # no break, because we read forward
382            pagelog.close()       
383            if matchingline is None :
[1606]384                self.logdebug("No matching line found in %s" % pagelogpath)
[1502]385                return # correct line not found, job-originating-hostname unknown
386            else :   
387                return matchingline.split()[-1]
388               
[1271]389    def doWork(self, policy, printer, user, userpquota) :   
390        """Most of the work is done here."""
391        # Two different values possible for policy here :
392        # ALLOW means : Either printer, user or user print quota doesn't exist,
393        #               but the job should be allowed anyway.
394        # OK means : Both printer, user and user print quota exist, job should
395        #            be allowed if current user is allowed to print on this printer
396        if policy == "OK" :
[1372]397            # exports user information with initial values
398            self.exportUserInfo(userpquota)
399           
[1502]400            # tries to extract job-originating-hostname
401            clienthost = self.getJobOriginatingHostname(printer.Name, user.Name, self.jobid)
[1503]402            self.logdebug("Client Hostname : %s" % (clienthost or "Unknown"))   
[1517]403            os.environ["PYKOTAJOBORIGINATINGHOSTNAME"] = str(clienthost or "")
[1502]404           
[1375]405            # enters first phase
[1517]406            os.environ["PYKOTAPHASE"] = "BEFORE"
[1375]407           
[1519]408            # do we want strict or laxist quota enforcement ?
[1497]409            if self.config.getPrinterEnforcement(printer.Name) == "STRICT" :
410                self.softwareJobSize = self.precomputeJobSize()
411                self.softwareJobPrice = userpquota.computeJobPrice(self.softwareJobSize)
[1606]412                self.logdebug("Precomputed job's size is %s pages, price is %s units" % (self.softwareJobSize, self.softwareJobPrice))
[1517]413            os.environ["PYKOTAPRECOMPUTEDJOBSIZE"] = str(self.softwareJobSize)
414            os.environ["PYKOTAPRECOMPUTEDJOBPRICE"] = str(self.softwareJobPrice)
[1519]415           
416            # if no data to pass to real backend, probably a filter
417            # higher in the chain failed because of a misconfiguration.
418            # we deny the job in this case (nothing to print anyway)
419            if not self.jobSizeBytes :
[1820]420                self.printMoreInfo(user, printer, _("Job contains no data. Printing is denied."), "warn")
[1519]421                action = "DENY"
[1606]422            else :   
423                # checks the user's quota
424                action = self.warnUserPQuota(userpquota)
[1519]425           
[1372]426            # exports some new environment variables
[1517]427            os.environ["PYKOTAACTION"] = action
[1372]428           
429            # launches the pre hook
430            self.prehook(userpquota)
431           
[1820]432            self.printMoreInfo(user, printer, _("Job accounting begins."))
[1624]433            self.accounter.beginJob(printer)
[1280]434        else :   
435            action = "ALLOW"
[1517]436            os.environ["PYKOTAACTION"] = action
[1271]437           
438        # pass the job's data to the real backend   
[1280]439        if action in ["ALLOW", "WARN"] :
[1291]440            if self.gotSigTerm :
[1280]441                retcode = self.removeJob()
442            else :   
443                retcode = self.handleData()       
444        else :       
[1271]445            retcode = self.removeJob()
446       
447        if policy == "OK" :       
[1374]448            # indicate phase change
[1517]449            os.environ["PYKOTAPHASE"] = "AFTER"
[1374]450           
[1271]451            # stops accounting.
[1624]452            self.accounter.endJob(printer)
[1820]453            self.printMoreInfo(user, printer, _("Job accounting ends."))
[1271]454               
455            # retrieve the job size   
[1321]456            if action == "DENY" :
457                jobsize = 0
[1820]458                self.printMoreInfo(user, printer, _("Job size forced to 0 because printing is denied."))
[1321]459            else :   
[1713]460                jobsize = self.accounter.getJobSize(printer)
[1820]461            self.printMoreInfo(user, printer, _("Job size : %i") % jobsize)
[1271]462           
463            # update the quota for the current user on this printer
[1606]464            self.printInfo(_("Updating user %s's quota on printer %s") % (user.Name, printer.Name))
[1285]465            jobprice = userpquota.increasePagesUsage(jobsize)
[1271]466           
467            # adds the current job to history   
[1520]468            printer.addJobToHistory(self.jobid, user, self.accounter.getLastPageCounter(), action, jobsize, jobprice, self.preserveinputfile, self.title, self.copies, self.options, clienthost, self.jobSizeBytes)
[1820]469            self.printMoreInfo(user, printer, _("Job added to history."))
[1271]470           
[1372]471            # exports some new environment variables
[1517]472            os.environ["PYKOTAJOBSIZE"] = str(jobsize)
473            os.environ["PYKOTAJOBPRICE"] = str(jobprice)
[1372]474           
[1517]475            # then re-export user information with new value
[1372]476            self.exportUserInfo(userpquota)
477           
478            # Launches the post hook
479            self.posthook(userpquota)
480           
[1271]481        return retcode   
[1478]482               
[1458]483    def unregisterFileNo(self, pollobj, fileno) :               
484        """Removes a file handle from the polling object."""
485        try :
486            pollobj.unregister(fileno)
487        except KeyError :   
[1584]488            self.printInfo(_("File number %s unregistered twice from polling object, ignored.") % fileno, "warn")
[1494]489        except :   
490            self.logdebug("Error while unregistering file number %s from polling object." % fileno)
[1458]491        else :   
492            self.logdebug("File number %s unregistered from polling object." % fileno)
493           
[1495]494    def formatFileEvent(self, fd, mask) :       
[1478]495        """Formats file debug info."""
[1495]496        maskval = []
497        if mask & select.POLLIN :
498            maskval.append("POLLIN")
499        if mask & select.POLLOUT :
500            maskval.append("POLLOUT")
501        if mask & select.POLLPRI :
502            maskval.append("POLLPRI")
503        if mask & select.POLLERR :
504            maskval.append("POLLERR")
505        if mask & select.POLLHUP :
506            maskval.append("POLLHUP")
507        if mask & select.POLLNVAL :
508            maskval.append("POLLNVAL")
509        return "%s (%s)" % (fd, " | ".join(maskval))
[1478]510       
[1271]511    def handleData(self) :                   
512        """Pass the job's data to the real backend."""
[1222]513        # Find the real backend pathname   
[1271]514        realbackend = os.path.join(os.path.split(sys.argv[0])[0], self.originalbackend)
[1222]515       
516        # And launch it
[1606]517        self.logdebug("Starting real backend %s with args %s" % (realbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + sys.argv[1:])])))
[1478]518        subprocess = PyKotaPopen4([realbackend] + sys.argv[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
[1222]519       
520        # Save file descriptors, we will need them later.
521        stderrfno = sys.stderr.fileno()
522        fromcfno = subprocess.fromchild.fileno()
[1494]523        tocfno = subprocess.tochild.fileno()
[1222]524       
525        # We will have to be careful when dealing with I/O
526        # So we use a poll object to know when to read or write
527        pollster = select.poll()
528        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
[1494]529        pollster.register(stderrfno, select.POLLOUT)
530        pollster.register(tocfno, select.POLLOUT)
[1222]531       
[1494]532        # Initialize our buffers
533        indata = ""
534        outdata = ""
535        endinput = endoutput = 0
536        inputclosed = outputclosed = 0
[1897]537        totaltochild = totalfromcups = 0
538        totalfromchild = totaltocups = 0
[1494]539       
[1411]540        if self.preserveinputfile is None :
[1494]541            # this is not a real file, we read the job's data
[1495]542            # from our temporary file which is a copy of stdin
[1494]543            infno = self.jobdatastream.fileno()
544            self.jobdatastream.seek(0)
545            pollster.register(infno, select.POLLIN | select.POLLPRI)
[1411]546        else :   
547            # job's data is in a file, no need to pass the data
548            # to the real backend
[1606]549            self.logdebug("Job's data is in %s" % self.preserveinputfile)
[1494]550            infno = None
551            endinput = 1
552       
[1606]553        self.logdebug("Entering streams polling loop...")
[1495]554        MEGABYTE = 1024*1024
[1494]555        killed = 0
556        status = -1
[1495]557        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
[1494]558            # First check if original backend is still alive
559            status = subprocess.poll()
560           
561            # Now if we got SIGTERM, we have
562            # to kill -TERM the original backend
563            if self.gotSigTerm and not killed :
564                try :
[1222]565                    os.kill(subprocess.pid, signal.SIGTERM)
[1495]566                except OSError, msg : # ignore but logs if process was already killed.
[1514]567                    self.logdebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg))
[1495]568                else :   
[1606]569                    self.printInfo(_("SIGTERM was sent to real backend %s (pid: %s)") % (realbackend, subprocess.pid))
[1291]570                    killed = 1
[1494]571           
572            # In any case, deal with any remaining I/O
[1498]573            try :
574                availablefds = pollster.poll(5000)
575            except select.error, msg :   
576                self.logdebug("Interrupted poll : %s" % msg)
577                availablefds = []
[1495]578            if not availablefds :
[1606]579                self.logdebug("Nothing to do, sleeping a bit...")
[1495]580                time.sleep(0.01) # give some time to the system
581            else :
582                for (fd, mask) in availablefds :
583                    # self.logdebug(self.formatFileEvent(fd, mask))
584                    try :
585                        if mask & select.POLLOUT :
586                            # We can write
587                            if fd == tocfno :
588                                if indata :
589                                    try :
[1897]590                                        nbwritten = os.write(fd, indata)   
[1515]591                                    except (OSError, IOError), msg :   
[1495]592                                        self.logdebug("Error while writing to real backend's stdin %s : %s" % (fd, msg))
593                                    else :   
[1897]594                                        if len(indata) != nbwritten :
595                                            self.logdebug("Short write to real backend's input !")
596                                        totaltochild += nbwritten   
597                                        self.logdebug("%s bytes sent to real backend so far..." % totaltochild)
598                                        indata = indata[nbwritten:]
[1498]599                                else :       
[1606]600                                    self.logdebug("No data to send to real backend yet, sleeping a bit...")
[1498]601                                    time.sleep(0.01)
602                                   
[1495]603                                if endinput :   
604                                    self.unregisterFileNo(pollster, tocfno)       
[1606]605                                    self.logdebug("Closing real backend's stdin.")
[1495]606                                    os.close(tocfno)
607                                    inputclosed = 1
608                            elif fd == stderrfno :
609                                if outdata :
610                                    try :
[1897]611                                        nbwritten = os.write(fd, outdata)
[1515]612                                    except (OSError, IOError), msg :   
[1495]613                                        self.logdebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
614                                    else :
[1897]615                                        if len(outdata) != nbwritten :
616                                            self.logdebug("Short write to stderr (CUPS) !")
617                                        totaltocups += nbwritten   
618                                        self.logdebug("%s bytes sent back to CUPS so far..." % totaltocups)
619                                        outdata = outdata[nbwritten:]
[1498]620                                else :       
621                                    # self.logdebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
622                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
623                                   
[1495]624                                if endoutput :   
625                                    self.unregisterFileNo(pollster, stderrfno)       
626                                    outputclosed = 1
[1498]627                            else :   
628                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
629                                time.sleep(0.01)
630                               
[1495]631                        if mask & (select.POLLIN | select.POLLPRI) :     
632                            # We have something to read
633                            try :
634                                data = os.read(fd, MEGABYTE)
635                            except (IOError, OSError), msg :   
636                                self.logdebug("Error while reading file %s : %s" % (fd, msg))
637                            else :
638                                if fd == infno :
639                                    if not data :    # If yes, then no more input data
640                                        self.unregisterFileNo(pollster, infno)
[1606]641                                        self.logdebug("Input data ends.")
[1495]642                                        endinput = 1 # this happens with real files.
[1498]643                                    else :   
644                                        indata += data
[1897]645                                        totalfromcups += len(data)
646                                        self.logdebug("%s bytes read from CUPS so far..." % totalfromcups)
[1495]647                                elif fd == fromcfno :
[1498]648                                    if not data :
[1606]649                                        self.logdebug("No back channel data to read from real backend yet, sleeping a bit...")
[1498]650                                        time.sleep(0.01)
651                                    else :
652                                        outdata += data
[1897]653                                        totalfromchild += len(data)
654                                        self.logdebug("%s bytes read from real backend so far..." % totalfromchild)
[1498]655                                else :   
656                                    self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
657                                    time.sleep(0.01)
658                                   
[1495]659                        if mask & (select.POLLHUP | select.POLLERR) :
660                            # Treat POLLERR as an EOF.
661                            # Some standard I/O stream has no more datas
662                            self.unregisterFileNo(pollster, fd)
[1494]663                            if fd == infno :
[1495]664                                # Here we are in the case where the input file is stdin.
665                                # which has no more data to be read.
[1606]666                                self.logdebug("Input data ends.")
[1495]667                                endinput = 1
668                            elif fd == fromcfno :   
669                                # We are no more interested in this file descriptor       
[1606]670                                self.logdebug("Closing real backend's stdout+stderr.")
[1495]671                                os.close(fromcfno)
672                                endoutput = 1
[1498]673                            else :   
674                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
675                                time.sleep(0.01)
[1495]676                               
677                        if mask & select.POLLNVAL :       
[1606]678                            self.logdebug("File %s was closed. Unregistering from polling object." % fd)
[1495]679                            self.unregisterFileNo(pollster, fd)
680                    except IOError, msg :           
681                        self.logdebug("Got an IOError : %s" % msg) # we got signalled during an I/O
[1191]682               
[1494]683        # We must close the real backend's input stream
684        if killed and not inputclosed :
[1606]685            self.logdebug("Forcing close of real backend's stdin.")
[1494]686            os.close(tocfno)
687       
[1606]688        self.logdebug("Exiting streams polling loop...")
[1492]689       
[1897]690        self.logdebug("input data's final length : %s" % len(indata))
691        self.logdebug("back-channel data's final length : %s" % len(outdata))
692       
693        self.logdebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups)
694        self.logdebug("Total bytes sent to real backend (job's datas) : %s" % totaltochild)
695       
696        self.logdebug("Total bytes read from real backend (back-channel datas) : %s" % totalfromchild)
697        self.logdebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups)
698       
[1494]699        # Check exit code of original CUPS backend.   
700        if status == -1 :
701            # we exited the loop before the real backend exited
702            # now we have to wait for it to finish and get its status
[1606]703            self.logdebug("Waiting for real backend to exit...")
[1494]704            try :
705                status = subprocess.wait()
706            except OSError : # already dead   
707                status = 0
[1222]708        if os.WIFEXITED(status) :
709            retcode = os.WEXITSTATUS(status)
[1291]710        elif not killed :   
[1606]711            self.sendBackChannelData(_("CUPS backend %s died abnormally.") % realbackend, "error")
[1222]712            retcode = -1
[1291]713        else :   
714            retcode = self.removeJob()
[1271]715        return retcode   
[1222]716   
[1177]717if __name__ == "__main__" :   
718    # This is a CUPS backend, we should act and die like a CUPS backend
[1542]719    retcode = 0
[1177]720    if len(sys.argv) == 1 :
[1178]721        # we will execute each existing backend in device enumeration mode
722        # and generate their PyKota accounting counterpart
723        (directory, myname) = os.path.split(sys.argv[0])
724        for backend in [os.path.join(directory, b) for b in os.listdir(directory) if os.path.isfile(os.path.join(directory, b)) and (b != myname)] :
725            answer = os.popen(backend, "r")
726            try :
727                devices = [line.strip() for line in answer.readlines()]
728            except :   
729                devices = []
730            status = answer.close()
731            if status is None :
732                for d in devices :
[1180]733                    # each line is of the form : 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
734                    # so we have to decompose it carefully
[1178]735                    fdevice = cStringIO.StringIO("%s" % d)
736                    tokenizer = shlex.shlex(fdevice)
737                    tokenizer.wordchars = tokenizer.wordchars + r".:,?!~/\_$*-+={}[]()#"
738                    arguments = []
739                    while 1 :
740                        token = tokenizer.get_token()
741                        if token :
742                            arguments.append(token)
743                        else :
744                            break
745                    fdevice.close()
[1180]746                    try :
747                        (devicetype, device, name, fullname) = arguments
748                    except ValueError :   
749                        pass    # ignore this 'bizarre' device
750                    else :   
751                        if name.startswith('"') and name.endswith('"') :
752                            name = name[1:-1]
753                        if fullname.startswith('"') and fullname.endswith('"') :
754                            fullname = fullname[1:-1]
[1191]755                        print '%s cupspykota:%s "PyKota+%s" "PyKota managed %s"' % (devicetype, device, name, fullname)
[1542]756        retcode = 0               
[1177]757    elif len(sys.argv) not in (6, 7) :   
758        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n" % sys.argv[0])
759        retcode = 1
760    else :   
761        try :
[1542]762            try :
763                # Initializes the backend
764                kotabackend = PyKotaBackend()   
765            except SystemExit :   
766                retcode = -1
767            except :   
768                crashed("cupspykota backend initialization failed")
769                retcode = 1
770            else :   
771                retcode = kotabackend.mainWork()
772                kotabackend.storage.close()
773                kotabackend.closeJobDataStream()   
[1513]774        except :
[1517]775            try :
776                kotabackend.crashed("cupspykota backend failed")
777            except :   
[1542]778                crashed("cupspykota backend failed")
779            retcode = 1   
[1177]780       
781    sys.exit(retcode)   
Note: See TracBrowser for help on using the browser.