root / pykota / trunk / bin / cupspykota @ 3080

Revision 3071, 69.4 kB (checked in by jerome, 18 years ago)

Improved the fix.

  • 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, 2006 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., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
22#
23# $Id$
24#
25#
26
27import sys
28import os
29import fcntl
30import time
31import errno
32import tempfile
33import popen2
34import cStringIO
35import shlex
36import signal
37import md5
38import fnmatch
39import pwd
40import socket
41import smtplib
42from email.MIMEText import MIMEText
43from email.Header import Header
44import email.Utils
45
46from mx import DateTime
47
48from pykota.tool import PyKotaTool, PyKotaToolError, crashed
49from pykota.accounter import openAccounter
50# TODO : remove the three lines below and the code which handles
51# TODO : them in a future release.
52from pykota.ipp import IPPRequest as oldIPPRequest
53from pykota.ipp import IPPError as oldIPPError
54
55try :
56    from pkipplib import pkipplib
57except ImportError :       
58    haspkipplib = False
59else :   
60    haspkipplib = True
61   
62class FakeObject :       
63    """Fake object."""
64    def __init__(self, name) :
65        """Fake init."""
66        self.Name = name
67       
68class FakePrinter(FakeObject) :       
69    """Fake printer instance."""
70    pass
71   
72class FakeUser(FakeObject) :   
73    """Fake user instance."""
74    def __init__(self, name) :
75        """Fake init."""
76        self.Email = name
77        FakeObject.__init__(self, name)
78   
79class CUPSBackend(PyKotaTool) :
80    """Base class for tools with no database access."""
81    def __init__(self) :
82        """Initializes the CUPS backend wrapper."""
83        PyKotaTool.__init__(self)
84        signal.signal(signal.SIGTERM, signal.SIG_IGN)
85        signal.signal(signal.SIGPIPE, signal.SIG_IGN)
86        self.MyName = "PyKota"
87        self.myname = "cupspykota"
88        self.pid = os.getpid()
89        self.DataFile = None
90        self.lockfilename = None
91        self.lockfile = None
92       
93    def deferredInit(self) :   
94        """Deferred initialization."""
95        PyKotaTool.deferredInit(self)
96        self.gotSigTerm = 0
97        self.disableSigInt()
98        self.installSigTermHandler()
99       
100    def sigtermHandler(self, signum, frame) :
101        """Sets an attribute whenever SIGTERM is received."""
102        self.gotSigTerm = 1
103        self.printInfo(_("SIGTERM received, job %s cancelled.") % self.JobId)
104        os.environ["PYKOTASTATUS"] = "CANCELLED"
105       
106    def deinstallSigTermHandler(self) :           
107        """Deinstalls the SIGTERM handler."""
108        self.logdebug("Deinstalling SIGTERM handler...")
109        signal.signal(signal.SIGTERM, signal.SIG_IGN)
110        self.logdebug("SIGTERM handler deinstalled.")
111       
112    def installSigTermHandler(self) :           
113        """Installs the SIGTERM handler."""
114        self.logdebug("Installing SIGTERM handler...")
115        signal.signal(signal.SIGTERM, self.sigtermHandler)
116        self.logdebug("SIGTERM handler installed.")
117       
118    def disableSigInt(self) :   
119        """Disables the SIGINT signal (which raises KeyboardInterrupt)."""
120        self.logdebug("Disabling SIGINT...")
121        self.oldSigIntHandler = signal.signal(signal.SIGINT, signal.SIG_IGN)
122        self.logdebug("SIGINT disabled.")
123       
124    def enableSigInt(self) :   
125        """Enables the SIGINT signal (which raises KeyboardInterrupt)."""
126        self.logdebug("Enabling SIGINT...")
127        signal.signal(signal.SIGINT, self.oldSigIntHandler)
128        self.logdebug("SIGINT enabled.")
129       
130    def waitForLock(self) :   
131        """Waits until we can acquire the lock file."""
132        self.logdebug("Waiting for lock %s to become available..." % self.lockfilename)
133        haslock = False
134        while not haslock :
135            try :
136                # open the lock file, optionally creating it if needed.
137                self.lockfile = open(self.lockfilename, "a+")
138               
139                # we wait indefinitely for the lock to become available.
140                # works over NFS too.
141                fcntl.lockf(self.lockfile, fcntl.LOCK_EX)
142                haslock = True
143               
144                self.logdebug("Lock %s acquired." % self.lockfilename)
145               
146                # Here we save the PID in the lock file, but we don't use
147                # it, because the lock file may be in a directory shared
148                # over NFS between two (or more) print servers, so the PID
149                # has no meaning in this case.
150                self.lockfile.truncate(0)
151                self.lockfile.seek(0, 0)
152                self.lockfile.write(str(self.pid))
153                self.lockfile.flush()
154            except IOError :           
155                self.logdebug("I/O Error while waiting for lock %s" % self.lockfilename)
156                time.sleep(0.25)
157                   
158    def discoverOtherBackends(self) :   
159        """Discovers the other CUPS backends.
160       
161           Executes each existing backend in turn in device enumeration mode.
162           Returns the list of available backends.
163        """
164        # Unfortunately this method can't output any debug information
165        # to stdout or stderr, else CUPS considers that the device is
166        # not available.
167        available = []
168        (directory, myname) = os.path.split(sys.argv[0])
169        if not directory :
170            directory = "./"
171        tmpdir = tempfile.gettempdir()
172        lockfilename = os.path.join(tmpdir, "%s..LCK" % myname)
173        if os.path.exists(lockfilename) :
174            lockfile = open(lockfilename, "r")
175            pid = int(lockfile.read())
176            lockfile.close()
177            try :
178                # see if the pid contained in the lock file is still running
179                os.kill(pid, 0)
180            except OSError, err :
181                if err.errno != errno.EPERM :
182                    # process doesn't exist anymore
183                    os.remove(lockfilename)
184           
185        if not os.path.exists(lockfilename) :
186            lockfile = open(lockfilename, "w")
187            lockfile.write("%i" % self.pid)
188            lockfile.close()
189            allbackends = [ os.path.join(directory, b) \
190                                for b in os.listdir(directory) \
191                                    if os.access(os.path.join(directory, b), os.X_OK) \
192                                        and (b != myname)] 
193            for backend in allbackends :                           
194                answer = os.popen(backend, "r")
195                try :
196                    devices = [line.strip() for line in answer.readlines()]
197                except :   
198                    devices = []
199                status = answer.close()
200                if status is None :
201                    for d in devices :
202                        # each line is of the form :
203                        # 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
204                        # so we have to decompose it carefully
205                        fdevice = cStringIO.StringIO(d)
206                        tokenizer = shlex.shlex(fdevice)
207                        tokenizer.wordchars = tokenizer.wordchars + \
208                                                        r".:,?!~/\_$*-+={}[]()#"
209                        arguments = []
210                        while 1 :
211                            token = tokenizer.get_token()
212                            if token :
213                                arguments.append(token)
214                            else :
215                                break
216                        fdevice.close()
217                        try :
218                            (devicetype, device, name, fullname) = arguments
219                        except ValueError :   
220                            pass    # ignore this 'bizarre' device
221                        else :   
222                            if name.startswith('"') and name.endswith('"') :
223                                name = name[1:-1]
224                            if fullname.startswith('"') and fullname.endswith('"') :
225                                fullname = fullname[1:-1]
226                            available.append('%s %s:%s "%s+%s" "%s managed %s"' \
227                                                 % (devicetype, self.myname, \
228                                                    device, self.MyName, \
229                                                    name, self.MyName, \
230                                                    fullname))
231            os.remove(lockfilename)
232        available.append('direct %s:// "%s+Nothing" "%s managed Virtual Printer"' \
233                             % (self.myname, self.MyName, self.MyName))
234        return available
235                       
236    def initBackendParameters(self) :   
237        """Initializes the backend's attributes."""
238        # check that the DEVICE_URI environment variable's value is
239        # prefixed with self.myname otherwise don't touch it.
240        # If this is the case, we have to remove the prefix from
241        # the environment before launching the real backend
242        self.logdebug("Initializing backend...")
243       
244        self.PrinterName = os.environ.get("PRINTER", "")
245        directories = [ self.config.getPrinterDirectory(self.PrinterName),
246                        "/tmp",
247                        "/var/tmp" ]
248        self.Directory = None
249        for direc in directories :
250            if os.access(direc, os.O_RDWR) :
251                self.Directory = direc
252                break
253            else :
254                self.printInfo("Insufficient permissions to access to temporary directory %s" % direc, "warn")
255               
256        self.Action = "ALLOW"   # job allowed by default
257        self.Reason = None
258        self.JobId = sys.argv[1].strip()
259        # use CUPS' user when printing test pages from CUPS' web interface
260        self.UserName = sys.argv[2].strip() or self.originalUserName or pwd.getpwuid(os.geteuid())[0]
261        self.OriginalUserName = self.UserName[:]
262        self.Title = sys.argv[3].strip()
263        self.Copies = int(sys.argv[4].strip())
264        self.Options = sys.argv[5].strip()
265        if len(sys.argv) == 7 :
266            self.InputFile = sys.argv[6] # read job's datas from file
267        else :   
268            self.InputFile = None        # read job's datas from stdin
269        self.DataFile = os.path.join(self.Directory, "%s-%s-%s-%s" % \
270                   (self.myname, self.PrinterName, self.UserName, self.JobId))
271       
272        muststartwith = "%s:" % self.myname
273        device_uri = os.environ.get("DEVICE_URI", "")
274        if device_uri.startswith(muststartwith) :
275            fulldevice_uri = device_uri[:]
276            device_uri = fulldevice_uri[len(muststartwith):]
277            for i in range(2) :
278                if device_uri.startswith("/") : 
279                    device_uri = device_uri[1:]
280        try :
281            (backend, destination) = device_uri.split(":", 1) 
282        except ValueError :   
283            if not device_uri :
284                self.logdebug("Not attached to an existing print queue.")
285                backend = ""
286                printerhostname = ""
287            else :   
288                raise PyKotaToolError, "Invalid DEVICE_URI : %s\n" % device_uri
289        else :       
290            if backend == "hp" :
291                try :
292                    printerhostname = destination.split("=")[1] # hp:/net/HP_LaserJet_8000_Series?ip=192.168.100.100
293                except IndexError :   
294                    self.logdebug("Unsupported hplip URI %s" % device_uri)
295                    printerhostname = "" 
296            else :   
297                while destination.startswith("/") :
298                    destination = destination[1:]
299                checkauth = destination.split("@", 1)   
300                if len(checkauth) == 2 :
301                    destination = checkauth[1]
302            printerhostname = destination.split("/")[0].split(":")[0]
303           
304        self.PrinterHostName = printerhostname   
305        self.RealBackend = backend
306        self.DeviceURI = device_uri
307       
308        connerror = False
309        if haspkipplib :
310            self.ControlFile = "NotUsedAnymore"
311            self.logdebug("Querying CUPS server...")
312            cupsserver = pkipplib.CUPS() # TODO : username and password and/or encryption
313            answer = cupsserver.getJobAttributes(self.JobId)
314            if answer is None :
315                self.printInfo(_("Network error while querying the CUPS server : %s") \
316                                          % cupsserver.lastErrorMessage, "error")
317                connerror = True                       
318            else :   
319                self.logdebug("CUPS server answered without error.")
320                try :
321                    john = answer.job["job-originating-host-name"]
322                except KeyError :   
323                    try :
324                        john = answer.operation["job-originating-host-name"]
325                    except KeyError :   
326                        john = (None, None)
327                try :       
328                    jbing = answer.job["job-billing"]
329                except KeyError :   
330                    jbing = (None, None)
331                   
332        if connerror or not haspkipplib :       
333            (ippfilename, ippmessage) = self.parseIPPRequestFile()
334            self.ControlFile = ippfilename
335            john = ippmessage.operation_attributes.get("job-originating-host-name", \
336                   ippmessage.job_attributes.get("job-originating-host-name", \
337                   (None, None)))
338            jbing = ippmessage.job_attributes.get("job-billing", (None, None))
339               
340        if type(john) == type([]) : 
341            john = john[-1]
342        (chtype, self.ClientHost) = john 
343        if type(jbing) == type([]) : 
344            jbing = jbing[-1]
345        (jbtype, self.JobBillingCode) = jbing
346        if self.JobBillingCode is None :
347            self.OriginalJobBillingCode = None
348        else :   
349            self.JobBillingCode = self.UTF8ToUserCharset(self.JobBillingCode)
350            self.OriginalJobBillingCode = self.JobBillingCode[:]
351           
352        baselockfilename = self.DeviceURI.replace("/", ".")
353        baselockfilename = baselockfilename.replace(":", ".")
354        baselockfilename = baselockfilename.replace("?", ".")
355        baselockfilename = baselockfilename.replace("&", ".")
356        baselockfilename = baselockfilename.replace("@", ".")
357        self.lockfilename = os.path.join(self.Directory, "%s-%s..LCK" % (self.myname, baselockfilename))
358       
359        self.logdebug("Backend : %s" % self.RealBackend)
360        self.logdebug("DeviceURI : %s" % self.DeviceURI)
361        self.logdebug("Printername : %s" % self.PrinterName)
362        self.logdebug("Username : %s" % self.UserName)
363        self.logdebug("JobId : %s" % self.JobId)
364        self.logdebug("Title : %s" % self.Title)
365        self.logdebug("Filename : %s" % self.InputFile)
366        self.logdebug("Copies : %s" % self.Copies)
367        self.logdebug("Options : %s" % self.Options)
368        self.logdebug("Directory : %s" % self.Directory) 
369        self.logdebug("DataFile : %s" % self.DataFile)
370        self.logdebug("ControlFile : %s" % self.ControlFile)
371        self.logdebug("JobBillingCode : %s" % self.JobBillingCode)
372        self.logdebug("JobOriginatingHostName : %s" % self.ClientHost)
373       
374        # fakes some entries to allow for external mailto
375        # before real entries are extracted from the database.
376        self.User = FakeUser(self.UserName)
377        self.Printer = FakePrinter(self.PrinterName)
378       
379        self.enableSigInt()
380        self.logdebug("Backend initialized.")
381       
382    def overwriteJobAttributes(self) :
383        """Overwrites some of the job's attributes if needed."""
384        self.logdebug("Sanitizing job's attributes...")
385        # First overwrite the job ticket
386        self.overwriteJobTicket()
387       
388        # do we want to strip out the Samba/Winbind domain name ?
389        separator = self.config.getWinbindSeparator()
390        if separator is not None :
391            self.UserName = self.UserName.split(separator)[-1]
392           
393        # do we want to lowercase usernames ?   
394        if self.config.getUserNameToLower() :
395            self.UserName = self.UserName.lower()
396           
397        # do we want to strip some prefix off of titles ?   
398        stripprefix = self.config.getStripTitle(self.PrinterName)
399        if stripprefix :
400            if fnmatch.fnmatch(self.Title[:len(stripprefix)], stripprefix) :
401                self.logdebug("Prefix [%s] removed from job's title [%s]." \
402                                      % (stripprefix, self.Title))
403                self.Title = self.Title[len(stripprefix):]
404               
405        self.logdebug("Username : %s" % self.UserName)
406        self.logdebug("BillingCode : %s" % self.JobBillingCode)
407        self.logdebug("Title : %s" % self.Title)
408        self.logdebug("Job's attributes sanitizing done.")
409               
410    def didUserConfirm(self) :
411        """Asks for user confirmation through an external script.
412       
413           returns False if the end user wants to cancel the job, else True.
414        """
415        self.logdebug("Checking if we have to ask for user's confirmation...")
416        answer = None                         
417        confirmationcommand = self.config.getAskConfirmation(self.PrinterName)
418        if confirmationcommand :
419            self.logdebug("Launching subprocess [%s] to ask for user confirmation." \
420                                     % confirmationcommand)
421            inputfile = os.popen(confirmationcommand, "r")
422            try :
423                for answer in inputfile.xreadlines() :
424                    answer = answer.strip().upper()
425                    if answer == "CANCEL" :
426                        break
427            except IOError, msg :           
428                self.logdebug("IOError while reading subprocess' output : %s" % msg)
429            inputfile.close()   
430            self.logdebug("User's confirmation received : %s" % (((answer == "CANCEL") and "CANCEL") or "CONTINUE"))
431        else :   
432            self.logdebug("No need to ask for user's confirmation, job processing will continue.")
433        return (answer != "CANCEL")   
434       
435    def overwriteJobTicket(self) :   
436        """Should we overwrite the job's ticket (username and billingcode) ?"""
437        self.logdebug("Checking if we need to overwrite the job ticket...")
438        jobticketcommand = self.config.getOverwriteJobTicket(self.PrinterName)
439        if jobticketcommand :
440            username = billingcode = action = None
441            self.logdebug("Launching subprocess [%s] to overwrite the job ticket." \
442                                     % jobticketcommand)
443            self.regainPriv()                         
444            inputfile = os.popen(jobticketcommand, "r")
445            try :
446                for line in inputfile.xreadlines() :
447                    line = line.strip()
448                    if line in ("DENY", "AUTH=NO", "AUTH=IMPOSSIBLE") :
449                        self.logdebug("Seen %s command." % line)
450                        action = "DENY"
451                    elif line == "CANCEL" :
452                        self.logdebug("Seen CANCEL command.")
453                        action = "CANCEL"
454                    elif line.startswith("USERNAME=") :   
455                        username = self.userCharsetToUTF8(line.split("=", 1)[1].strip())
456                        self.logdebug("Seen new username [%s]" % username)
457                    elif line.startswith("BILLINGCODE=") :   
458                        billingcode = self.userCharsetToUTF8(line.split("=", 1)[1].strip())
459                        self.logdebug("Seen new billing code [%s]" % billingcode)
460            except IOError, msg :           
461                self.logdebug("IOError while reading subprocess' output : %s" % msg)
462            inputfile.close()   
463            self.dropPriv()
464           
465            # now overwrite the job's ticket if new data was supplied
466            if action == "DENY" :
467                self.Action = action
468                self.Reason = _("You are not allowed to print at this time.")
469            elif action == "CANCEL" :
470                self.Action = action
471                self.Reason = _("Print job cancelled.")
472                os.environ["PYKOTASTATUS"] = "CANCELLED"
473            else :
474                # don't overwrite anything unless job authorized
475                # to continue to the physical printer.
476                if username and username.strip() :
477                    self.UserName = username
478                if billingcode is not None :
479                    self.JobBillingCode = billingcode 
480        self.logdebug("Job ticket overwriting done.")
481           
482    def saveDatasAndCheckSum(self) :
483        """Saves the input datas into a static file."""
484        self.logdebug("Duplicating data stream into %s" % self.DataFile)
485        mustclose = 0
486        outfile = open(self.DataFile, "wb")   
487        if self.InputFile is not None :
488            self.regainPriv()
489            infile = open(self.InputFile, "rb")
490            self.logdebug("Reading input datas from %s" % self.InputFile)
491            mustclose = 1
492        else :   
493            infile = sys.stdin
494            self.logdebug("Reading input datas from stdin")
495        CHUNK = 64*1024         # read 64 Kb at a time
496        dummy = 0
497        sizeread = 0
498        checksum = md5.new()
499        while 1 :
500            data = infile.read(CHUNK) 
501            if not data :
502                break
503            sizeread += len(data)   
504            outfile.write(data)
505            checksum.update(data)   
506            if not (dummy % 32) : # Only display every 2 Mb
507                self.logdebug("%s bytes saved..." % sizeread)
508            dummy += 1   
509        if mustclose :   
510            infile.close()
511            self.dropPriv()
512           
513        outfile.close()
514        self.JobSizeBytes = sizeread   
515        self.JobMD5Sum = checksum.hexdigest()
516       
517        self.logdebug("JobSizeBytes : %s" % self.JobSizeBytes)
518        self.logdebug("JobMD5Sum : %s" % self.JobMD5Sum)
519        self.logdebug("Data stream duplicated into %s" % self.DataFile)
520           
521    def clean(self) :
522        """Cleans up the place."""
523        self.logdebug("Cleaning up...")
524        self.regainPriv()
525        self.deinstallSigTermHandler()
526        if (self.DataFile is not None) and os.path.exists(self.DataFile) :
527            try :
528                keep = self.config.getPrinterKeepFiles(self.PrinterName)
529            except AttributeError :   
530                keep = False
531            if not keep :
532                self.logdebug("Work file %s will be deleted." % self.DataFile)
533                try :
534                    os.remove(self.DataFile)
535                except OSError, msg :
536                    self.logdebug("Problem while deleting work file %s : %s" % (self.DataFile, msg))
537                else :
538                    self.logdebug("Work file %s has been deleted." % self.DataFile)
539            else :   
540                self.logdebug("Work file %s will be kept." % self.DataFile)
541        PyKotaTool.clean(self)   
542        if self.lockfile is not None :
543            self.logdebug("Unlocking %s..." %  self.lockfilename)
544            try :
545                fcntl.lockf(self.lockfile, fcntl.LOCK_UN)
546                self.lockfile.close()
547            except :   
548                self.printInfo("Problem while unlocking %s" % self.lockfilename, "error")
549            else :   
550                self.logdebug("%s unlocked." % self.lockfilename)
551        self.logdebug("Clean.")
552           
553    def precomputeJobSize(self) :   
554        """Computes the job size with a software method."""
555        self.logdebug("Precomputing job's size...")
556        self.preaccounter.beginJob(None)
557        self.preaccounter.endJob(None)
558        self.softwareJobSize = self.preaccounter.getJobSize(None)
559        self.logdebug("Precomputed job's size is %s pages." % self.softwareJobSize)
560       
561    def precomputeJobPrice(self) :   
562        """Precomputes the job price with a software method."""
563        self.logdebug("Precomputing job's price...")
564        self.softwareJobPrice = self.UserPQuota.computeJobPrice(self.softwareJobSize, self.preaccounter.inkUsage)
565        self.logdebug("Precomputed job's price is %.3f credits." \
566                                   % self.softwareJobPrice)
567       
568    def getCupsConfigDirectives(self, directives=[]) :
569        """Retrieves some CUPS directives from its configuration file.
570       
571           Returns a mapping with lowercased directives as keys and
572           their setting as values.
573        """
574        self.logdebug("Parsing CUPS' configuration file...")
575        dirvalues = {} 
576        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
577        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
578        try :
579            conffile = open(cupsdconf, "r")
580        except IOError :   
581            raise PyKotaToolError, "Unable to open %s" % cupsdconf
582        else :   
583            for line in conffile.readlines() :
584                linecopy = line.strip().lower()
585                for di in [d.lower() for d in directives] :
586                    if linecopy.startswith("%s " % di) :
587                        try :
588                            val = line.split()[1]
589                        except :   
590                            pass # ignore errors, we take the last value in any case.
591                        else :   
592                            dirvalues[di] = val
593            conffile.close()           
594        self.logdebug("CUPS' configuration file parsed successfully.")
595        return dirvalues       
596           
597    def parseIPPRequestFile(self) :       
598        """Parses the IPP message file and returns a tuple (filename, parsedvalue)."""
599        self.logdebug("Parsing IPP request file...")
600       
601        class DummyClass :
602            """Class used to avoid errors."""
603            operation_attributes = {}
604            job_attributes = {}
605           
606        ippmessage = DummyClass() # in case the code below fails
607       
608        self.regainPriv()
609        cupsdconf = self.getCupsConfigDirectives(["RequestRoot"])
610        requestroot = cupsdconf.get("requestroot", "/var/spool/cups")
611        if (len(self.JobId) < 5) and self.JobId.isdigit() :
612            ippmessagefile = "c%05i" % int(self.JobId)
613        else :   
614            ippmessagefile = "c%s" % self.JobId
615        ippmessagefile = os.path.join(requestroot, ippmessagefile)
616        try :
617            ippdatafile = open(ippmessagefile)
618        except :   
619            self.logdebug("Unable to open IPP request file %s" % ippmessagefile)
620        else :   
621            self.logdebug("Parsing of IPP request file %s begins." % ippmessagefile)
622            try :
623                ippmessage = oldIPPRequest(ippdatafile.read())
624                ippmessage.parse()
625            except oldIPPError, msg :   
626                self.printInfo("Error while parsing %s : %s" \
627                                      % (ippmessagefile, msg), "warn")
628            else :   
629                self.logdebug("Parsing of IPP request file %s ends." \
630                                       % ippmessagefile)
631            ippdatafile.close()
632        self.dropPriv()
633        self.logdebug("IPP request file parsed successfully.")
634        return (ippmessagefile, ippmessage)
635               
636    def exportJobInfo(self) :   
637        """Exports the actual job's attributes to the environment."""
638        self.logdebug("Exporting job information to the environment...")
639        os.environ["DEVICE_URI"] = self.DeviceURI       # WARNING !
640        os.environ["PYKOTAPRINTERNAME"] = self.PrinterName
641        os.environ["PYKOTADIRECTORY"] = self.Directory
642        os.environ["PYKOTADATAFILE"] = self.DataFile
643        os.environ["PYKOTAJOBSIZEBYTES"] = str(self.JobSizeBytes)
644        os.environ["PYKOTAMD5SUM"] = self.JobMD5Sum
645        os.environ["PYKOTAJOBORIGINATINGHOSTNAME"] = self.ClientHost or ""
646        os.environ["PYKOTAJOBID"] = self.JobId
647        os.environ["PYKOTAUSERNAME"] = self.UserName
648        os.environ["PYKOTAORIGINALUSERNAME"] = self.OriginalUserName
649        os.environ["PYKOTATITLE"] = self.Title
650        os.environ["PYKOTACOPIES"] = str(self.Copies)
651        os.environ["PYKOTAOPTIONS"] = self.Options
652        os.environ["PYKOTAFILENAME"] = self.InputFile or ""
653        os.environ["PYKOTAJOBBILLING"] = self.JobBillingCode or ""
654        os.environ["PYKOTAORIGINALJOBBILLING"] = self.OriginalJobBillingCode or ""
655        os.environ["PYKOTACONTROLFILE"] = self.ControlFile
656        os.environ["PYKOTAPRINTERHOSTNAME"] = self.PrinterHostName
657        os.environ["PYKOTAPRECOMPUTEDJOBSIZE"] = str(self.softwareJobSize)
658        self.logdebug("Environment updated.")
659       
660    def exportUserInfo(self) :
661        """Exports user information to the environment."""
662        self.logdebug("Exporting user information to the environment...")
663        os.environ["PYKOTAOVERCHARGE"] = str(self.User.OverCharge)
664        os.environ["PYKOTALIMITBY"] = str(self.User.LimitBy)
665        os.environ["PYKOTABALANCE"] = str(self.User.AccountBalance or 0.0)
666        os.environ["PYKOTALIFETIMEPAID"] = str(self.User.LifeTimePaid or 0.0)
667        os.environ["PYKOTAUSERDESCRIPTION"] = str(self.User.Description or "")
668       
669        os.environ["PYKOTAPAGECOUNTER"] = str(self.UserPQuota.PageCounter or 0)
670        os.environ["PYKOTALIFEPAGECOUNTER"] = str(self.UserPQuota.LifePageCounter or 0)
671        os.environ["PYKOTASOFTLIMIT"] = str(self.UserPQuota.SoftLimit)
672        os.environ["PYKOTAHARDLIMIT"] = str(self.UserPQuota.HardLimit)
673        os.environ["PYKOTADATELIMIT"] = str(self.UserPQuota.DateLimit)
674        os.environ["PYKOTAWARNCOUNT"] = str(self.UserPQuota.WarnCount)
675       
676        # TODO : move this elsewhere once software accounting is done only once.
677        os.environ["PYKOTAPRECOMPUTEDJOBPRICE"] = str(self.softwareJobPrice)
678       
679        self.logdebug("Environment updated.")
680       
681    def exportPrinterInfo(self) :
682        """Exports printer information to the environment."""
683        self.logdebug("Exporting printer information to the environment...")
684        # exports the list of printers groups the current
685        # printer is a member of
686        os.environ["PYKOTAPGROUPS"] = ",".join([p.Name for p in self.storage.getParentPrinters(self.Printer)])
687        os.environ["PYKOTAPRINTERDESCRIPTION"] = str(self.Printer.Description or "")
688        os.environ["PYKOTAPRINTERMAXJOBSIZE"] = str(self.Printer.MaxJobSize or _("Unlimited"))
689        os.environ["PYKOTAPRINTERPASSTHROUGHMODE"] = (self.Printer.PassThrough and _("ON")) or _("OFF")
690        os.environ["PYKOTAPRICEPERPAGE"] = str(self.Printer.PricePerPage or 0)
691        os.environ["PYKOTAPRICEPERJOB"] = str(self.Printer.PricePerJob or 0)
692        self.logdebug("Environment updated.")
693       
694    def exportPhaseInfo(self, phase) :
695        """Exports phase information to the environment."""
696        self.logdebug("Exporting phase information [%s] to the environment..." % phase)
697        os.environ["PYKOTAPHASE"] = phase
698        self.logdebug("Environment updated.")
699       
700    def exportJobSizeAndPrice(self) :
701        """Exports job's size and price information to the environment."""
702        self.logdebug("Exporting job's size and price information to the environment...")
703        os.environ["PYKOTAJOBSIZE"] = str(self.JobSize)
704        os.environ["PYKOTAJOBPRICE"] = str(self.JobPrice)
705        self.logdebug("Environment updated.")
706       
707    def exportReason(self) :
708        """Exports the job's action status and optional reason."""
709        self.logdebug("Exporting job's action status...")
710        os.environ["PYKOTAACTION"] = str(self.Action)
711        if self.Reason :
712            os.environ["PYKOTAREASON"] = str(self.Reason)
713        self.logdebug("Environment updated.")
714       
715    def acceptJob(self) :       
716        """Returns the appropriate exit code to tell CUPS all is OK."""
717        return 0
718           
719    def removeJob(self) :           
720        """Returns the appropriate exit code to let CUPS think all is OK.
721       
722           Returning 0 (success) prevents CUPS from stopping the print queue.
723        """   
724        return 0
725       
726    def launchPreHook(self) :
727        """Allows plugging of an external hook before the job gets printed."""
728        prehook = self.config.getPreHook(self.PrinterName)
729        if prehook :
730            self.logdebug("Executing pre-hook [%s]..." % prehook)
731            retcode = os.system(prehook)
732            self.logdebug("pre-hook exited with status %s." % retcode)
733       
734    def launchPostHook(self) :
735        """Allows plugging of an external hook after the job gets printed and/or denied."""
736        posthook = self.config.getPostHook(self.PrinterName)
737        if posthook :
738            self.logdebug("Executing post-hook [%s]..." % posthook)
739            retcode = os.system(posthook)
740            self.logdebug("post-hook exited with status %s." % retcode)
741           
742    def improveMessage(self, message) :       
743        """Improves a message by adding more informations in it if possible."""
744        try :
745            return "%s@%s(%s) => %s" % (self.UserName, \
746                                        self.PrinterName, \
747                                        self.JobId, \
748                                        message)
749        except :                                               
750            return message
751       
752    def logdebug(self, message) :       
753        """Improves the debug message before outputting it."""
754        PyKotaTool.logdebug(self, self.improveMessage(message))
755       
756    def printInfo(self, message, level="info") :       
757        """Improves the informational message before outputting it."""
758        self.logger.log_message(self.improveMessage(message), level)
759   
760    def startingBanner(self, withaccounting) :
761        """Retrieves a starting banner for current printer and returns its content."""
762        self.logdebug("Retrieving starting banner...")
763        self.printBanner(self.config.getStartingBanner(self.PrinterName), withaccounting)
764        self.logdebug("Starting banner retrieved.")
765   
766    def endingBanner(self, withaccounting) :
767        """Retrieves an ending banner for current printer and returns its content."""
768        self.logdebug("Retrieving ending banner...")
769        self.printBanner(self.config.getEndingBanner(self.PrinterName), withaccounting)
770        self.logdebug("Ending banner retrieved.")
771       
772    def printBanner(self, bannerfileorcommand, withaccounting) :
773        """Reads a banner or generates one through an external command.
774       
775           Returns the banner's content in a format which MUST be accepted
776           by the printer.
777        """
778        self.logdebug("Printing banner...")
779        if bannerfileorcommand :
780            if os.access(bannerfileorcommand, os.X_OK) or \
781                  not os.path.isfile(bannerfileorcommand) :
782                self.logdebug("Launching %s to generate a banner." % bannerfileorcommand)
783                child = popen2.Popen3(bannerfileorcommand, capturestderr=1)
784                self.runOriginalBackend(child.fromchild, isBanner=1)
785                child.tochild.close()
786                child.childerr.close()
787                child.fromchild.close()
788                status = child.wait()
789                if os.WIFEXITED(status) :
790                    status = os.WEXITSTATUS(status)
791                self.printInfo(_("Banner generator %s exit code is %s") \
792                                         % (bannerfileorcommand, str(status)))
793                if withaccounting :
794                    if self.accounter.isSoftware :
795                        self.BannerSize += 1 # TODO : fix this by passing the banner's content through software accounting
796            else :
797                self.logdebug("Using %s as the banner." % bannerfileorcommand)
798                try :
799                    fh = open(bannerfileorcommand, 'rb')
800                except IOError, msg :   
801                    self.printInfo("Impossible to open %s : %s" \
802                                       % (bannerfileorcommand, msg), "error")
803                else :   
804                    self.runOriginalBackend(fh, isBanner=1)
805                    fh.close()
806                    if withaccounting :
807                        if self.accounter.isSoftware :
808                            self.BannerSize += 1 # TODO : fix this by passing the banner's content through software accounting
809        self.logdebug("Banner printed...")
810               
811    def handleBanner(self, bannertype, withaccounting) :
812        """Handles the banner with or without accounting."""
813        if withaccounting :
814            acc = "with"
815        else :   
816            acc = "without"
817        self.logdebug("Handling %s banner %s accounting..." % (bannertype, acc))
818        if (self.Action == 'DENY') and \
819           (self.UserPQuota.WarnCount >= \
820                            self.config.getMaxDenyBanners(self.PrinterName)) :
821            self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), \
822                             "warn")
823        else :
824            if self.Action == 'DENY' :
825                self.logdebug("Incrementing the number of deny banners for user %s on printer %s" \
826                                  % (self.UserName, self.PrinterName))
827                self.UserPQuota.incDenyBannerCounter() # increments the warning counter
828                self.exportUserInfo()
829            getattr(self, "%sBanner" % bannertype)(withaccounting)
830        self.logdebug("%s banner done." % bannertype.title())
831       
832    def sanitizeJobSize(self) :   
833        """Sanitizes the job's size if needed."""
834        # TODO : there's a difficult to see bug here when banner accounting is activated and hardware accounting is used.
835        self.logdebug("Sanitizing job's size...")
836        if self.softwareJobSize and (self.JobSize != self.softwareJobSize) :
837            self.printInfo(_("Beware : computed job size (%s) != precomputed job size (%s)") % \
838                                       (self.JobSize, self.softwareJobSize), \
839                           "error")
840            (limit, replacement) = self.config.getTrustJobSize(self.PrinterName)
841            if limit is None :
842                self.printInfo(_("The job size will be trusted anyway according to the 'trustjobsize' directive"), "warn")
843            else :
844                if self.JobSize <= limit :
845                    self.printInfo(_("The job size will be trusted because it is inferior to the 'trustjobsize' directive's limit %s") % limit, "warn")
846                else :
847                    self.printInfo(_("The job size will be modified according to the 'trustjobsize' directive : %s") % replacement, "warn")
848                    if replacement == "PRECOMPUTED" :
849                        self.JobSize = self.softwareJobSize
850                    else :   
851                        self.JobSize = replacement
852        self.logdebug("Job's size sanitized.")
853                       
854    def getPrinterUserAndUserPQuota(self) :       
855        """Returns a tuple (policy, printer, user, and user print quota) on this printer.
856       
857           "OK" is returned in the policy if both printer, user and user print quota
858           exist in the Quota Storage.
859           Otherwise, the policy as defined for this printer in pykota.conf is returned.
860           
861           If policy was set to "EXTERNAL" and one of printer, user, or user print quota
862           doesn't exist in the Quota Storage, then an external command is launched, as
863           defined in the external policy for this printer in pykota.conf
864           This external command can do anything, like automatically adding printers
865           or users, for example, and finally extracting printer, user and user print
866           quota from the Quota Storage is tried a second time.
867           
868           "EXTERNALERROR" is returned in case policy was "EXTERNAL" and an error status
869           was returned by the external command.
870        """
871        self.logdebug("Retrieving printer, user, and user print quota entry from database...")
872        for passnumber in range(1, 3) :
873            printer = self.storage.getPrinter(self.PrinterName)
874            user = self.storage.getUser(self.UserName)
875            userpquota = self.storage.getUserPQuota(user, printer)
876            if printer.Exists and user.Exists and userpquota.Exists :
877                policy = "OK"
878                break
879            (policy, args) = self.config.getPrinterPolicy(self.PrinterName)
880            if policy == "EXTERNAL" :   
881                commandline = self.formatCommandLine(args, user, printer)
882                if not printer.Exists :
883                    self.printInfo(_("Printer %s not registered in the PyKota system, applying external policy (%s) for printer %s") % (self.PrinterName, commandline, self.PrinterName))
884                if not user.Exists :
885                    self.printInfo(_("User %s not registered in the PyKota system, applying external policy (%s) for printer %s") % (self.UserName, commandline, self.PrinterName))
886                if not userpquota.Exists :
887                    self.printInfo(_("User %s doesn't have quota on printer %s in the PyKota system, applying external policy (%s) for printer %s") % (self.UserName, self.PrinterName, commandline, self.PrinterName))
888                if os.system(commandline) :
889                    self.printInfo(_("External policy %s for printer %s produced an error. Job rejected. Please check PyKota's configuration files.") % (commandline, self.PrinterName), "error")
890                    policy = "EXTERNALERROR"
891                    break
892            else :       
893                if not printer.Exists :
894                    self.printInfo(_("Printer %s not registered in the PyKota system, applying default policy (%s)") % (self.PrinterName, policy))
895                if not user.Exists :
896                    self.printInfo(_("User %s not registered in the PyKota system, applying default policy (%s) for printer %s") % (self.UserName, policy, self.PrinterName))
897                if not userpquota.Exists :
898                    self.printInfo(_("User %s doesn't have quota on printer %s in the PyKota system, applying default policy (%s)") % (self.UserName, self.PrinterName, policy))
899                break
900               
901        if policy == "EXTERNAL" :   
902            if not printer.Exists :
903                self.printInfo(_("Printer %s still not registered in the PyKota system, job will be rejected") % self.PrinterName)
904            if not user.Exists :
905                self.printInfo(_("User %s still not registered in the PyKota system, job will be rejected on printer %s") % (self.UserName, self.PrinterName))
906            if not userpquota.Exists :
907                self.printInfo(_("User %s still doesn't have quota on printer %s in the PyKota system, job will be rejected") % (self.UserName, self.PrinterName))
908        self.Policy = policy         
909        self.Printer = printer
910        self.User = user
911        self.UserPQuota = userpquota
912        self.logdebug("Retrieval of printer, user and user print quota entry done.")
913       
914    def getBillingCode(self) :   
915        """Extracts the billing code from the database.
916         
917           An optional script is launched to notify the user when
918           the billing code is unknown and PyKota was configured to
919           deny printing in this case.
920        """
921        self.logdebug("Retrieving billing code information from the database...")
922        self.BillingCode = None
923        if self.JobBillingCode :
924            self.BillingCode = self.storage.getBillingCode(self.JobBillingCode)
925            if self.BillingCode.Exists :
926                self.logdebug("Billing code [%s] found in database." % self.JobBillingCode)
927            else :
928                msg = "Unknown billing code [%s] : " % self.JobBillingCode
929                (newaction, script) = self.config.getUnknownBillingCode(self.PrinterName)
930                if newaction == "CREATE" :
931                    self.logdebug(msg + "will be created.")
932                    self.storage.addBillingCode(self.BillingCode)
933                    self.BillingCode = self.storage.getBillingCode(self.JobBillingCode)
934                    if self.BillingCode.Exists :
935                        self.logdebug(msg + "has been created.")
936                    else :   
937                        self.printInfo(msg + "couldn't be created.", "error")
938                else :   
939                    self.logdebug(msg + "job will be denied.")
940                    self.Action = newaction
941                    if script is not None : 
942                        self.logdebug(msg + "launching subprocess [%s] to notify user." % script)
943                        os.system(script)
944        self.logdebug("Retrieval of billing code information done.")
945       
946    def checkIfDupe(self) :   
947        """Checks if the job is a duplicate, and handles the situation."""
948        self.logdebug("Checking if the job is a duplicate...")
949        denyduplicates = self.config.getDenyDuplicates(self.PrinterName)
950        if not denyduplicates :
951            self.logdebug("We don't care about duplicate jobs after all.")
952        else :
953            if self.Printer.LastJob.Exists \
954                    and (self.Printer.LastJob.UserName == self.UserName) \
955                    and (self.Printer.LastJob.JobMD5Sum == self.JobMD5Sum) :
956                now = DateTime.now()
957                try :
958                    previous = DateTime.ISO.ParseDateTime(str(self.Printer.LastJob.JobDate)[:19]).localtime()
959                except :
960                    previous = now
961                difference = (now - previous).seconds
962                duplicatesdelay = self.config.getDuplicatesDelay(self.PrinterName)
963                self.logdebug("Difference with previous job : %.2f seconds. Duplicates delay : %.2f seconds." % (difference, duplicatesdelay))
964                if difference > duplicatesdelay :
965                    self.logdebug("Duplicate job allowed because previous one is more than %.2f seconds old." % duplicatesdelay)
966                else :
967                    # TODO : use the current user's last job instead of 
968                    # TODO : the current printer's last job. This would be
969                    # TODO : better but requires an additional database query
970                    # TODO : with SQL, and is much more complex with the
971                    # TODO : actual LDAP schema. Maybe this is not very
972                    # TODO : important, because usually duplicate jobs are sucessive.
973                    msg = _("Job is a dupe")
974                    if denyduplicates == 1 :
975                        self.printInfo("%s : %s." % (msg, _("Printing is denied by configuration")), "warn")
976                        self.Action = "DENY"
977                        self.Reason = _("Duplicate print jobs are not allowed on printer %s.") % self.PrinterName
978                    else :   
979                        self.logdebug("Launching subprocess [%s] to see if duplicate jobs should be allowed or not." % denyduplicates)
980                        fanswer = os.popen(denyduplicates, "r")
981                        self.Action = fanswer.read().strip().upper()
982                        fanswer.close()
983                        if self.Action == "DENY" :     
984                            self.printInfo("%s : %s." % (msg, _("Subprocess denied printing of a dupe")), "warn")
985                            self.Reason = _("Duplicate print jobs are not allowed on printer %s at this time.") % self.PrinterName
986                        else :   
987                            self.printInfo("%s : %s." % (msg, _("Subprocess allowed printing of a dupe")), "warn")
988            else :           
989                self.logdebug("Job doesn't seem to be a duplicate.")
990        self.logdebug("Checking if the job is a duplicate done.")
991       
992    def tellUser(self) :
993        """Sends a message to an user."""
994        self.logdebug("Sending some feedback to user %s..." % self.UserName) 
995        if not self.Reason :
996            self.logdebug("No feedback to send to user %s." % self.UserName)
997        else :   
998            (mailto, arguments) = self.config.getMailTo(self.PrinterName)
999            if mailto == "EXTERNAL" :
1000                # TODO : clean this again
1001                self.regainPriv()
1002                self.externalMailTo(arguments, self.Action, self.User, self.Printer, self.Reason)
1003                self.dropPriv()
1004            else :   
1005                # TODO : clean this again
1006                admin = self.config.getAdmin(self.PrinterName)
1007                adminmail = self.config.getAdminMail(self.PrinterName)
1008                usermail = self.User.Email or self.User.Name
1009                if "@" not in usermail :
1010                    usermail = "%s@%s" % (usermail, self.maildomain or self.smtpserver)
1011                destination = []
1012                if mailto in ("BOTH", "ADMIN") :
1013                    destination.append(adminmail)
1014                if mailto in ("BOTH", "USER") :   
1015                    destination.append(usermail)
1016                   
1017                fullmessage = self.Reason + (_("\n\nYour system administrator :\n\n\t%s - <%s>\n") % (admin, adminmail))
1018                try :   
1019                    server = smtplib.SMTP(self.smtpserver)
1020                except socket.error, msg :   
1021                    self.printInfo(_("Impossible to connect to SMTP server : %s") % msg, "error")
1022                else :
1023                    try :
1024                        msg = MIMEText(fullmessage, _charset=self.charset)
1025                        msg["Subject"] = str(Header(_("Print Quota"), charset=self.charset))
1026                        msg["From"] = adminmail
1027                        if mailto in ("BOTH", "USER") :
1028                            msg["To"] = usermail
1029                            if mailto == "BOTH" :
1030                                msg["Cc"] = adminmail
1031                        else :   
1032                            msg["To"] = adminmail
1033                        msg["Date"] = email.Utils.formatdate(localtime=True)
1034                        server.sendmail(adminmail, destination, msg.as_string())
1035                    except smtplib.SMTPException, answer :   
1036                        try :
1037                            for (k, v) in answer.recipients.items() :
1038                                self.printInfo(_("Impossible to send mail to %s, error %s : %s") % (k, v[0], v[1]), "error")
1039                        except AttributeError :
1040                            self.printInfo(_("Problem when sending mail : %s") % str(answer), "error")
1041                    server.quit()
1042            self.logdebug("Feedback sent to user %s." % self.UserName)
1043               
1044    def mainWork(self) :   
1045        """Main work is done here."""
1046        if not self.JobSizeBytes :
1047            # if no data to pass to real backend, probably a filter
1048            # higher in the chain failed because of a misconfiguration.
1049            # we deny the job in this case (nothing to print anyway)
1050            self.Reason = _("Job contains no data. Printing is denied.")
1051            self.printInfo(self.Reason, "error")
1052            self.tellUser()
1053            return self.removeJob()
1054           
1055        self.getPrinterUserAndUserPQuota()
1056        if self.Policy == "EXTERNALERROR" :
1057            # Policy was 'EXTERNAL' and the external command returned an error code
1058            self.Reason = _("Error in external policy script. Printing is denied.")
1059            self.printInfo(self.Reason, "error")
1060            self.tellUser()
1061            return self.removeJob()
1062        elif self.Policy == "EXTERNAL" :
1063            # Policy was 'EXTERNAL' and the external command wasn't able
1064            # to add either the printer, user or user print quota
1065            self.Reason = _("Still no print quota entry for user %s on printer %s after external policy. Printing is denied.") % (self.UserName, self.PrinterName)
1066            self.printInfo(self.Reason, "warn")
1067            self.tellUser()
1068            return self.removeJob()
1069        elif self.Policy == "DENY" :   
1070            # Either printer, user or user print quota doesn't exist,
1071            # and the job should be rejected.
1072            self.Reason = _("Printing is denied by printer policy.")
1073            self.printInfo(self.Reason, "warn")
1074            self.tellUser()
1075            return self.removeJob()
1076        elif self.Policy == "ALLOW" :
1077            # ALLOW means : Either printer, user or user print quota doesn't exist,
1078            #               but the job should be allowed anyway.
1079            self.Reason = _("Job allowed by printer policy. No accounting will be done.")
1080            self.printInfo(self.Reason, "warn")
1081            self.tellUser()
1082            return self.printJobDatas()
1083        elif self.Policy == "OK" :
1084            # OK means : Both printer, user and user print quota exist, job should
1085            #            be allowed if current user is allowed to print on this printer
1086            return self.doWork()
1087        else :   
1088            self.Reason = _("Invalid policy %s for printer %s") % (self.Policy, self.PrinterName)
1089            self.printInfo(self.Reason, "error")
1090            self.tellUser()
1091            return self.removeJob()
1092   
1093    def doWork(self) :   
1094        """The accounting work is done here."""
1095        self.precomputeJobPrice()
1096        self.exportUserInfo()
1097        self.exportPrinterInfo()
1098        self.exportPhaseInfo("BEFORE")
1099       
1100        if self.Action not in ("DENY", "CANCEL") : 
1101            if not self.didUserConfirm() :
1102                self.Action = "CANCEL"
1103                self.Reason = _("Print job cancelled.")
1104                os.environ["PYKOTASTATUS"] = "CANCELLED"
1105               
1106        if self.Action not in ("DENY", "CANCEL") : 
1107            if self.Printer.MaxJobSize and (self.softwareJobSize > self.Printer.MaxJobSize) :
1108                # This printer was set to refuse jobs this large.
1109                self.printInfo(_("Precomputed job size (%s pages) too large for printer %s.") % (self.softwareJobSize, self.PrinterName), "warn")
1110                self.Action = "DENY"
1111                # here we don't put the precomputed job size in the message
1112                # because in case of error the user could complain :-)
1113                self.Reason = _("You are not allowed to print so many pages on printer %s at this time.") % self.PrinterName
1114           
1115        if self.Action not in ("DENY", "CANCEL") :
1116            if self.User.LimitBy == "noprint" :
1117                self.printInfo(_("User %s is not allowed to print at this time.") % self.UserName, "warn")
1118                self.Action = "DENY"
1119                self.Reason = _("Your account settings forbid you to print at this time.")
1120               
1121        if self.Action not in ("DENY", "CANCEL") :
1122            # If printing is still allowed at this time, we
1123            # need to extract the billing code information from the database.
1124            # No need to do this if the job is denied, this way we
1125            # save some database queries.
1126            self.getBillingCode()
1127           
1128        if self.Action not in ("DENY", "CANCEL") :
1129            # If printing is still allowed at this time, we
1130            # need to check if the job is a dupe or not, and what to do then.
1131            # No need to do this if the job is denied, this way we
1132            # save some database queries.
1133            self.checkIfDupe()
1134                   
1135        if self.Action not in ("DENY", "CANCEL") :
1136            # If printing is still allowed at this time, we
1137            # need to check the user's print quota on the current printer.
1138            # No need to do this if the job is denied, this way we
1139            # save some database queries.
1140            if self.User.LimitBy in ('noquota', 'nochange') :
1141                self.logdebug("User %s is allowed to print with no limit, no need to check quota." % self.UserName)
1142            elif self.Printer.PassThrough :   
1143                self.logdebug("Printer %s is in PassThrough mode, no need to check quota." % self.PrinterName)
1144            else :
1145                self.logdebug("Checking user %s print quota entry on printer %s" \
1146                                    % (self.UserName, self.PrinterName))
1147                self.Action = self.checkUserPQuota(self.UserPQuota)
1148                if self.Action.startswith("POLICY_") :
1149                    self.Action = self.Action[7:]
1150                if self.Action == "DENY" :
1151                    self.printInfo(_("Print Quota exceeded for user %s on printer %s") % (self.UserName, self.PrinterName))
1152                    self.Reason = self.config.getHardWarn(self.PrinterName)
1153                elif self.Action == "WARN" :   
1154                    self.printInfo(_("Print Quota low for user %s on printer %s") % (self.UserName, self.PrinterName))
1155                    if self.User.LimitBy and (self.User.LimitBy.lower() == "balance") : 
1156                        self.Reason = self.config.getPoorWarn()
1157                    else :     
1158                        self.Reason = self.config.getSoftWarn(self.PrinterName)
1159           
1160        # exports some new environment variables
1161        self.exportReason()
1162       
1163        # now tell the user if he needs to know something
1164        self.tellUser()
1165       
1166        # launches the pre hook
1167        self.launchPreHook()
1168       
1169        # handle starting banner pages without accounting
1170        self.BannerSize = 0
1171        accountbanner = self.config.getAccountBanner(self.PrinterName)
1172        if accountbanner in ["ENDING", "NONE"] :
1173            self.handleBanner("starting", 0)
1174       
1175        if self.Action == "DENY" :
1176            self.printInfo(_("Job denied, no accounting will be done."))
1177        elif self.Action == "CANCEL" :   
1178            self.printInfo(_("Job cancelled, no accounting will be done."))
1179        else :
1180            self.printInfo(_("Job accounting begins."))
1181            self.deinstallSigTermHandler()
1182            self.accounter.beginJob(self.Printer)
1183            self.installSigTermHandler()
1184       
1185        # handle starting banner pages with accounting
1186        if accountbanner in ["STARTING", "BOTH"] :
1187            if not self.gotSigTerm :
1188                self.handleBanner("starting", 1)
1189       
1190        # pass the job's data to the real backend   
1191        if (not self.gotSigTerm) and (self.Action in ["ALLOW", "WARN"]) :
1192            retcode = self.printJobDatas()
1193        else :       
1194            retcode = self.removeJob()
1195       
1196        # indicate phase change
1197        self.exportPhaseInfo("AFTER")
1198       
1199        # handle ending banner pages with accounting
1200        if accountbanner in ["ENDING", "BOTH"] :
1201            if not self.gotSigTerm :
1202                self.handleBanner("ending", 1)
1203       
1204        # stops accounting
1205        if self.Action == "DENY" :
1206            self.printInfo(_("Job denied, no accounting has been done."))
1207        elif self.Action == "CANCEL" :   
1208            self.printInfo(_("Job cancelled, no accounting has been done."))
1209        else :
1210            self.deinstallSigTermHandler()
1211            self.accounter.endJob(self.Printer)
1212            self.installSigTermHandler()
1213            self.printInfo(_("Job accounting ends."))
1214       
1215        # Do all these database changes within a single transaction   
1216        # NB : we don't enclose ALL the changes within a single transaction
1217        # because while waiting for the printer to answer its internal page
1218        # counter, we would open the door to accounting problems for other
1219        # jobs launched by the same user at the same time on other printers.
1220        # All the code below doesn't take much time, so it's fine.
1221        self.storage.beginTransaction()
1222        try :
1223            onbackenderror = self.config.getPrinterOnBackendError(self.PrinterName)
1224            if retcode :
1225                # NB : We don't send any feedback to the end user. Only the admin
1226                # has to know that the real CUPS backend failed.
1227                self.Action = "PROBLEM"
1228                self.exportReason()
1229                if "NOCHARGE" in onbackenderror :
1230                    self.JobSize = 0
1231                    self.printInfo(_("Job size forced to 0 because the real CUPS backend failed. No accounting will be done."), "warn")
1232                else :   
1233                    self.printInfo(_("The real CUPS backend failed, but the job will be accounted for anyway."), "warn")
1234                   
1235            # retrieve the job size   
1236            if self.Action == "DENY" :
1237                self.JobSize = 0
1238                self.printInfo(_("Job size forced to 0 because printing is denied."))
1239            elif self.Action == "CANCEL" :     
1240                self.JobSize = 0
1241                self.printInfo(_("Job size forced to 0 because printing was cancelled."))
1242            else :   
1243                self.UserPQuota.resetDenyBannerCounter()
1244                if (self.Action != "PROBLEM") or ("CHARGE" in onbackenderror) : 
1245                    self.JobSize = self.accounter.getJobSize(self.Printer)
1246                    self.sanitizeJobSize()
1247                    self.JobSize += self.BannerSize
1248            self.printInfo(_("Job size : %i") % self.JobSize)
1249           
1250            if ((self.Action == "PROBLEM") and ("NOCHARGE" in onbackenderror)) or \
1251                (self.Action in ("DENY", "CANCEL")) :
1252                self.JobPrice = 0.0
1253            elif (self.User.LimitBy == "nochange") or self.Printer.PassThrough :
1254                # no need to update the quota for the current user on this printer
1255                self.printInfo(_("User %s's quota on printer %s won't be modified") % (self.UserName, self.PrinterName))
1256                self.JobPrice = 0.0
1257            else :
1258                # update the quota for the current user on this printer
1259                self.printInfo(_("Updating user %s's quota on printer %s") % (self.UserName, self.PrinterName))
1260                self.JobPrice = self.UserPQuota.increasePagesUsage(self.JobSize, self.accounter.inkUsage)
1261           
1262            # adds the current job to history   
1263            self.Printer.addJobToHistory(self.JobId, self.User, self.accounter.getLastPageCounter(), \
1264                                    self.Action, self.JobSize, self.JobPrice, self.InputFile, \
1265                                    self.Title, self.Copies, self.Options, self.ClientHost, \
1266                                    self.JobSizeBytes, self.JobMD5Sum, None, self.JobBillingCode, \
1267                                    self.softwareJobSize, self.softwareJobPrice)
1268            self.printInfo(_("Job added to history."))
1269           
1270            if hasattr(self, "BillingCode") and self.BillingCode and self.BillingCode.Exists :
1271                if (self.Action in ("ALLOW", "WARN")) or \
1272                   ((self.Action == "PROBLEM") and ("CHARGE" in onbackenderror)) :
1273                    self.BillingCode.consume(self.JobSize, self.JobPrice)
1274                    self.printInfo(_("Billing code %s was updated.") % self.BillingCode.BillingCode)
1275        except :   
1276            self.storage.rollbackTransaction()
1277            raise
1278        else :   
1279            self.storage.commitTransaction()
1280           
1281        # exports some new environment variables
1282        self.exportJobSizeAndPrice()
1283       
1284        # then re-export user information with new values
1285        self.exportUserInfo()
1286       
1287        # handle ending banner pages without accounting
1288        if accountbanner in ["STARTING", "NONE"] :
1289            self.handleBanner("ending", 0)
1290                   
1291        self.launchPostHook()
1292           
1293        return retcode   
1294               
1295    def printJobDatas(self) :           
1296        """Sends the job's datas to the real backend."""
1297        self.logdebug("Sending job's datas to real backend...")
1298       
1299        delay = 0
1300        number = 1
1301        for onb in self.config.getPrinterOnBackendError(self.PrinterName) :
1302            if onb.startswith("RETRY:") :
1303                try :
1304                    (number, delay) = [int(p) for p in onb[6:].split(":", 2)]
1305                    if (number < 0) or (delay < 0) :
1306                        raise ValueError
1307                except ValueError :   
1308                    self.printInfo(_("Incorrect value for the 'onbackenderror' directive in section [%s]") % self.PrinterName, "error")
1309                    delay = 0
1310                    number = 1
1311                else :   
1312                    break
1313        loopcnt = 1 
1314        while True :           
1315            if self.InputFile is None :
1316                infile = open(self.DataFile, "rb")
1317            else :   
1318                infile = None
1319            retcode = self.runOriginalBackend(infile)
1320            if self.InputFile is None :
1321                infile.close()
1322            if not retcode :
1323                break
1324            else :
1325                if (not number) or (loopcnt < number) :
1326                    self.logdebug(_("The real backend produced an error, we will try again in %s seconds.") % delay)
1327                    time.sleep(delay)
1328                    loopcnt += 1
1329                else :   
1330                    break
1331           
1332        self.logdebug("Job's datas sent to real backend.")
1333        return retcode
1334       
1335    def runOriginalBackend(self, filehandle=None, isBanner=0) :
1336        """Launches the original backend."""
1337        originalbackend = os.path.join(os.path.split(sys.argv[0])[0], self.RealBackend)
1338        if not isBanner :
1339            arguments = [os.environ["DEVICE_URI"]] + sys.argv[1:]
1340        else :   
1341            # For banners, we absolutely WANT
1342            # to remove any filename from the command line !
1343            self.logdebug("It looks like we try to print a banner.")
1344            arguments = [os.environ["DEVICE_URI"]] + sys.argv[1:6]
1345        arguments[2] = self.UserName # in case it was overwritten by external script
1346        # TODO : do something about job-billing option, in case it was overwritten as well...
1347        # TODO : do something about the job title : if we are printing a banner and the backend
1348        # TODO : uses the job's title to name an output file (cups-pdf:// for example), we're stuck !
1349       
1350        self.logdebug("Starting original backend %s with args %s" % (originalbackend, " ".join(['"%s"' % a for a in arguments])))
1351        self.regainPriv()   
1352        pid = os.fork()
1353        self.logdebug("Forked !")
1354        if pid == 0 :
1355            if filehandle is not None :
1356                self.logdebug("Redirecting file handle to real backend's stdin")
1357                os.dup2(filehandle.fileno(), 0)
1358            try :
1359                self.logdebug("Calling execve...")
1360                os.execve(originalbackend, arguments, os.environ)
1361            except OSError, msg :
1362                self.logdebug("execve() failed: %s" % msg)
1363            self.logdebug("We shouldn't be there !!!")   
1364            os._exit(-1)
1365        self.dropPriv()   
1366       
1367        self.logdebug("Waiting for original backend to exit...")   
1368        killed = 0
1369        status = -1
1370        while status == -1 :
1371            try :
1372                status = os.waitpid(pid, 0)[1]
1373            except OSError, (err, msg) :
1374                if (err == 4) and self.gotSigTerm :
1375                    os.kill(pid, signal.SIGTERM)
1376                    killed = 1
1377                   
1378        if os.WIFEXITED(status) :
1379            status = os.WEXITSTATUS(status)
1380            message = "CUPS backend %s returned %d." % \
1381                            (originalbackend, status)
1382            if status :
1383                level = "error"
1384                self.Reason = message
1385            else :   
1386                level = "info"
1387            self.printInfo(message, level)
1388            return status
1389        elif not killed :
1390            self.Reason = "CUPS backend %s died abnormally." % originalbackend
1391            self.printInfo(self.Reason, "error")
1392            return -1
1393        else :
1394            self.Reason = "CUPS backend %s was killed." % originalbackend
1395            self.printInfo(self.Reason, "warn")
1396            return 1
1397       
1398if __name__ == "__main__" :   
1399    # This is a CUPS backend, we should act and die like a CUPS backend
1400    wrapper = CUPSBackend()
1401    if len(sys.argv) == 1 :
1402        print "\n".join(wrapper.discoverOtherBackends())
1403        sys.exit(0)               
1404    elif len(sys.argv) not in (6, 7) :   
1405        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n"\
1406                              % sys.argv[0])
1407        sys.exit(1)
1408    else :   
1409        os.environ["PATH"] = "%s:/bin:/usr/bin:/usr/local/bin:/opt/bin:/sbin:/usr/sbin" % os.environ.get("PATH", "")
1410        try :
1411            try :
1412                wrapper.deferredInit()
1413                wrapper.initBackendParameters()
1414                wrapper.waitForLock()
1415                if os.environ.get("PYKOTASTATUS") == "CANCELLED" :
1416                    raise KeyboardInterrupt
1417                wrapper.saveDatasAndCheckSum()
1418                wrapper.preaccounter = openAccounter(wrapper, ispreaccounter=1)
1419                wrapper.accounter = openAccounter(wrapper)
1420                wrapper.precomputeJobSize()
1421                wrapper.exportJobInfo() # exports a first time to give hints to external scripts
1422                wrapper.overwriteJobAttributes()
1423                wrapper.exportJobInfo() # re-exports in case it was overwritten
1424                retcode = wrapper.mainWork()
1425            except KeyboardInterrupt :   
1426                wrapper.printInfo(_("Job %s interrupted by the administrator !") % wrapper.JobId, "warn")
1427                retcode = 0
1428            except SystemExit, err :   
1429                retcode = err.code
1430            except :   
1431                try :
1432                    wrapper.crashed("cupspykota backend failed")
1433                except :   
1434                    crashed("cupspykota backend failed")
1435                retcode = 1
1436        finally :       
1437            wrapper.clean()
1438        sys.exit(retcode)
Note: See TracBrowser for help on using the browser.