[cups] Print job inverts colours halfway

Tue Aug 11 06:13:50 PDT 2015

Doeds printing the testpage *really* invert the colors halfway?
In your first post you told from documents with images from LibreOffice showing the issue.

To make clear what my suspicion is:
I know from many JPEG images that they internally use an inverted notation of colors, and I suspect
that when converting these data to PostScript, this inverting has not been confined to the image data
but erroneously extended to the subsequent data.

Helge

> Am 11.08.2015 um 14:56 schrieb Emmanuel Noobadmin <centos.admin at gmail.com>:
> 
> On 8/10/15, Helge Blischke <helgeblischke at web.de> wrote:
>> Please do the following:
>> –	cupsctl —debug-logging
>> –	print a test job exhibiting the issue
>> –	grep 'Job xxx‘ /var/log/cups/error_log > an_arbitrary_temporary_file
>> 	where xxx is the Job ID
>> –	post the contents of the temporary file.
>> 
>> This information will probably give some first hints on where the cause of
>> the issue is.
> 
> Thanks for the help, grepped content as below, nothing appears out of
> ordinary to my untrained eye though since it seems to be full of
> "exited without errors"
> 
> ====================================
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Adding start banner page "none".
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Adding end banner page "none".
> I [11/Aug/2015:20:45:50 +0800] [Job 8] File of type
> application/vnd.cups-pdf-banner queued by "c7admin".
> D [11/Aug/2015:20:45:50 +0800] [Job 8] hold_until=0
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Queued on "Canon-MF4700-OCB1"
> by "c7admin".
> D [11/Aug/2015:20:45:50 +0800] [Job 8] time-at-processing=1439297150
> D [11/Aug/2015:20:45:50 +0800] [Job 8] 4 filters for job:
> D [11/Aug/2015:20:45:50 +0800] [Job 8] bannertopdf
> (application/vnd.cups-pdf-banner to application/pdf, cost 32)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pdftopdf (application/pdf to
> application/vnd.cups-pdf, cost 66)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pdftops
> (application/vnd.cups-pdf to application/vnd.cups-postscript, cost
> 100)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pstoufr2cpca
> (application/vnd.cups-postscript to printer/Canon-MF4700-OCB1, cost 0)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] job-sheets=none,none
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[0]="Canon-MF4700-OCB1"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[1]="8"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[2]="c7admin"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[3]="Test page"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[4]="1"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> argv[5]="job-uuid=urn:uuid:2acf125f-c65d-3b1d-56c6-f5233d4cf6fd
> job-originating-host-name=localhost time-at-creation=1439297150
> time-at-processing=1439297150"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] argv[6]="/var/spool/cups/d00008-001"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[1]="CUPS_DATADIR=/usr/share/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[7]="CUPS_STATEDIR=/var/run/cups"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[8]="HOME=/var/spool/cups/tmp"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[9]="PATH=/usr/lib/cups/filter:/usr/lib64/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[10]="SERVER_ADMIN=root at localhost.localdomain"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[11]="SOFTWARE=CUPS/1.6.3"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[12]="TMPDIR=/var/spool/cups/tmp"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[13]="USER=root"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[14]="CUPS_MAX_MESSAGE=2047"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[16]="CUPS_ENCRYPTION=IfRequested"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[17]="IPP_PORT=631"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[18]="CHARSET=utf-8"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[19]="LANG=en_US.UTF-8"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[20]="PPD=/etc/cups/ppd/Canon-MF4700-OCB1.ppd"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[21]="RIP_MAX_CACHE=128m"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[23]="DEVICE_URI=socket://10.0.0.201"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[24]="PRINTER_INFO=Canon
> MF4700 Series"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[25]="PRINTER_LOCATION="
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[26]="PRINTER=Canon-MF4700-OCB1"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[27]="PRINTER_STATE_REASONS=none"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[28]="CUPS_FILETYPE=document"
> D [11/Aug/2015:20:45:50 +0800] [Job 8]
> envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] envp[30]="AUTH_I****"
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter
> /usr/lib/cups/filter/bannertopdf (PID 13685)
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter
> /usr/lib/cups/filter/pdftopdf (PID 13686)
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter
> /usr/lib/cups/filter/pdftops (PID 13687)
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter
> /usr/lib/cups/filter/pstoufr2cpca (PID 13688)
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Started backend
> /usr/lib/cups/backend/socket (PID 13689)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] STATE: +connecting-to-device
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Looking up "10.0.0.201"...
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pdftops - copying to temp print
> file "/var/spool/cups/tmp/cupsGgTsEO"
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pstoufr2cpca start.
> D [11/Aug/2015:20:45:50 +0800] [Job 8] PID 13685
> (/usr/lib/cups/filter/bannertopdf) exited with no errors.
> D [11/Aug/2015:20:45:50 +0800] [Job 8] PID 13686
> (/usr/lib/cups/filter/pdftopdf) exited with no errors.
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Using image rendering resolution 600 dpi
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter pdftops (PID 13690)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Started filter pstops (PID 13691)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Page = 595x842; 14,14 to 581,828
> D [11/Aug/2015:20:45:50 +0800] [Job 8] slow_collate=0, slow_duplex=0,
> slow_order=0
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Before copy_comments - %!PS-Adobe-3.0
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %!PS-Adobe-3.0
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %Produced by poppler pdftops
> version: 0.22.5 (http://poppler.freedesktop.org)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%Creator: cairo 1.10.2
> (http://cairographics.org)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%LanguageLevel: 3
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%DocumentSuppliedResources: (atend)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%DocumentMedia: 595x842 595 842 0 () ()
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%BoundingBox: 0 0 595 842
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%Pages: 1
> D [11/Aug/2015:20:45:50 +0800] [Job 8] %%EndComments
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Before copy_prolog - %%BeginProlog
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Before copy_setup - %%BeginSetup
> D [11/Aug/2015:20:45:50 +0800] [Job 8] prtGeneralCurrentLocalization
> type is 5, expected 2!
> D [11/Aug/2015:20:45:50 +0800] [Job 8] backendWaitLoop(snmp_fd=6,
> addr=0x7fd06dec6298, side_cb=0x7fd06c5e8360)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Before page loop - %%Page: 1 1
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Copying page 1...
> D [11/Aug/2015:20:45:50 +0800] [Job 8] pagew = 566.9, pagel = 813.5
> D [11/Aug/2015:20:45:50 +0800] [Job 8] bboxx = 0, bboxy = 0, bboxw =
> 595, bboxl = 842
> D [11/Aug/2015:20:45:50 +0800] [Job 8] PageLeft = 14.2, PageRight = 581.1
> D [11/Aug/2015:20:45:50 +0800] [Job 8] PageTop = 827.8, PageBottom = 14.3
> D [11/Aug/2015:20:45:50 +0800] [Job 8] PageWidth = 595.0, PageLength = 842.0
> D [11/Aug/2015:20:45:50 +0800] [Job 8] opvpOpenPrinter(463)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] CStubOpenPrinter(397)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] opvpOpenPrinter(463)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] CStubOpenPrinter(397)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Connecting to 10.0.0.201:9100
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Connecting to printer.
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Set job-printer-state-message
> to "Connecting to printer.", current level=INFO
> D [11/Aug/2015:20:45:50 +0800] [Job 8] STATE: -connecting-to-device
> I [11/Aug/2015:20:45:50 +0800] [Job 8] Connected to printer.
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Set job-printer-state-message
> to "Connected to printer.", current level=INFO
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Connected to 10.0.0.201:9100...
> D [11/Aug/2015:20:45:50 +0800] [Job 8] backendRunLoop(print_fd=0,
> device_fd=7, snmp_fd=6, addr=0x7fd06dec6298, use_bc=1,
> side_cb=0x7fd06c5e8360)
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Read 81 bytes of print data...
> D [11/Aug/2015:20:45:50 +0800] [Job 8] Wrote 81 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] PID 13690 (pdftops) exited with
> no errors.
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Wrote 1 pages...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] PID 13691 (pstops) exited with no errors.
> D [11/Aug/2015:20:45:52 +0800] [Job 8] PID 13687
> (/usr/lib/cups/filter/pdftops) exited with no errors.
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Read 97 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Wrote 97 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:52 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] PID 13688
> (/usr/lib/cups/filter/pstoufr2cpca) exited with no errors.
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 8192 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Read 4040 bytes of print data...
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Wrote 4040 bytes of print data...
> I [11/Aug/2015:20:45:53 +0800] [Job 8] Waiting for printer to finish.
> D [11/Aug/2015:20:45:53 +0800] [Job 8] Set job-printer-state-message
> to "Waiting for printer to finish.", current level=INFO
> D [11/Aug/2015:20:45:53 +0800] [Job 8] PID 13689
> (/usr/lib/cups/backend/socket) exited with no errors.
> D [11/Aug/2015:20:45:53 +0800] [Job 8] time-at-completed=1439297153
> I [11/Aug/2015:20:45:53 +0800] [Job 8] Job completed.
> D [11/Aug/2015:20:48:11 +0800] [Job 8] Unloading...
> D [11/Aug/2015:20:48:11 +0800] [Job 8] Loading from cache...
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups