root / pykota / trunk / bin / cupspykota @ 1901

Revision 1901, 34.6 kB (checked in by jalet, 19 years ago)

Added a miniparser for IPP messages (RFC 2910). The job-originating-host-name
retrieval is now fiable, unless the CUPS developpers change something...

  • 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.76  2004/11/06 22:35:58  jalet
27# Added a miniparser for IPP messages (RFC 2910). The job-originating-host-name
28# retrieval is now fiable, unless the CUPS developpers change something...
29#
30# Revision 1.75  2004/11/01 15:45:25  jalet
31# Added many debug messages.
32# Added some code to prevent short writes.
33#
34# Revision 1.74  2004/10/13 20:51:27  jalet
35# Made debugging levels be the same in cupspykota and lprngpykota.
36# Now outputs more information in informational messages : user, printer, jobid
37#
38# Revision 1.73  2004/10/13 16:56:45  jalet
39# Added a space to the pattern to differentiate jobs which id begins with
40# the same digits, like jobs 87 and 879 for example : if printed by same
41# user on same printer, but from a different host this could have broken
42# the result. (In reality this couldn't happen because 879 would be the
43# last line to match anyway because of job ordering, but we never know
44# if the page_log file gets corrupt somewhat)
45#
46# Revision 1.72  2004/09/13 16:02:44  jalet
47# Added fix for incorrect job's size when hardware accounting fails
48#
49# Revision 1.71  2004/09/06 17:05:06  jalet
50# Fix for autodetection of SC_OPEN_MAX
51#
52# Revision 1.70  2004/07/26 09:20:27  jalet
53# Unneeded module
54#
55# Revision 1.69  2004/07/22 22:41:47  jalet
56# Hardware accounting for LPRng should be OK now. UNTESTED.
57#
58# Revision 1.68  2004/07/20 22:19:44  jalet
59# Sanitized a bit + use of gettext
60#
61# Revision 1.67  2004/07/16 12:22:45  jalet
62# LPRng support early version
63#
64# Revision 1.66  2004/07/01 19:56:25  jalet
65# Better dispatching of error messages
66#
67# Revision 1.65  2004/06/22 09:31:17  jalet
68# Always send some debug info to CUPS' back channel stream (stderr) as
69# informationnal messages.
70#
71# Revision 1.64  2004/06/18 13:34:46  jalet
72# Now all tracebacks include PyKota's version number
73#
74# Revision 1.63  2004/06/17 13:26:50  jalet
75# Better exception handling code
76#
77# Revision 1.62  2004/06/16 20:56:34  jalet
78# Smarter initialisation code
79#
80# Revision 1.61  2004/06/08 09:00:04  jalet
81# Fixed problem when username was passed in uppercase from Samba and we
82# tried to find correct line in CUPS page_log to extract the hostname.
83#
84# Revision 1.60  2004/06/03 23:14:08  jalet
85# Now stores the job's size in bytes in the database.
86# Preliminary work on payments storage : database schemas are OK now,
87# but no code to store payments yet.
88# Removed schema picture, not relevant anymore.
89#
90# Revision 1.59  2004/06/03 22:12:53  jalet
91# Now denies empty jobs
92#
93# Revision 1.58  2004/06/03 21:50:33  jalet
94# Improved error logging.
95# crashrecipient directive added.
96# Now exports the job's size in bytes too.
97#
98# Revision 1.57  2004/06/02 22:18:07  jalet
99# I think the bug when cancelling jobs should be fixed right now
100#
101# Revision 1.56  2004/06/02 21:50:56  jalet
102# Moved the sigterm capturing elsewhere
103#
104# Revision 1.55  2004/06/02 14:25:07  jalet
105# Should correctly capture ALL errors now
106#
107# Revision 1.54  2004/05/26 16:44:48  jalet
108# Now logs something when client hostname can't be extracted
109#
110# Revision 1.53  2004/05/26 14:49:35  jalet
111# First try at saving the job-originating-hostname in the database
112#
113# Revision 1.52  2004/05/25 09:15:13  jalet
114# accounter.py : old code deleted
115# the rest : now exports PYKOTAPRECOMPUTEDJOBSIZE and PYKOTAPRECOMPUTEDJOBPRICE
116#
117# Revision 1.51  2004/05/25 08:31:16  jalet
118# Heavy CPU usage seems to be fixed at least !
119#
120# Revision 1.50  2004/05/25 05:17:50  jalet
121# Now precomputes the job's size only if current printer's enforcement
122# is "STRICT"
123#
124# Revision 1.49  2004/05/24 22:45:48  jalet
125# New 'enforcement' directive added
126# Polling loop improvements
127#
128# Revision 1.48  2004/05/24 14:36:24  jalet
129# Revert to old polling loop. Will need optimisations
130#
131# Revision 1.47  2004/05/24 11:59:46  jalet
132# More robust (?) code
133#
134# Revision 1.46  2004/05/21 22:02:51  jalet
135# Preliminary work on pre-accounting
136#
137# Revision 1.45  2004/05/19 07:15:32  jalet
138# Could the 'misterious' bug in my loop be finally fixed ???
139#
140# Revision 1.44  2004/05/18 14:48:47  jalet
141# Big code changes to completely remove the need for "requester" directives,
142# jsut use "hardware(... your previous requester directive's content ...)"
143#
144# Revision 1.43  2004/05/17 11:46:05  jalet
145# First try at cupspykota's main loop rewrite
146#
147# Revision 1.42  2004/05/10 11:22:28  jalet
148# Typo
149#
150# Revision 1.41  2004/05/10 10:07:30  jalet
151# Catches OSError while reading
152#
153# Revision 1.40  2004/05/10 09:29:48  jalet
154# Should be more robust if we receive a SIGTERM during an I/O operation
155#
156# Revision 1.39  2004/05/07 14:44:53  jalet
157# Fix for file handles unregistered twice from the polling object
158#
159# Revision 1.38  2004/04/09 22:24:46  jalet
160# Began work on correct handling of child processes when jobs are cancelled by
161# the user. Especially important when an external requester is running for a
162# long time.
163#
164# Revision 1.37  2004/03/18 19:11:25  jalet
165# Fix for raw jobs in cupspykota
166#
167# Revision 1.36  2004/03/18 14:03:18  jalet
168# Added fsync() calls
169#
170# Revision 1.35  2004/03/16 12:05:01  jalet
171# Small fix for new waitprinter.sh : when job was denied, would wait forever
172# for printer being in printing mode.
173#
174# Revision 1.34  2004/03/15 10:47:56  jalet
175# This time the traceback formatting should be correct !
176#
177# Revision 1.33  2004/03/05 12:46:07  jalet
178# Improve tracebacks
179#
180# Revision 1.32  2004/03/05 12:31:35  jalet
181# Now should output full traceback when crashing
182#
183# Revision 1.31  2004/03/01 14:35:56  jalet
184# PYKOTAPHASE wasn't set soon enough at the start of the job
185#
186# Revision 1.30  2004/03/01 14:34:15  jalet
187# PYKOTAPHASE wasn't set at the right time at the end of data transmission
188# to underlying layer (real backend)
189#
190# Revision 1.29  2004/03/01 11:23:25  jalet
191# Pre and Post hooks to external commands are available in the cupspykota
192# backend. Forthe pykota filter they will be implemented real soon now.
193#
194# Revision 1.28  2004/02/26 14:18:07  jalet
195# Should fix the remaining bugs wrt printers groups and users groups.
196#
197# Revision 1.27  2004/02/04 23:41:27  jalet
198# Should fix the incorrect "backend died abnormally" problem.
199#
200# Revision 1.26  2004/01/30 16:35:03  jalet
201# Fixes stupid software accounting bug in CUPS backend
202#
203# Revision 1.25  2004/01/16 17:51:46  jalet
204# Fuck Fuck Fuck !!!
205#
206# Revision 1.24  2004/01/14 15:52:01  jalet
207# Small fix for job cancelling code.
208#
209# Revision 1.23  2004/01/13 10:48:28  jalet
210# Small streams polling loop modification.
211#
212# Revision 1.22  2004/01/12 22:43:40  jalet
213# New formula to compute a job's price
214#
215# Revision 1.21  2004/01/12 18:17:36  jalet
216# Denied jobs weren't stored into the history anymore, this is now fixed.
217#
218# Revision 1.20  2004/01/11 23:22:42  jalet
219# Major code refactoring, it's way cleaner, and now allows automated addition
220# of printers on first print.
221#
222# Revision 1.19  2004/01/08 14:10:32  jalet
223# Copyright year changed.
224#
225# Revision 1.18  2004/01/07 16:16:32  jalet
226# Better debugging information
227#
228# Revision 1.17  2003/12/27 16:49:25  uid67467
229# Should be ok now.
230#
231# Revision 1.17  2003/12/06 08:54:29  jalet
232# Code simplifications.
233# Added many debugging messages.
234#
235# Revision 1.16  2003/11/26 20:43:29  jalet
236# Inadvertantly introduced a bug, which is fixed.
237#
238# Revision 1.15  2003/11/26 19:17:35  jalet
239# Printing on a printer not present in the Quota Storage now results
240# in the job being stopped or cancelled depending on the system.
241#
242# Revision 1.14  2003/11/25 13:25:45  jalet
243# Boolean problem with old Python, replaced with 0
244#
245# Revision 1.13  2003/11/23 19:01:35  jalet
246# Job price added to history
247#
248# Revision 1.12  2003/11/21 14:28:43  jalet
249# More complete job history.
250#
251# Revision 1.11  2003/11/19 23:19:35  jalet
252# Code refactoring work.
253# Explicit redirection to /dev/null has to be set in external policy now, just
254# like in external mailto.
255#
256# Revision 1.10  2003/11/18 17:54:24  jalet
257# SIGTERMs are now transmitted to original backends.
258#
259# Revision 1.9  2003/11/18 14:11:07  jalet
260# Small fix for bizarre urls
261#
262# Revision 1.8  2003/11/15 14:26:44  jalet
263# General improvements to the documentation.
264# Email address changed in sample configuration file, because
265# I receive low quota messages almost every day...
266#
267# Revision 1.7  2003/11/14 22:05:12  jalet
268# New CUPS backend fully functionnal.
269# Old CUPS configuration method is now officially deprecated.
270#
271# Revision 1.6  2003/11/14 20:13:11  jalet
272# We exit the loop too soon.
273#
274# Revision 1.5  2003/11/14 18:31:27  jalet
275# Not perfect, but seems to work with the poll() loop.
276#
277# Revision 1.4  2003/11/14 17:04:15  jalet
278# More (untested) work on the CUPS backend.
279#
280# Revision 1.3  2003/11/12 23:27:44  jalet
281# More work on new backend. This commit may be unstable.
282#
283# Revision 1.2  2003/11/12 09:33:34  jalet
284# New CUPS backend supports device enumeration
285#
286# Revision 1.1  2003/11/08 16:05:31  jalet
287# CUPS backend added for people to experiment.
288#
289#
290#
291
292import sys
293import os
294import popen2
295import cStringIO
296import shlex
297import select
298import signal
299import time
300
301from pykota.tool import PyKotaFilterOrBackend, PyKotaToolError, crashed
302from pykota.config import PyKotaConfigError
303from pykota.storage import PyKotaStorageError
304from pykota.accounter import PyKotaAccounterError
305from pykota.ipp import IPPMessage, PyKotaIPPError
306   
307class PyKotaPopen4(popen2.Popen4) :
308    """Our own class to execute real backends.
309   
310       Their first argument is different from their path so using
311       native popen2.Popen3 would not be feasible.
312    """
313    def __init__(self, cmd, bufsize=-1, arg0=None) :
314        self.arg0 = arg0
315        popen2.Popen4.__init__(self, cmd, bufsize)
316       
317    def _run_child(self, cmd):
318        try :
319            MAXFD = os.sysconf("SC_OPEN_MAX")
320        except (AttributeError, ValueError) :   
321            MAXFD = 256
322        for i in range(3, MAXFD) : 
323            try:
324                os.close(i)
325            except OSError:
326                pass
327        try:
328            os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ)
329        finally:
330            os._exit(1)
331   
332class PyKotaBackend(PyKotaFilterOrBackend) :       
333    """A class for the pykota backend."""
334    def acceptJob(self) :       
335        """Returns the appropriate exit code to tell CUPS all is OK."""
336        return 0
337           
338    def removeJob(self) :           
339        """Returns the appropriate exit code to let CUPS think all is OK.
340       
341           Returning 0 (success) prevents CUPS from stopping the print queue.
342        """   
343        return 0
344       
345    def getCupsConfigDirectives(self, directives=[]) :
346        """Retrieves some CUPS directives from its configuration file."""
347        dirvalues = {} 
348        cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups")
349        cupsdconf = os.path.join(cupsroot, "cupsd.conf")
350        try :
351            conffile = open(cupsdconf, "r")
352        except IOError :   
353            self.logdebug("Unable to open %s" % cupsdconf)
354        else :   
355            for line in conffile.readlines() :
356                linecopy = line.strip().lower()
357                for di in [d.lower() for d in directives] :
358                    if linecopy.startswith("%s " % di) :
359                        try :
360                            val = line.split()[1]
361                        except :   
362                            pass # ignore errors, we take the last value in any case.
363                        else :   
364                            dirvalues[di] = val
365            conffile.close()           
366        return dirvalues       
367           
368    def getJobOriginatingHostnameFromPageLog(self, cupsconfig, printername, username, jobid) :
369        """Retrieves the job-originating-hostname from the CUPS page_log file if possible."""
370        pagelogpath = cupsconfig.get("pagelog", "/var/log/cups/page_log")
371        self.logdebug("Trying to extract job-originating-host-name from %s" % pagelogpath)
372        try :
373            pagelog = open(pagelogpath, "r")
374        except IOError :   
375            self.logdebug("Unable to open %s" % pagelogpath)
376            return # no page log or can't read it, originating hostname unknown yet
377        else :   
378            # TODO : read backward so we could take first value seen
379            # TODO : here we read forward so we must take the last value seen
380            prefix = ("%s %s %s " % (printername, username, jobid)).lower()
381            matchingline = None
382            while 1 :
383                line = pagelog.readline()
384                if not line :
385                    break
386                else :
387                    line = line.strip()
388                    if line.lower().startswith(prefix) :   
389                        matchingline = line # no break, because we read forward
390            pagelog.close()       
391            if matchingline is None :
392                self.logdebug("No matching line found in %s" % pagelogpath)
393                return # correct line not found, job-originating-host-name unknown
394            else :   
395                return matchingline.split()[-1]
396               
397    def doWork(self, policy, printer, user, userpquota) :   
398        """Most of the work is done here."""
399        # Two different values possible for policy here :
400        # ALLOW means : Either printer, user or user print quota doesn't exist,
401        #               but the job should be allowed anyway.
402        # OK means : Both printer, user and user print quota exist, job should
403        #            be allowed if current user is allowed to print on this printer
404        if policy == "OK" :
405            # exports user information with initial values
406            self.exportUserInfo(userpquota)
407           
408            # tries to extract job-originating-host-name and other information
409            cupsdconf = self.getCupsConfigDirectives(["PageLog", "RequestRoot"])
410            requestroot = cupsdconf.get("requestroot", "/var/spool/cups")
411            if (len(self.jobid) < 5) and self.jobid.isdigit() :
412                ippmessagefile = "c%05i" % int(self.jobid)
413            else :   
414                ippmessagefile = "c%s" % self.jobid
415            ippmessagefile = os.path.join(requestroot, ippmessagefile)
416            ippmessage = {}
417            try :
418                ippdatafile = open(ippmessagefile)
419            except :   
420                self.printInfo("Unable to open IPP message file %s" % ippmessagefile, "warn")
421            else :   
422                self.logdebug("Parsing of IPP message file %s begins." % ippmessagefile)
423                ippmessage = IPPMessage(ippdatafile.read())
424                self.logdebug("Parsing of IPP message file %s ends." % ippmessagefile)
425                ippdatafile.close()
426               
427            clienthost = ippmessage.get("job-originating-host-name") \
428                         or self.getJobOriginatingHostnameFromPageLog(cupsdconf, printer.Name, user.Name, self.jobid)
429            self.logdebug("Client Hostname : %s" % (clienthost or "Unknown"))   
430            os.environ["PYKOTAJOBORIGINATINGHOSTNAME"] = str(clienthost or "")
431           
432            # TODO : extract username (double check ?) and billing code too
433           
434            # enters first phase
435            os.environ["PYKOTAPHASE"] = "BEFORE"
436           
437            # do we want strict or laxist quota enforcement ?
438            if self.config.getPrinterEnforcement(printer.Name) == "STRICT" :
439                self.softwareJobSize = self.precomputeJobSize()
440                self.softwareJobPrice = userpquota.computeJobPrice(self.softwareJobSize)
441                self.logdebug("Precomputed job's size is %s pages, price is %s units" % (self.softwareJobSize, self.softwareJobPrice))
442            os.environ["PYKOTAPRECOMPUTEDJOBSIZE"] = str(self.softwareJobSize)
443            os.environ["PYKOTAPRECOMPUTEDJOBPRICE"] = str(self.softwareJobPrice)
444           
445            # if no data to pass to real backend, probably a filter
446            # higher in the chain failed because of a misconfiguration.
447            # we deny the job in this case (nothing to print anyway)
448            if not self.jobSizeBytes :
449                self.printMoreInfo(user, printer, _("Job contains no data. Printing is denied."), "warn")
450                action = "DENY"
451            else :   
452                # checks the user's quota
453                action = self.warnUserPQuota(userpquota)
454           
455            # exports some new environment variables
456            os.environ["PYKOTAACTION"] = action
457           
458            # launches the pre hook
459            self.prehook(userpquota)
460           
461            self.printMoreInfo(user, printer, _("Job accounting begins."))
462            self.accounter.beginJob(printer)
463        else :   
464            action = "ALLOW"
465            os.environ["PYKOTAACTION"] = action
466           
467        # pass the job's data to the real backend   
468        if action in ["ALLOW", "WARN"] :
469            if self.gotSigTerm :
470                retcode = self.removeJob()
471            else :   
472                retcode = self.handleData()       
473        else :       
474            retcode = self.removeJob()
475       
476        if policy == "OK" :       
477            # indicate phase change
478            os.environ["PYKOTAPHASE"] = "AFTER"
479           
480            # stops accounting.
481            self.accounter.endJob(printer)
482            self.printMoreInfo(user, printer, _("Job accounting ends."))
483               
484            # retrieve the job size   
485            if action == "DENY" :
486                jobsize = 0
487                self.printMoreInfo(user, printer, _("Job size forced to 0 because printing is denied."))
488            else :   
489                jobsize = self.accounter.getJobSize(printer)
490            self.printMoreInfo(user, printer, _("Job size : %i") % jobsize)
491           
492            # update the quota for the current user on this printer
493            self.printInfo(_("Updating user %s's quota on printer %s") % (user.Name, printer.Name))
494            jobprice = userpquota.increasePagesUsage(jobsize)
495           
496            # adds the current job to history   
497            printer.addJobToHistory(self.jobid, user, self.accounter.getLastPageCounter(), action, jobsize, jobprice, self.preserveinputfile, self.title, self.copies, self.options, clienthost, self.jobSizeBytes)
498            self.printMoreInfo(user, printer, _("Job added to history."))
499           
500            # exports some new environment variables
501            os.environ["PYKOTAJOBSIZE"] = str(jobsize)
502            os.environ["PYKOTAJOBPRICE"] = str(jobprice)
503           
504            # then re-export user information with new value
505            self.exportUserInfo(userpquota)
506           
507            # Launches the post hook
508            self.posthook(userpquota)
509           
510        return retcode   
511               
512    def unregisterFileNo(self, pollobj, fileno) :               
513        """Removes a file handle from the polling object."""
514        try :
515            pollobj.unregister(fileno)
516        except KeyError :   
517            self.printInfo(_("File number %s unregistered twice from polling object, ignored.") % fileno, "warn")
518        except :   
519            self.logdebug("Error while unregistering file number %s from polling object." % fileno)
520        else :   
521            self.logdebug("File number %s unregistered from polling object." % fileno)
522           
523    def formatFileEvent(self, fd, mask) :       
524        """Formats file debug info."""
525        maskval = []
526        if mask & select.POLLIN :
527            maskval.append("POLLIN")
528        if mask & select.POLLOUT :
529            maskval.append("POLLOUT")
530        if mask & select.POLLPRI :
531            maskval.append("POLLPRI")
532        if mask & select.POLLERR :
533            maskval.append("POLLERR")
534        if mask & select.POLLHUP :
535            maskval.append("POLLHUP")
536        if mask & select.POLLNVAL :
537            maskval.append("POLLNVAL")
538        return "%s (%s)" % (fd, " | ".join(maskval))
539       
540    def handleData(self) :                   
541        """Pass the job's data to the real backend."""
542        # Find the real backend pathname   
543        realbackend = os.path.join(os.path.split(sys.argv[0])[0], self.originalbackend)
544       
545        # And launch it
546        self.logdebug("Starting real backend %s with args %s" % (realbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + sys.argv[1:])])))
547        subprocess = PyKotaPopen4([realbackend] + sys.argv[1:], bufsize=0, arg0=os.environ["DEVICE_URI"])
548       
549        # Save file descriptors, we will need them later.
550        stderrfno = sys.stderr.fileno()
551        fromcfno = subprocess.fromchild.fileno()
552        tocfno = subprocess.tochild.fileno()
553       
554        # We will have to be careful when dealing with I/O
555        # So we use a poll object to know when to read or write
556        pollster = select.poll()
557        pollster.register(fromcfno, select.POLLIN | select.POLLPRI)
558        pollster.register(stderrfno, select.POLLOUT)
559        pollster.register(tocfno, select.POLLOUT)
560       
561        # Initialize our buffers
562        indata = ""
563        outdata = ""
564        endinput = endoutput = 0
565        inputclosed = outputclosed = 0
566        totaltochild = totalfromcups = 0
567        totalfromchild = totaltocups = 0
568       
569        if self.preserveinputfile is None :
570            # this is not a real file, we read the job's data
571            # from our temporary file which is a copy of stdin
572            infno = self.jobdatastream.fileno()
573            self.jobdatastream.seek(0)
574            pollster.register(infno, select.POLLIN | select.POLLPRI)
575        else :   
576            # job's data is in a file, no need to pass the data
577            # to the real backend
578            self.logdebug("Job's data is in %s" % self.preserveinputfile)
579            infno = None
580            endinput = 1
581       
582        self.logdebug("Entering streams polling loop...")
583        MEGABYTE = 1024*1024
584        killed = 0
585        status = -1
586        while (status == -1) and (not killed) and not (inputclosed and outputclosed) :
587            # First check if original backend is still alive
588            status = subprocess.poll()
589           
590            # Now if we got SIGTERM, we have
591            # to kill -TERM the original backend
592            if self.gotSigTerm and not killed :
593                try :
594                    os.kill(subprocess.pid, signal.SIGTERM)
595                except OSError, msg : # ignore but logs if process was already killed.
596                    self.logdebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg))
597                else :   
598                    self.printInfo(_("SIGTERM was sent to real backend %s (pid: %s)") % (realbackend, subprocess.pid))
599                    killed = 1
600           
601            # In any case, deal with any remaining I/O
602            try :
603                availablefds = pollster.poll(5000)
604            except select.error, msg :   
605                self.logdebug("Interrupted poll : %s" % msg)
606                availablefds = []
607            if not availablefds :
608                self.logdebug("Nothing to do, sleeping a bit...")
609                time.sleep(0.01) # give some time to the system
610            else :
611                for (fd, mask) in availablefds :
612                    # self.logdebug(self.formatFileEvent(fd, mask))
613                    try :
614                        if mask & select.POLLOUT :
615                            # We can write
616                            if fd == tocfno :
617                                if indata :
618                                    try :
619                                        nbwritten = os.write(fd, indata)   
620                                    except (OSError, IOError), msg :   
621                                        self.logdebug("Error while writing to real backend's stdin %s : %s" % (fd, msg))
622                                    else :   
623                                        if len(indata) != nbwritten :
624                                            self.logdebug("Short write to real backend's input !")
625                                        totaltochild += nbwritten   
626                                        self.logdebug("%s bytes sent to real backend so far..." % totaltochild)
627                                        indata = indata[nbwritten:]
628                                else :       
629                                    self.logdebug("No data to send to real backend yet, sleeping a bit...")
630                                    time.sleep(0.01)
631                                   
632                                if endinput :   
633                                    self.unregisterFileNo(pollster, tocfno)       
634                                    self.logdebug("Closing real backend's stdin.")
635                                    os.close(tocfno)
636                                    inputclosed = 1
637                            elif fd == stderrfno :
638                                if outdata :
639                                    try :
640                                        nbwritten = os.write(fd, outdata)
641                                    except (OSError, IOError), msg :   
642                                        self.logdebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg))
643                                    else :
644                                        if len(outdata) != nbwritten :
645                                            self.logdebug("Short write to stderr (CUPS) !")
646                                        totaltocups += nbwritten   
647                                        self.logdebug("%s bytes sent back to CUPS so far..." % totaltocups)
648                                        outdata = outdata[nbwritten:]
649                                else :       
650                                    # self.logdebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs
651                                    time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems.
652                                   
653                                if endoutput :   
654                                    self.unregisterFileNo(pollster, stderrfno)       
655                                    outputclosed = 1
656                            else :   
657                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
658                                time.sleep(0.01)
659                               
660                        if mask & (select.POLLIN | select.POLLPRI) :     
661                            # We have something to read
662                            try :
663                                data = os.read(fd, MEGABYTE)
664                            except (IOError, OSError), msg :   
665                                self.logdebug("Error while reading file %s : %s" % (fd, msg))
666                            else :
667                                if fd == infno :
668                                    if not data :    # If yes, then no more input data
669                                        self.unregisterFileNo(pollster, infno)
670                                        self.logdebug("Input data ends.")
671                                        endinput = 1 # this happens with real files.
672                                    else :   
673                                        indata += data
674                                        totalfromcups += len(data)
675                                        self.logdebug("%s bytes read from CUPS so far..." % totalfromcups)
676                                elif fd == fromcfno :
677                                    if not data :
678                                        self.logdebug("No back channel data to read from real backend yet, sleeping a bit...")
679                                        time.sleep(0.01)
680                                    else :
681                                        outdata += data
682                                        totalfromchild += len(data)
683                                        self.logdebug("%s bytes read from real backend so far..." % totalfromchild)
684                                else :   
685                                    self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
686                                    time.sleep(0.01)
687                                   
688                        if mask & (select.POLLHUP | select.POLLERR) :
689                            # Treat POLLERR as an EOF.
690                            # Some standard I/O stream has no more datas
691                            self.unregisterFileNo(pollster, fd)
692                            if fd == infno :
693                                # Here we are in the case where the input file is stdin.
694                                # which has no more data to be read.
695                                self.logdebug("Input data ends.")
696                                endinput = 1
697                            elif fd == fromcfno :   
698                                # We are no more interested in this file descriptor       
699                                self.logdebug("Closing real backend's stdout+stderr.")
700                                os.close(fromcfno)
701                                endoutput = 1
702                            else :   
703                                self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask))
704                                time.sleep(0.01)
705                               
706                        if mask & select.POLLNVAL :       
707                            self.logdebug("File %s was closed. Unregistering from polling object." % fd)
708                            self.unregisterFileNo(pollster, fd)
709                    except IOError, msg :           
710                        self.logdebug("Got an IOError : %s" % msg) # we got signalled during an I/O
711               
712        # We must close the real backend's input stream
713        if killed and not inputclosed :
714            self.logdebug("Forcing close of real backend's stdin.")
715            os.close(tocfno)
716       
717        self.logdebug("Exiting streams polling loop...")
718       
719        self.logdebug("input data's final length : %s" % len(indata))
720        self.logdebug("back-channel data's final length : %s" % len(outdata))
721       
722        self.logdebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups)
723        self.logdebug("Total bytes sent to real backend (job's datas) : %s" % totaltochild)
724       
725        self.logdebug("Total bytes read from real backend (back-channel datas) : %s" % totalfromchild)
726        self.logdebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups)
727       
728        # Check exit code of original CUPS backend.   
729        if status == -1 :
730            # we exited the loop before the real backend exited
731            # now we have to wait for it to finish and get its status
732            self.logdebug("Waiting for real backend to exit...")
733            try :
734                status = subprocess.wait()
735            except OSError : # already dead   
736                status = 0
737        if os.WIFEXITED(status) :
738            retcode = os.WEXITSTATUS(status)
739        elif not killed :   
740            self.sendBackChannelData(_("CUPS backend %s died abnormally.") % realbackend, "error")
741            retcode = -1
742        else :   
743            retcode = self.removeJob()
744        return retcode   
745   
746if __name__ == "__main__" :   
747    # This is a CUPS backend, we should act and die like a CUPS backend
748    retcode = 0
749    if len(sys.argv) == 1 :
750        # we will execute each existing backend in device enumeration mode
751        # and generate their PyKota accounting counterpart
752        (directory, myname) = os.path.split(sys.argv[0])
753        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)] :
754            answer = os.popen(backend, "r")
755            try :
756                devices = [line.strip() for line in answer.readlines()]
757            except :   
758                devices = []
759            status = answer.close()
760            if status is None :
761                for d in devices :
762                    # each line is of the form : 'xxxx xxxx "xxxx xxx" "xxxx xxx"'
763                    # so we have to decompose it carefully
764                    fdevice = cStringIO.StringIO("%s" % d)
765                    tokenizer = shlex.shlex(fdevice)
766                    tokenizer.wordchars = tokenizer.wordchars + r".:,?!~/\_$*-+={}[]()#"
767                    arguments = []
768                    while 1 :
769                        token = tokenizer.get_token()
770                        if token :
771                            arguments.append(token)
772                        else :
773                            break
774                    fdevice.close()
775                    try :
776                        (devicetype, device, name, fullname) = arguments
777                    except ValueError :   
778                        pass    # ignore this 'bizarre' device
779                    else :   
780                        if name.startswith('"') and name.endswith('"') :
781                            name = name[1:-1]
782                        if fullname.startswith('"') and fullname.endswith('"') :
783                            fullname = fullname[1:-1]
784                        print '%s cupspykota:%s "PyKota+%s" "PyKota managed %s"' % (devicetype, device, name, fullname)
785        retcode = 0               
786    elif len(sys.argv) not in (6, 7) :   
787        sys.stderr.write("ERROR: %s job-id user title copies options [file]\n" % sys.argv[0])
788        retcode = 1
789    else :   
790        try :
791            try :
792                # Initializes the backend
793                kotabackend = PyKotaBackend()   
794            except SystemExit :   
795                retcode = -1
796            except :   
797                crashed("cupspykota backend initialization failed")
798                retcode = 1
799            else :   
800                retcode = kotabackend.mainWork()
801                kotabackend.storage.close()
802                kotabackend.closeJobDataStream()   
803        except :
804            try :
805                kotabackend.crashed("cupspykota backend failed")
806            except :   
807                crashed("cupspykota backend failed")
808            retcode = 1   
809       
810    sys.exit(retcode)   
Note: See TracBrowser for help on using the browser.