root / pykota / trunk / bin / cupspykota @ 2141

Revision 2139, 45.0 kB (checked in by jerome, 20 years ago)

Added the Log keyword property

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