root / pykota / trunk / bin / cupspykota @ 1498

Revision 1498, 25.1 kB (checked in by jalet, 20 years ago)

Heavy CPU usage seems to be fixed at least !

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