Discussion:
Jobs going to Stopped - Cups Restart the Only Resort
Anurag
2010-11-04 03:01:57 UTC
Permalink
Dear Cups Team,

We are facing a problem whereby the label printer stops printing when multiple print requests are received in a short span of time.

In my tests, i sent around 80 Labels to print to the printer within a span of 20 seconds. This volume is pretty low for the Warehouse Operations and it is important that the printing works without any problems in such a scenario. Any help in this regard would be highly appreciated.

In my tests, the job number 7357 was the one that got stuck. All other jobs following the job 7357 went to pending status.

After waiting on job 7357, the printer finally decided to Stop the job and the job went to Stopped status. At this stage, the printer status is shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the remaining labels is to restart the printer again.

I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7

Here are some of the lines from the error_log that are relevant to job 7357, It seems to have failed exactly after 5 minutes of job submission.

I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page "none".
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type text/plain.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by "lgfadm".
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost (Domain)
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515 (IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18 bytes)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond with command status byte after 300 seconds!
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd) stopped with status 1!
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1 (failed)
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196


The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 - localhost

The printer is using lpd as indicated below and also shown are the printer options
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1

[***@L573P] /home/lgfadm :\>lpoptions -pconcepcion_115
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info='Concepcion 115' printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion printer-make-and-model='Local Raw Printer' printer-state=5 printer-state-change-time=1288836721 printer-state-reasons=paused printer-type=4

Please guide.

Regards,
Anurag
Michael Sweet
2010-11-04 03:58:58 UTC
Permalink
LPD is not a reliable protocol. If the printer in question supports IPP or socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when multiple print requests are received in a short span of time.
In my tests, i sent around 80 Labels to print to the printer within a span of 20 seconds. This volume is pretty low for the Warehouse Operations and it is important that the printing works without any problems in such a scenario. Any help in this regard would be highly appreciated.
In my tests, the job number 7357 was the one that got stuck. All other jobs following the job 7357 went to pending status.
After waiting on job 7357, the printer finally decided to Stop the job and the job went to Stopped status. At this stage, the printer status is shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the remaining labels is to restart the printer again.
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job 7357, It seems to have failed exactly after 5 minutes of job submission.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page "none".
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type text/plain.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by "lgfadm".
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost (Domain)
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515 (IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18 bytes)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond with command status byte after 300 seconds!
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd) stopped with status 1!
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1 (failed)
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 - localhost
The printer is using lpd as indicated below and also shown are the printer options
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info='Concepcion 115' printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion printer-make-and-model='Local Raw Printer' printer-state=5 printer-state-change-time=1288836721 printer-state-reasons=paused printer-type=4
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
Anurag Chourasia
2010-11-04 04:09:21 UTC
Permalink
Hi Mike,

This is a Zebra printer. Zebra earlier indicated that IPP is not supported.

Earlier we tried to use Socket but ran into even more serious issues. With
Socket Protocol, out of every 10 label requests submitted all the jobs go
to successful status but only 1 or 2 labels actually used to come out of the
printer.

Is there anything else we could try to make lpd behave better in this
scenario? Please guide.

Regards,
Anurag
Post by Michael Sweet
LPD is not a reliable protocol. If the printer in question supports IPP or
socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when
multiple print requests are received in a short span of time.
Post by Anurag
In my tests, i sent around 80 Labels to print to the printer within a
span of 20 seconds. This volume is pretty low for the Warehouse Operations
and it is important that the printing works without any problems in such a
scenario. Any help in this regard would be highly appreciated.
Post by Anurag
In my tests, the job number 7357 was the one that got stuck. All other
jobs following the job 7357 went to pending status.
Post by Anurag
After waiting on job 7357, the printer finally decided to Stop the job
and the job went to Stopped status. At this stage, the printer status is
shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the
remaining labels is to restart the printer again.
Post by Anurag
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job
7357, It seems to have failed exactly after 5 minutes of job submission.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page
"none".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type
text/plain.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by
"lgfadm".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0
(successful-ok)
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost
(Domain)
Post by Anurag
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515(IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18
bytes)...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond
with command status byte after 300 seconds!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd)
stopped with status 1!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1
(failed)
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 -
localhost
Post by Anurag
The printer is using lpd as indicated below and also shown are the
printer options
Post by Anurag
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1
auth-info-required=none job-sheets=none,none printer-info='Concepcion 115'
printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion
printer-make-and-model='Local Raw Printer' printer-state=5
printer-state-change-time=1288836721 printer-state-reasons=paused
printer-type=4
Post by Anurag
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
Michael Sweet
2010-11-04 04:18:58 UTC
Permalink
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With Socket Protocol, out of every 10 label requests submitted all the jobs go to successful status but only 1 or 2 labels actually used to come out of the printer.
Is there anything else we could try to make lpd behave better in this scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is either not sending its response packet (that tells us the job was submitted successfully) or the packet is getting lost on the network and the printer isn't re-sending the packet when it doesn't get an ack from the CUPS system. If socket isn't working, my guess is either a problem with the printer's network interface or your network in general.

It would be useful for you to run Wireshark on the CUPS system to monitor the LPD traffic between the system and printer. You can also hook up a hardware network analyzer to see what kind of packet loss/error rate you have. (Many routers also provide this information...)
Post by Anurag Chourasia
Regards,
Anurag
LPD is not a reliable protocol. If the printer in question supports IPP or socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when multiple print requests are received in a short span of time.
In my tests, i sent around 80 Labels to print to the printer within a span of 20 seconds. This volume is pretty low for the Warehouse Operations and it is important that the printing works without any problems in such a scenario. Any help in this regard would be highly appreciated.
In my tests, the job number 7357 was the one that got stuck. All other jobs following the job 7357 went to pending status.
After waiting on job 7357, the printer finally decided to Stop the job and the job went to Stopped status. At this stage, the printer status is shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the remaining labels is to restart the printer again.
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job 7357, It seems to have failed exactly after 5 minutes of job submission.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page "none".
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type text/plain.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by "lgfadm".
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost (Domain)
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515 (IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18 bytes)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond with command status byte after 300 seconds!
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd) stopped with status 1!
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1 (failed)
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 - localhost
The printer is using lpd as indicated below and also shown are the printer options
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info='Concepcion 115' printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion printer-make-and-model='Local Raw Printer' printer-state=5 printer-state-change-time=1288836721 printer-state-reasons=paused printer-type=4
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
Anurag Chourasia
2010-11-04 05:33:24 UTC
Permalink
Hi Mike,

Thanks for the response.

There is a "ErrorPolicy" variable. Do you think I could use that to overcome
this situation? Basically asking the printer to retry the job instead of
stopping?

What is not clear to me is whether the printer will retry the job once or as
many times until the job succeeds?

http://www.cups.org/documentation.php/doc-1.4/ref-printers-conf.html has
more on this Variable.

Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With
Socket Protocol, out of every 10 label requests submitted all the jobs go
to successful status but only 1 or 2 labels actually used to come out of the
printer.
Is there anything else we could try to make lpd behave better in this
scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is either
not sending its response packet (that tells us the job was submitted
successfully) or the packet is getting lost on the network and the printer
isn't re-sending the packet when it doesn't get an ack from the CUPS system.
If socket isn't working, my guess is either a problem with the printer's
network interface or your network in general.
It would be useful for you to run Wireshark on the CUPS system to monitor
the LPD traffic between the system and printer. You can also hook up a
hardware network analyzer to see what kind of packet loss/error rate you
have. (Many routers also provide this information...)
Regards,
Anurag
Post by Michael Sweet
LPD is not a reliable protocol. If the printer in question supports IPP or
socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when
multiple print requests are received in a short span of time.
Post by Anurag
In my tests, i sent around 80 Labels to print to the printer within a
span of 20 seconds. This volume is pretty low for the Warehouse Operations
and it is important that the printing works without any problems in such a
scenario. Any help in this regard would be highly appreciated.
Post by Anurag
In my tests, the job number 7357 was the one that got stuck. All other
jobs following the job 7357 went to pending status.
Post by Anurag
After waiting on job 7357, the printer finally decided to Stop the job
and the job went to Stopped status. At this stage, the printer status is
shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the
remaining labels is to restart the printer again.
Post by Anurag
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job
7357, It seems to have failed exactly after 5 minutes of job submission.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page
"none".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type
text/plain.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by
"lgfadm".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0
(successful-ok)
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost
(Domain)
Post by Anurag
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515(IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02
lp-cd-esp-115-P1
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18
bytes)...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond
with command status byte after 300 seconds!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd)
stopped with status 1!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1
(failed)
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped
event...
Post by Anurag
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 -
localhost
Post by Anurag
The printer is using lpd as indicated below and also shown are the
printer options
Post by Anurag
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1
auth-info-required=none job-sheets=none,none printer-info='Concepcion 115'
printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion
printer-make-and-model='Local Raw Printer' printer-state=5
printer-state-change-time=1288836721 printer-state-reasons=paused
printer-type=4
Post by Anurag
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
Michael Sweet
2010-11-04 06:27:23 UTC
Permalink
Post by Anurag Chourasia
Hi Mike,
Thanks for the response.
There is a "ErrorPolicy" variable. Do you think I could use that to overcome this situation? Basically asking the printer to retry the job instead of stopping?
Yes, you can use the retry-job or retry-current-job (in recent versions of CUPS) to have the scheduler (cupsd) retry the job. Use the "lpadmin" command to set the printer-error-policy option ("lpadmin -p name -o printer-error-policy=retry-current-job").
Post by Anurag Chourasia
What is not clear to me is whether the printer will retry the job once or as many times until the job succeeds?
The limits are controlled by the JobRetryLimit and JobRetryInterval directives in cupsd.conf. The defaults are 5 and 30, respectively. Use the "cupsctl" command to change them ("cupsctl JobRetryLimit=999 JobRetryInterval=5").
Post by Anurag Chourasia
http://www.cups.org/documentation.php/doc-1.4/ref-printers-conf.html has more on this Variable.
Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With Socket Protocol, out of every 10 label requests submitted all the jobs go to successful status but only 1 or 2 labels actually used to come out of the printer.
Is there anything else we could try to make lpd behave better in this scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is either not sending its response packet (that tells us the job was submitted successfully) or the packet is getting lost on the network and the printer isn't re-sending the packet when it doesn't get an ack from the CUPS system. If socket isn't working, my guess is either a problem with the printer's network interface or your network in general.
It would be useful for you to run Wireshark on the CUPS system to monitor the LPD traffic between the system and printer. You can also hook up a hardware network analyzer to see what kind of packet loss/error rate you have. (Many routers also provide this information...)
Post by Anurag Chourasia
Regards,
Anurag
LPD is not a reliable protocol. If the printer in question supports IPP or socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when multiple print requests are received in a short span of time.
In my tests, i sent around 80 Labels to print to the printer within a span of 20 seconds. This volume is pretty low for the Warehouse Operations and it is important that the printing works without any problems in such a scenario. Any help in this regard would be highly appreciated.
In my tests, the job number 7357 was the one that got stuck. All other jobs following the job 7357 went to pending status.
After waiting on job 7357, the printer finally decided to Stop the job and the job went to Stopped status. At this stage, the printer status is shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the remaining labels is to restart the printer again.
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job 7357, It seems to have failed exactly after 5 minutes of job submission.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page "none".
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type text/plain.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by "lgfadm".
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost (Domain)
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515 (IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18 bytes)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond with command status byte after 300 seconds!
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd) stopped with status 1!
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1 (failed)
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 - localhost
The printer is using lpd as indicated below and also shown are the printer options
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info='Concepcion 115' printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion printer-make-and-model='Local Raw Printer' printer-state=5 printer-state-change-time=1288836721 printer-state-reasons=paused printer-type=4
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
Anurag Chourasia
2010-11-04 16:52:10 UTC
Permalink
Hi Mike,

When we use this command, the printer options are remaining the same as
before. Please see the transcript below. I ran the command but the error
policy is not appearing in the lpoptions output. Even the cupsd.conf remain
untouched. Are we missing something here?

[***@L573P] / :\>./usr/sbin/lpadmin -p SOCKET -o
printer-error-policy=retry-job

[***@L573P] / :\>lpoptions -p SOCKET
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1
auth-info-required=none job-sheets=none,none printer-info=Socket
printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Socket
printer-make-and-model='Local Raw Printer' printer-state=3
printer-state-change-time=1288886176 printer-state-reasons=none
printer-type=4

Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
Thanks for the response.
There is a "ErrorPolicy" variable. Do you think I could use that to
overcome this situation? Basically asking the printer to retry the job
instead of stopping?
Yes, you can use the retry-job or retry-current-job (in recent versions of
CUPS) to have the scheduler (cupsd) retry the job. Use the "lpadmin"
command to set the printer-error-policy option ("lpadmin -p name -o
printer-error-policy=retry-current-job").
What is not clear to me is whether the printer will retry the job once or
as many times until the job succeeds?
The limits are controlled by the JobRetryLimit and JobRetryInterval
directives in cupsd.conf. The defaults are 5 and 30, respectively. Use the
"cupsctl" command to change them ("cupsctl JobRetryLimit=999
JobRetryInterval=5").
http://www.cups.org/documentation.php/doc-1.4/ref-printers-conf.html has
more on this Variable.
Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With
Socket Protocol, out of every 10 label requests submitted all the jobs go
to successful status but only 1 or 2 labels actually used to come out of the
printer.
Is there anything else we could try to make lpd behave better in this
scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is
either not sending its response packet (that tells us the job was submitted
successfully) or the packet is getting lost on the network and the printer
isn't re-sending the packet when it doesn't get an ack from the CUPS system.
If socket isn't working, my guess is either a problem with the printer's
network interface or your network in general.
It would be useful for you to run Wireshark on the CUPS system to monitor
the LPD traffic between the system and printer. You can also hook up a
hardware network analyzer to see what kind of packet loss/error rate you
have. (Many routers also provide this information...)
Regards,
Anurag
Post by Michael Sweet
LPD is not a reliable protocol. If the printer in question supports IPP
or socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when
multiple print requests are received in a short span of time.
Post by Anurag
In my tests, i sent around 80 Labels to print to the printer within a
span of 20 seconds. This volume is pretty low for the Warehouse Operations
and it is important that the printing works without any problems in such a
scenario. Any help in this regard would be highly appreciated.
Post by Anurag
In my tests, the job number 7357 was the one that got stuck. All other
jobs following the job 7357 went to pending status.
Post by Anurag
After waiting on job 7357, the printer finally decided to Stop the job
and the job went to Stopped status. At this stage, the printer status is
shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the
remaining labels is to restart the printer again.
Post by Anurag
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job
7357, It seems to have failed exactly after 5 minutes of job submission.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page
"none".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type
text/plain.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page
"none".
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by
"lgfadm".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0
(successful-ok)
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost
(Domain)
Post by Anurag
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515(IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02
lp-cd-esp-115-P1
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18
bytes)...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond
with command status byte after 300 seconds!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd)
stopped with status 1!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1
(failed)
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped
event...
Post by Anurag
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 -
localhost
Post by Anurag
The printer is using lpd as indicated below and also shown are the
printer options
Post by Anurag
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50
number-up=1 auth-info-required=none job-sheets=none,none
printer-info='Concepcion 115' printer-is-accepting-jobs=1
printer-is-shared=1 printer-location=Concepcion
printer-make-and-model='Local Raw Printer' printer-state=5
printer-state-change-time=1288836721 printer-state-reasons=paused
printer-type=4
Post by Anurag
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
Michael Sweet
2010-11-04 19:37:12 UTC
Permalink
The lpoptions command does not show the current state of the printer-op-policy or printer-error-policy.

The cupsd.conf file does not contain the printer definitions - you want to look at printers.conf (however, keep in mind that cupsd will delay writing to printers.conf to minimize disk activity...)
Post by Anurag Chourasia
Hi Mike,
When we use this command, the printer options are remaining the same as before. Please see the transcript below. I ran the command but the error policy is not appearing in the lpoptions output. Even the cupsd.conf remain untouched. Are we missing something here?
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info=Socket printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Socket printer-make-and-model='Local Raw Printer' printer-state=3 printer-state-change-time=1288886176 printer-state-reasons=none printer-type=4
Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
Thanks for the response.
There is a "ErrorPolicy" variable. Do you think I could use that to overcome this situation? Basically asking the printer to retry the job instead of stopping?
Yes, you can use the retry-job or retry-current-job (in recent versions of CUPS) to have the scheduler (cupsd) retry the job. Use the "lpadmin" command to set the printer-error-policy option ("lpadmin -p name -o printer-error-policy=retry-current-job").
Post by Anurag Chourasia
What is not clear to me is whether the printer will retry the job once or as many times until the job succeeds?
The limits are controlled by the JobRetryLimit and JobRetryInterval directives in cupsd.conf. The defaults are 5 and 30, respectively. Use the "cupsctl" command to change them ("cupsctl JobRetryLimit=999 JobRetryInterval=5").
Post by Anurag Chourasia
http://www.cups.org/documentation.php/doc-1.4/ref-printers-conf.html has more on this Variable.
Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With Socket Protocol, out of every 10 label requests submitted all the jobs go to successful status but only 1 or 2 labels actually used to come out of the printer.
Is there anything else we could try to make lpd behave better in this scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is either not sending its response packet (that tells us the job was submitted successfully) or the packet is getting lost on the network and the printer isn't re-sending the packet when it doesn't get an ack from the CUPS system. If socket isn't working, my guess is either a problem with the printer's network interface or your network in general.
It would be useful for you to run Wireshark on the CUPS system to monitor the LPD traffic between the system and printer. You can also hook up a hardware network analyzer to see what kind of packet loss/error rate you have. (Many routers also provide this information...)
Post by Anurag Chourasia
Regards,
Anurag
LPD is not a reliable protocol. If the printer in question supports IPP or socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when multiple print requests are received in a short span of time.
In my tests, i sent around 80 Labels to print to the printer within a span of 20 seconds. This volume is pretty low for the Warehouse Operations and it is important that the printing works without any problems in such a scenario. Any help in this regard would be highly appreciated.
In my tests, the job number 7357 was the one that got stuck. All other jobs following the job 7357 went to pending status.
After waiting on job 7357, the printer finally decided to Stop the job and the job went to Stopped status. At this stage, the printer status is shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the remaining labels is to restart the printer again.
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job 7357, It seems to have failed exactly after 5 minutes of job submission.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page "none".
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type text/plain.
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by "lgfadm".
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost (Domain)
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515 (IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02 lp-cd-esp-115-P1
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18 bytes)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond with command status byte after 300 seconds!
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd) stopped with status 1!
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1 (failed)
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed event...
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped event...
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 - localhost
The printer is using lpd as indicated below and also shown are the printer options
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1 auth-info-required=none job-sheets=none,none printer-info='Concepcion 115' printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion printer-make-and-model='Local Raw Printer' printer-state=5 printer-state-change-time=1288836721 printer-state-reasons=paused printer-type=4
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
Anurag Chourasia
2010-11-04 18:34:59 UTC
Permalink
HI Mike,

We have tried using Socket Protocol again for printing but the problem
persists. Out of 100 Label print requests, only a few actually come out of
the printer while the others are shown as completed successfully but nothing
comes out of the printer.

I have also captured the logs using tcpdump for this scenario.

The log in http://paste.org/pastebin/view/22779 is when the print command
was sent to the printer but nothing came out of the printer (Even though the
JOB Was set to successful Status).

The log in http://paste.org/pastebin/view/22780 is when the print command
was sent to the printer and a label came out of the printer well printed.

The IP of the printer is 10.15.98.14

The IP of the machine from where the command was sent is 10.0.157.86

There is a small difference in the logs. The logs when the label came out of
the printer contains a line as below in the last communication between the
two IPs.

11:51:58.652644 IP 10.15.98.14.jetdirect > 10.0.157.86.54743: R
2064334032:2064334032(0) win 0

This seems to be the printer telling something back to the Linux Machine.
This communication is missing in the logs when the label did not come out of
the printer.

I am not sure how to interpret this. From another Linux machine in the
network, I am able to print successfully to this same physical printer using
socket protocol.

Any help would be highly appreciated.

Regards,
Anurag
Post by Anurag Chourasia
Hi Mike,
This is a Zebra printer. Zebra earlier indicated that IPP is not supported.
Earlier we tried to use Socket but ran into even more serious issues. With
Socket Protocol, out of every 10 label requests submitted all the jobs go
to successful status but only 1 or 2 labels actually used to come out of the
printer.
Is there anything else we could try to make lpd behave better in this
scenario? Please guide.
Unfortunately, the issue you are running into is that the printer is either
not sending its response packet (that tells us the job was submitted
successfully) or the packet is getting lost on the network and the printer
isn't re-sending the packet when it doesn't get an ack from the CUPS system.
If socket isn't working, my guess is either a problem with the printer's
network interface or your network in general.
It would be useful for you to run Wireshark on the CUPS system to monitor
the LPD traffic between the system and printer. You can also hook up a
hardware network analyzer to see what kind of packet loss/error rate you
have. (Many routers also provide this information...)
Regards,
Anurag
Post by Michael Sweet
LPD is not a reliable protocol. If the printer in question supports IPP or
socket printing, use that instead.
Post by Anurag
Dear Cups Team,
We are facing a problem whereby the label printer stops printing when
multiple print requests are received in a short span of time.
Post by Anurag
In my tests, i sent around 80 Labels to print to the printer within a
span of 20 seconds. This volume is pretty low for the Warehouse Operations
and it is important that the printing works without any problems in such a
scenario. Any help in this regard would be highly appreciated.
Post by Anurag
In my tests, the job number 7357 was the one that got stuck. All other
jobs following the job 7357 went to pending status.
Post by Anurag
After waiting on job 7357, the printer finally decided to Stop the job
and the job went to Stopped status. At this stage, the printer status is
shown as "/usr/lib/cups/backend/lpd Failed". The only way to print the
remaining labels is to restart the printer again.
Post by Anurag
I have uploaded the complete error_log at http://pastebin.com/2i7V7SZ7
Here are some of the lines from the error_log that are relevant to job
7357, It seems to have failed exactly after 5 minutes of job submission.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding start banner page
"none".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] Discarding unused job-created event...
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding job file of type
text/plain.
Post by Anurag
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Adding end banner page "none".
I [03/Nov/2010:23:06:58 -0300] [Job 7357] Queued on "concepcion_115" by
"lgfadm".
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] [Job 7357] hold_until = 0
D [03/Nov/2010:23:06:58 -0300] cupsdProcessIPPRequest: 13 status_code=0
(successful-ok)
Post by Anurag
D [03/Nov/2010:23:06:58 -0300] cupsdCloseClient: 13
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: skipping getpeercon()
D [03/Nov/2010:23:06:59 -0300] cupsdAcceptClient: 13 from localhost
(Domain)
Post by Anurag
D [03/Nov/2010:23:06:59 -0300] [Job 7352] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7353] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7354] Unloading...
D [03/Nov/2010:23:06:59 -0300] [Job 7355] Unloading...
D [03/Nov/2010:23:06:59 -0300] cupsdReadClient: 13 POST / HTTP/1.1
.
.
.
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Connected to 10.8.25.115:515(IPv4) (local port 994)...
D [03/Nov/2010:23:07:01 -0300] [Job 7357] lpd_command 02
lp-cd-esp-115-P1
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Sending command string (18
bytes)...
Post by Anurag
D [03/Nov/2010:23:07:01 -0300] [Job 7357] Reading command status...
.
.
.
W [03/Nov/2010:23:12:01 -0300] [Job 7357] Remote host did not respond
with command status byte after 300 seconds!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] lpd_command returning 4
E [03/Nov/2010:23:12:01 -0300] PID 19148 (/usr/lib/cups/backend/lpd)
stopped with status 1!
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] [Job 7357] File 0 is complete.
I [03/Nov/2010:23:12:01 -0300] [Job 7357] Backend returned status 1
(failed)
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-state-changed
event...
Post by Anurag
D [03/Nov/2010:23:12:01 -0300] Discarding unused printer-stopped
event...
Post by Anurag
I [03/Nov/2010:23:12:01 -0300] Saving printers.conf...
D [03/Nov/2010:23:12:01 -0300] Discarding unused job-stopped event...
D [03/Nov/2010:23:12:02 -0300] [Job 7357] Unloading...
D [03/Nov/2010:23:12:02 -0300] Report: clients=1
D [03/Nov/2010:23:12:02 -0300] Report: jobs=196
The last line in page_log is as follows
concepcion_115 lgfadm 7357 [03/Nov/2010:23:07:01 -0300] 1 1 -
localhost
Post by Anurag
The printer is using lpd as indicated below and also shown are the
printer options
Post by Anurag
device for concepcion_115: lpd://10.8.25.115/lp-cd-esp-115-P1
finishings=3 copies=1 job-hold-until=no-hold job-priority=50 number-up=1
auth-info-required=none job-sheets=none,none printer-info='Concepcion 115'
printer-is-accepting-jobs=1 printer-is-shared=1 printer-location=Concepcion
printer-make-and-model='Local Raw Printer' printer-state=5
printer-state-change-time=1288836721 printer-state-reasons=paused
printer-type=4
Post by Anurag
Please guide.
Regards,
Anurag
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
Michael Sweet
2010-11-04 20:25:13 UTC
Permalink
Post by Anurag Chourasia
HI Mike,
We have tried using Socket Protocol again for printing but the problem persists. Out of 100 Label print requests, only a few actually come out of the printer while the others are shown as completed successfully but nothing comes out of the printer.
I have also captured the logs using tcpdump for this scenario.
The log in http://paste.org/pastebin/view/22779 is when the print command was sent to the printer but nothing came out of the printer (Even though the JOB Was set to successful Status).
The log in http://paste.org/pastebin/view/22780 is when the print command was sent to the printer and a label came out of the printer well printed.
The IP of the printer is 10.15.98.14
The IP of the machine from where the command was sent is 10.0.157.86
Do the printer and machine have the same netmask defined?

How about the default router?
Post by Anurag Chourasia
...
I am not sure how to interpret this. From another Linux machine in the network, I am able to print successfully to this same physical printer using socket protocol.
Is the other machine on the same network segment as the non-working one?

My suspicion is that you either have a configuration problem or have a bad network card, port, or cable causing the one machine not to work with this printer.

________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
Anurag Chourasia
2010-11-04 20:47:34 UTC
Permalink
Hi Mike,

Both the printer and the machines have the same subnet mask i.e.
255.255.255.0

Please note that both the working and non-working machine are on same
network.

However, I have seen this problem with two physical printers now. Printer
model is Zebra ZM400 and both are using D-Link Network Server.

Is there anything else I could try to get to the bottom of this issue?

Regards,
Anurag
Post by Anurag Chourasia
HI Mike,
We have tried using Socket Protocol again for printing but the problem
persists. Out of 100 Label print requests, only a few actually come out of
the printer while the others are shown as completed successfully but nothing
comes out of the printer.
I have also captured the logs using tcpdump for this scenario.
The log in http://paste.org/pastebin/view/22779 is when the print command
was sent to the printer but nothing came out of the printer (Even though the
JOB Was set to successful Status).
The log in http://paste.org/pastebin/view/22780 is when the print command
was sent to the printer and a label came out of the printer well printed.
The IP of the printer is 10.15.98.14
The IP of the machine from where the command was sent is 10.0.157.86
Do the printer and machine have the same netmask defined?
How about the default router?
...
I am not sure how to interpret this. From another Linux machine in the
network, I am able to print successfully to this same physical printer using
socket protocol.
Is the other machine on the same network segment as the non-working one?
My suspicion is that you either have a configuration problem or have a bad
network card, port, or cable causing the one machine not to work with this
printer.
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
Michael Sweet
2010-11-04 21:00:42 UTC
Permalink
Post by Anurag Chourasia
Hi Mike,
Both the printer and the machines have the same subnet mask i.e. 255.255.255.0
Please note that both the working and non-working machine are on same network.
However, I have seen this problem with two physical printers now. Printer model is Zebra ZM400 and both are using D-Link Network Server.
I don't have a whole lot of personal experience with D-Link servers, but since it works from one machine and not another I think we can rule out the printers and print servers. Look at the machines and how they connect to the network (cable, card, port on the switch, etc.)
Post by Anurag Chourasia
Is there anything else I could try to get to the bottom of this issue?
Network analyzers are your best bet; you can also look at port logs (if you have a "smart" switch that provides you with this information).

I'd also try swapping the working and non-working systems - move them as needed and connect the non-working machine to the working machine's cables and visa-versa.

Verify that both systems have the exact same software installed. If the machines are identical (same make/model/configuration of hardware) they should yield identical results over the same network cable and port on the switch you connect to.
Post by Anurag Chourasia
Regards,
Anurag
Post by Anurag Chourasia
HI Mike,
We have tried using Socket Protocol again for printing but the problem persists. Out of 100 Label print requests, only a few actually come out of the printer while the others are shown as completed successfully but nothing comes out of the printer.
I have also captured the logs using tcpdump for this scenario.
The log in http://paste.org/pastebin/view/22779 is when the print command was sent to the printer but nothing came out of the printer (Even though the JOB Was set to successful Status).
The log in http://paste.org/pastebin/view/22780 is when the print command was sent to the printer and a label came out of the printer well printed.
The IP of the printer is 10.15.98.14
The IP of the machine from where the command was sent is 10.0.157.86
Do the printer and machine have the same netmask defined?
How about the default router?
Post by Anurag Chourasia
...
I am not sure how to interpret this. From another Linux machine in the network, I am able to print successfully to this same physical printer using socket protocol.
Is the other machine on the same network segment as the non-working one?
My suspicion is that you either have a configuration problem or have a bad network card, port, or cable causing the one machine not to work with this printer.
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
________________________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair
gene heskett
2010-11-04 21:16:56 UTC
Permalink
Post by Anurag Chourasia
Hi Mike,
Both the printer and the machines have the same subnet mask i.e.
255.255.255.0
If you have the devices on different 10.xx.subnets, AIUI, you are forcing
the first 3 triplets to match. I may be wrong, but that raises flags to me
as historically, the 255.255.255.0 has always indicated that miss-matches
in the first 3 triplets are a full miss, and to be ignored.
Post by Anurag Chourasia
From the addresses quoted below that would be 255.0.0.0, which would open
up a security hole.

Or is my ancient wet ram in error? Heck, I don't even know which man page
would be authoritative.
Post by Anurag Chourasia
Please note that both the working and non-working machine are on same
network.
I assume you are referring to the same switch when you say network.
Post by Anurag Chourasia
However, I have seen this problem with two physical printers now.
Printer model is Zebra ZM400 and both are using D-Link Network Server.
Is there anything else I could try to get to the bottom of this issue?
Regards,
Anurag
Post by Anurag Chourasia
HI Mike,
We have tried using Socket Protocol again for printing but the problem
persists. Out of 100 Label print requests, only a few actually come
out of the printer while the others are shown as completed
successfully but nothing comes out of the printer.
I have also captured the logs using tcpdump for this scenario.
The log in http://paste.org/pastebin/view/22779 is when the print
command was sent to the printer but nothing came out of the printer
(Even though the JOB Was set to successful Status).
The log in http://paste.org/pastebin/view/22780 is when the print
command was sent to the printer and a label came out of the printer
well printed.
The IP of the printer is 10.15.98.14
The IP of the machine from where the command was sent is 10.0.157.86
Do the printer and machine have the same netmask defined?
How about the default router?
...
I am not sure how to interpret this. From another Linux machine in the
network, I am able to print successfully to this same physical printer
using socket protocol.
Is the other machine on the same network segment as the non-working one?
My suspicion is that you either have a configuration problem or have a
bad network card, port, or cable causing the one machine not to work
with this printer.
_____________________________________________________________________
___
Michael Sweet, Senior Printing System Engineer, PWG Chair
_______________________________________________
cups mailing list
http://lists.easysw.com/mailman/listinfo/cups
--
Cheers, Gene
"There are four boxes to be used in defense of liberty:
soap, ballot, jury, and ammo. Please use in that order."
-Ed Howdershelt (Author)
Halley's Comet: It came, we saw, we drank.
Continue reading on narkive:
Loading...