[Da diese Mail von Donnerstagnachmittag immer noch nicht angekommen zu
sein scheint, schicke ich sie ein weiteres Mal. Sorry, falls dadurch ein
Duplikat entstehen sollte.]
Hallo!
On 16 Sep 2004 at 09:20 +0200, Marcus Walther wrote:
> ># strace -o /tmp/LOG -v -tt -f -s256 -p `pidof cupsd`
> Ich habe die Logs unter <http://www.marcus-walther.de/LOG.fail.bz2>
> bzw. <http://www.marcus-walther.de/LOG.ok.bz2> abgelegt.
Dann wollen wir mal...
Generell scheint der grobe Programmablauf in Ordnung zu sein: cupsd
akzeptiert den Job und startet korrekt die Filter texttops und pstops
sowie das HTTP-Backend.
texttops hatten wir ja schon als unschuldig ausgeschlossen, pstops liest
zumindest die passende PPD ein und müsste damit eigentlich gehalten
sein, eine Wandlung von PS Level 3 auf Level 2 vornehmen (ich kürze hier
auf der Liste mal die recht langen Timestamps):
| 3506 execve("/usr/lib/cups/filter/pstops", [..., "PPD=/etc/cups/ppd/fs1010.ppd"
| 3506 open("/etc/cups/ppd/fs1010.ppd", O_RDONLY) = 3
| 3506 read(3, "*PPD-Adobe: \"4.3\"\n ...
Allerdings gibt pstops offenbar nichtsdestotrotz PS Level 3 aus. Da ist
es vermutlich auch kein Trost, dass die PJL-Befehle korrekt aus der PPD
übernommen worden zu sein scheinen:
| 3506 write(1, "\33%-12345X@PJL\n@PJL JOB NAME = \"text.txt\" ... \
| @PJL ENTER LANGUAGE=POSTSCRIPT\n%!PS-Adobe-3.0 ...
| [...]
| 3506 write(1, "%%Trailer\n%%Pages: 1\n%%EOF\n\33%-12345X@PJL EOJ\n\33%-12345X"
Und sogar die EOJ-Markierung stimmt. Auch werden diese Daten korrekt vom
HTTP-Backend eingelesen:
| 3507 execve("/usr/lib/cups/backend/http", ["http://192.168.100.98:631/ipp";, ...
| [...]
| 3507 read(4, "\33%-12345X@PJL\n@PJL JOB NAME = \"text.txt\" ..., 131072) = 131072
| 3507 send(3, "\33%-12345X@PJL\n@PJL JOB NAME = \"text.txt\" ..., 32768, 0) = 32768
| 3507 send(3, "c7d27582b3894 ..." 32768, 0) = 32768
| [...]
| 3507 recv(3, "HTTP/1.1 200 OK\r\nPragma: no-cache\r\nConnection: close ...
Hier fällt jedoch auf, dass die (ersten) 128 KiB der Job-Datei gelesen
werden (die von texttops/pstops erzeugte Datei also >= 131072 Bytes groß
sein muss), vom Printserver aber schon nach erfolgreicher Übertragung
von 2x32 KiB eine 'Connection: close'-Nachricht versendet wird. Beim
funktionieren Druckjob geschieht das erst nach Empfang des gesamten
Jobs, so wie es sein sollte.
Ich kann mir das spontan nur damit erklären, dass sich der
PS-Interpreter des Druckers am falschen PS-Level verschluckt und der
Printserver daraufhin (noch während CUPS immer neue Daten schickt) die
Verbindung beendet.
Da die PPD (welche ja explizit Level 2 fordert) von jedem Filter
zumindest eingelesen wird, bleibt fast nur noch ein CUPS-Bug in puncto
PS-Wandlung/Erzeugung übrig. Das HTTP-Backend scheint soweit zu
funktionieren (Ob es auch korrekt IPP spricht, haben wir allerdings noch
nicht überprüft).
Natürlich ist ein strace-Durchlauf kein Ersatz für ein ausführliches
Debugging, aber ich denke, dass wir das ab jetzt den CUPS-Entwicklern
überlassen sollten. Ich denke auch, dass du mittlerweile so viele
Informationen über das Fehlverhalten gesammelt hast, dass dir ein
vorbildlicher Bug-Report möglich wird.
Es wäre prima, wenn du die Liste dann abschließend kurz über das
Ergebnis informieren könntest (z.B. durch Verweis aufs CUPS-ML-Archiv
oder eine Bug-Nummer).
> Mir auffällige Fehlermeldungen finden sich in beiden Logs.
Welche genau meinst du? Mir ist (abgesehen von Obigem) nichts Unübliches
aufgefallen, und ein paar ENOENTs z.B. sind normal, wenn potentiell
existente Dateien durchprobiert werden...
Gruß und viel Erfolg,
Elmar
--
[ GnuPG: D8A88C0D / 2407 063C 1C92 90E9 4766 B170 5E95 0D7F D8A8 8C0D ]
·······································································
Die eigene Erfahrung hat den Vorteil völliger Gewißheit.
-- Schopenhauer
Attachment:
pgp0GE9GaLkSn.pgp
Description: PGP signature