slow raw queue with inkjet

Fri Nov 3 00:20:35 PST 2006

Hello All,

I have a CUPS 1.2.5 running on Slackware 10.1 box and acting like a raw 
printer spooler for wins and macs. All printers are on network, connected 
through jetdirects and similar hardware. Some printers are LaserJets (use 
pap or lpd backends) and there is no problems (slowdowns) with them.
But I have one Epson SP R220 (inkjet) and it is very slow from CUPS raw 
queue. Printhead takes 1-2 seconds pause after every printed row. I have 
tried lpd and socket backends, no improvements. I can not see anything in 
log (log is attached below).
There is no slowdown when printing from wins directly to printer's IP. Also 
no slowdowns when printing through CUPS & ghostscript driven queue.

Any ideas?

Regards,
bebris

error_log:
I [02/Nov/2006:20:22:17 +0200] Listening to 127.0.0.1:631 (IPv4)
I [02/Nov/2006:20:22:17 +0200] Listening to 192.168.0.13:631 (IPv4)
I [02/Nov/2006:20:22:17 +0200] Listening to /var/run/cups/cups.sock (Domain)
I [02/Nov/2006:20:22:17 +0200] Loaded configuration file 
"/etc/cups/cupsd.conf"
I [02/Nov/2006:20:22:17 +0200] Using default TempDir of 
/var/spool/cups/tmp...
I [02/Nov/2006:20:22:17 +0200] Cleaning out old temporary files in 
"/var/spool/cups/tmp"...
I [02/Nov/2006:20:22:17 +0200] Configured for up to 100 clients.
I [02/Nov/2006:20:22:17 +0200] Allowing up to 100 client connections per 
host.
I [02/Nov/2006:20:22:17 +0200] Using policy "default" as the default!
I [02/Nov/2006:20:22:17 +0200] Full reload is required.
I [02/Nov/2006:20:22:17 +0200] Loaded MIME database from '/etc/cups': 34 
types, 39 filters...
D [02/Nov/2006:20:22:17 +0200] Loading printer HP1300-ps...
D [02/Nov/2006:20:22:17 +0200] Loading printer HP1300-raw...
D [02/Nov/2006:20:22:17 +0200] Loading printer HP4100-ps...
D [02/Nov/2006:20:22:17 +0200] Loading printer HP4100-raw...
D [02/Nov/2006:20:22:17 +0200] Loading printer R220-ps...
D [02/Nov/2006:20:22:17 +0200] Loading printer R220-raw...
I [02/Nov/2006:20:22:17 +0200] Loading job cache file 
"/var/cache/cups/job.cache"...
D [02/Nov/2006:20:22:17 +0200] Loading job 38588 from cache...
.....
D [02/Nov/2006:20:22:17 +0200] Loading job 39086 from cache...
D [02/Nov/2006:20:22:17 +0200] Loading job 39087 from cache...
D [02/Nov/2006:20:22:17 +0200] Loading attributes for job 38588...
D [02/Nov/2006:20:22:17 +0200] Discarding unused job-completed event...
I [02/Nov/2006:20:22:17 +0200] Full reload complete.
I [02/Nov/2006:20:22:17 +0200] Listening to 127.0.0.1:631 on fd 0...
I [02/Nov/2006:20:22:17 +0200] Listening to 192.168.0.13:631 on fd 2...
I [02/Nov/2006:20:22:17 +0200] Listening to /var/run/cups/cups.sock on fd 
3...
D [02/Nov/2006:20:22:30 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:22:30 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:22:30 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:22:30 +0200] Get-Jobs ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:22:30 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:22:30 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:22:30 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:22:30 +0200] Get-Printer-Attributes 
ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:22:30 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:22:30 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:23:02 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:23:02 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:23:02 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:23:02 +0200] Get-Jobs ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:23:02 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:23:02 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:23:02 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:23:02 +0200] Get-Printer-Attributes 
ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:23:02 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:23:02 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:23:22 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:23:22 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:23:22 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:23:22 +0200] Get-Jobs ipp://localhost/printers/HP4100-raw
D [02/Nov/2006:20:23:22 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:23:22 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:23:22 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:23:22 +0200] Get-Printer-Attributes 
ipp://localhost/printers/HP4100-raw
D [02/Nov/2006:20:23:22 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:23:22 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:23:29 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:23:29 +0200] cupsdReadClient: 6 POST /printers/R220-raw 
HTTP/1.1
D [02/Nov/2006:20:23:29 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:23:29 +0200] Print-Job ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:23:29 +0200] print_job: auto-typing file...
D [02/Nov/2006:20:23:29 +0200] print_job: request file type is 
application/octet-stream.
D [02/Nov/2006:20:23:29 +0200] add_job: requesting-user-name="repro"
D [02/Nov/2006:20:23:29 +0200] Adding default job-sheets values 
"none,none"...
I [02/Nov/2006:20:23:29 +0200] Adding start banner page "none" to job 39088.
D [02/Nov/2006:20:23:29 +0200] Discarding unused job-created event...
I [02/Nov/2006:20:23:29 +0200] Adding end banner page "none" to job 39088.
I [02/Nov/2006:20:23:29 +0200] Job 39088 queued on "R220-raw" by "repro".
D [02/Nov/2006:20:23:29 +0200] Job 39088 hold_until = 0
D [02/Nov/2006:20:23:29 +0200] [Job 39088] Sending job to queue tagged as 
raw...
D [02/Nov/2006:20:23:29 +0200] Discarding unused printer-state-changed 
event...
D [02/Nov/2006:20:23:29 +0200] job-sheets=none,none
D [02/Nov/2006:20:23:29 +0200] banner_page = 0
D [02/Nov/2006:20:23:29 +0200] [Job 39088] argv[0]="R220-raw"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] argv[1]="39088"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] argv[2]="repro"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] argv[3]="smbprn.00000041 
PMS-Kalendrisi-3Gab.pdf"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] argv[4]="1"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
argv[5]="job-uuid=urn:uuid:ec745479-b263-34f6-5a34-932d8c62a949"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
argv[6]="/var/spool/cups/d39088-001"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[1]="CUPS_DATADIR=/usr/share/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[2]="CUPS_DOCROOT=/usr/share/doc/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[6]="CUPS_SERVERROOT=/etc/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[7]="CUPS_STATEDIR=/var/run/cups"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[9]="SERVER_ADMIN=root at linuz.jt.lv"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[10]="SOFTWARE=CUPS/1.2.5"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[11]="TMPDIR=/var/spool/cups/tmp"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[12]="USER=root"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[14]="CUPS_ENCRYPTION=IfRequested"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[15]="IPP_PORT=631"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[16]="CHARSET=utf-8"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[17]="LANG=en_US"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[18]="PPD=/etc/cups/ppd/R220-raw.ppd"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[19]="RIP_MAX_CACHE=8m"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[20]="CONTENT_TYPE=application/octet-stream"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] 
envp[21]="DEVICE_URI=lpd://192.168.0.40/lpt1"
D [02/Nov/2006:20:23:29 +0200] [Job 39088] envp[22]="PRINTER=R220-raw"
I [02/Nov/2006:20:23:29 +0200] Started backend /usr/lib/cups/backend/lpd 
(PID 18783) for job 39088.
D [02/Nov/2006:20:23:29 +0200] Discarding unused job-state event...
D [02/Nov/2006:20:23:29 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:23:29 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:23:29 +0200] Discarding unused printer-state-changed 
event...
D [02/Nov/2006:20:23:29 +0200] Discarding unused printer-state-changed 
event...
D [02/Nov/2006:20:23:29 +0200] [Job 39088] Connected on ports 515 (local 
1023)...
D [02/Nov/2006:20:23:29 +0200] [Job 39088] lpd_command 02 lpt1
D [02/Nov/2006:20:23:29 +0200] [Job 39088] Sending command string (6 
bytes)...
D [02/Nov/2006:20:23:29 +0200] [Job 39088] Reading command status...
D [02/Nov/2006:20:23:30 +0200] [Job 39088] lpd_command returning 0
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Control file is:
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Hlinuz.jt.lv
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Prepro
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Jsmbprn_00000041 
PMS_Kalendrisi_3Gab_pdf
D [02/Nov/2006:20:23:30 +0200] [Job 39088] ldfA783linuz.jt.lv
D [02/Nov/2006:20:23:30 +0200] [Job 39088] UdfA783linuz.jt.lv
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Nsmbprn_00000041 
PMS_Kalendrisi_3Gab_pdf
D [02/Nov/2006:20:23:30 +0200] [Job 39088] lpd_command 02 140 
cfA783linuz.jt.lv
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Sending command string (23 
bytes)...
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Reading command status...
D [02/Nov/2006:20:23:30 +0200] [Job 39088] lpd_command returning 0
D [02/Nov/2006:20:23:30 +0200] [Job 39088] lpd_command 03 7862509 
dfA783linuz.jt.lv
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Sending command string (27 
bytes)...
D [02/Nov/2006:20:23:30 +0200] [Job 39088] Reading command status...
D [02/Nov/2006:20:23:30 +0200] [Job 39088] lpd_command returning 0
D [02/Nov/2006:20:24:31 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:24:31 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:24:31 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:24:31 +0200] Get-Jobs ipp://localhost/printers/HP1300-raw
D [02/Nov/2006:20:24:31 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:24:31 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:24:31 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:24:31 +0200] Get-Printer-Attributes 
ipp://localhost/printers/HP1300-raw
D [02/Nov/2006:20:24:31 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:24:31 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:24:31 +0200] cupsdAcceptClient: 6 from localhost (Domain)
D [02/Nov/2006:20:24:31 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:24:31 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:24:31 +0200] Get-Jobs ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:24:31 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:24:31 +0200] cupsdReadClient: 6 POST / HTTP/1.1
D [02/Nov/2006:20:24:31 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:24:31 +0200] Get-Printer-Attributes 
ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:24:31 +0200] cupsdProcessIPPRequest: 6 status_code=0 
(successful-ok)
D [02/Nov/2006:20:24:31 +0200] cupsdCloseClient: 6
D [02/Nov/2006:20:26:27 +0200] Discarding unused job-progress event...
D [02/Nov/2006:20:26:27 +0200] PID 18783 (/usr/lib/cups/backend/lpd) exited 
with no errors.
D [02/Nov/2006:20:26:27 +0200] [Job 39088] File 0 is complete.
D [02/Nov/2006:20:26:27 +0200] Discarding unused printer-state-changed 
event...
D [02/Nov/2006:20:26:27 +0200] Discarding unused job-completed event...
D [02/Nov/2006:20:26:27 +0200] cupsdAcceptClient: 8 from localhost (Domain)
D [02/Nov/2006:20:26:27 +0200] cupsdReadClient: 8 POST / HTTP/1.1
D [02/Nov/2006:20:26:27 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:26:27 +0200] Get-Jobs ipp://localhost/printers/HP4100-raw
D [02/Nov/2006:20:26:27 +0200] cupsdProcessIPPRequest: 8 status_code=0 
(successful-ok)
D [02/Nov/2006:20:26:27 +0200] cupsdReadClient: 8 POST / HTTP/1.1
D [02/Nov/2006:20:26:27 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:26:27 +0200] Get-Printer-Attributes 
ipp://localhost/printers/HP4100-raw
D [02/Nov/2006:20:26:27 +0200] cupsdProcessIPPRequest: 8 status_code=0 
(successful-ok)
D [02/Nov/2006:20:26:27 +0200] cupsdCloseClient: 8
D [02/Nov/2006:20:26:27 +0200] cupsdAcceptClient: 8 from localhost (Domain)
D [02/Nov/2006:20:26:27 +0200] cupsdReadClient: 8 POST / HTTP/1.1
D [02/Nov/2006:20:26:27 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:26:27 +0200] Get-Jobs ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:26:27 +0200] cupsdProcessIPPRequest: 8 status_code=0 
(successful-ok)
D [02/Nov/2006:20:26:27 +0200] cupsdReadClient: 8 POST / HTTP/1.1
D [02/Nov/2006:20:26:27 +0200] cupsdAuthorize: No authentication data 
provided.
D [02/Nov/2006:20:26:27 +0200] Get-Printer-Attributes 
ipp://localhost/printers/R220-raw
D [02/Nov/2006:20:26:27 +0200] cupsdProcessIPPRequest: 8 status_code=0 
(successful-ok)
D [02/Nov/2006:20:26:27 +0200] cupsdCloseClient: 8
D [02/Nov/2006:20:26:28 +0200] Unloading job 39088...