root / pykota / trunk / bin / cupspykota @ 1499

Revision 1499, 25.5 kB (checked in by jalet, 20 years ago)

accounter.py : old code deleted
the rest : now exports PYKOTAPRECOMPUTEDJOBSIZE and PYKOTAPRECOMPUTEDJOBPRICE

  • 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 Jerome Alet <alet@librelogiciel.com>
9# This program is free software; you can redistribute it and/or modify
10# it under the terms of the GNU General Public License as published by
11# the Free Software Foundation; either version 2 of the License, or
12# (at your option) any later version.
13#
14# This program is distributed in the hope that it will be useful,
15# but WITHOUT ANY WARRANTY; without even the implied warranty of
16# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
17# GNU General Public License for more details.
18#
19# You should have received a copy of the GNU General Public License
20# along with this program; if not, write to the Free Software
21# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307, USA.
22#
23# $Id$
24#
25# $Log$
26# Revision 1.52  2004/05/25 09:15:13  jalet
27# accounter.py : old code deleted
28# the rest : now exports PYKOTAPRECOMPUTEDJOBSIZE and PYKOTAPRECOMPUTEDJOBPRICE
29#
30# Revision 1.51  2004/05/25 08:31:16  jalet
31# Heavy CPU usage seems to be fixed at least !
32#
33# Revision 1.50  2004/05/25 05:17:50  jalet
34# Now precomputes the job's size only if current printer's enforcement
35# is "STRICT"
36#
37# Revision 1.49  2004/05/24 22:45:48  jalet
38# New 'enforcement' directive added
39# Polling loop improvements
40#
41# Revision 1.48  2004/05/24 14:36:24  jalet
42# Revert to old polling loop. Will need optimisations
43#
44# Revision 1.47  2004/05/24 11:59:46  jalet
45# More robust (?) code
46#
47# Revision 1.46  2004/05/21 22:02:51  jalet
48# Preliminary work on pre-accounting
49#
50# Revision 1.45  2004/05/19 07:15:32  jalet
51# Could the 'misterious' bug in my loop be finally fixed ???
52#
53# Revision 1.44  2004/05/18 14:48:47  jalet
54# Big code changes to completely remove the need for "requester" directives,
55# jsut use "hardware(... your previous requester directive's content ...)"
56#
57# Revision 1.43  2004/05/17 11:46:05  jalet
58# First try at cupspykota's main loop rewrite
59#
60# Revision 1.42  2004/05/10 11:22:28  jalet
61# Typo
62#
63# Revision 1.41  2004/05/10 10:07:30  jalet
64# Catches OSError while reading
65#
66# Revision 1.40  2004/05/10 09:29:48  jalet
67# Should be more robust if we receive a SIGTERM during an I/O operation
68#
69# Revision 1.39  2004/05/07 14:44:53  jalet
70# Fix for file handles unregistered twice from the polling object
71#
72# Revision 1.38  2004/04/09 22:24:46  jalet
73# Began work on correct handling of child processes when jobs are cancelled by
74# the user. Especially important when an external requester is running for a
75# long time.
76#
77# Revision 1.37  2004/03/18 19:11:25  jalet
78# Fix for raw jobs in cupspykota
79#
80# Revision 1.36  2004/03/18 14:03:18  jalet
81# Added fsync() calls
82#
83# Revision 1.35  2004/03/16 12:05:01  jalet
84# Small fix for new waitprinter.sh : when job was denied, would wait forever
85# for printer being in printing mode.
86#
87# Revision 1.34  2004/03/15 10:47:56  jalet
88# This time the traceback formatting should be correct !
89#
90# Revision 1.33  2004/03/05 12:46:07  jalet
91# Improve tracebacks
92#
93# Revision 1.32  2004/03/05 12:31:35  jalet
94# Now should output full traceback when crashing
95#
96# Revision 1.31  2004/03/01 14:35:56  jalet
97# PYKOTAPHASE wasn't set soon enough at the start of the job
98#
99# Revision 1.30  2004/03/01 14:34:15  jalet
100# PYKOTAPHASE wasn't set at the right time at the end of data transmission
101# to underlying layer (real backend)
102#
103# Revision 1.29  2004/03/01 11:23:25  jalet
104# Pre and Post hooks to external commands are available in the cupspykota
105# backend. Forthe pykota filter they will be implemented real soon now.
106#
107# Revision 1.28  2004/02/26 14:18:07  jalet
108# Should fix the remaining bugs wrt printers groups and users groups.
109#
110# Revision 1.27  2004/02/04 23:41:27  jalet
111# Should fix the incorrect "backend died abnormally" problem.
112#
113# Revision 1.26  2004/01/30 16:35:03  jalet
114# Fixes stupid software accounting bug in CUPS backend
115#
116# Revision 1.25  2004/01/16 17:51:46  jalet
117# Fuck Fuck Fuck !!!
118#
119# Revision 1.24  2004/01/14 15:52:01  jalet
120# Small fix for job cancelling code.
121#
122# Revision 1.23  2004/01/13 10:48:28  jalet
123# Small streams polling loop modification.
124#
125# Revision 1.22  2004/01/12 22:43:40  jalet
126# New formula to compute a job's price
127#
128# Revision 1.21  2004/01/12 18:17:36  jalet
129# Denied jobs weren't stored into the history anymore, this is now fixed.
130#
131# Revision 1.20  2004/01/11 23:22:42  jalet
132# Major code refactoring, it's way cleaner, and now allows automated addition
133# of printers on first print.
134#
135# Revision 1.19  2004/01/08 14:10:32  jalet
136# Copyright year changed.
137#
138# Revision 1.18  2004/01/07 16:16:32  jalet
139# Better debugging information
140#
141# Revision 1.17  2003/12/27 16:49:25  uid67467
142# Should be ok now.
143#
144# Revision 1.17  2003/12/06 08:54:29  jalet
145# Code simplifications.
146# Added many debugging messages.
147#
148# Revision 1.16  2003/11/26 20:43:29  jalet
149# Inadvertantly introduced a bug, which is fixed.
150#
151# Revision 1.15  2003/11/26 19:17:35  jalet
152# Printing on a printer not present in the Quota Storage now results
153# in the job being stopped or cancelled depending on the system.
154#
155# Revision 1.14  2003/11/25 13:25:45  jalet
156# Boolean problem with old Python, replaced with 0
157#
158# Revision 1.13  2003/11/23 19:01:35  jalet
159# Job price added to history
160#
161# Revision 1.12  2003/11/21 14:28:43  jalet
162# More complete job history.
163#
164# Revision 1.11  2003/11/19 23:19:35  jalet
165# Code refactoring work.
166# Explicit redirection to /dev/null has to be set in external policy now, just
167# like in external mailto.
168#
169# Revision 1.10  2003/11/18 17:54:24  jalet
170# SIGTERMs are now transmitted to original backends.
171#
172# Revision 1.9  2003/11/18 14:11:07  jalet
173# Small fix for bizarre urls
174#
175# Revision 1.8  2003/11/15 14:26:44  jalet
176# General improvements to the documentation.
177# Email address changed in sample configuration file, because
178# I receive low quota messages almost every day...
179#
180# Revision 1.7  2003/11/14 22:05:12  jalet
181# New CUPS backend fully functionnal.
182# Old CUPS configuration method is now officially deprecated.
183#
184# Revision 1.6  2003/11/14 20:13:11  jalet
185# We exit the loop too soon.
186#
187# Revision 1.5  2003/11/14 18:31:27  jalet
188# Not perfect, but seems to work with the poll() loop.
189#
190# Revision 1.4  2003/11/14 17:04:15  jalet
191# More (untested) work on the CUPS backend.
192#
193# Revision 1.3  2003/11/12 23:27:44  jalet
194# More work on new backend. This commit may be unstable.
195#
196# Revision 1.2  2003/11/12 09:33:34  jalet
197# New CUPS backend supports device enumeration
198#
199# Revision 1.1  2003/11/08 16:05:31  jalet
200# CUPS backend added for people to experiment.
201#
202#
203#
204
205import sys
206import os
207import fcntl
208import popen2
209import cStringIO
210import shlex
211import select
212import signal
213import time
214
215from pykota.tool import PyKotaFilterOrBackend, PyKotaToolError
216from pykota.config import PyKotaConfigError
217from pykota.storage import PyKotaStorageError
218from pykota.accounter import PyKotaAccounterError
219   
220class PyKotaPopen4(popen2.Popen4) :
221    """Our own class to execute real backends.
222   
223       Their first argument is different from their path so using
224       native popen2.Popen3 would not be feasible.
225    """
226    def __init__(self, cmd, bufsize=-1, arg0=None) :
227        self.arg0 = arg0
228        popen2.Popen4.__init__(self, cmd, bufsize)
229       
230    def _run_child(self, cmd):
231        for i in range(3, 256): # TODO : MAXFD in original popen2 module
232            try:
233                os.close(i)
234            except OSError:
235                pass
236        try:
237            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
238        finally:
239            os._exit(1)
240   
241class PyKotaBackend(PyKotaFilterOrBackend) :       
242    """A class for the pykota backend."""
243    def acceptJob(self) :       
244        """Returns the appropriate exit code to tell CUPS all is OK."""
245        return 0
246           
247    def removeJob(self) :           
248        """Returns the appropriate exit code to let CUPS think all is OK.
249       
250           Returning 0 (success) prevents CUPS from stopping the print queue.
251        """   
252        return 0
253       
254    def doWork(self, policy, printer, user, userpquota) :   
255        """Most of the work is done here."""
256        # Two different values possible for policy here :
257        # ALLOW means : Either printer, user or user print quota doesn't exist,
258        #               but the job should be allowed anyway.
259        # OK means : Both printer, user and user print quota exist, job should
260        #            be allowed if current user is allowed to print on this printer
261        if policy == "OK" :
262            # exports user information with initial values
263            self.exportUserInfo(userpquota)
264           
265            # enters first phase
266            os.putenv("PYKOTAPHASE", "BEFORE")
267           
268            # checks the user's quota
269            if self.config.getPrinterEnforcement(printer.Name) == "STRICT" :
270                self.softwareJobSize = self.precomputeJobSize()
271                self.softwareJobPrice = userpquota.computeJobPrice(self.softwareJobSize)
272                self.logdebug("Precomputed job's size is %s pages, price is %s units" % (self.softwareJobSize, self.softwareJobPrice))
273            os.putenv("PYKOTAPRECOMPUTEDJOBSIZE", str(self.softwareJobSize))   
274            os.putenv("PYKOTAPRECOMPUTEDJOBPRICE", str(self.softwareJobPrice))   
275            action = self.warnUserPQuota(userpquota)
276           
277            # exports some new environment variables
278            os.putenv("PYKOTAACTION", action)
279           
280            # launches the pre hook
281            self.prehook(userpquota)
282           
283            self.logdebug("Job accounting begins.")
284            self.accounter.beginJob(userpquota)
285        else :   
286            action = "ALLOW"
287            os.putenv("PYKOTAACTION", action)
288           
289        # pass the job's data to the real backend   
290        if action in ["ALLOW", "WARN"] :
291            if self.gotSigTerm :
292                retcode = self.removeJob()
293            else :   
294                retcode = self.handleData()       
295        else :       
296            retcode = self.removeJob()
297       
298        if policy == "OK" :       
299            # indicate phase change
300            os.putenv("PYKOTAPHASE", "AFTER")
301           
302            # stops accounting.
303            self.accounter.endJob(userpquota)
304            self.logdebug("Job accounting ends.")
305               
306            # retrieve the job size   
307            if action == "DENY" :
308                jobsize = 0
309                self.logdebug("Job size forced to 0 because printing is denied.")
310            else :   
311                jobsize = self.accounter.getJobSize()
312            self.logdebug("Job size : %i" % jobsize)
313           
314            # update the quota for the current user on this printer
315            self.logdebug("Updating user %s's quota on printer %s" % (user.Name, printer.Name))
316            jobprice = userpquota.increasePagesUsage(jobsize)
317           
318            # adds the current job to history   
319            printer.addJobToHistory(self.jobid, user, self.accounter.getLastPageCounter(), action, jobsize, jobprice, self.preserveinputfile, self.title, self.copies, self.options)
320            self.logdebug("Job added to history.")
321           
322            # exports some new environment variables
323            os.putenv("PYKOTAJOBSIZE", str(jobsize))
324            os.putenv("PYKOTAJOBPRICE", str(jobprice))
325           
326            # then re-export user information with new values
327            self.exportUserInfo(userpquota)
328           
329            # Launches the post hook
330            self.posthook(userpquota)
331           
332        return retcode   
333               
334    def unregisterFileNo(self, pollobj, fileno) :               
335        """Removes a file handle from the polling object."""
336        try :
337            pollobj.unregister(fileno)
338        except KeyError :   
339            self.logger.log_message(_("File number %s unregistered twice from polling object, ignored.") % fileno, "warn")
340        except :   
341            self.logdebug("Error while unregistering file number %s from polling object." % fileno)
342        else :   
343            self.logdebug("File number %s unregistered from polling object." % fileno)
344           
345    def formatFileEvent(self, fd, mask) :       
346        """Formats file debug info."""
347        maskval = []
348        if mask & select.POLLIN :
349            maskval.append("POLLIN")
350        if mask & select.POLLOUT :
351            maskval.append("POLLOUT")
352        if mask & select.POLLPRI :
353            maskval.append("POLLPRI")
354        if mask & select.POLLERR :
355            maskval.append("POLLERR")
356        if mask & select.POLLHUP :
357            maskval.append("POLLHUP")
358        if mask & select.POLLNVAL :
359            maskval.append("POLLNVAL")
360        return "%s (%s)" % (fd, " | ".join(maskval))
361       
362    def handleData(self) :                   
363        """Pass the job's data to the real backend."""
364        # Find the real backend pathname   
365        realbackend = os.path.join(os.path.split(sys.argv[0])[0], self.originalbackend)
366       
367        # And launch it
368        self.logdebug("Starting real backend %s with args %s" % (realbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + sys.argv[1:])])))
369        subprocess = PyKotaPopen4([realbackend] + sys.argv[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
370       
371        # Save file descriptors, we will need them later.
372        stderrfno = sys.stderr.fileno()
373        fromcfno = subprocess.fromchild.fileno()
374        tocfno = subprocess.tochild.fileno()
375       
376        # We will have to be careful when dealing with I/O
377        # So we use a poll object to know when to read or write
378        pollster = select.poll()
379        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
380        pollster.register(stderrfno, select.POLLOUT)
381        pollster.register(tocfno, select.POLLOUT)
382       
383        # Initialize our buffers
384        indata = ""
385        outdata = ""
386        endinput = endoutput = 0
387        inputclosed = outputclosed = 0
388       
389        if self.preserveinputfile is None :
390            # this is not a real file, we read the job's data
391            # from our temporary file which is a copy of stdin
392            infno = self.jobdatastream.fileno()
393            self.jobdatastream.seek(0)
394            pollster.register(infno, select.POLLIN | select.POLLPRI)
395        else :   
396            # job's data is in a file, no need to pass the data
397            # to the real backend
398            self.logdebug("Job's data is in %s" % self.preserveinputfile)
399            infno = None
400            endinput = 1
401       
402        self.logdebug("Capturing SIGTERM events.")
403        signal.signal(signal.SIGTERM, self.sigterm_handler)
404       
405        self.logdebug("Entering streams polling loop...")
406        MEGABYTE = 1024*1024
407        killed = 0
408        status = -1
409        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
410            # First check if original backend is still alive
411            status = subprocess.poll()
412           
413            # Now if we got SIGTERM, we have
414            # to kill -TERM the original backend
415            if self.gotSigTerm and not killed :
416                try :
417                    os.kill(subprocess.pid, signal.SIGTERM)
418                except OSError, msg : # ignore but logs if process was already killed.
419                    self.logdebug("Error while sending signal to pid %s" % subprocess.pid)
420                else :   
421                    self.logger.log_message(_("SIGTERM was sent to real backend %s (pid: %s)") % (realbackend, subprocess.pid), "info")
422                    killed = 1
423           
424            # In any case, deal with any remaining I/O
425            try :
426                availablefds = pollster.poll(5000)
427            except select.error, msg :   
428                self.logdebug("Interrupted poll : %s" % msg)
429                availablefds = []
430            if not availablefds :
431                self.logdebug("Nothing to do, sleeping a bit...")
432                time.sleep(0.01) # give some time to the system
433            else :
434                for (fd, mask) in availablefds :
435                    # self.logdebug(self.formatFileEvent(fd, mask))
436                    try :
437                        if mask & select.POLLOUT :
438                            # We can write
439                            if fd == tocfno :
440                                if indata :
441                                    try :
442                                        os.write(fd, indata)   
443                                    except IOError, msg :   
444                                        self.logdebug("Error while writing to real backend's stdin %s : %s" % (fd, msg))
445                                    else :   
446                                        indata = ""
447                                else :       
448                                    self.logdebug("No data to send to real backend yet, sleeping a bit...")
449                                    time.sleep(0.01)
450                                   
451                                if endinput :   
452                                    self.unregisterFileNo(pollster, tocfno)       
453                                    self.logdebug("Closing real backend's stdin.")
454                                    os.close(tocfno)
455                                    inputclosed = 1
456                            elif fd == stderrfno :
457                                if outdata :
458                                    try :
459                                        os.write(fd, outdata)
460                                    except IOError, msg :   
461                                        self.logdebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
462                                    else :
463                                        outdata = ""
464                                else :       
465                                    # self.logdebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
466                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
467                                   
468                                if endoutput :   
469                                    self.unregisterFileNo(pollster, stderrfno)       
470                                    outputclosed = 1
471                            else :   
472                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
473                                time.sleep(0.01)
474                               
475                        if mask & (select.POLLIN | select.POLLPRI) :     
476                            # We have something to read
477                            try :
478                                data = os.read(fd, MEGABYTE)
479                            except (IOError, OSError), msg :   
480                                self.logdebug("Error while reading file %s : %s" % (fd, msg))
481                            else :
482                                if fd == infno :
483                                    if not data :    # If yes, then no more input data
484                                        self.unregisterFileNo(pollster, infno)
485                                        self.logdebug("Input data ends.")
486                                        endinput = 1 # this happens with real files.
487                                    else :   
488                                        indata += data
489                                elif fd == fromcfno :
490                                    if not data :
491                                        self.logdebug("No back channel data to read from real backend yet, sleeping a bit...")
492                                        time.sleep(0.01)
493                                    else :
494                                        outdata += data
495                                else :   
496                                    self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
497                                    time.sleep(0.01)
498                                   
499                        if mask & (select.POLLHUP | select.POLLERR) :
500                            # Treat POLLERR as an EOF.
501                            # Some standard I/O stream has no more datas
502                            self.unregisterFileNo(pollster, fd)
503                            if fd == infno :
504                                # Here we are in the case where the input file is stdin.
505                                # which has no more data to be read.
506                                self.logdebug("Input data ends.")
507                                endinput = 1
508                            elif fd == fromcfno :   
509                                # We are no more interested in this file descriptor       
510                                self.logdebug("Closing real backend's stdout+stderr.")
511                                os.close(fromcfno)
512                                endoutput = 1
513                            else :   
514                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
515                                time.sleep(0.01)
516                               
517                        if mask & select.POLLNVAL :       
518                            self.logdebug("File %s was closed. Unregistering from polling object." % fd)
519                            self.unregisterFileNo(pollster, fd)
520                    except IOError, msg :           
521                        self.logdebug("Got an IOError : %s" % msg) # we got signalled during an I/O
522               
523        # We must close the real backend's input stream
524        if killed and not inputclosed :
525            self.logdebug("Forcing close of real backend's stdin.")
526            os.close(tocfno)
527       
528        self.logdebug("Exiting streams polling loop...")
529       
530        self.logdebug("Ignoring SIGTERM again.")
531        signal.signal(signal.SIGTERM, signal.SIG_IGN)
532           
533        # Check exit code of original CUPS backend.   
534        if status == -1 :
535            # we exited the loop before the real backend exited
536            # now we have to wait for it to finish and get its status
537            self.logdebug("Waiting for real backend to exit...")
538            try :
539                status = subprocess.wait()
540            except OSError : # already dead   
541                status = 0
542        if os.WIFEXITED(status) :
543            retcode = os.WEXITSTATUS(status)
544        elif not killed :   
545            self.logger.log_message(_("CUPS backend %s died abnormally.") % realbackend, "error")
546            retcode = -1
547        else :   
548            retcode = self.removeJob()
549        return retcode   
550   
551if __name__ == "__main__" :   
552    # This is a CUPS backend, we should act and die like a CUPS backend
553    if len(sys.argv) == 1 :
554        # we will execute each existing backend in device enumeration mode
555        # and generate their PyKota accounting counterpart
556        (directory, myname) = os.path.split(sys.argv[0])
557        for backend in [os.path.join(directory, b) for b in os.listdir(directory) if os.path.isfile(os.path.join(directory, b)) and (b != myname)] :
558            answer = os.popen(backend, "r")
559            try :
560                devices = [line.strip() for line in answer.readlines()]
561            except :   
562                devices = []
563            status = answer.close()
564            if status is None :
565                for d in devices :
566                    # each line is of the form : 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
567                    # so we have to decompose it carefully
568                    fdevice = cStringIO.StringIO("%s" % d)
569                    tokenizer = shlex.shlex(fdevice)
570                    tokenizer.wordchars = tokenizer.wordchars + r".:,?!~/\_$*-+={}[]()#"
571                    arguments = []
572                    while 1 :
573                        token = tokenizer.get_token()
574                        if token :
575                            arguments.append(token)
576                        else :
577                            break
578                    fdevice.close()
579                    try :
580                        (devicetype, device, name, fullname) = arguments
581                    except ValueError :   
582                        pass    # ignore this 'bizarre' device
583                    else :   
584                        if name.startswith('"') and name.endswith('"') :
585                            name = name[1:-1]
586                        if fullname.startswith('"') and fullname.endswith('"') :
587                            fullname = fullname[1:-1]
588                        print '%s cupspykota:%s "PyKota+%s" "PyKota managed %s"' % (devicetype, device, name, fullname)
589        retcode = 0
590    elif len(sys.argv) not in (6, 7) :   
591        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n" % sys.argv[0])
592        retcode = 1
593    else :   
594        try :
595            # Initializes the backend
596            kotabackend = PyKotaBackend()   
597            retcode = kotabackend.mainWork()
598        except (PyKotaToolError, PyKotaConfigError, PyKotaStorageError, PyKotaAccounterError, AttributeError, KeyError, IndexError, ValueError, TypeError, IOError), msg :
599            import traceback
600            mm = [((f.endswith('\n') and f) or (f + '\n')) for f in traceback.format_exception(*sys.exc_info())]
601            sys.stderr.write("ERROR : cupspykota backend failed (%s)\n%s" % (msg, "ERROR : ".join(mm)))
602            sys.stderr.flush()
603            retcode = 1
604       
605        try :
606            kotabackend.storage.close()
607        except (TypeError, NameError, AttributeError) :   
608            pass
609           
610        kotabackend.closeJobDataStream()   
611       
612    sys.exit(retcode)   
Note: See TracBrowser for help on using the browser.