[cups.general] Always show "No pages found" when print to Brother Printer via Samba

[Helge Blischke]

Darren Yang wrote:

> I already install brother official lpr and cups driver on RHEL6. It is
> working well that using lpr command to print locally. But if I try to
> use Windows XP client via Samba print to CUPS then Printer will warm
> up but don't print anything. I open cups debug and saw that -
> 
> D [25/Nov/2010:18:21:10 +0800] cupsdAcceptClient: 13 from localhost
> (Domain) D [25/Nov/2010:18:21:10 +0800] cupsdReadClient: 13 POST
> /printers/4040CDN-BR HTTP/1.1
> D [25/Nov/2010:18:21:10 +0800] cupsdSetBusyState: Active clients
> D [25/Nov/2010:18:21:10 +0800] cupsdAuthorize: No authentication data
> provided. D [25/Nov/2010:18:21:10 +0800] cupsdReadClient: 13 1.1 Print-Job
> 1 D [25/Nov/2010:18:21:10 +0800] Print-Job
> ipp://localhost/printers/4040CDN-BR D [25/Nov/2010:18:21:10 +0800] [Job
> ???] Auto-typing file... I [25/Nov/2010:18:21:10 +0800] [Job ???] Request
> file type is application/postscript.
> D [25/Nov/2010:18:21:10 +0800] add_job: setting context of job to UNKNOWN
> SL D [25/Nov/2010:18:21:10 +0800] cupsdMarkDirty(----J-)
> D [25/Nov/2010:18:21:10 +0800] cupsdSetBusyState: Active clients and dirty
> files D [25/Nov/2010:18:21:10 +0800] add_job: requesting-user-name="root"
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Adding start banner page "none".
> D [25/Nov/2010:18:21:10 +0800] Discarding unused job-created event...
> D [25/Nov/2010:18:21:10 +0800] cupsdMarkDirty(----J-)
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Adding end banner page "none".
> I [25/Nov/2010:18:21:10 +0800] [Job 31] File of type
> application/postscript queued by "root".
> D [25/Nov/2010:18:21:10 +0800] [Job 31] hold_until=0
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Queued on "4040CDN-BR" by "root".
> D [25/Nov/2010:18:21:10 +0800] cupsdMarkDirty(----J-)
> D [25/Nov/2010:18:21:10 +0800] cupsdSetBusyState: Active clients,
> printing jobs, and dirty files
> D [25/Nov/2010:18:21:10 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:10 +0800] [Job 31] job-sheets=none,none
> D [25/Nov/2010:18:21:10 +0800] [Job 31] argv[0]="4040CDN-BR"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] argv[1]="31"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] argv[2]="root"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] argv[3]="smbprn.00000022 test.txt
> - 記事本" D [25/Nov/2010:18:21:10 +0800] [Job 31] argv[4]="1"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> argv[5]="job-originating-host-name=::ffff:10.11.160.167
> job-uuid=urn:uuid:303d646b-c373-38cd-44d6-05719156a33d"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> argv[6]="/var/spool/cups/d00031-001" D [25/Nov/2010:18:21:10 +0800] [Job
> 31] envp[0]="CUPS_CACHEDIR=/var/cache/cups" D [25/Nov/2010:18:21:10 +0800]
> [Job 31] envp[1]="CUPS_DATADIR=/usr/share/cups" D [25/Nov/2010:18:21:10
> +0800] [Job 31] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[5]="CUPS_SERVERBIN=/usr/lib/cups" D [25/Nov/2010:18:21:10 +0800] [Job
> 31] envp[6]="CUPS_SERVERROOT=/etc/cups" D [25/Nov/2010:18:21:10 +0800]
> [Job 31] envp[7]="CUPS_STATEDIR=/var/run/cups" D [25/Nov/2010:18:21:10
> +0800] [Job 31] envp[8]="HOME=/var/spool/cups/tmp" D [25/Nov/2010:18:21:10
> +0800] [Job 31]
> envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin" D
> [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[10]="SERVER_ADMIN=root at localhost" D [25/Nov/2010:18:21:10 +0800] [Job
> 31] envp[11]="SOFTWARE=CUPS/1.4.2" D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[12]="TMPDIR=/var/spool/cups/tmp" D [25/Nov/2010:18:21:10 +0800] [Job
> 31] envp[13]="USER=root" D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[14]="CUPS_SERVER=/var/run/cups/cups.sock" D [25/Nov/2010:18:21:10
> +0800] [Job 31] envp[15]="CUPS_ENCRYPTION=IfRequested" D
> [25/Nov/2010:18:21:10 +0800] [Job 31] envp[16]="IPP_PORT=631" D
> [25/Nov/2010:18:21:10 +0800] [Job 31] envp[17]="CHARSET=utf-8" D
> [25/Nov/2010:18:21:10 +0800] [Job 31] envp[18]="LANG=zn_US.UTF-8" D
> [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[19]="PPD=/etc/cups/ppd/4040CDN-BR.ppd" D [25/Nov/2010:18:21:10 +0800]
> [Job 31] envp[20]="RIP_MAX_CACHE=8m" D [25/Nov/2010:18:21:10 +0800] [Job
> 31] envp[21]="CONTENT_TYPE=application/postscript"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[22]="DEVICE_URI=lpd://10.11.249.112/binary_p1"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] envp[23]="PRINTER_INFO=4040CDN-BR"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] envp[24]="PRINTER_LOCATION="
> D [25/Nov/2010:18:21:10 +0800] [Job 31] envp[25]="PRINTER=4040CDN-BR"
> D [25/Nov/2010:18:21:10 +0800] [Job 31] envp[26]="CUPS_FILETYPE=document"
> D [25/Nov/2010:18:21:10 +0800] [Job 31]
> envp[27]="FINAL_CONTENT_TYPE=printer/4040CDN-BR"
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Started filter
> /usr/lib/cups/filter/pstops (PID 1383)
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Started filter
> /usr/lib/cups/filter/brlpdwrapperhl4040cdn (PID 1384)
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Started backend
> /usr/lib/cups/backend/lpd (PID 1385)
> D [25/Nov/2010:18:21:10 +0800] Discarding unused job-state-changed
> event... D [25/Nov/2010:18:21:10 +0800] Returning IPP successful-ok for
> Print-Job (ipp://localhost/printers/4040CDN-BR) from localhost
> D [25/Nov/2010:18:21:10 +0800] cupsdSetBusyState: Printing jobs and dirty
> files D [25/Nov/2010:18:21:10 +0800] cupsdReadClient: 13 WAITING Closing
> on EOF D [25/Nov/2010:18:21:10 +0800] cupsdCloseClient: 13
> D [25/Nov/2010:18:21:10 +0800] [Job 31] STATE: +connecting-to-device
> D [25/Nov/2010:18:21:10 +0800] [Job 31] Looking up "10.11.249.112"...
> I [25/Nov/2010:18:21:10 +0800] [Job 31] Copying print data...
> D [25/Nov/2010:18:21:10 +0800] [Job 31] backendRunLoop(print_fd=-1,
> device_fd=6, snmp_fd=5, addr=0x16888bc, use_bc=0, side_cb=0x98af40)
> D [25/Nov/2010:18:21:10 +0800] [Job 31] Page = 612x792; 0,0 to 612,792
> D [25/Nov/2010:18:21:10 +0800] [Job 31] slow_collate=0, slow_duplex=0,
> slow_order=0
> D [25/Nov/2010:18:21:10 +0800] [Job 31] Before copy_comments -
> %!PS-Adobe-3.0 D [25/Nov/2010:18:21:10 +0800] [Job 31] %!PS-Adobe-3.0
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %cupsJobTicket:
> job-hold-until=no-hold D [25/Nov/2010:18:21:10 +0800] [Job 31]
> %cupsJobTicket: job-sheets=none,none D [25/Nov/2010:18:21:10 +0800] [Job
> 31] %!PS-Adobe-3.0 D [25/Nov/2010:18:21:10 +0800] [Job 31] %%Title:
> (test.txt - \260O\250\306\245\273)
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%Creator: PScript5.dll Version
> 5.2.2 D [25/Nov/2010:18:21:10 +0800] [Job 31] %%CreationDate: 11/25/2010
> 18:21:16 D [25/Nov/2010:18:21:10 +0800] [Job 31] %%For: root
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%BoundingBox: (atend)
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%Pages: (atend)
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%Orientation: Portrait
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%PageOrder: Ascend
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%DocumentNeededResources: (atend)
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%DocumentSuppliedResources:
> (atend) D [25/Nov/2010:18:21:10 +0800] [Job 31] %%DocumentData: Clean7Bit
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%TargetDevice: (HL-4040CDN
> series) (3010.106) 3
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%LanguageLevel: 3
> D [25/Nov/2010:18:21:10 +0800] [Job 31] %%EndComments
> D [25/Nov/2010:18:21:10 +0800] [Job 31] Before copy_prolog -
> D [25/Nov/2010:18:21:10 +0800] [Job 31] Before copy_setup -
> D [25/Nov/2010:18:21:10 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:10 +0800] Discarding unused job-progress
> event... D [25/Nov/2010:18:21:10 +0800] [Job 31] Before page loop -
> %%Page: 1 1 D [25/Nov/2010:18:21:10 +0800] [Job 31] Copying page 1...
> D [25/Nov/2010:18:21:10 +0800] [Job 31] pagew = 612.0, pagel = 792.0
> D [25/Nov/2010:18:21:10 +0800] [Job 31] bboxx = 0, bboxy = 0, bboxw =
> 612, bboxl = 792
> D [25/Nov/2010:18:21:10 +0800] [Job 31] PageLeft = 0.0, PageRight = 612.0
> D [25/Nov/2010:18:21:10 +0800] [Job 31] PageTop = 792.0, PageBottom = 0.0
> D [25/Nov/2010:18:21:10 +0800] [Job 31] PageWidth = 612.0, PageLength =
> 792.0 D [25/Nov/2010:18:21:10 +0800] [Job 31] Wrote 1 pages...
> D [25/Nov/2010:18:21:10 +0800] PID 1383 (/usr/lib/cups/filter/pstops)
> exited with no errors.
> D [25/Nov/2010:18:21:13 +0800] [Job 31] Error: error occurred at print
> phase !! E [25/Nov/2010:18:21:13 +0800] [Job 31] No pages found!
> D [25/Nov/2010:18:21:13 +0800] [Job 31] Set job-printer-state-message
> to "No pages found!", current level=ERROR
> D [25/Nov/2010:18:21:13 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:13 +0800] Discarding unused job-progress
> event... D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> +connecting-to-device D [25/Nov/2010:18:21:14 +0800] [Job 31] Looking up
> "10.11.249.112"... D [25/Nov/2010:18:21:14 +0800] [Job 31] Connecting to
> 10.11.249.112:515 for printer binary_p1
> I [25/Nov/2010:18:21:14 +0800] [Job 31] Connecting to printer...
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:14 +0800] Discarding unused job-progress
> event... D [25/Nov/2010:18:21:14 +0800] PID 1384
> (/usr/lib/cups/filter/brlpdwrapperhl4040cdn) exited with no errors.
> D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE: -connecting-to-device
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... I [25/Nov/2010:18:21:14 +0800] [Job 31] Connected to printer...
> D [25/Nov/2010:18:21:14 +0800] [Job 31] Connected to 10.11.249.112:515
> (IPv4) (local port 1023)...
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:14 +0800] Discarding unused job-progress
> event... D [25/Nov/2010:18:21:14 +0800] [Job 31] ATTR:
> marker-colors=#000000,#00FFFF,#FFFF00,#FF00FF,none,none,none
> D [25/Nov/2010:18:21:14 +0800] cupsdMarkDirty(P-----)
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:14 +0800] [Job 31] ATTR: marker-names="Black
> Toner Brother TN-110/115/130/135/150/155/170/175BK","Cyan Toner
> Brother TN-110/115/130/135/150/155/170/175C","Magenta Toner Brother
> TN-110/115/130/135/150/155/170/175M","Yellow Toner Brother
> TN-110/115/130/135/150/155/170/175Y","Waste Toner Box Brother
> WT-100CL","Belt Unit Brother BU-100CL","Drum Unit Brother
> DR-110/130/150/170CL"
> D [25/Nov/2010:18:21:14 +0800] cupsdMarkDirty(P-----)
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:14 +0800] [Job 31] ATTR:
> marker-types=toner,toner,toner,toner,wasteToner,other,opc
> D [25/Nov/2010:18:21:14 +0800] cupsdMarkDirty(P-----)
> D [25/Nov/2010:18:21:14 +0800] Discarding unused printer-state-changed
> event... D [25/Nov/2010:18:21:14 +0800] [Job 31] ATTR:
> marker-levels=-1,-1,-1,-1,-1,99,99 D [25/Nov/2010:18:21:14 +0800]
> cupsdMarkDirty(P-----) D [25/Nov/2010:18:21:14 +0800] Discarding unused
> printer-state-changed event... D [25/Nov/2010:18:21:14 +0800] [Job 31]
> STATE: -media-low-report D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -media-empty-warning D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -toner-low-report D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -toner-empty-warning D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -door-open-report D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -media-jam-warning D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -input-tray-missing-warning D [25/Nov/2010:18:21:14 +0800] [Job 31] STATE:
> -output-tray-missing-warning D [25/Nov/2010:18:21:14 +0800] [Job 31]
> STATE: -marker-supply-missing-warning D [25/Nov/2010:18:21:14 +0800] [Job
> 31] STATE: -output-area-almost-full-report D [25/Nov/2010:18:21:14 +0800]
> [Job 31] STATE: -output-area-full-warning D [25/Nov/2010:18:21:14 +0800]
> [Job 31] lpd_command 02 binary_p1 D [25/Nov/2010:18:21:14 +0800] [Job 31]
> Sending command string (11 bytes)... D [25/Nov/2010:18:21:14 +0800] [Job
> 31] Reading command status... D [25/Nov/2010:18:21:14 +0800] [Job 31]
> lpd_command returning 0 D [25/Nov/2010:18:21:14 +0800] [Job 31] Control
> file is: D [25/Nov/2010:18:21:14 +0800] [Job 31] Hlocalhost.localdomain
> D [25/Nov/2010:18:21:14 +0800] [Job 31] Proot
> D [25/Nov/2010:18:21:14 +0800] [Job 31] Jsmbprn_00000022 test_txt _
> _________ D [25/Nov/2010:18:21:14 +0800] [Job 31] ldfA385localhost.local
> D [25/Nov/2010:18:21:14 +0800] [Job 31] UdfA385localhost.local
> D [25/Nov/2010:18:21:14 +0800] [Job 31] Nsmbprn_00000022 test_txt _
> _________ D [25/Nov/2010:18:21:14 +0800] [Job 31] lpd_command 02 151
> cfA385localhost.local D [25/Nov/2010:18:21:14 +0800] [Job 31] Sending
> command string (27 bytes)... D [25/Nov/2010:18:21:14 +0800] [Job 31]
> Reading command status... D [25/Nov/2010:18:21:14 +0800] [Job 31]
> lpd_command returning 0 I [25/Nov/2010:18:21:14 +0800] [Job 31] Sending
> control file (151 bytes) D [25/Nov/2010:18:21:14 +0800] Discarding unused
> printer-state-changed event... D [25/Nov/2010:18:21:14 +0800] Discarding
> unused job-progress event... I [25/Nov/2010:18:21:14 +0800] [Job 31]
> Control file sent successfully D [25/Nov/2010:18:21:14 +0800] [Job 31]
> lpd_command 03 0 dfA385localhost.local D [25/Nov/2010:18:21:14 +0800] [Job
> 31] Sending command string (25 bytes)... D [25/Nov/2010:18:21:14 +0800]
> [Job 31] Reading command status... D [25/Nov/2010:18:21:14 +0800]
> Discarding unused printer-state-changed event... D [25/Nov/2010:18:21:14
> +0800] Discarding unused job-progress event... D [25/Nov/2010:18:21:14
> +0800] [Job 31] lpd_command returning 0 I [25/Nov/2010:18:21:14 +0800]
> [Job 31] Sending data file (0 bytes) D [25/Nov/2010:18:21:14 +0800]
> Discarding unused printer-state-changed event... D [25/Nov/2010:18:21:14
> +0800] Discarding unused job-progress event... I [25/Nov/2010:18:21:41
> +0800] Saving printers.conf... I [25/Nov/2010:18:21:41 +0800] Saving job
> cache file "/var/cache/cups/job.cache"...
> D [25/Nov/2010:18:21:41 +0800] cupsdSetBusyState: Printing jobs
> 
> 
> It seems filters of pstops and brlpdwrapperhl4040cdn are no error, I
> don't know why it parse to "No Pages found" error message and then
> "Sending data file (0 bytes)".
> 
> Anyone have idea about this?
> 
> Thanks,
> Pigsign

I suspect one of the filters used is the culprit:
brlpdwrapperhl4040cdn
I suspect the debug-message
D [25/Nov/2010:18:21:13 +0800] [Job 31] Error: error occurred at print phase 
!!
comes from that filter.

I'd recommend to get the original brother PPD from:
http://www.openprinting.org/ppd-o-matic.php?driver=Postscript-
Brother&printer=Brother-HL-4050CDN&show=1
and use that.

Helge