root / pykota / trunk / bin / cupspykota @ 2007

Revision 2007, 38.4 kB (checked in by jalet, 19 years ago)

Regain priviledge the time to read the job control file to extract the client
hostname

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