root / pykota / trunk / bin / cupspykota @ 2062

Revision 2062, 43.7 kB (checked in by jalet, 19 years ago)

Introduces the new 'trustjobsize' directive to workaround some printers
generating unstable internal page counter values when queried through SNMP.

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