#! /usr/bin/env python # -*- coding: ISO-8859-15 -*- # CUPSPyKota accounting backend # # PyKota - Print Quotas for CUPS and LPRng # # (c) 2003, 2004, 2005 Jerome Alet # This program is free software; you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by # the Free Software Foundation; either version 2 of the License, or # (at your option) any later version. # # This program is distributed in the hope that it will be useful, # but WITHOUT ANY WARRANTY; without even the implied warranty of # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the # GNU General Public License for more details. # # You should have received a copy of the GNU General Public License # along with this program; if not, write to the Free Software # Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307, USA. # # $Id$ # # import sys import os import errno import tempfile import popen2 import cStringIO import shlex import select import signal import time from pykota.tool import PyKotaFilterOrBackend, PyKotaToolError, crashed from pykota.config import PyKotaConfigError from pykota.storage import PyKotaStorageError from pykota.accounter import PyKotaAccounterError from pykota.ipp import IPPMessage, PyKotaIPPError class PyKotaPopen4(popen2.Popen4) : """Our own class to execute real backends. Their first argument is different from their path so using native popen2.Popen3 would not be feasible. """ def __init__(self, cmd, bufsize=-1, arg0=None) : self.arg0 = arg0 popen2.Popen4.__init__(self, cmd, bufsize) def _run_child(self, cmd): try : MAXFD = os.sysconf("SC_OPEN_MAX") except (AttributeError, ValueError) : MAXFD = 256 for i in range(3, MAXFD) : try: os.close(i) except OSError: pass try: os.execvpe(cmd[0], [self.arg0 or cmd[0]] + cmd[1:], os.environ) finally: os._exit(1) class PyKotaBackend(PyKotaFilterOrBackend) : """A class for the pykota backend.""" def acceptJob(self) : """Returns the appropriate exit code to tell CUPS all is OK.""" return 0 def removeJob(self) : """Returns the appropriate exit code to let CUPS think all is OK. Returning 0 (success) prevents CUPS from stopping the print queue. """ return 0 def genBanner(self, bannerfileorcommand) : """Reads a banner or generates one through an external command. Returns the banner's content in a format which MUST be accepted by the printer. """ if bannerfileorcommand : banner = "" # no banner by default if os.access(bannerfileorcommand, os.X_OK) or not os.path.isfile(bannerfileorcommand) : self.logdebug("Launching %s to generate a banner." % bannerfileorcommand) child = popen2.Popen3(bannerfileorcommand, capturestderr=1) banner = child.fromchild.read() child.tochild.close() child.childerr.close() child.fromchild.close() status = child.wait() if os.WIFEXITED(status) : status = os.WEXITSTATUS(status) self.printInfo(_("Banner generator %s exit code is %s") % (bannerfileorcommand, str(status))) else : self.logdebug("Using %s as the banner." % bannerfileorcommand) try : fh = open(bannerfileorcommand, 'r') except IOError, msg : self.printInfo("Impossible to open %s : %s" % (bannerfileorcommand, msg), "error") else : banner = fh.read() fh.close() if banner : return cStringIO.StringIO(banner) def startingBanner(self, printername) : """Retrieves a starting banner for current printer and returns its content.""" self.logdebug("Retrieving starting banner...") return self.genBanner(self.config.getStartingBanner(printername)) def endingBanner(self, printername) : """Retrieves an ending banner for current printer and returns its content.""" self.logdebug("Retrieving ending banner...") return self.genBanner(self.config.getEndingBanner(printername)) def getCupsConfigDirectives(self, directives=[]) : """Retrieves some CUPS directives from its configuration file. Returns a mapping with lowercased directives as keys and their setting as values. """ dirvalues = {} cupsroot = os.environ.get("CUPS_SERVERROOT", "/etc/cups") cupsdconf = os.path.join(cupsroot, "cupsd.conf") try : conffile = open(cupsdconf, "r") except IOError : self.logdebug("Unable to open %s" % cupsdconf) else : for line in conffile.readlines() : linecopy = line.strip().lower() for di in [d.lower() for d in directives] : if linecopy.startswith("%s " % di) : try : val = line.split()[1] except : pass # ignore errors, we take the last value in any case. else : dirvalues[di] = val conffile.close() return dirvalues def getJobInfosFromPageLog(self, cupsconfig, printername, username, jobid) : """Retrieves the job-originating-hostname and job-billing attributes from the CUPS page_log file if possible.""" pagelogpath = cupsconfig.get("pagelog", "/var/log/cups/page_log") self.logdebug("Trying to extract job-originating-host-name from %s" % pagelogpath) try : pagelog = open(pagelogpath, "r") except IOError : self.logdebug("Unable to open %s" % pagelogpath) return (None, None) # no page log or can't read it, originating hostname unknown yet else : # TODO : read backward so we could take first value seen # TODO : here we read forward so we must take the last value seen prefix = ("%s %s %s " % (printername, username, jobid)).lower() matchingline = None while 1 : line = pagelog.readline() if not line : break else : line = line.strip() if line.lower().startswith(prefix) : matchingline = line # no break, because we read forward pagelog.close() if matchingline is None : self.logdebug("No matching line found in %s" % pagelogpath) return (None, None) # correct line not found, job-originating-host-name unknown else : (jobbilling, hostname) = matchingline.split()[-2:] if jobbilling == "-" : jobbilling = "" return (jobbilling, hostname) def doWork(self, policy, printer, user, userpquota) : """Most of the work is done here.""" # Two different values possible for policy here : # ALLOW means : Either printer, user or user print quota doesn't exist, # but the job should be allowed anyway. # OK means : Both printer, user and user print quota exist, job should # be allowed if current user is allowed to print on this printer if policy == "OK" : # exports user information with initial values self.exportUserInfo(userpquota) # tries to extract job-originating-host-name and other information self.regainPriv() cupsdconf = self.getCupsConfigDirectives(["PageLog", "RequestRoot"]) requestroot = cupsdconf.get("requestroot", "/var/spool/cups") if (len(self.jobid) < 5) and self.jobid.isdigit() : ippmessagefile = "c%05i" % int(self.jobid) else : ippmessagefile = "c%s" % self.jobid ippmessagefile = os.path.join(requestroot, ippmessagefile) ippmessage = {} try : ippdatafile = open(ippmessagefile) except : self.printInfo("Unable to open IPP message file %s" % ippmessagefile, "warn") else : self.logdebug("Parsing of IPP message file %s begins." % ippmessagefile) try : ippmessage = IPPMessage(ippdatafile.read()) except PyKotaIPPError, msg : self.printInfo("Error while parsing %s : %s" % (ippmessagefile, msg), "warn") else : self.logdebug("Parsing of IPP message file %s ends." % ippmessagefile) ippdatafile.close() self.dropPriv() clienthost = ippmessage.get("job-originating-host-name") billingcode = ippmessage.get("job-billing") if clienthost is None : (billingcode, clienthost) = self.getJobInfosFromPageLog(cupsdconf, printer.Name, user.Name, self.jobid) self.logdebug("Client Hostname : %s" % (clienthost or "Unknown")) self.logdebug("Billing Code : %s" % (billingcode or "None")) os.environ["PYKOTAJOBORIGINATINGHOSTNAME"] = str(clienthost or "") os.environ["PYKOTAJOBBILLING"] = str(billingcode or "") # enters first phase os.environ["PYKOTAPHASE"] = "BEFORE" # precomputes the job's price self.softwareJobPrice = userpquota.computeJobPrice(self.softwareJobSize) os.environ["PYKOTAPRECOMPUTEDJOBPRICE"] = str(self.softwareJobPrice) self.logdebug("Precomputed job's size is %s pages, price is %s units" % (self.softwareJobSize, self.softwareJobPrice)) if not self.jobSizeBytes : # if no data to pass to real backend, probably a filter # higher in the chain failed because of a misconfiguration. # we deny the job in this case (nothing to print anyway) self.printMoreInfo(user, printer, _("Job contains no data. Printing is denied."), "warn") action = "DENY" elif self.config.getDenyDuplicates(printer.Name) \ and printer.LastJob.Exists \ and (printer.LastJob.UserName == user.Name) \ and (printer.LastJob.JobMD5Sum == self.checksum) : self.printMoreInfo(user, printer, _("Job is a duplicate. Printing is denied."), "warn") action = "DENY" else : # checks the user's quota action = self.warnUserPQuota(userpquota) # exports some new environment variables os.environ["PYKOTAACTION"] = action # launches the pre hook self.prehook(userpquota) # saves the size of banners which have to be accounted for # this is needed in the case of software accounting bannersize = 0 # handle starting banner pages before accounting accountbanner = self.config.getAccountBanner(printer.Name) if accountbanner in ["ENDING", "NONE"] : if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) : self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn") else : if action == 'DENY' : self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name)) userpquota.incDenyBannerCounter() # increments the warning counter self.exportUserInfo(userpquota) banner = self.startingBanner(printer.Name) if banner : self.logdebug("Printing starting banner before accounting begins.") self.handleData(banner) self.printMoreInfo(user, printer, _("Job accounting begins.")) self.accounter.beginJob(printer) # handle starting banner pages during accounting if accountbanner in ["STARTING", "BOTH"] : if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) : self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn") else : if action == 'DENY' : self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name)) userpquota.incDenyBannerCounter() # increments the warning counter self.exportUserInfo(userpquota) banner = self.startingBanner(printer.Name) if banner : self.logdebug("Printing starting banner during accounting.") self.handleData(banner) if self.accounter.isSoftware : bannersize += 1 # TODO : fix this by passing the banner's content through PDLAnalyzer else : action = "ALLOW" os.environ["PYKOTAACTION"] = action # pass the job's data to the real backend if action in ["ALLOW", "WARN"] : if self.gotSigTerm : retcode = self.removeJob() else : retcode = self.handleData() else : retcode = self.removeJob() if policy == "OK" : # indicate phase change os.environ["PYKOTAPHASE"] = "AFTER" # handle ending banner pages during accounting if accountbanner in ["ENDING", "BOTH"] : if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) : self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn") else : if action == 'DENY' : self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name)) userpquota.incDenyBannerCounter() # increments the warning counter self.exportUserInfo(userpquota) banner = self.endingBanner(printer.Name) if banner : self.logdebug("Printing ending banner during accounting.") self.handleData(banner) if self.accounter.isSoftware : bannersize += 1 # TODO : fix this by passing the banner's content through PDLAnalyzer # stops accounting. self.accounter.endJob(printer) self.printMoreInfo(user, printer, _("Job accounting ends.")) # retrieve the job size if action == "DENY" : jobsize = 0 self.printMoreInfo(user, printer, _("Job size forced to 0 because printing is denied.")) else : userpquota.resetDenyBannerCounter() jobsize = self.accounter.getJobSize(printer) if self.softwareJobSize and (jobsize != self.softwareJobSize) : self.printInfo(_("Beware : computed job size (%s) != precomputed job size (%s)") % (jobsize, self.softwareJobSize), "error") (limit, replacement) = self.config.getTrustJobSize(printer.Name) if limit is None : self.printInfo(_("The job size will be trusted anyway according to the 'trustjobsize' directive"), "warn") else : if jobsize <= limit : self.printInfo(_("The job size will be trusted because it is inferior to the 'trustjobsize' directive's limit %s") % limit, "warn") else : self.printInfo(_("The job size will be modified according to the 'trustjobsize' directive : %s") % replacement, "warn") if replacement == "PRECOMPUTED" : jobsize = self.softwareJobSize else : jobsize = replacement jobsize += bannersize self.printMoreInfo(user, printer, _("Job size : %i") % jobsize) # update the quota for the current user on this printer self.printInfo(_("Updating user %s's quota on printer %s") % (user.Name, printer.Name)) jobprice = userpquota.increasePagesUsage(jobsize) # adds the current job to history printer.addJobToHistory(self.jobid, user, self.accounter.getLastPageCounter(), \ action, jobsize, jobprice, self.preserveinputfile, \ self.title, self.copies, self.options, clienthost, \ self.jobSizeBytes, self.checksum, None, billingcode) self.printMoreInfo(user, printer, _("Job added to history.")) # exports some new environment variables os.environ["PYKOTAJOBSIZE"] = str(jobsize) os.environ["PYKOTAJOBPRICE"] = str(jobprice) # then re-export user information with new value self.exportUserInfo(userpquota) # handle ending banner pages after accounting ends if accountbanner in ["STARTING", "NONE"] : if (action == 'DENY') and (userpquota.WarnCount >= self.config.getMaxDenyBanners(printer.Name)) : self.printInfo(_("Banner won't be printed : maximum number of deny banners reached."), "warn") else : if action == 'DENY' : self.logdebug("Incrementing the number of deny banners for user %s on printer %s" % (user.Name, printer.Name)) userpquota.incDenyBannerCounter() # increments the warning counter self.exportUserInfo(userpquota) banner = self.endingBanner(printer.Name) if banner : self.logdebug("Printing ending banner after accounting ends.") self.handleData(banner) # Launches the post hook self.posthook(userpquota) return retcode def unregisterFileNo(self, pollobj, fileno) : """Removes a file handle from the polling object.""" try : pollobj.unregister(fileno) except KeyError : self.printInfo(_("File number %s unregistered twice from polling object, ignored.") % fileno, "warn") except : self.logdebug("Error while unregistering file number %s from polling object." % fileno) else : self.logdebug("File number %s unregistered from polling object." % fileno) def formatFileEvent(self, fd, mask) : """Formats file debug info.""" maskval = [] if mask & select.POLLIN : maskval.append("POLLIN") if mask & select.POLLOUT : maskval.append("POLLOUT") if mask & select.POLLPRI : maskval.append("POLLPRI") if mask & select.POLLERR : maskval.append("POLLERR") if mask & select.POLLHUP : maskval.append("POLLHUP") if mask & select.POLLNVAL : maskval.append("POLLNVAL") return "%s (%s)" % (fd, " | ".join(maskval)) def handleData(self, filehandle=None) : """Pass the job's data to the real backend.""" # Find the real backend pathname realbackend = os.path.join(os.path.split(sys.argv[0])[0], self.originalbackend) # And launch it if filehandle is None : arguments = sys.argv else : # Here we absolutely WANT to remove any filename from the command line ! arguments = [ "Fake this because we are printing a banner" ] + sys.argv[1:6] self.regainPriv() self.logdebug("Starting real backend %s with args %s" % (realbackend, " ".join(['"%s"' % a for a in ([os.environ["DEVICE_URI"]] + arguments[1:])]))) subprocess = PyKotaPopen4([realbackend] + arguments[1:], bufsize=0, arg0=os.environ["DEVICE_URI"]) # Save file descriptors, we will need them later. stderrfno = sys.stderr.fileno() fromcfno = subprocess.fromchild.fileno() tocfno = subprocess.tochild.fileno() # We will have to be careful when dealing with I/O # So we use a poll object to know when to read or write pollster = select.poll() pollster.register(fromcfno, select.POLLIN | select.POLLPRI) pollster.register(stderrfno, select.POLLOUT) pollster.register(tocfno, select.POLLOUT) # Initialize our buffers indata = "" outdata = "" endinput = endoutput = 0 inputclosed = outputclosed = 0 totaltochild = totalfromcups = 0 totalfromchild = totaltocups = 0 if filehandle is None: if self.preserveinputfile is None : # this is not a real file, we read the job's data # from our temporary file which is a copy of stdin infno = self.jobdatastream.fileno() self.jobdatastream.seek(0) pollster.register(infno, select.POLLIN | select.POLLPRI) else : # job's data is in a file, no need to pass the data # to the real backend self.logdebug("Job's data is in %s" % self.preserveinputfile) infno = None endinput = 1 else: self.logdebug("Printing data passed from filehandle") indata = filehandle.read() infno = None endinput = 1 filehandle.close() self.logdebug("Entering streams polling loop...") MEGABYTE = 1024*1024 killed = 0 status = -1 while (status == -1) and (not killed) and not (inputclosed and outputclosed) : # First check if original backend is still alive status = subprocess.poll() # Now if we got SIGTERM, we have # to kill -TERM the original backend if self.gotSigTerm and not killed : try : os.kill(subprocess.pid, signal.SIGTERM) except OSError, msg : # ignore but logs if process was already killed. self.logdebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg)) else : self.printInfo(_("SIGTERM was sent to real backend %s (pid: %s)") % (realbackend, subprocess.pid)) killed = 1 # In any case, deal with any remaining I/O try : availablefds = pollster.poll(5000) except select.error, msg : self.logdebug("Interrupted poll : %s" % msg) availablefds = [] if not availablefds : self.logdebug("Nothing to do, sleeping a bit...") time.sleep(0.01) # give some time to the system else : for (fd, mask) in availablefds : # self.logdebug(self.formatFileEvent(fd, mask)) try : if mask & select.POLLOUT : # We can write if fd == tocfno : if indata : try : nbwritten = os.write(fd, indata) except (OSError, IOError), msg : self.logdebug("Error while writing to real backend's stdin %s : %s" % (fd, msg)) else : if len(indata) != nbwritten : self.logdebug("Short write to real backend's input !") totaltochild += nbwritten self.logdebug("%s bytes sent to real backend so far..." % totaltochild) indata = indata[nbwritten:] else : self.logdebug("No data to send to real backend yet, sleeping a bit...") time.sleep(0.01) if endinput : self.unregisterFileNo(pollster, tocfno) self.logdebug("Closing real backend's stdin.") os.close(tocfno) inputclosed = 1 elif fd == stderrfno : if outdata : try : nbwritten = os.write(fd, outdata) except (OSError, IOError), msg : self.logdebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg)) else : if len(outdata) != nbwritten : self.logdebug("Short write to stderr (CUPS) !") totaltocups += nbwritten self.logdebug("%s bytes sent back to CUPS so far..." % totaltocups) outdata = outdata[nbwritten:] else : # self.logdebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems. if endoutput : self.unregisterFileNo(pollster, stderrfno) outputclosed = 1 else : self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) time.sleep(0.01) if mask & (select.POLLIN | select.POLLPRI) : # We have something to read try : data = os.read(fd, MEGABYTE) except (IOError, OSError), msg : self.logdebug("Error while reading file %s : %s" % (fd, msg)) else : if fd == infno : if not data : # If yes, then no more input data self.unregisterFileNo(pollster, infno) self.logdebug("Input data ends.") endinput = 1 # this happens with real files. else : indata += data totalfromcups += len(data) self.logdebug("%s bytes read from CUPS so far..." % totalfromcups) elif fd == fromcfno : if not data : self.logdebug("No back channel data to read from real backend yet, sleeping a bit...") time.sleep(0.01) else : outdata += data totalfromchild += len(data) self.logdebug("%s bytes read from real backend so far..." % totalfromchild) else : self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) time.sleep(0.01) if mask & (select.POLLHUP | select.POLLERR) : # Treat POLLERR as an EOF. # Some standard I/O stream has no more datas self.unregisterFileNo(pollster, fd) if fd == infno : # Here we are in the case where the input file is stdin. # which has no more data to be read. self.logdebug("Input data ends.") endinput = 1 elif fd == fromcfno : # We are no more interested in this file descriptor self.logdebug("Closing real backend's stdout+stderr.") os.close(fromcfno) endoutput = 1 else : self.logdebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) time.sleep(0.01) if mask & select.POLLNVAL : self.logdebug("File %s was closed. Unregistering from polling object." % fd) self.unregisterFileNo(pollster, fd) except IOError, msg : self.logdebug("Got an IOError : %s" % msg) # we got signalled during an I/O # We must close the real backend's input stream if killed and not inputclosed : self.logdebug("Forcing close of real backend's stdin.") os.close(tocfno) self.logdebug("Exiting streams polling loop...") self.logdebug("input data's final length : %s" % len(indata)) self.logdebug("back-channel data's final length : %s" % len(outdata)) self.logdebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups) self.logdebug("Total bytes sent to real backend (job's datas) : %s" % totaltochild) self.logdebug("Total bytes read from real backend (back-channel datas) : %s" % totalfromchild) self.logdebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups) # Check exit code of original CUPS backend. if status == -1 : # we exited the loop before the real backend exited # now we have to wait for it to finish and get its status self.logdebug("Waiting for real backend to exit...") try : status = subprocess.wait() except OSError : # already dead : TODO : detect when abnormal status = 0 if os.WIFEXITED(status) : retcode = os.WEXITSTATUS(status) elif not killed : self.sendBackChannelData(_("CUPS backend %s died abnormally.") % realbackend, "error") retcode = -1 else : retcode = self.removeJob() self.dropPriv() return retcode if __name__ == "__main__" : # This is a CUPS backend, we should act and die like a CUPS backend retcode = 0 if len(sys.argv) == 1 : (directory, myname) = os.path.split(sys.argv[0]) tmpdir = tempfile.gettempdir() lockfilename = os.path.join(tmpdir, "%s..LCK" % myname) if os.path.exists(lockfilename) : # there's already a lockfile, see if still used lockfile = open(lockfilename, "r") pid = int(lockfile.read()) lockfile.close() try : # see if the pid contained in the lock file is still running os.kill(pid, 0) except OSError, e : if e.errno != errno.EPERM : # process doesn't exist anymore, remove the lock os.remove(lockfilename) if not os.path.exists(lockfilename) : lockfile = open(lockfilename, "w") lockfile.write("%i" % os.getpid()) lockfile.close() # we will execute each existing backend in device enumeration mode # and generate their PyKota accounting counterpart allbackends = [ os.path.join(directory, b) \ for b in os.listdir(directory) if os.access(os.path.join(directory, b), os.X_OK) \ and (b != myname)] for backend in allbackends : answer = os.popen(backend, "r") try : devices = [line.strip() for line in answer.readlines()] except : devices = [] status = answer.close() if status is None : for d in devices : # each line is of the form : 'xxxx xxxx "xxxx xxx" "xxxx xxx"' # so we have to decompose it carefully fdevice = cStringIO.StringIO("%s" % d) tokenizer = shlex.shlex(fdevice) tokenizer.wordchars = tokenizer.wordchars + r".:,?!~/\_$*-+={}[]()#" arguments = [] while 1 : token = tokenizer.get_token() if token : arguments.append(token) else : break fdevice.close() try : (devicetype, device, name, fullname) = arguments except ValueError : pass # ignore this 'bizarre' device else : if name.startswith('"') and name.endswith('"') : name = name[1:-1] if fullname.startswith('"') and fullname.endswith('"') : fullname = fullname[1:-1] print '%s cupspykota:%s "PyKota+%s" "PyKota managed %s"' % (devicetype, device, name, fullname) os.remove(lockfilename) retcode = 0 elif len(sys.argv) not in (6, 7) : sys.stderr.write("ERROR: %s job-id user title copies options [file]\n" % sys.argv[0]) retcode = 1 else : try : # Initializes the backend kotabackend = PyKotaBackend() kotabackend.deferredInit() retcode = kotabackend.mainWork() kotabackend.storage.close() kotabackend.closeJobDataStream() except SystemExit : retcode = -1 except : try : kotabackend.crashed("cupspykota backend failed") except : crashed("cupspykota backend failed") retcode = 1 sys.exit(retcode)