CUPS print queue stalls on serial printer - startfixes - permanent solution ?

Wed May 17 04:16:02 PDT 2006

> This is a multi-part message in MIME format.
> --------------070207070308080103090101
> Content-Type: text/plain; charset=ISO-8859-1; format=flowed
> Content-Transfer-Encoding: 7bit
>
> Hi,
>
> I've been using cups on an FC3 server for some time with versions:
> cups-1.1.22-0.rc1.8.9
> cups-devel-1.1.22-0.rc1.8.9
> cups-libs-1.1.22-0.rc1.8.9
> hal-cups-utils-0.5.2-8
> libgnomecups-0.1.12-5
>
> For one print queue, queue-barcode, a d-link print server (2 Parallel
> and 1 serial port) receives the print jobs (from a winXP client machine
> via samba) and prints to a serial port connected barcode thermal printer.
>
> Each print job is actually two pages long (of the label size). While
> other peoples machines may happily print a list of say 5-pairs of
> labels, the person who uses it most will find that only the first page
> of the first job gets printed.
>
> The manual workaround is to access cups web service, go to the queue in
> question, and click Start Printer. This allows the last page in the
> first job to print, and the first of the second job, but it then
> printing stalls again. Refresh the queue info page, and I'll see that
> the printer is again stopped. This is starting to get a bit boring...
>
> Attached is the /var/log/cups/error_log
> No particular error seems to be noted...
>
> Any ideas ?
>
> DaveT.
>
>
> --------------070207070308080103090101
> Content-Type: text/plain;
>  name="cups.error-barcode.txt"
> Content-Transfer-Encoding: 7bit
> Content-Disposition: inline;
>  filename="cups.error-barcode.txt"
>
> D [03/May/2006:14:00:04 +1000] AcceptClient: 7 from localhost:631.
> D [03/May/2006:14:00:04 +1000] ReadClient: 7 POST / HTTP/1.1
> D [03/May/2006:14:00:04 +1000] ProcessIPPRequest: 7 status_code=0
> D [03/May/2006:14:00:04 +1000] ReadClient: 7 POST / HTTP/1.1
> D [03/May/2006:14:00:04 +1000] ProcessIPPRequest: 7 status_code=0
> D [03/May/2006:14:00:04 +1000] CloseClient: 7
> D [04/May/2006:14:00:04 +1000] AcceptClient: 7 from localhost:631.
> D [04/May/2006:14:00:04 +1000] ReadClient: 7 POST / HTTP/1.1
> D [04/May/2006:14:00:04 +1000] ProcessIPPRequest: 7 status_code=0
> D [04/May/2006:14:00:04 +1000] ReadClient: 7 POST / HTTP/1.1
> D [04/May/2006:14:00:04 +1000] ProcessIPPRequest: 7 status_code=0
> D [04/May/2006:14:00:04 +1000] AcceptClient: 9 from localhost:631.
> D [04/May/2006:14:00:04 +1000] ReadClient: 9 POST /printers/q-stores-barcode HTTP/1.1
> D [04/May/2006:14:00:04 +1000] print_job: auto-typing file...
> D [04/May/2006:14:00:04 +1000] print_job: request file type is text/plain.
> D [04/May/2006:14:00:04 +1000] CancelJob: id = 3781
> D [04/May/2006:14:00:04 +1000] check_quotas: requesting-user-name = 'robd'
> D [04/May/2006:14:00:04 +1000] print_job: requesting-user-name = 'robd'
> D [04/May/2006:14:00:04 +1000] Adding default job-sheets values "none,none"...
> I [04/May/2006:14:00:04 +1000] Adding start banner page "none" to job 4281.
> I [04/May/2006:14:00:04 +1000] Adding end banner page "none" to job 4281.
> I [04/May/2006:14:00:04 +1000] Job 4281 queued on 'q-stores-barcode' by 'robd'.
> D [04/May/2006:14:00:04 +1000] Job 4281 hold_until = 0
> D [04/May/2006:14:00:04 +1000] StartJob(4281, 0x834aee0)
> D [04/May/2006:14:00:04 +1000] StartJob() id = 4281, file = 0/1
> D [04/May/2006:14:00:04 +1000] StartJob: Sending job to queue tagged as raw...
> D [04/May/2006:14:00:04 +1000] job-sheets=none,none
> D [04/May/2006:14:00:04 +1000] banner_page = 0
> D [04/May/2006:14:00:04 +1000] StartJob: argv = "q-stores-barcode","4281","robd","smbprn.00000941 ","1","","/var/spool/cups/d04281-001"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[2]="USER=root"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[3]="CHARSET=utf-8"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[4]="LANG=en_AU"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[5]="PPD=/etc/cups/ppd/q-stores-barcode.ppd"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[7]="RIP_MAX_CACHE=8m"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[9]="CONTENT_TYPE=text/plain"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[10]="DEVICE_URI=lpd://192.168.2.250/com"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[11]="PRINTER=q-stores-barcode"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[14]="CUPS_SERVER=localhost"
> D [04/May/2006:14:00:04 +1000] StartJob: envp[15]="IPP_PORT=631"
> D [04/May/2006:14:00:04 +1000] StartJob: statusfds = [ 10 11 ]
> D [04/May/2006:14:00:04 +1000] StartJob: filterfds[1] = [ 12 -1 ]
> D [04/May/2006:14:00:04 +1000] StartJob: backend = "/usr/lib/cups/backend/lpd"
> D [04/May/2006:14:00:04 +1000] StartJob: filterfds[0] = [ -1 13 ]
> D [04/May/2006:14:00:04 +1000] start_process("/usr/lib/cups/backend/lpd", 0xbf915380, 0xbf9146f0, 12, 13, 11)
> I [04/May/2006:14:00:04 +1000] Started backend /usr/lib/cups/backend/lpd (PID 3351) for job 4281.
> D [04/May/2006:14:00:04 +1000] ProcessIPPRequest: 9 status_code=0
> D [04/May/2006:14:00:04 +1000] CloseClient: 9
> D [04/May/2006:14:00:04 +1000] [Job 4281] Connected on ports 515 (local 1022)...
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command 02 com
> D [04/May/2006:14:00:04 +1000] [Job 4281] Sending command string (5 bytes)...
> D [04/May/2006:14:00:04 +1000] [Job 4281] Reading command status...
> D [04/May/2006:14:00:04 +1000] CloseClient: 7
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command returning 0
> D [04/May/2006:14:00:04 +1000] [Job 4281] Control file is:
> D [04/May/2006:14:00:04 +1000] [Job 4281] Hserver1
> D [04/May/2006:14:00:04 +1000] [Job 4281] Probd
> D [04/May/2006:14:00:04 +1000] [Job 4281] Jsmbprn_00000941
> D [04/May/2006:14:00:04 +1000] [Job 4281] ldfA351server1
> D [04/May/2006:14:00:04 +1000] [Job 4281] UdfA351server1
> D [04/May/2006:14:00:04 +1000] [Job 4281] Nsmbprn_00000941
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command 02 81 cfA351server1
> D [04/May/2006:14:00:04 +1000] [Job 4281] Sending command string (18 bytes)...
> D [04/May/2006:14:00:04 +1000] [Job 4281] Reading command status...
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command returning 0
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command 03 1878 dfA351server1
> D [04/May/2006:14:00:04 +1000] [Job 4281] Sending command string (20 bytes)...
> D [04/May/2006:14:00:04 +1000] [Job 4281] Reading command status...
> D [04/May/2006:14:00:04 +1000] [Job 4281] lpd_command returning 0
> D [04/May/2006:14:00:04 +1000] UpdateJob: job 4281, file 0 is complete.
> D [04/May/2006:14:00:04 +1000] CancelJob: id = 4281
> D [04/May/2006:14:00:04 +1000] StopJob: id = 4281, force = 0
> D [04/May/2006:14:00:04 +1000] StopJob: printer state is 3
>
>
> --------------070207070308080103090101--
>
I have identical problem either the same or other print server. Sometimes it will run through 50-60 prints then halts and printer has to be re enabled. Halts on printer state 1 or 3. I still have not been able to resolve this issue have you?