| 572 | | self.logDebug("Launching data thread.") |
| 573 | | infile = open(self.DataFile, "rb") |
| 574 | | iothread = threading.Thread(target = self.handleOriginalBackendIO, kwargs = { "parent" : threading.currentThread(), "event" : rendezvous, "inf": infile, "outf" : subprocess.tochild}) |
| 575 | | iothread.start() |
| 576 | | |
| 577 | | # here we only want to read its output and send it on our stderr |
| 578 | | while (self.InputFile is not None) or iothread.isAlive() : # until all data transmitted to original backend |
| 579 | | data = subprocess.fromchild.readline() |
| 580 | | if (not data) or rendezvous.isSet() : |
| 581 | | break |
| 582 | | sys.stderr.write(data) |
| 583 | | sys.stderr.flush() |
| 584 | | |
| 585 | | if not rendezvous.isSet() : |
| 586 | | rendezvous.set() |
| 587 | | if self.InputFile is None : |
| 588 | | infile.close() |
| 589 | | iothread.join() |
| 590 | | subprocess.fromchild.close() |
| 591 | | subprocess.tochild.close() |
| 592 | | status = subprocess.wait() |
| | 638 | # this is not a real file, we read the job's data |
| | 639 | # from our temporary file which is a copy of stdin |
| | 640 | inf = open(self.DataFile, "rb") |
| | 641 | infno = inf.fileno() |
| | 642 | pollster.register(infno, select.POLLIN | select.POLLPRI) |
| | 643 | else : |
| | 644 | # job's data is in a file, no need to pass the data |
| | 645 | # to the original backend |
| | 646 | self.logDebug("Job's data is in %s" % self.InputFile) |
| | 647 | infno = None |
| | 648 | endinput = 1 |
| | 649 | |
| | 650 | self.logDebug("Entering streams polling loop...") |
| | 651 | MEGABYTE = 1024*1024 |
| | 652 | killed = 0 |
| | 653 | status = -1 |
| | 654 | while (status == -1) and (not killed) and not (inputclosed and outputclosed) : |
| | 655 | # First check if original backend is still alive |
| | 656 | status = subprocess.poll() |
| | 657 | |
| | 658 | # Now if we got SIGTERM, we have |
| | 659 | # to kill -TERM the original backend |
| | 660 | if self.gotSigTerm and not killed : |
| | 661 | try : |
| | 662 | os.kill(subprocess.pid, signal.SIGTERM) |
| | 663 | except OSError, msg : # ignore but logs if process was already killed. |
| | 664 | self.logDebug("Error while sending signal to pid %s : %s" % (subprocess.pid, msg)) |
| | 665 | else : |
| | 666 | self.logInfo(_("SIGTERM was sent to original backend %s (PID %s)") % (originalbackend, subprocess.pid)) |
| | 667 | killed = 1 |
| | 668 | |
| | 669 | # In any case, deal with any remaining I/O |
| | 670 | try : |
| | 671 | availablefds = pollster.poll(5000) |
| | 672 | except select.error, msg : |
| | 673 | self.logDebug("Interrupted poll : %s" % msg) |
| | 674 | availablefds = [] |
| | 675 | if not availablefds : |
| | 676 | self.logDebug("Nothing to do, sleeping a bit...") |
| | 677 | time.sleep(0.01) # give some time to the system |
| | 678 | else : |
| | 679 | for (fd, mask) in availablefds : |
| | 680 | try : |
| | 681 | if mask & select.POLLOUT : |
| | 682 | # We can write |
| | 683 | if fd == tocfno : |
| | 684 | if indata : |
| | 685 | try : |
| | 686 | nbwritten = os.write(fd, indata) |
| | 687 | except (OSError, IOError), msg : |
| | 688 | self.logDebug("Error while writing to original backend's stdin %s : %s" % (fd, msg)) |
| | 689 | else : |
| | 690 | if len(indata) != nbwritten : |
| | 691 | self.logDebug("Short write to original backend's input !") |
| | 692 | totaltochild += nbwritten |
| | 693 | self.logDebug("%s bytes sent to original backend so far..." % totaltochild) |
| | 694 | indata = indata[nbwritten:] |
| | 695 | else : |
| | 696 | self.logDebug("No data to send to original backend yet, sleeping a bit...") |
| | 697 | time.sleep(0.01) |
| | 698 | |
| | 699 | if endinput : |
| | 700 | self.unregisterFileNo(pollster, tocfno) |
| | 701 | self.logDebug("Closing original backend's stdin.") |
| | 702 | os.close(tocfno) |
| | 703 | inputclosed = 1 |
| | 704 | elif fd == stderrfno : |
| | 705 | if outdata : |
| | 706 | try : |
| | 707 | nbwritten = os.write(fd, outdata) |
| | 708 | except (OSError, IOError), msg : |
| | 709 | self.logDebug("Error while writing to CUPS back channel (stderr) %s : %s" % (fd, msg)) |
| | 710 | else : |
| | 711 | if len(outdata) != nbwritten : |
| | 712 | self.logDebug("Short write to stderr (CUPS) !") |
| | 713 | totaltocups += nbwritten |
| | 714 | self.logDebug("%s bytes sent back to CUPS so far..." % totaltocups) |
| | 715 | outdata = outdata[nbwritten:] |
| | 716 | else : |
| | 717 | # self.logDebug("No data to send back to CUPS yet, sleeping a bit...") # Uncommenting this fills your logs |
| | 718 | time.sleep(0.01) # Give some time to the system, stderr is ALWAYS writeable it seems. |
| | 719 | |
| | 720 | if endoutput : |
| | 721 | self.unregisterFileNo(pollster, stderrfno) |
| | 722 | outputclosed = 1 |
| | 723 | else : |
| | 724 | self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) |
| | 725 | time.sleep(0.01) |
| | 726 | |
| | 727 | if mask & (select.POLLIN | select.POLLPRI) : |
| | 728 | # We have something to read |
| | 729 | try : |
| | 730 | data = os.read(fd, MEGABYTE) |
| | 731 | except (IOError, OSError), msg : |
| | 732 | self.logDebug("Error while reading file %s : %s" % (fd, msg)) |
| | 733 | else : |
| | 734 | if fd == infno : |
| | 735 | if not data : # If yes, then no more input data |
| | 736 | self.unregisterFileNo(pollster, infno) |
| | 737 | self.logDebug("Input data ends.") |
| | 738 | endinput = 1 # this happens with real files. |
| | 739 | else : |
| | 740 | indata += data |
| | 741 | totalfromcups += len(data) |
| | 742 | self.logDebug("%s bytes read from CUPS so far..." % totalfromcups) |
| | 743 | elif fd == fromcfno : |
| | 744 | if not data : |
| | 745 | self.logDebug("No back channel data to read from original backend yet, sleeping a bit...") |
| | 746 | time.sleep(0.01) |
| | 747 | else : |
| | 748 | outdata += data |
| | 749 | totalfromchild += len(data) |
| | 750 | self.logDebug("%s bytes read from original backend so far..." % totalfromchild) |
| | 751 | else : |
| | 752 | self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) |
| | 753 | time.sleep(0.01) |
| | 754 | |
| | 755 | if mask & (select.POLLHUP | select.POLLERR) : |
| | 756 | # Treat POLLERR as an EOF. |
| | 757 | # Some standard I/O stream has no more datas |
| | 758 | self.unregisterFileNo(pollster, fd) |
| | 759 | if fd == infno : |
| | 760 | # Here we are in the case where the input file is stdin. |
| | 761 | # which has no more data to be read. |
| | 762 | self.logDebug("Input data ends.") |
| | 763 | endinput = 1 |
| | 764 | elif fd == fromcfno : |
| | 765 | # We are no more interested in this file descriptor |
| | 766 | self.logDebug("Closing original backend's stdout+stderr.") |
| | 767 | os.close(fromcfno) |
| | 768 | endoutput = 1 |
| | 769 | else : |
| | 770 | self.logDebug("Unexpected : %s - Sleeping a bit..." % self.formatFileEvent(fd, mask)) |
| | 771 | time.sleep(0.01) |
| | 772 | |
| | 773 | if mask & select.POLLNVAL : |
| | 774 | self.logDebug("File %s was closed. Unregistering from polling object." % fd) |
| | 775 | self.unregisterFileNo(pollster, fd) |
| | 776 | except IOError, msg : |
| | 777 | self.logDebug("Got an IOError : %s" % msg) # we got signalled during an I/O |
| | 778 | |
| | 779 | # We must close the original backend's input stream |
| | 780 | if killed and not inputclosed : |
| | 781 | self.logDebug("Forcing close of original backend's stdin.") |
| | 782 | os.close(tocfno) |
| | 783 | |
| | 784 | self.logDebug("Exiting streams polling loop...") |
| | 785 | |
| | 786 | self.logDebug("input data's final length : %s" % len(indata)) |
| | 787 | self.logDebug("back-channel data's final length : %s" % len(outdata)) |
| | 788 | |
| | 789 | self.logDebug("Total bytes read from CUPS (job's datas) : %s" % totalfromcups) |
| | 790 | self.logDebug("Total bytes sent to original backend (job's datas) : %s" % totaltochild) |
| | 791 | |
| | 792 | self.logDebug("Total bytes read from original backend (back-channel datas) : %s" % totalfromchild) |
| | 793 | self.logDebug("Total bytes sent back to CUPS (back-channel datas) : %s" % totaltocups) |
| | 794 | |
| | 795 | # Check exit code of original CUPS backend. |
| | 796 | if status == -1 : |
| | 797 | # we exited the loop before the original backend exited |
| | 798 | # now we have to wait for it to finish and get its status |
| | 799 | self.logDebug("Waiting for original backend to exit...") |
| | 800 | try : |
| | 801 | status = subprocess.wait() |
| | 802 | except OSError : # already dead : TODO : detect when abnormal |
| | 803 | status = 0 |
