[cups.general] spooling delays - take 2

gotj at iinet.net.au gotj at iinet.net.au
Sun Sep 23 18:19:43 PDT 2007


Hello,

we have a cups server and two clients and all are running RHEL v4 with cups v1.1.22

We've noticed that when sending jobs from the clients, there is a noticeable 5-6
sec delay before the job number is finally displayed and for the lp command to
finish.

the cups server is setup NOT to use dns lookups and both cups server and client
OSes are setup to use /etc/hosts file to resolve hostnames.

here is a typical example:

$time lp -d lptest /etc/hosts
request id is lptest-757975 (1 file(s))

real    0m5.235s
user    0m0.007s
sys     0m0.007s

Server and clients are running gigabit ethernet and there is no network related
problem.

The delay is pretty consistent and it never seems to get more than 6 secs. Even
when I have both servers sending jobs in a loop the delay from both is between
5-6 secs.

An strace of the lp command shows that the client end is just waiting for the
server to finish sending printer information to it. Most of the output was like this:

27960 recv(3, "\1\1\0\1\0\0\0\1", 2048, 0) = 8
27960 time(NULL)                        = 1190261046
27960 recv(3, "\1G\0\22attributes-charset\0\5utf-8", 2048, 0) = 29
27960 time(NULL)                        = 1190261046
27960 recv(3, "H\0\33attributes-natural-language\0\5"..., 2048, 0) = 37
27960 time(NULL)                        = 1190261046
27960 recv(3, "\4#\0\rprinter-state\0\4\0\0\0\3", 2048, 0) = 23
27960 time(NULL)                        = 1190261046
27960 recv(3, "D\0\25printer-state-reasons\0\4none", 2048, 0) = 30
27960 time(NULL)                        = 1190261046
27960 recv(3, "A\0\25printer-state-message\0001Print "..., 2048, 0) = 75
27960 time(NULL)                        = 1190261046
27960 recv(3, "\"\0\31printer-is-accepting-jobs\0\1\1", 2048, 0) = 31
27960 time(NULL)                        = 1190261046
27960 recv(3, "!\0\17printer-up-time\0\4F\361\3615", 2048, 0) = 24
27960 time(NULL)                        = 1190261046
27960 recv(3, "!\0\22printer-state-time\0\4F\355<\237", 2048, 0) = 27
27960 time(NULL)                        = 1190261046
27960 recv(3, "1\0\24printer-current-time\0\v\7\327\t\24\4\4\5"..., 2048, 0) = 36
27960 time(NULL)                        = 1190261046
27960 recv(3, "!\0\20queued-job-count\0\4\0\0\0\0", 2048, 0) = 25
27960 time(NULL)                        = 1190261046
27960 recv(3, "B\0\fprinter-name\0\10hp8khume", 2048, 0) = 25
27960 time(NULL)                        = 1190261046
27960 recv(3, "B\0\22job-sheets-default\0\4noneB\0\0\0\4"..., 2048, 0) = 36
27960 time(NULL)                        = 1190261046
27960 recv(3, "\4#\0\rprinter-state\0\4\0\0\0\3", 2048, 0) = 23
27960 time(NULL)                        = 1190261046
27960 recv(3, "D\0\25printer-state-reasons\0\4none", 2048, 0) = 30

Does anyone have any ideas ?

Thanks. 





More information about the cups mailing list