root / pykota / trunk / bin / cupspykota @ 2007

Revision 2007, 38.4 kB (checked in by jalet, 14 years ago)

Regain priviledge the time to read the job control file to extract the client
hostname

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