Cups appears printing fine to MFP, but nothing happens

Paul Conklin paul.conklin at cerner.com
Thu Oct 27 10:49:15 PDT 2011


this looks like a custom filter
Started filter /usr/lib/cups/filter/est6550_Authentication
if so is it passing on the job or hoarding it?

try lp'ing a file raw to it to see if that prints.

> Below is the debug log file. We've gotten a Toshiba E-Studio 2540c, and I'm trying to set it up with cups. I've gotten the print filter from the Toshiba site, and whenever I try to print a test page, it appears to work, but nothing happens. The printer's logs confirm it never received anything.
>
>
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Adding start banner page "topsecret".
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Adding job file of type application/postscript.
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Adding end banner page "none".
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Queued on "Office_Toshiba-EStudio2540c" by "root".
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] hold_until = 0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] job-sheets=topsecret,none
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] banner_page = 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[0]="Office_Toshiba-EStudio2540c"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[1]="10510"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[2]="root"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[3]="Test Page"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[4]="1"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[5]="job-uuid=urn:uuid:1d30996b-2bbe-384e-5c30-059d4dddaa33"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[6]="/var/spool/cups/d10510-001"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[1]="CUPS_DATADIR=/usr/share/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.3.7"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[7]="CUPS_STATEDIR=/var/run/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[9]="SERVER_ADMIN=root at ceres.core.apparatus.net"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[10]="SOFTWARE=CUPS/1.3.7"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[11]="TMPDIR=/var/spool/cups/tmp"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[12]="USER=root"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[14]="CUPS_ENCRYPTION=IfRequested"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[15]="IPP_PORT=631"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[16]="CHARSET=utf-8"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[17]="LANG=en_US.UTF8"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[18]="PPD=/etc/cups/ppd/Office_Toshiba-EStudio2540c.ppd"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[19]="RIP_MAX_CACHE=8m"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[20]="CONTENT_TYPE=application/postscript"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[21]="DEVICE_URI=socket://10.204.3.21:9100/Print"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[22]="PRINTER=Office_Toshiba-EStudio2540c"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[23]="FINAL_CONTENT_TYPE=printer/Office_Toshiba-EStudio2540c"
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Started filter /usr/lib/cups/filter/pstops (PID 21045)
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Started filter /usr/lib/cups/filter/est6550_Authentication (PID 21046)
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Started backend /usr/lib/cups/backend/socket (PID 21047)
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Page = 612x792; 14,14 to 599,777
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] slow_collate=0, slow_duplex=0, slow_order=0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_comments - %!PS-Adobe-3.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %!PS-Adobe-3.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%BoundingBox: 0 0 612 792
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Pages: 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%LanguageLevel: 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentData: Clean7Bit
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentSuppliedResources: procset bannerprint/1.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentNeededResources: font Helvetica Helvetica-Bold Times-Roman
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Creator: Michael Sweet, Apple Inc.
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%CreationDate: D:20070620123000+0700
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Title: Test Page
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%EndComments
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_prolog - %%BeginProlog
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_setup - %%Page: 1 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Label Page = 612x792; 14,14 to 599,777
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before page loop - %%Page: 1 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Copying page 1...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] pagew = 584.7, pagel = 762.7
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageLeft = 14.2, PageRight = 598.8
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageTop = 776.8, PageBottom = 14.2
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageWidth = 612.0, PageLength = 792.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 1 pages...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] File 0 is complete.
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] job-sheets=topsecret,none
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] banner_page = 0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[0]="Office_Toshiba-EStudio2540c"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[1]="10510"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[2]="root"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[3]="Test Page"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[4]="1"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[5]="job-uuid=urn:uuid:1d30996b-2bbe-384e-5c30-059d4dddaa33"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] argv[6]="/var/spool/cups/d10510-002"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[1]="CUPS_DATADIR=/usr/share/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.3.7"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[7]="CUPS_STATEDIR=/var/run/cups"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[9]="SERVER_ADMIN=root at ceres.core.apparatus.net"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[10]="SOFTWARE=CUPS/1.3.7"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[11]="TMPDIR=/var/spool/cups/tmp"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[12]="USER=root"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[14]="CUPS_ENCRYPTION=IfRequested"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[15]="IPP_PORT=631"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[16]="CHARSET=utf-8"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[17]="LANG=en_US.UTF8"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[18]="PPD=/etc/cups/ppd/Office_Toshiba-EStudio2540c.ppd"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[19]="RIP_MAX_CACHE=8m"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[20]="CONTENT_TYPE=application/postscript"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[21]="DEVICE_URI=socket://10.204.3.21:9100/Print"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[22]="PRINTER=Office_Toshiba-EStudio2540c"
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] envp[23]="FINAL_CONTENT_TYPE=printer/Office_Toshiba-EStudio2540c"
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Started filter /usr/lib/cups/filter/pstops (PID 21049)
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Started filter /usr/lib/cups/filter/est6550_Authentication (PID 21050)
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Connected to 10.204.3.21:9100 (IPv4)...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] backendRunLoop(print_fd=0, device_fd=8, use_bc=1, side_cb=0x6d0de0)
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 8192 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 8192 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4341 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4341 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Page = 612x792; 14,14 to 599,777
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] slow_collate=0, slow_duplex=0, slow_order=0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_comments - %!PS-Adobe-3.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %!PS-Adobe-3.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%BoundingBox: 0 0 612 792
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Pages: 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%LanguageLevel: 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentData: Clean7Bit
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentSuppliedResources: procset testprint/1.3
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%DocumentNeededResources: font Helvetica Helvetica-Bold Times-Roman
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Creator: Michael Sweet, Apple Inc.
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%CreationDate: D:20070606214000+0500
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%Title: Test Page
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] %%EndComments
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_prolog - %%BeginProlog
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before copy_setup - %%Page: 1 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Label Page = 612x792; 14,14 to 599,777
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Before page loop - %%Page: 1 1
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Copying page 1...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] pagew = 584.7, pagel = 762.7
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageLeft = 14.2, PageRight = 598.8
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageTop = 776.8, PageBottom = 14.2
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] PageWidth = 612.0, PageLength = 792.0
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 1 pages...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 4096 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Read 670 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] Wrote 670 bytes of print data...
> D [26/Oct/2011:15:32:23 -0400] [Job 10510] File 1 is complete.
> I [26/Oct/2011:15:32:23 -0400] [Job 10510] Completed successfully.
> D [26/Oct/2011:15:32:24 -0400] [Job 10510] Unloading...
>
>
> Any ideas would be very helpful.
>
> Thank you in advance,
> Michael Lubert





More information about the cups mailing list