[cups] Only able to print from CUPS web interface ("filter failed" error otherwise)

Mario Sanchez Prada mario at endlessm.com
Wed Nov 5 13:20:56 PST 2014


Hi Helge,

On 05/11/14 20:46, Helge Blischke wrote:
> [...]
> Mario,
> 
> I suspect it is due to your filter/mime configuration. Please do the following:
> –	execute
> 	cupsctl —debug-logging
> –	print a test job e.g. using your system-config-printer or the gnome control center,
> 	and save the job ID
> –	extract the messages that refer to the test job (containing „Job nnn“ where nun is the job OD)
> 	from /var/log/cups/error_log
> –	execute cupsctl —no-debuglogging if you want
> –	post the extracted log portion.

Thanks a lot for your help, and prompt feedback!

Please see attached two logs(*) comparing the case where printing the
test page fails (from gnome-control-center) and where it's Ok (from web
interface).

Surprisingly enough, I do not see any line now related to
authentication, so indeed it looks like I was previously chasing a red
herring. Instead, it seems there has been some trouble with 'gs' and/or
the generated document for the test page. See an excerpt here:

    Started filter gs (PID 3442)
    Started filter pstops (PID 3443)
    GPL Ghostscript 9.07: Unrecoverable error, exit code 1
    Page = 595x842; 10,14 to 586,833
    slow_collate=0, slow_duplex=0, slow_order=0
    This document does not conform to the Adobe Document Structuring
Conventions and may not print correctly.
    ****$$$ endpage_count,line_count = 114, 215
    ****$$$ rotate_info = 0
    device_uri=(usb://Canon/MG4100%20series?serial=C10618&interface=1)
    #  p_size->name=A4 , p_size_default->name = A4 #
    ### num_opt(lpr optins) = 4 ###
    # ppdPageSize width=595.000000 height=842.000000 ###
    (3)Make cif options : p_choice found in p_ppd (p_choice:A4
[8.27"x11.69" 210.0x297.0mm] /  A4)
    (3)Make cif options : choice=A4(p_table->ppd_key=PageSize)
    PID 3442 (gs) stopped with status 1!

Not sure why this is happening though, hope the logs will help clarify
this a bit, at least to someone more familiar with this domain

Thanks!
Mario

(*) I replaced a bunch of lines in the logs following a "pattern" with
'[...]' to make the logs smaller, so the mail did not get stuck pending
on moderation (original attempt was > 200Kb)
-------------- next part --------------
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Adding start banner page "none".
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Adding end banner page "none".
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] File of type application/vnd.cups-pdf-banner queued by "anonymous".
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] hold_until=0
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Queued on "MG4100-series" by "anonymous".
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] time-at-processing=1415221080
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] 4 filters for job:
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] pdftops (application/vnd.cups-pdf to application/vnd.cups-postscript, cost 100)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] pstocanonij (application/vnd.cups-postscript to printer/MG4100-series, cost 0)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] job-sheets=none,none
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[0]="MG4100-series"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[1]="57"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[2]="anonymous"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[3]="Test Page"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[4]="1"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[5]="job-uuid=urn:uuid:cfc35074-a832-3209-7e61-586564f754c1 job-originating-host-name=localhost time-at-creation=1415221080 time-at-processing=1415221080"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] argv[6]="/var/spool/cups/d00057-001"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[1]="CUPS_DATADIR=/usr/share/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[6]="CUPS_SERVERROOT=/etc/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[7]="CUPS_STATEDIR=/var/run/cups"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[8]="HOME=/var/spool/cups/tmp"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[10]="SERVER_ADMIN=root at localmachine"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[11]="SOFTWARE=CUPS/1.7.1"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[12]="TMPDIR=/var/spool/cups/tmp"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[13]="USER=root"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[14]="CUPS_MAX_MESSAGE=2047"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[16]="CUPS_ENCRYPTION=IfRequested"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[17]="IPP_PORT=631"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[18]="CHARSET=utf-8"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[19]="LANG=C"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[20]="PPD=/etc/cups/ppd/MG4100-series.ppd"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[21]="RIP_MAX_CACHE=128m"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[23]="DEVICE_URI=usb://Canon/MG4100%20series?serial=C10618&interface=1"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[24]="PRINTER_INFO=Canon MG4100 series"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[25]="PRINTER_LOCATION=localmachine"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[26]="PRINTER=MG4100-series"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[27]="PRINTER_STATE_REASONS=none"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[28]="CUPS_FILETYPE=document"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[29]="FINAL_CONTENT_TYPE=printer/MG4100-series"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] envp[30]="AUTH_I****"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter /usr/lib/cups/filter/bannertopdf (PID 4338)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter /usr/lib/cups/filter/pdftopdf (PID 4339)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter /usr/lib/cups/filter/pdftops (PID 4340)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter /usr/lib/cups/filter/pstocanonij (PID 4341)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started backend /usr/lib/cups/backend/usb (PID 4342)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] pdftops - copying to temp print file "/var/spool/cups/tmp/010f4546062aa"
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] PDF template file doesn't have form. It's okay.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] pstocanonij start.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Loading USB quirks from "/usr/share/cups/usb".
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Loaded 109 quirks.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Printing on printer with URI: usb://Canon/MG4100%20series?serial=C10618&interface=1
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] libusb_get_device_list=5
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] STATE: +connecting-to-device
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] PID 4338 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] STATE: -connecting-to-device
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Device protocol: 2
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Sending data to printer.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Set job-printer-state-message to "Sending data to printer.", current level=INFO
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] PID 4339 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Read 69 bytes of back-channel data...
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Printer make and model: Canon mg4100
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Running command line for pstops: pstops 57 anonymous 'Test Page' 1 'job-uuid=urn:uuid:cfc35074-a832-3209-7e61-586564f754c1 job-originating-host-name=localhost time-at-creation=1415221080 time-at-processing=1415221080'
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Using image rendering resolution 600 dpi
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Running command line for gs: gs -q -dNOPAUSE -dBATCH -dSAFER -sDEVICE=ps2write -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r600 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c 'save pop' -f /var/spool/cups/tmp/010f4546062aa
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter gs (PID 4346)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Started filter pstops (PID 4347)
nov 05 20:58:00 localmachine cupsd[3146]: [Job 57] Read 364 bytes of back-channel data...
nov 05 20:58:02 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:02 localmachine cupsd[3146]: [Job 57] Read 412 bytes of back-channel data...

[...]

nov 05 20:58:06 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:07 localmachine cupsd[3146]: [Job 57] Read 412 bytes of back-channel data...
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Page = 595x842; 10,14 to 586,833
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] slow_collate=0, slow_duplex=0, slow_order=0
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Before copy_comments - %!PS-Adobe-3.0
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %!PS-Adobe-3.0
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%BoundingBox: 0 0 595 842
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%HiResBoundingBox: 0 0 595.00 842.00
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%Creator: GPL Ghostscript 907 (ps2write)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%LanguageLevel: 2
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%CreationDate: D:20141105205800Z00'00'
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%Pages: 1
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] %%EndComments
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Before copy_prolog - %%BeginProlog
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Copies = 1(PostScriptLevel2)¥nDEBUG: Before copy_setup - %%Page: 1 1
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Before page loop - %%Page: 1 1
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Copying page 1...
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] pagew = 576.0, pagel = 819.2
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] PageLeft = 9.6, PageRight = 585.6
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] PageTop = 833.4, PageBottom = 14.2
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] PageWidth = 595.0, PageLength = 842.0
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ****$$$ endpage_count,line_count = 1308, 1409
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ****$$$ rotate_info = 0
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] device_uri=(usb://Canon/MG4100%20series?serial=C10618&interface=1)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] #  p_size->name=A4 , p_size_default->name = A4 #
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ### num_opt(lpr optins) = 4 ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] # ppdPageSize width=595.000000 height=842.000000 ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:A4 [8.27"x11.69" 210.0x297.0mm] /  A4)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=A4(p_table->ppd_key=PageSize)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:Plain Paper /  plain)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=plain(p_table->ppd_key=MediaType)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:Front Tray /  front2)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=front2(p_table->ppd_key=InputSlot)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : CNCartridge is not found in p_ppd
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:3 /  3)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=3(p_table->ppd_key=CNQuality)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:Photo /  photo)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=photo(p_table->ppd_key=CNRenderIntent)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:Normal /  1.8)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=1.8(p_table->ppd_key=CNGamma)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceC)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceM)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceY)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=0(p_table->ppd_key=CNDensity)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:OFF /  False)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=False(p_table->ppd_key=CNGrayscale)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : CNCopies is not found in p_ppd
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:OFF /  None)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : CNStapleSide is not found in p_ppd
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=0(p_table->ppd_key=CNContrast)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:Both Black and Color /  bkcolor)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=bkcolor(p_table->ppd_key=CNInkCartridgeSettings)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : p_choice found in p_ppd (p_choice:2 /  2)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] (3)Make cif options : choice=2(p_table->ppd_key=CNExtension)
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ### lpr optins(3) : job-originating-host-name=localhost ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ### lpr optins(2) : job-uuid=urn:uuid:cfc35074-a832-3209-7e61-586564f754c1 ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ### lpr optins(1) : time-at-creation=1415221080 ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] ### lpr optins(0) : time-at-processing=1415221080 ###
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --copies
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --fit
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --bbox
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --extension
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --inkcartridgesettings
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --contrast
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --grayscale
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --density
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --balance_y
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --balance_m
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --balance_c
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --gamma
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --renderintent
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --quality
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --paperload
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --media
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] make_filter_param_list: --papersize
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] pstocanonij: /usr/bin/gs -sstdout=%stderr -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=%stdout -| /usr/bin/cifmg4100 --imageres 600 --papersize a4 --media plain --paperload front2 --quality 3 --renderintent photo --gamma 1.8 --balance_c 0 --balance_m 0 --balance_y 0 --density 0 --contrast 0 --inkcartridgesettings bkcolor --bbox 9,14,586,834 --fit  --copies 1 
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Read 768 bytes of print data...
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Wrote 768 bytes of print data...
nov 05 20:58:08 localmachine cupsd[3146]: [Job 57] Read 366 bytes of back-channel data...
nov 05 20:58:09 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:10 localmachine cupsd[3146]: [Job 57] Read 69 bytes of back-channel data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 1 pages...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] PID 4346 (gs) exited with no errors.
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] PID 4347 (pstops) exited with no errors.
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] PID 4340 (/usr/lib/cups/filter/pdftops) exited with no errors.
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 147 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 147 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 18 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 18 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 208 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 208 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 245 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 245 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...

[...]

nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:11 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...

[...]

nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 257 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 257 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 301 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 301 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 415 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 415 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 503 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 503 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 533 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 533 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 587 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 587 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 587 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 587 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 837 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 837 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1324 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1324 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1291 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1291 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1624 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1624 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1403 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1403 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1353 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1353 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1339 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1339 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1273 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1273 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1127 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1127 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1097 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1097 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1163 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1163 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1155 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1155 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1167 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1167 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1135 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1135 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1143 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1143 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1245 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1245 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1387 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1387 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1197 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1197 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1149 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1149 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 623 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 623 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 293 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 293 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 293 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 293 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 317 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 317 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 321 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 321 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 281 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 281 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 287 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 287 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 263 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 263 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...

[...]

nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1040 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1040 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1764 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1764 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 2567 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 2567 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 2809 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 2809 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 2915 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 2915 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 2958 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 2958 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1018 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1018 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 790 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 790 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 325 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 325 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 983 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 983 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1170 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1170 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 959 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 959 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 435 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 435 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 986 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 986 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1309 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 1309 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 2705 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Wrote 2705 bytes of print data...
nov 05 20:58:12 localmachine cupsd[3146]: [Job 57] Read 1486 bytes of print data...
nov 05 20:58:13 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:14 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:15 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:16 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:17 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:18 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:19 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:20 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:21 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:22 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:23 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Wrote 1486 bytes of print data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:24 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:25 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:25 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:25 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:25 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:25 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...

[...]

nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 5589 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 5589 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 1420 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 1420 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 1271 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 1271 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 1216 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 1216 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 857 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 857 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 680 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 680 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 205 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 205 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 3100 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 3100 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 5310 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 5310 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:26 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...

[...]

nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 4582 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 4582 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5328 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5328 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5252 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5252 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5284 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5284 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5087 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5087 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5101 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5101 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 843 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 843 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 2339 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 2339 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 1846 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 1846 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5018 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5018 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5006 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5006 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 933 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 933 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 2342 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 2342 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 5205 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 5205 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:27 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...

[...]

nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...

[...]

nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:28 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:29 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:30 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:31 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 8192 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 5756 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 5756 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 1518 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 1518 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...

[...]

nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] PID 4341 (/usr/lib/cups/filter/pstocanonij) exited with no errors.
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...

[...]

nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 253 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 7629 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...

[...]

nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] PID 4342 (/usr/lib/cups/backend/usb) exited with no errors.
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...

[...]

nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 41 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Wrote 7629 bytes of print data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Sent 963832 bytes...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Waiting for read thread to exit...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Read 512 bytes of back-channel data...
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] time-at-completed=1415221112
nov 05 20:58:32 localmachine cupsd[3146]: [Job 57] Job completed.
nov 05 20:59:04 localmachine cupsd[3146]: [Job 57] Unloading...
-------------- next part --------------
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Adding start banner page "none".
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Adding end banner page "none".
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] File of type application/vnd.cups-pdf-banner queued by "mario".
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] hold_until=0
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Queued on "MG4100-series" by "mario".
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] time-at-processing=1415220727
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] 4 filters for job:
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] pdftops (application/vnd.cups-pdf to application/vnd.cups-postscript, cost 100)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] pstocanonij (application/vnd.cups-postscript to printer/MG4100-series, cost 0)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] job-sheets=none,none
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[0]="MG4100-series"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[1]="56"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[2]="mario"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[3]="Página de prueba"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[4]="1"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[5]="job-uuid=urn:uuid:e8a1fa00-11f5-36bd-6e69-be2cdd6384d4 job-originating-host-name=localhost time-at-creation=1415220727 time-at-processing=1415220727"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] argv[6]="/var/spool/cups/d00056-001"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[1]="CUPS_DATADIR=/usr/share/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[6]="CUPS_SERVERROOT=/etc/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[7]="CUPS_STATEDIR=/var/run/cups"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[8]="HOME=/var/spool/cups/tmp"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[10]="SERVER_ADMIN=root at localmachine"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[11]="SOFTWARE=CUPS/1.7.1"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[12]="TMPDIR=/var/spool/cups/tmp"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[13]="USER=root"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[14]="CUPS_MAX_MESSAGE=2047"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[16]="CUPS_ENCRYPTION=IfRequested"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[17]="IPP_PORT=631"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[18]="CHARSET=utf-8"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[19]="LANG=es_GT.UTF-8"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[20]="PPD=/etc/cups/ppd/MG4100-series.ppd"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[21]="RIP_MAX_CACHE=128m"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[23]="DEVICE_URI=usb://Canon/MG4100%20series?serial=C10618&interface=1"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[24]="PRINTER_INFO=Canon MG4100 series"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[25]="PRINTER_LOCATION=localmachine"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[26]="PRINTER=MG4100-series"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[27]="PRINTER_STATE_REASONS=none"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[28]="CUPS_FILETYPE=document"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[29]="FINAL_CONTENT_TYPE=printer/MG4100-series"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] envp[30]="AUTH_I****"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Started filter /usr/lib/cups/filter/bannertopdf (PID 3434)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Started filter /usr/lib/cups/filter/pdftopdf (PID 3435)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Started filter /usr/lib/cups/filter/pdftops (PID 3436)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Started filter /usr/lib/cups/filter/pstocanonij (PID 3437)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Started backend /usr/lib/cups/backend/usb (PID 3438)
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] pdftops - copying to temp print file "/var/spool/cups/tmp/00d6c54692e8a"
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] pstocanonij start.
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Loading USB quirks from "/usr/share/cups/usb".
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Loaded 109 quirks.
nov 05 20:52:07 localmachine cupsd[3146]: [Job 56] Printing on printer with URI: usb://Canon/MG4100%20series?serial=C10618&interface=1
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] libusb_get_device_list=5
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] STATE: +connecting-to-device
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] STATE: -connecting-to-device
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Device protocol: 2
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Enviando datos a la impresora.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Set job-printer-state-message to "Enviando datos a la impresora.", current level=INFO
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PDF template file doesn't have form. It's okay.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 69 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 364 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 412 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...

[...]

nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 412 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3434 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3435 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 412 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 412 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...

[...]

nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 512 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 412 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Printer make and model: Canon mg4100
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Running command line for pstops: pstops 56 mario 'Página de prueba' 1 'job-uuid=urn:uuid:e8a1fa00-11f5-36bd-6e69-be2cdd6384d4 job-originating-host-name=localhost time-at-creation=1415220727 time-at-processing=1415220727'
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Using image rendering resolution 600 dpi
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Running command line for gs: gs -q -dNOPAUSE -dBATCH -dSAFER -sDEVICE=ps2write -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r600 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c 'save pop' -f /var/spool/cups/tmp/00d6c54692e8a
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Started filter gs (PID 3442)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Started filter pstops (PID 3443)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] GPL Ghostscript 9.07: Unrecoverable error, exit code 1
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Page = 595x842; 10,14 to 586,833
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] slow_collate=0, slow_duplex=0, slow_order=0
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] This document does not conform to the Adobe Document Structuring Conventions and may not print correctly.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ****$$$ endpage_count,line_count = 114, 215
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ****$$$ rotate_info = 0
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] device_uri=(usb://Canon/MG4100%20series?serial=C10618&interface=1)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] #  p_size->name=A4 , p_size_default->name = A4 #
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ### num_opt(lpr optins) = 4 ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] # ppdPageSize width=595.000000 height=842.000000 ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:A4 [8.27"x11.69" 210.0x297.0mm] /  A4)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=A4(p_table->ppd_key=PageSize)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3442 (gs) stopped with status 1!
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Plain Paper /  plain)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=plain(p_table->ppd_key=MediaType)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Front Tray /  front2)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=front2(p_table->ppd_key=InputSlot)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : CNCartridge is not found in p_ppd
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:3 /  3)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Photo /  photo)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=photo(p_table->ppd_key=CNRenderIntent)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Normal /  1.8)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=1.8(p_table->ppd_key=CNGamma)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceC)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceM)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=0(p_table->ppd_key=CNBalanceY)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=0(p_table->ppd_key=CNDensity)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:OFF /  False)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=False(p_table->ppd_key=CNGrayscale)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : CNCopies is not found in p_ppd
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:OFF /  None)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : CNStapleSide is not found in p_ppd
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:0 /  0)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=0(p_table->ppd_key=CNContrast)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Both Black and Color /  bkcolor)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=bkcolor(p_table->ppd_key=CNInkCartridgeSettings)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:2 /  2)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] (3)Make cif options : choice=2(p_table->ppd_key=CNExtension)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ### lpr optins(3) : job-originating-host-name=localhost ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ### lpr optins(2) : job-uuid=urn:uuid:e8a1fa00-11f5-36bd-6e69-be2cdd6384d4 ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3436 (/usr/lib/cups/filter/pdftops) stopped with status 1.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ### lpr optins(1) : time-at-creation=1415220727 ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] ### lpr optins(0) : time-at-processing=1415220727 ###
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --fit
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --bbox
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --extension
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --inkcartridgesettings
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --contrast
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --grayscale
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --density
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --balance_y
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --balance_m
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --balance_c
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --gamma
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --renderintent
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --quality
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --paperload
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --media
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] make_filter_param_list: --papersize
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] pstocanonij: /usr/bin/gs -sstdout=%stderr -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=%stdout -| /usr/bin/cifmg4100 --imageres 600 --papersize a4 --media plain --paperload front2 --quality 3 --renderintent photo --gamma 1.8 --balance_c 0 --balance_m 0 --balance_y 0 --density 0 --contrast 0 --inkcartridgesettings bkcolor --bbox 9,14,586,834 --fit  
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3443 (pstops) exited with no errors.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 289 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Wrote 289 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 479 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Wrote 479 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Error: /undefined in Error:
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Operand stack:
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Execution stack:
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1916   1   3   %oparray_pop   1915   1   3   %oparray_pop   1899   1   3   %oparray_pop   1787   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Dictionary stack:
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] --dict:1170/1684(ro)(G)--   --dict:0/20(G)--   --dict:83/200(L)--
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Current allocation mode is local
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Last OS error: No such file or directory
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] GPL Ghostscript 9.07: Unrecoverable error, exit code 1
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 277 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Wrote 277 bytes of print data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Sent 1045 bytes...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Waiting for read thread to exit...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3437 (/usr/lib/cups/filter/pstocanonij) did not catch or ignore signal 13.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Read 366 bytes of back-channel data...
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] PID 3438 (/usr/lib/cups/backend/usb) exited with no errors.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Job stopped due to filter errors; please consult the error_log file for details.
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] The following messages were recorded from 20:52:08 to 20:52:08
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] Printer found with device ID: MFG:Canon;CMD:BJL,BJRaster3,BSCCe,NCCe,IVEC,IVECPLI;SOJ:BJNP2,BJNPe;MDL:MG4100 series;CLS:PRINTER;DES:Canon MG4100 series;VER:2.011;STA:10;FSI:00;HRI:D;MSI:B240,DAT,E3,HFSF,JOFF,K21000700,LOFF;PDR:4;PSE:ACKH34183; Device URI: usb://Canon/MG4100%20series?serial=C10618&interface=1
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] End of messages
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] printer-state=3(idle)
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] printer-state-message="Filter failed"
nov 05 20:52:08 localmachine cupsd[3146]: [Job 56] printer-state-reasons=none
nov 05 20:52:09 localmachine cupsd[3146]: [Job 56] Unloading...
nov 05 20:52:12 localmachine cupsd[3146]: [Job 56] Loading attributes...


More information about the cups mailing list