[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#732278: libcups2: lpq takes a long time (one minute) to report



Package: libcups2
Version: 1.7.4-4
Followup-For: Bug #732278

Hi,

After almost one year, I recently did hit the exact same bug in the
exact same context than Samuel (I am in the same lab).

The lab's CUPS server is currently a 1.4.2 server and it seems that it
does not respond to one of the request of lpq (I have a similar problem
with iceweasel with the exact same request).

lpq is then hitting the timeout after 60s and terminating by reporting
the needed data (the default printer is idle and ready to print).

Note also that lpstat is working without any delay when asked the exact
same information (lpstat -p <printer>). And, if Iceweasel has the same
problem than lpq, Chromium or any Gnome-based application, doesn't.

I managed to get the faulty CUPS request from a gdb session, but I am
far from being a specialist in CUPS protocol, so a little help could
make it easier for me to keep going investigating this problem:


$ gdb /usr/bin/lpq
GNU gdb (Debian 7.7.1-2) 7.7.1
...
This GDB was configured as "x86_64-linux-gnu".
...
Reading symbols from /usr/bin/lpq...Reading symbols from
/usr/lib/debug/.build-id/fd/9af3ee494610c8920a091cfbc57b77ed2c3505.debug...done.
done.
(gdb) r
Starting program: /usr/bin/lpq
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

[Here, I hit the timeout wait, so I interrupted the process]

^Z
Program received signal SIGTSTP, Stopped (user).

0x00007ffff78984f0 in __poll_nocancel () at
../sysdeps/unix/syscall-template.S:81
81	../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) bt
#0  0x00007ffff78984f0 in __poll_nocancel () at
../sysdeps/unix/syscall-template.S:81
#1  0x00007ffff7b9502f in poll (__timeout=60000, __nfds=1,
__fds=0x7fffffff3bd0)
    at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  _httpWait (http=<optimized out>, msec=60000, usessl=<optimized out>)
at http.c:3335
#3  0x00007ffff7b9520e in http_read (http=0x5555557adbe0,
buffer=0x7fffffff3cb0 "", length=91) at http.c:4413
#4  0x00007ffff7b96098 in httpRead2 (http=0x5555557adbe0,
buffer=0x7fffffff3cb0 "", length=8192) at http.c:2194
#5  0x00007ffff7b96210 in httpFlush (http=http@entry=0x5555557adbe0) at
http.c:772
#6  0x00007ffff7bb4502 in cupsDoIORequest (http=0x5555557adbe0,
request=0x5555557b1390,
    resource=0x55555555682c "/", infile=-1, outfile=-1) at request.c:297
#7  0x0000555555555b00 in show_printer (command=0x7fffffffe621
"/usr/bin/lpq", http=0x5555557adbe0,
    dest=0x55555575e0d4 "caxton") at lpq.c:632
#8  0x00005555555556b8 in main (argc=<optimized out>,
argv=0x7fffffffe378) at lpq.c:258

[Then, I wanted to know what was the request that has been sent to cups]

(gdb) up 7
#7  0x0000555555555b00 in show_printer (command=0x7fffffffe621
"/usr/bin/lpq", http=0x5555557adbe0,
    dest=0x55555575e0d4 "caxton") at lpq.c:632
632	  if ((response = cupsDoRequest(http, request, "/")) != NULL)
(gdb) p *request
$1 = {state = IPP_STATE_DATA, request = {any = {version = "\002",
      op_status = 11, request_id = 2}, op = { version = "\002",
      operation_id = IPP_OP_GET_PRINTER_ATTRIBUTES, request_id = 2},
      status = {version = "\002", status_code = 11, request_id = 2},
      event = {version = "\002", status_code = 11, request_id = 2}},
      attrs = 0x5555557ba3e0, last = 0x5555557ba250, current = 0x0,
      curtag = IPP_TAG_OPERATION, prev = 0x0, use = 1}


So, here is the request that is not replied by our CUPS server. I can't
understand the format right now, so a little bit of help to read it
could be interesting.

For those that have the code of lpq.c at hand reach, the problem occurs
at line lpq.c:632:

-> if ((response = cupsDoRequest(http, request, "/")) != NULL)
   {
     if (response->request.status.status_code > IPP_OK_CONFLICT)
     {
      _cupsLangPrintf(stderr, "%s: %s", command, cupsLastErrorString());
      ippDelete(response);
      return;
     }

Note also that no IPP_OK_CONFLICT is sent back, just we just hit the
timeout and keep go in the following of the code.


-- System Information:
Debian Release: jessie/sid
  APT prefers unstable
  APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 3.15.6 (SMP w/4 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages libcups2 depends on:
ii  libavahi-client3   0.6.31-4
ii  libavahi-common3   0.6.31-4
ii  libc6              2.19-7
ii  libgnutls-deb0-28  3.2.16-1
ii  libgssapi-krb5-2   1.12.1+dfsg-5
ii  multiarch-support  2.19-7
ii  zlib1g             1:1.2.8.dfsg-1

libcups2 recommends no packages.

Versions of packages libcups2 suggests:
ii  cups-common  1.7.4-4

-- no debconf information

Attachment: signature.asc
Description: OpenPGP digital signature


Reply to: