root / pykota / trunk / bin / cupspykota @ 2060

Revision 2060, 42.7 kB (checked in by jalet, 19 years ago)

Now always precomputes the job's size with the internal PDL parser, and not
only when 'enforcement: strict' was set in pykota.conf

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