root / pykota / trunk / bin / cupspykota @ 3013

Revision 3013, 69.6 kB (checked in by jerome, 18 years ago)

Killed another item from the TODO list

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