[Pkg-cups-devel] cupsys: job is in "processing" state forever due to a filter exited with error code 1

Németh Márton nm127 at freemail.hu
Thu Feb 21 21:12:57 UTC 2008


Németh Márton wrote:
> Németh Márton wrote:
>> Németh Márton wrote:
>>> Package: cupsys
>>> Version: 1.3.5-1+b1
>>> Severity: important
>>>
>>> I have a Canon PIXMA MP160 printer connected to the USB port. I am using
>>> the printer with the filter "pstocanonij" written by Canon, and available
>>> at http://software.canon-europe.com/software/0027403.asp . I tried to print
>>> the PDF file http://www.kommentar.info.hu/a_lehetetlent_meg_kell_kiserteni.pdf
>>> from Acrobat Reader 7.0.0 (03/21/2005).
>>>
>>> The result was that nothing was printed, but the job was pending forever
>>> (see the attached cups_job_processing.png) at the state column.
>>>
>>> I set the "LogLevel debug" in the /etc/cups/cupsd.conf file, the result is included
>>> here. Although the "pstocanonij" filter exited with error code 1, the print process
>>> was not stopped, and no feedback was sent to the user that it was not possible to
>>> print this document.
>>>
>>> The other problem with this behavior is that no more printing job can complete after
>>> this until this "processing" job is not removed. I thing this job is not "processing",
>>> but it got a fatal error and should be removed from the printing queue in order other jobs
>>> can complete.
>>>
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAcceptClient: 11 from localhost (Domain)
>>> D [21/Feb/2008:18:23:50 +0100] cupsdReadClient: 11 POST / HTTP/1.1
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAuthorize: No authentication data provided.
>>> D [21/Feb/2008:18:23:50 +0100] CUPS-Get-Printers
>>> D [21/Feb/2008:18:23:50 +0100] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
>>> D [21/Feb/2008:18:23:50 +0100] cupsdReadClient: 11 POST / HTTP/1.1
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAuthorize: No authentication data provided.
>>> D [21/Feb/2008:18:23:50 +0100] CUPS-Get-Classes
>>> D [21/Feb/2008:18:23:50 +0100] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
>>> D [21/Feb/2008:18:23:50 +0100] cupsdReadClient: 11 POST / HTTP/1.1
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAuthorize: No authentication data provided.
>>> D [21/Feb/2008:18:23:50 +0100] CUPS-Get-Default
>>> D [21/Feb/2008:18:23:50 +0100] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
>>> D [21/Feb/2008:18:23:50 +0100] cupsdCloseClient: 11
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAcceptClient: 11 from localhost (Domain)
>>> D [21/Feb/2008:18:23:50 +0100] cupsdReadClient: 11 POST /printers/Canon_PIXMA HTTP/1.1
>>> D [21/Feb/2008:18:23:50 +0100] cupsdAuthorize: No authentication data provided.
>>> D [21/Feb/2008:18:23:50 +0100] Print-Job ipp://localhost/printers/Canon_PIXMA
>>> D [21/Feb/2008:18:23:50 +0100] print_job: auto-typing file...
>>> D [21/Feb/2008:18:23:50 +0100] add_job: requesting-user-name="nmarci"
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Adding start banner page "none".
>>> D [21/Feb/2008:18:23:50 +0100] Discarding unused job-created event...
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Adding job file of type application/postscript.
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Adding end banner page "none".
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Queued on "Canon_PIXMA" by "nmarci".
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] hold_until = 0
>>> D [21/Feb/2008:18:23:50 +0100] Discarding unused printer-state-changed event...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] job-sheets=none,none
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] banner_page = 0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[0]="Canon_PIXMA"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[1]="187"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[2]="nmarci"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[3]="Acro000kOnkp7"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[4]="1"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[5]="media=A4 finishings=3 number-up=1 job-uuid=urn:uuid:96d646f5-7e47-374d-4ce5-19bdfe5a97f6"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] argv[6]="/var/spool/cups/d00187-001"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[1]="CUPS_DATADIR=/usr/share/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[6]="CUPS_SERVERROOT=/etc/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[7]="CUPS_STATEDIR=/var/run/cups"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[9]="SERVER_ADMIN=root at localhost.localdomain"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[10]="SOFTWARE=CUPS/1.3.5"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[11]="TMPDIR=/var/spool/cups/tmp"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[12]="TZ=Europe/Budapest"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[13]="USER=root"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[15]="CUPS_ENCRYPTION=IfRequested"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[16]="IPP_PORT=631"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[17]="CHARSET=utf-8"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[18]="LANG=hu_HU.UTF8"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[19]="PPD=/etc/cups/ppd/Canon_PIXMA.ppd"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[20]="RIP_MAX_CACHE=8m"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[21]="CONTENT_TYPE=application/postscript"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[22]="DEVICE_URI=cnij_usb:/dev/usb/lp0"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[23]="PRINTER=Canon_PIXMA"
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] envp[24]="FINAL_CONTENT_TYPE=printer/Canon_PIXMA"
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Started filter /usr/lib/cups/filter/pstops (PID 4144)
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Started filter /usr/lib/cups/filter/pstocanonij (PID 4145)
>>> I [21/Feb/2008:18:23:50 +0100] [Job 187] Started backend /usr/lib/cups/backend/cnij_usb (PID 4146)
>>> D [21/Feb/2008:18:23:50 +0100] Discarding unused job-state event...
>>> D [21/Feb/2008:18:23:50 +0100] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Page = 595x842; 10,14 to 586,833
>>> D [21/Feb/2008:18:23:50 +0100] cupsdCloseClient: 11
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pstocanonij start.
>>> D [21/Feb/2008:18:23:50 +0100] Discarding unused printer-state-changed event...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] slow_collate=0, slow_duplex=0, slow_order=0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Before copy_comments - %!PS-Adobe-3.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %!PS-Adobe-3.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%Title: (kommentar2007-6-kesz.qxd)
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%Version: 1 4
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%CreationDate: 18.23.49 2008-02-21
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%DocumentData: Clean7Bit
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%LanguageLevel: 2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%BoundingBox: 30 29 502 710
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%HiResBoundingBox: 29.5937 29.1118 501.591 709.928
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%Pages: 11
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%DocumentProcessColors: (atend)
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%DocumentSuppliedResources:
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%+ procset (Adobe Acrobat - PDF operators) 1.2 0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%+ procset (Adobe Acrobat - type operators) 1.2 0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] %%EndComments
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Before copy_prolog - %%BeginDefaults
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Before copy_setup - %%BeginSetup
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] (Canon) langage moniter[/usr/local/bin/lgmonmp160 --gui --cups] start!
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Before page loop - %%Page: 1 1
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 1...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 2...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 3...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 4...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 5...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 6...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] Copying page 7...
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:50 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:51 +0100] [Job 187] pstocanonij: /usr/bin/gs -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=- -|
>>> /usr/local/bin/cifmp160 --imageres 600 --papersize a4 --media plain --paperload asf --bbox 9,14,585,834
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] CIF COMMAND ERROR :file access Error!
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] not support this image format
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] ESP Ghostscript 815.03: Unrecoverable error, exit code 1
>>> E [21/Feb/2008:18:23:52 +0100] [Job 187] pstocanonij write error,32.
>>> D [21/Feb/2008:18:23:52 +0100] Discarding unused printer-state-changed event...
>>> E [21/Feb/2008:18:23:52 +0100] PID 4145 (/usr/lib/cups/filter/pstocanonij) stopped with status 1!
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] Copying page 8...
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] Copying page 9...
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] Copying page 10...
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] Copying page 11...
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] pagew = 576.0, pagel = 819.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageLeft = 9.6, PageRight = 585.6
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageTop = 833.4, PageBottom = 14.2
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] PageWidth = 595.0, PageLength = 842.0
>>> D [21/Feb/2008:18:23:52 +0100] [Job 187] Wrote 11 pages...
>>> D [21/Feb/2008:18:23:52 +0100] PID 4144 (/usr/lib/cups/filter/pstops) exited with no errors.
>>>
>>> My /etc/cups/printers.conf looks like:
>>>
>>> <DefaultPrinter Canon_PIXMA>
>>> Info Canon PIXMA MP160
>>> DeviceURI cnij_usb:/dev/usb/lp0
>>> State Idle
>>> StateTime 1203614563
>>> Accepting Yes
>>> Shared Yes
>>> JobSheets none none
>>> QuotaPeriod 0
>>> PageLimit 0
>>> KLimit 0
>>> OpPolicy default
>>> ErrorPolicy stop-printer
>>> </Printer>
>>>
>>>
>>> -- System Information:
>>> Debian Release: lenny/sid
>>>   APT prefers testing
>>>   APT policy: (500, 'testing')
>>> Architecture: i386 (i686)
>>>
>>> Kernel: Linux 2.6.23 (PREEMPT)
>>> Locale: LANG=hu_HU, LC_CTYPE=hu_HU (charmap=ISO-8859-2)
>>> Shell: /bin/sh linked to /bin/bash
>>>
>>> Versions of packages cupsys depends on:
>>> ii  adduser               3.105              add and remove users and groups
>>> ii  cupsys-common         1.3.5-1            Common UNIX Printing System(tm) -
>>> ii  debconf [debconf-2.0] 1.5.19             Debian configuration management sy
>>> ii  gs-esp                8.15.3.dfsg.1-1    The Ghostscript PostScript interpr
>>> ii  libavahi-compat-libdn 0.6.22-2           Avahi Apple Bonjour compatibility
>>> ii  libc6                 2.7-6              GNU C Library: Shared libraries
>>> ii  libcupsimage2         1.3.5-1+b1         Common UNIX Printing System(tm) -
>>> ii  libcupsys2            1.3.5-1+b1         Common UNIX Printing System(tm) -
>>> ii  libdbus-1-3           1.1.2-1            simple interprocess messaging syst
>>> ii  libgnutls13           2.0.4-1            the GNU TLS library - runtime libr
>>> ii  libkrb53              1.6.dfsg.3~beta1-2 MIT Kerberos runtime libraries
>>> ii  libldap-2.4-2         2.4.7-4            OpenLDAP libraries
>>> ii  libpam0g              0.99.7.1-5         Pluggable Authentication Modules l
>>> ii  libpaper1             1.1.23             library for handling paper charact
>>> ii  libslp1               1.2.1-7.1          OpenSLP libraries
>>> ii  lsb-base              3.1-24             Linux Standard Base 3.1 init scrip
>>> ii  perl-modules          5.8.8-12           Core Perl modules
>>> ii  procps                1:3.2.7-5          /proc file system utilities
>>> ii  ssl-cert              1.0.14             Simple debconf wrapper for openssl
>>> ii  xpdf-utils [poppler-u 3.02-1.3           Portable Document Format (PDF) sui
>>>
>>> Versions of packages cupsys recommends:
>>> pn  avahi-utils           <none>             (no description available)
>>> ii  cupsys-client         1.3.5-1+b1         Common UNIX Printing System(tm) -
>>> ii  foomatic-filters      3.0.2-20061031-1.2 linuxprinting.org printer support
>>> ii  smbclient             3.0.28-2+b1        a LanManager-like simple client fo
>>>
>>> -- debconf information:
>>>   cupsys/raw-print: true
>>>   cupsys/backend: ipp, lpd, parallel, scsi, serial, socket, usb, snmp, dnssd
>> I found that the command:
>>
>> $ echo x | /usr/local/bin/cifmp160 --imageres 600 --papersize a4 --media plain --paperload asf --bbox 9,14,585,834
>>
>> will print the following lines to the stdout:
>>
>> BJLSTART
>> ControlMode=Common
>> SetTime=20080221195342
>> BJLEND
>>
>> and will print the following lines after this to the stderr:
>>
>> CIF COMMAND ERROR :file access Error!
>> not support this image format
>>
>> After this the cifmp160 exits with error code 0.
>>
>> It was not clear for me from the logfile that which process printed out these
>> the two error messages.
>>
> 
> I printed the only the first page of the document to 'test.ps' file and I found the
> followings:
> 
> $ cat test.ps |/usr/bin/gs -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=- -| /usr/local/bin/cifmp160 --imageres 600 --papersize a4
> --media plain --paperload asf --bbox 9,14,585,834
> BJLSTART
> ControlMode=Common
> SetTime=20080221204253
> BJLEND
> CIF COMMAND ERROR :file access Error!
> not support this image format
> $ echo $?
> 0
> $ cat test.ps |/usr/bin/gs -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=- -
> ERROR: /undefined in 75,353996
> Operand stack:
> 
> Execution stack:
>    %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--
> false   1   %stopped_push   1   3   %oparray_pop   1   3   %oparray_pop   1   3   %oparray_pop   1   3   %oparray_pop   .runexec2   --nostringval--
> --nostringval--   --nostringval--   2   %stopped_push   --nostringval--
> Dictionary stack:
>    --dict:1125/1686(ro)(G)--   --dict:0/20(G)--   --dict:108/200(L)--   --dict:36/89(L)--   --dict:87/162(ro)(L)--   --dict:64/78(ro)(L)--
> Current allocation mode is local
> Last OS error: 2
> ESP Ghostscript 815.03: Unrecoverable error, exit code 1
> $ echo $?
> 1
> 
> This means that 'gs' will exit with exit code 1 in case of error, however, 'cifmp160'
> will exit with exit code 0 in case of an error. The following can be read in bash(1),
> chapter "Pipelines":
> 
>> The return status of a pipeline is the exit status of the last command, unless the
>> pipefail option is  enabled. If pipefail is enabled, the pipeline's return status
>> is the value of the last (rightmost) command to exit with a non-zero status, or
>> zero if all commands exit successfully.
> 
> This means that the exit code of the full pipeline will be zero, but there was some
> commands which failed in the pipe!
> 

It was possible to print out the http://www.kommentar.info.hu/a_lehetetlent_meg_kell_kiserteni.pdf
PDF file with the command:

$ lpr a_lehetetlent_meg_kell_kiserteni.pdf

The following appears in the log file when the printing is successful:

D [21/Feb/2008:22:05:17 +0100] cupsdCloseClient: 8
D [21/Feb/2008:22:05:53 +0100] cupsdAcceptClient: 8 from localhost (Domain)
D [21/Feb/2008:22:05:53 +0100] cupsdReadClient: 8 POST / HTTP/1.1
D [21/Feb/2008:22:05:53 +0100] cupsdAuthorize: No authentication data provided.
D [21/Feb/2008:22:05:53 +0100] CUPS-Get-Printers
D [21/Feb/2008:22:05:53 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
D [21/Feb/2008:22:05:53 +0100] cupsdReadClient: 8 POST / HTTP/1.1
D [21/Feb/2008:22:05:53 +0100] cupsdAuthorize: No authentication data provided.
D [21/Feb/2008:22:05:53 +0100] CUPS-Get-Classes
D [21/Feb/2008:22:05:53 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
D [21/Feb/2008:22:05:53 +0100] cupsdReadClient: 8 POST / HTTP/1.1
D [21/Feb/2008:22:05:53 +0100] cupsdAuthorize: No authentication data provided.
D [21/Feb/2008:22:05:53 +0100] CUPS-Get-Default
D [21/Feb/2008:22:05:53 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
D [21/Feb/2008:22:05:53 +0100] cupsdCloseClient: 8
D [21/Feb/2008:22:05:53 +0100] cupsdAcceptClient: 8 from localhost (Domain)
D [21/Feb/2008:22:05:53 +0100] cupsdReadClient: 8 POST /printers/Canon_PIXMA HTTP/1.1
D [21/Feb/2008:22:05:53 +0100] cupsdAuthorize: No authentication data provided.
D [21/Feb/2008:22:05:53 +0100] Print-Job ipp://localhost/printers/Canon_PIXMA
D [21/Feb/2008:22:05:53 +0100] print_job: auto-typing file...
D [21/Feb/2008:22:05:53 +0100] add_job: requesting-user-name="nmarci"
I [21/Feb/2008:22:05:53 +0100] [Job 193] Adding start banner page "none".
D [21/Feb/2008:22:05:53 +0100] Discarding unused job-created event...
I [21/Feb/2008:22:05:53 +0100] [Job 193] Adding job file of type application/pdf.
I [21/Feb/2008:22:05:53 +0100] [Job 193] Adding end banner page "none".
I [21/Feb/2008:22:05:53 +0100] [Job 193] Queued on "Canon_PIXMA" by "nmarci".
D [21/Feb/2008:22:05:53 +0100] [Job 193] hold_until = 0
D [21/Feb/2008:22:05:53 +0100] Discarding unused printer-state-changed event...
D [21/Feb/2008:22:05:53 +0100] [Job 193] job-sheets=none,none
D [21/Feb/2008:22:05:53 +0100] [Job 193] banner_page = 0
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[0]="Canon_PIXMA"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[1]="193"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[2]="nmarci"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[3]="a_lehetetlent_meg_kell_kiserteni.pdf"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[4]="1"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[5]="media=A4 finishings=3 number-up=1 job-uuid=urn:uuid:86e93de3-3161-324d-4207-172f3f9a7647"
D [21/Feb/2008:22:05:53 +0100] [Job 193] argv[6]="/var/spool/cups/d00193-001"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[9]="SERVER_ADMIN=root at localhost.localdomain"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[10]="SOFTWARE=CUPS/1.3.5"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[12]="TZ=Europe/Budapest"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[13]="USER=root"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[16]="IPP_PORT=631"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[17]="CHARSET=utf-8"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[18]="LANG=hu_HU.UTF8"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[19]="PPD=/etc/cups/ppd/Canon_PIXMA.ppd"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[20]="RIP_MAX_CACHE=8m"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[21]="CONTENT_TYPE=application/pdf"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[22]="DEVICE_URI=cnij_usb:/dev/usb/lp0"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[23]="PRINTER=Canon_PIXMA"
D [21/Feb/2008:22:05:53 +0100] [Job 193] envp[24]="FINAL_CONTENT_TYPE=printer/Canon_PIXMA"
I [21/Feb/2008:22:05:53 +0100] [Job 193] Started filter /usr/lib/cups/filter/pdftops (PID 19236)
I [21/Feb/2008:22:05:53 +0100] [Job 193] Started filter /usr/lib/cups/filter/pstops (PID 19237)
I [21/Feb/2008:22:05:53 +0100] [Job 193] Started filter /usr/lib/cups/filter/pstocanonij (PID 19238)
I [21/Feb/2008:22:05:53 +0100] [Job 193] Started backend /usr/lib/cups/backend/cnij_usb (PID 19239)
D [21/Feb/2008:22:05:53 +0100] Discarding unused job-state event...
D [21/Feb/2008:22:05:53 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
D [21/Feb/2008:22:05:53 +0100] [Job 193] pstocanonij start.
D [21/Feb/2008:22:05:53 +0100] Discarding unused printer-state-changed event...
D [21/Feb/2008:22:05:53 +0100] [Job 193] (Canon) langage moniter[/usr/local/bin/lgmonmp160 --gui --cups] start!
D [21/Feb/2008:22:05:53 +0100] cupsdCloseClient: 8
E [21/Feb/2008:22:05:53 +0100] [Job 193] pdftops-options: -cfg /etc/cups/pdftops.conf
D [21/Feb/2008:22:05:53 +0100] Discarding unused printer-state-changed event...
D [21/Feb/2008:22:05:53 +0100] [Job 193] Page = 595x842; 10,14 to 586,833
D [21/Feb/2008:22:05:53 +0100] [Job 193] slow_collate=0, slow_duplex=0, slow_order=0
D [21/Feb/2008:22:05:53 +0100] [Job 193] Before copy_comments - %!PS-Adobe-3.0
D [21/Feb/2008:22:05:53 +0100] [Job 193] %!PS-Adobe-3.0
D [21/Feb/2008:22:05:53 +0100] [Job 193] % Produced by xpdf/pdftops 3.02
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%Creator: PSCRIPT.DRV 4.0-s verzi\363
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%Title: kommentar2007-6-kesz.qxd
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%LanguageLevel: 2
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%DocumentSuppliedResources: (atend)
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%DocumentMedia: plain 553 741 0 () ()
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%BoundingBox: 0 0 553 741
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%Pages: 11
D [21/Feb/2008:22:05:53 +0100] [Job 193] %%EndComments
D [21/Feb/2008:22:05:53 +0100] [Job 193] Before copy_prolog - %%BeginDefaults
D [21/Feb/2008:22:05:53 +0100] [Job 193] Before copy_setup - %%BeginSetup
D [21/Feb/2008:22:05:53 +0100] [Job 193] Before page loop - %%Page: 1 1
D [21/Feb/2008:22:05:53 +0100] [Job 193] Copying page 1...
D [21/Feb/2008:22:05:53 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:53 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:53 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:53 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:53 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:53 +0100] [Job 193] pstocanonij: /usr/bin/gs -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=- -|
/usr/local/bin/cifmp160 --imageres 600 --papersize a4 --media plain --paperload asf --bbox 9,14,585,834
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 2...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 3...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 4...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 5...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 6...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 7...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 8...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] [Job 193] Copying page 9...
D [21/Feb/2008:22:05:54 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:05:54 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:05:54 +0100] PID 19236 (/usr/lib/cups/filter/pdftops) exited with no errors.
D [21/Feb/2008:22:06:02 +0100] cupsdAcceptClient: 8 from localhost:631 (IPv4)
D [21/Feb/2008:22:06:02 +0100] cupsdReadClient: 8 GET /jobs/ HTTP/1.1
D [21/Feb/2008:22:06:02 +0100] cupsdAuthorize: Authorized as root using Basic
D [21/Feb/2008:22:06:02 +0100] [CGI] /usr/lib/cups/cgi-bin/jobs.cgi started - PID = 19248
I [21/Feb/2008:22:06:02 +0100] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=19248)
D [21/Feb/2008:22:06:02 +0100] cupsdSendCommand: 8 file=11
D [21/Feb/2008:22:06:02 +0100] cupsdAcceptClient: 12 from localhost (Domain)
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] cupsdReadClient: 12 POST / HTTP/1.1
D [21/Feb/2008:22:06:02 +0100] cupsdAuthorize: No authentication data provided.
D [21/Feb/2008:22:06:02 +0100] Get-Jobs ipp://localhost/jobs
D [21/Feb/2008:22:06:02 +0100] cupsdProcessIPPRequest: 12 status_code=0 (successful-ok)
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] [CGI] lang="en_US.UTF8", locale="/en_US"...
D [21/Feb/2008:22:06:02 +0100] cupsdCloseClient: 12
D [21/Feb/2008:22:06:02 +0100] PID 19248 (/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
D [21/Feb/2008:22:06:20 +0100] [Job 193] Copying page 10...
D [21/Feb/2008:22:06:20 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:06:20 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:06:20 +0100] [Job 193] Copying page 11...
D [21/Feb/2008:22:06:20 +0100] [Job 193] pagew = 576.0, pagel = 819.2
D [21/Feb/2008:22:06:20 +0100] [Job 193] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageLeft = 9.6, PageRight = 585.6
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageTop = 833.4, PageBottom = 14.2
D [21/Feb/2008:22:06:20 +0100] [Job 193] PageWidth = 595.0, PageLength = 842.0
D [21/Feb/2008:22:06:20 +0100] [Job 193] Wrote 11 pages...
D [21/Feb/2008:22:06:20 +0100] PID 19237 (/usr/lib/cups/filter/pstops) exited with no errors.



More information about the Pkg-cups-devel mailing list