[Pkg-cups-devel] Bug#501903: Problems with cups web interface not working

debian debian at kch.net
Sat Oct 11 13:06:24 UTC 2008


Package: cups
Version: 1.3.8-1lenny1
Severity: grave
Justification: renders package unusable

Upon upgrading to 1.3.8-1lenny1, cups suddenly stopped printing.

Going to http://localhost:631 produced the expected page, but trying to
access any of the tabs to check on printers or queues just gave a
'waiting for localhost' response on the browser.

I tried removing the package and re-installing. No change in behavior.

Following some hints from other bug reports, I set "LogLevel debug" in
the cupsd.conf file. Accessing the web interface and then selecting the
'printers' tab gives the following in /var/log/error_log

D [11/Oct/2008:08:31:37 -0400] cupsdAcceptClient: 7 from localhost:631 (IPv4)
D [11/Oct/2008:08:31:37 -0400] Report: clients=1
D [11/Oct/2008:08:31:37 -0400] Report: jobs=0
D [11/Oct/2008:08:31:37 -0400] Report: jobs-active=0
D [11/Oct/2008:08:31:37 -0400] Report: printers=0
D [11/Oct/2008:08:31:37 -0400] Report: printers-implicit=0
D [11/Oct/2008:08:31:37 -0400] Report: stringpool-string-count=170
D [11/Oct/2008:08:31:37 -0400] Report: stringpool-alloc-bytes=4976
D [11/Oct/2008:08:31:37 -0400] Report: stringpool-total-bytes=3720
D [11/Oct/2008:08:31:37 -0400] cupsdReadClient: 7 GET /printers/ HTTP/1.1
D [11/Oct/2008:08:31:37 -0400] cupsdAuthorize: No authentication data provided.
D [11/Oct/2008:08:31:37 -0400] [CGI] /usr/lib/cups/cgi-bin/printers.cgi
started - PID = 28005
I [11/Oct/2008:08:31:37 -0400] Started "/usr/lib/cups/cgi-bin/printers.cgi"
(pid=28005)
D [11/Oct/2008:08:31:37 -0400] cupsdSendCommand: 7 file=8
E [11/Oct/2008:08:31:37 -0400] PID 28005 (/usr/lib/cups/cgi-bin/printers.cgi)
stopped with status 22!
D [11/Oct/2008:08:31:37 -0400] [CGI] /usr/lib/cups/cgi-bin/printers.cgi:
Permission denied

I ran /usr/lib/cups/cgi-bin/printers.cgi from the command line both as root
and as a regular user. Both times I get html output (omitted for
brevity of report)

Running 'strace' on the cupsd binary gives the following when the
'Printers' tab is selected on the web interface.

recv(11, "GET /printers/ HTTP/1.1\r\nHost: lo"..., 2048, 0) = 417
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
write(2, "D [11/Oct/2008:08:40:08 -0400] cu"..., 75) = 75
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
write(2, "D [11/Oct/2008:08:40:08 -0400] cu"..., 80) = 80
pipe([13, 14])                          = 0
fcntl64(13, F_GETFD)                    = 0
fcntl64(13, F_SETFD, FD_CLOEXEC)        = 0
fcntl64(14, F_GETFD)                    = 0
fcntl64(14, F_SETFD, FD_CLOEXEC)        = 0
access("/usr/lib/cups/cgi-bin/printers.cgi", X_OK) = 0
rt_sigprocmask(SIG_BLOCK, [TERM CHLD], [], 8) = 0
clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb79e0718) = 28019
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
time(NULL)                              = 1223728808
write(2, "D [11/Oct/2008:08:40:08 -0400] [C"..., 94) = 94
close(14)                               = 0
time(NULL)                              = 1223728808
write(2, "I [11/Oct/2008:08:40:08 -0400] St"..., 88) = 88
time(NULL)                              = 1223728808
write(2, "D [11/Oct/2008:08:40:08 -0400] cu"..., 60) = 60
fcntl64(13, F_GETFD)                    = 0x1 (flags FD_CLOEXEC)
fcntl64(13, F_SETFD, FD_CLOEXEC)        = 0
write(9, "localhost - - [11/Oct/2008:08:40:"..., 79) = 79
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}, {fd=12,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=16, events=POLLIN}], 11,
1000) = 2 ([{fd=5, revents=POLLIN}, {fd=13, revents=POLLHUP}])
--- SIGCHLD (Child exited) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
read(5, "/usr/lib/cups/cgi-bin/printers.cg"..., 1023) = 54
time(NULL)                              = 1223728808
write(2, "D [11/Oct/2008:08:40:08 -0400] [C"..., 91) = 91
epoll_ctl(-1, EPOLL_CTL_DEL, 13,
{EPOLLRDNORM|EPOLLRDBAND|EPOLLWRBAND|EPOLLMSG|EPOLLERR|0x8a29800,
{u32=3213176700, u64=13248886471035006844}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
time(NULL)                              = 1223728808
waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 22}], WNOHANG) = 28019
time(NULL)                              = 1223728808
write(2, "E [11/Oct/2008:08:40:08 -0400] PI"..., 102) = 102
waitpid(-1, 0xbf853138, WNOHANG)        = -1 ECHILD (No child processes)
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}, {fd=12,
events=POLLIN}, {fd=16, events=POLLIN}], 10, 1000) = 1 ([{fd=11,
revents=POLLOUT}])
read(13, ""..., 16384)                  = 0
write(9, "localhost - - [11/Oct/2008:08:40:"..., 79) = 79
epoll_ctl(-1, EPOLL_CTL_DEL, 13,
{EPOLLRDNORM|EPOLLWRNORM|EPOLLWRBAND|EPOLLMSG|0x8a6d800,
{u32=4278845440, u64=578866397829529600}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
kill(28019, SIGTERM)                    = -1 ESRCH (No such process)
close(13)                               = 0
time(NULL)                              = 1223728808
time(NULL)                              = 1223728808
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}, {fd=12,
events=POLLIN}, {fd=16, events=POLLIN}], 10, 1000) = 0 (Timeout)
time(NULL)                              = 1223728809
time(NULL)                              = 1223728809
time(NULL)                              = 1223728809
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}, {fd=12,
events=POLLIN}, {fd=16, events=POLLIN}], 10, 269000) = 5 ([{fd=7,
revents=POLLIN}, {fd=8, revents=POLLIN}, {fd=10, revents=POLLIN},
{fd=12, revents=POLLIN}, {fd=16, revents=POLLIN}])
poll([{fd=7, events=POLLIN}], 1, 10000) = 1 ([{fd=7, revents=POLLIN}])
recv(7, ""..., 2048, 0)                 = 0
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] cu"..., 51) = 51
epoll_ctl(-1, EPOLL_CTL_DEL, 7, {EPOLLOUT|EPOLLERR|EPOLLET|0x37dd8000,
{u32=144891224, u64=13800323211795291480}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
close(7)                                = 0
poll([{fd=8, events=POLLIN}], 1, 10000) = 1 ([{fd=8, revents=POLLIN}])
recv(8, ""..., 2048, 0)                 = 0
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] cu"..., 51) = 51
epoll_ctl(-1, EPOLL_CTL_DEL, 8, {EPOLLOUT|EPOLLERR|EPOLLET|0x37dd8000,
{u32=144891224, u64=13800323211795291480}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
close(8)                                = 0
poll([{fd=10, events=POLLIN}], 1, 10000) = 1 ([{fd=10, revents=POLLIN}])
recv(10, ""..., 2048, 0)                = 0
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] cu"..., 52) = 52
epoll_ctl(-1, EPOLL_CTL_DEL, 10, {EPOLLOUT|EPOLLERR|EPOLLET|0x37dd8000,
{u32=144891224, u64=13800323211795291480}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
close(10)                               = 0
poll([{fd=12, events=POLLIN}], 1, 10000) = 1 ([{fd=12, revents=POLLIN}])
recv(12, ""..., 2048, 0)                = 0
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] cu"..., 52) = 52
epoll_ctl(-1, EPOLL_CTL_DEL, 12, {EPOLLOUT|EPOLLERR|EPOLLET|0x37dd8000,
{u32=144891224, u64=13800323211795291480}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
close(12)                               = 0
poll([{fd=16, events=POLLIN}], 1, 10000) = 1 ([{fd=16, revents=POLLIN}])
recv(16, ""..., 2048, 0)                = 0
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] cu"..., 52) = 52
epoll_ctl(-1, EPOLL_CTL_DEL, 16, {EPOLLOUT|EPOLLERR|EPOLLET|0x37dd8000,
{u32=144891224, u64=13800323211795291480}}) = -1 EBADF (Bad file
descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
close(16)                               = 0
time(NULL)                              = 1223728851
time(NULL)                              = 1223728851
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 49) = 49
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 46) = 46
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 53) = 53
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 50) = 50
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 59) = 59
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 67) = 67
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 67) = 67
time(NULL)                              = 1223728851
write(2, "D [11/Oct/2008:08:40:51 -0400] Re"..., 67) = 67
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}], 5, 1000)
= 0 (Timeout)
time(NULL)                              = 1223728852
time(NULL)                              = 1223728852
time(NULL)                              = 1223728852

At this point, I am not sure where to start looking to resolve the problems
myself. The printing system is unusable in this state, hence the grave level
report.

If there is more information that is required, I will be happy to provide
that, just let me know what is needed.

-- System Information:
Debian Release: lenny/sid
  APT prefers testing
  APT policy: (500, 'testing')
Architecture: i386 (i686)

Kernel: Linux 2.6.26-1-686 (SMP w/1 CPU core)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash

Versions of packages cups depends on:
ii  adduser               3.110              add and remove users and groups
ii  cups-common           1.3.8-1lenny1      Common UNIX Printing System(tm) -
ii  debconf [debconf-2.0] 1.5.22             Debian configuration management sy
ii  ghostscript           8.62.dfsg.1-3.1    The GPL Ghostscript PostScript/PDF
ii  libavahi-compat-libdn 0.6.22-3           Avahi Apple Bonjour compatibility
ii  libc6                 2.7-13             GNU C Library: Shared libraries
ii  libcups2              1.3.8-1lenny1      Common UNIX Printing System(tm) -
ii  libcupsimage2         1.3.8-1lenny1      Common UNIX Printing System(tm) -
ii  libdbus-1-3           1.2.1-3            simple interprocess messaging syst
ii  libgnutls26           2.4.1-1            the GNU TLS library - runtime libr
ii  libkrb53              1.6.dfsg.4~beta1-4 MIT Kerberos runtime libraries
ii  libldap-2.4-2         2.4.10-3           OpenLDAP libraries
ii  libpam0g              1.0.1-4            Pluggable Authentication Modules l
ii  libpaper1             1.1.23+nmu1        library for handling paper charact
ii  libslp1               1.2.1-7.4          OpenSLP libraries
ii  lsb-base              3.2-20             Linux Standard Base 3.2 init scrip
ii  perl-modules          5.10.0-15          Core Perl modules
ii  procps                1:3.2.7-8          /proc file system utilities
ii  ssl-cert              1.0.23             simple debconf wrapper for OpenSSL
ii  xpdf-utils [poppler-u 3.02-1.4           Portable Document Format (PDF) sui

Versions of packages cups recommends:
ii  avahi-utils           0.6.22-3           Avahi browsing, publishing and dis
ii  cups-client           1.3.8-1lenny1      Common UNIX Printing System(tm) -
ii  foomatic-filters      3.0.2-20080211-3.1 OpenPrinting printer support - fil
ii  smbclient             2:3.2.3-1          a LanManager-like simple client fo

Versions of packages cups suggests:
pn  cups-bsd                <none>           (no description available)
pn  cups-driver-gutenprint  <none>           (no description available)
pn  cups-pdf                <none>           (no description available)
ii  foomatic-db             20080211-2+nmu1  OpenPrinting printer support - dat
ii  foomatic-db-engine      3.0.2-20080211-1 OpenPrinting printer support - pro
pn  hplip                   <none>           (no description available)
pn  xpdf-korean | xpdf-japa <none>           (no description available)

-- debconf information:
* cupsys/raw-print: false
* cupsys/backend: ipp, lpd, parallel, scsi, serial, socket, usb, snmp, dnssd






More information about the Pkg-cups-devel mailing list