root / pykota / trunk / bin / cupspykota @ 3232

Revision 3189, 72.8 kB (checked in by jerome, 17 years ago)

Now fails and logs a meaningful error message immediately when the cupspykota
backend can't read ~pykota/pykotadmin.conf, instead of printing the
document and failing at the time the job is written to the history.

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