[Pkg-cups-devel] Bug#403336: cupsys: Hangs when trying to add a newly found printer

Frank Küster frank at debian.org
Sat Dec 16 11:40:22 UTC 2006


Package: cupsys
Version: 1.2.7-1~bpo.1
Severity: important

I have experienced this three times, I think always with USB printers.
At http://localhost:631/admin, the printer is shown correctly as newly
found.  After clicking on "Add this printer", the browser displays
"Loading", but nothing happens, and cupsd and cups-driverd together eat
up all CPU (both about 48%, the rest is taken by Xorg and firefox-bin;
after clicking on stop both have near to 50%).

When I click on "Stop" in the browser, the CPU usage does not
drop. "/etc/init.d/cupsys restart" frees the CPU from the load.  These
are the last entries in access.log:

localhost - - [16/Dec/2006:12:28:44 +0100] "GET /admin HTTP/1.1" 200 0 - -
localhost - - [16/Dec/2006:12:28:44 +0100] "POST / HTTP/1.1" 200 1618 CUPS-Get-Devices -
localhost - - [16/Dec/2006:12:28:44 +0100] "GET /admin HTTP/1.1" 200 6462 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-add-this-printer.gif HTTP/1.1" 200 577 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-edit-configuration-file.gif HTTP/1.1" 200 699 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-view-access-log.gif HTTP/1.1" 200 638 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-view-error-log.gif HTTP/1.1" 200 554 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-view-page-log.gif HTTP/1.1" 200 590 - -
localhost - - [16/Dec/2006:12:28:46 +0100] "GET /images/button-change-settings.gif HTTP/1.1" 200 615 - -
localhost - - [16/Dec/2006:12:28:55 +0100] "GET /admin?op=add-printer&PRINTER_NAME=HP_LaserJet_1200_USB_1&PRINTER_LOCATION=Local+Printer&PRINTER_INFO=HP+LaserJet+1200&DEVICE_URI=usb://HP/LaserJet%25201200|HP+LaserJet+1200 HTTP/1.1" 200 0 - -

error.log is empty.  I set the loglevel to debug in the web interfaces,
this leads to:

localhost - - [16/Dec/2006:12:36:29 +0100] "GET /admin?op=config-server HTTP/1.1" 200 0 - -
localhost - - [16/Dec/2006:12:36:29 +0100] "GET /admin?op=config-server HTTP/1.1" 200 8794 - -
localhost - - [16/Dec/2006:12:36:30 +0100] "GET /images/button-use-default-config.gif HTTP/1.1" 200 864 - -
localhost - - [16/Dec/2006:12:36:30 +0100] "GET /images/button-save-changes.gif HTTP/1.1" 200 580 - -
localhost - - [16/Dec/2006:12:36:48 +0100] "POST /admin/ HTTP/1.1" 200 2853 - -
localhost - - [16/Dec/2006:12:36:48 +0100] "PUT /admin/conf/cupsd.conf HTTP/1.1" 401 0 - -
localhost - - [16/Dec/2006:12:36:48 +0100] "POST /admin/ HTTP/1.1" 401 2853 - -
localhost - - [16/Dec/2006:12:36:48 +0100] "POST /admin/ HTTP/1.1" 200 2853 - -
localhost - root [16/Dec/2006:12:36:55 +0100] "POST /admin/ HTTP/1.1" 200 2853 - -
localhost - - [16/Dec/2006:12:36:55 +0100] "PUT /admin/conf/cupsd.conf HTTP/1.1" 401 0 - -
localhost - root [16/Dec/2006:12:36:56 +0100] "PUT /admin/conf/cupsd.conf HTTP/1.1" 201 2252 - -
localhost - root [16/Dec/2006:12:36:55 +0100] "POST /admin/ HTTP/1.1" 200 6302 - -
localhost - root [16/Dec/2006:12:37:01 +0100] "GET /admin/?OP=redirect HTTP/1.1" 200 0 - -
localhost - root [16/Dec/2006:12:37:01 +0100] "GET /admin/?OP=redirect HTTP/1.1" 200 0 - -
localhost - - [16/Dec/2006:12:37:01 +0100] "GET /admin HTTP/1.1" 200 0 - -
localhost - - [16/Dec/2006:12:37:01 +0100] "POST / HTTP/1.1" 200 1615 CUPS-Get-Devices -
localhost - - [16/Dec/2006:12:37:01 +0100] "GET /admin HTTP/1.1" 200 6469 - -
localhost - - [16/Dec/2006:12:37:05 +0100] "GET /admin?op=add-printer&PRINTER_NAME=HP_LaserJet_1200_USB_1&PRINTER_LOCATION=Local+Printer&PRINTER_INFO=HP+LaserJet+1200&DEVICE_URI=usb://HP/LaserJet%25201200|HP+LaserJet+1200 HTTP/1.1" 200 0 - -

and the same problem: Nothing happens, 100% CPU is eaten up.  Now
error.log contains lots of output, I attach the file.

Regards, Frank

-- System Information:
Debian Release: 3.1
  APT prefers unstable
  APT policy: (99, 'unstable')
Architecture: i386 (i686)
Kernel: Linux 2.6.17-2-686
Locale: LANG=de_DE at euro, LC_CTYPE=de_DE at euro (charmap=ISO-8859-15)

Versions of packages cupsys depends on:
ii  adduser               3.63               Add and remove users and groups
ii  cupsys-common         1.2.7-1~bpo.1      Common UNIX Printing System(tm) - 
ii  dbus-1                0.23.4-1           simple interprocess messaging syst
ii  debconf [debconf-2.0] 1.4.30.13          Debian configuration management sy
ii  gs-esp                7.07.1-9           The Ghostscript PostScript interpr
ii  libc6                 2.3.2.ds1-22sarge4 GNU C Library: Shared libraries an
ii  libcupsimage2         1.2.7-1~bpo.1      Common UNIX Printing System(tm) - 
ii  libcupsys2            1.2.7-1~bpo.1      Common UNIX Printing System(tm) - 
ii  libgnutls11           1.0.16-13.2sarge2  GNU TLS library - runtime library
ii  libldap2              2.1.30-8           OpenLDAP libraries
ii  libpam0g              0.76-22            Pluggable Authentication Modules l
ii  libpaper1             1.1.14-3           Library for handling paper charact
ii  libslp1               1.0.11a-2          OpenSLP libraries
ii  lsb-base              3.1-15~bpo.1       Linux Standard Base 3.1 init scrip
ii  patch                 2.5.9-2            Apply a diff file to an original
ii  perl-modules          5.8.4-8sarge5      Core Perl modules
ii  procps                1:3.2.1-2          The /proc file system utilities
ii  xpdf-utils            3.00-13.6          Portable Document Format (PDF) sui
ii  zlib1g                1:1.2.2-4.sarge.2  compression library - runtime

-- debconf information:
  cupsys/raw-print: true
  cupsys/backend: ipp, lpd, parallel, socket, usb

-- 
Dr. Frank Küster
Single Molecule Spectroscopy, Protein Folding @ Inst. f. Biochemie, Univ. Zürich
Debian Developer (teTeX/TeXLive)

-------------- next part --------------
I [16/Dec/2006:12:36:56 +0100] Listening to 127.0.0.1:631 (IPv4)
I [16/Dec/2006:12:36:56 +0100] Listening to /var/run/cups/cups.sock (Domain)
I [16/Dec/2006:12:36:56 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [16/Dec/2006:12:36:56 +0100] Using default TempDir of /var/spool/cups/tmp...
I [16/Dec/2006:12:36:56 +0100] Cleaning out old temporary files in "/var/spool/cups/tmp"...
D [16/Dec/2006:12:36:56 +0100] Removed temporary file "/var/spool/cups/tmp/4583da50c9ae4"...
I [16/Dec/2006:12:36:56 +0100] Configured for up to 100 clients.
I [16/Dec/2006:12:36:56 +0100] Allowing up to 100 client connections per host.
I [16/Dec/2006:12:36:56 +0100] Using policy "default" as the default!
I [16/Dec/2006:12:36:56 +0100] Partial reload complete.
I [16/Dec/2006:12:36:56 +0100] Listening to 127.0.0.1:631 on fd 0...
I [16/Dec/2006:12:36:56 +0100] Listening to /var/run/cups/cups.sock on fd 2...
D [16/Dec/2006:12:37:01 +0100] cupsdAcceptClient: 6 from localhost:631 (IPv4)
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 6 GET /admin/?OP=redirect HTTP/1.1
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 6 Browser asked for language "en-us.utf-8"...
D [16/Dec/2006:12:37:01 +0100] cupsdAuthorize: username="root"
D [16/Dec/2006:12:37:01 +0100] CGI /usr/lib/cups/cgi-bin/admin.cgi started - PID = 9756
I [16/Dec/2006:12:37:01 +0100] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9756)
D [16/Dec/2006:12:37:01 +0100] cupsdSendCommand: 6 file=7
D [16/Dec/2006:12:37:01 +0100] PID 9756 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [16/Dec/2006:12:37:01 +0100] [CGI] admin.cgi started...
D [16/Dec/2006:12:37:01 +0100] [CGI] http=0x8076a90
D [16/Dec/2006:12:37:01 +0100] [CGI] op="redirect"...
D [16/Dec/2006:12:37:01 +0100] cupsdAcceptClient: 9 from localhost (Domain)
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 6 GET /admin HTTP/1.1
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 6 Browser asked for language "en-us.utf-8"...
D [16/Dec/2006:12:37:01 +0100] cupsdAuthorize: No authentication data provided.
D [16/Dec/2006:12:37:01 +0100] CGI /usr/lib/cups/cgi-bin/admin.cgi started - PID = 9757
I [16/Dec/2006:12:37:01 +0100] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9757)
D [16/Dec/2006:12:37:01 +0100] cupsdSendCommand: 6 file=7
D [16/Dec/2006:12:37:01 +0100] cupsdCloseClient: 9
D [16/Dec/2006:12:37:01 +0100] [CGI] admin.cgi started...
D [16/Dec/2006:12:37:01 +0100] [CGI] http=0x8076a90
D [16/Dec/2006:12:37:01 +0100] [CGI] No form data, showing main menu...
D [16/Dec/2006:12:37:01 +0100] cupsdAcceptClient: 9 from localhost (Domain)
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 9 POST / HTTP/1.1
D [16/Dec/2006:12:37:01 +0100] cupsdAuthorize: No authentication data provided.
D [16/Dec/2006:12:37:01 +0100] CUPS-Get-Printers
D [16/Dec/2006:12:37:01 +0100] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
D [16/Dec/2006:12:37:01 +0100] cupsdReadClient: 9 POST / HTTP/1.1
D [16/Dec/2006:12:37:01 +0100] cupsdAuthorize: No authentication data provided.
D [16/Dec/2006:12:37:01 +0100] CUPS-Get-Devices
D [16/Dec/2006:12:37:01 +0100] CGI /usr/lib/cups/daemon/cups-deviced started - PID = 9758
I [16/Dec/2006:12:37:01 +0100] Started "/usr/lib/cups/daemon/cups-deviced" (pid=9758)
D [16/Dec/2006:12:37:01 +0100] cupsdSendCommand: 9 file=10
D [16/Dec/2006:12:37:01 +0100] [cups-deviced] Added device "smb"...
D [16/Dec/2006:12:37:01 +0100] [cups-deviced] Added device "ipp"...
D [16/Dec/2006:12:37:01 +0100] [cups-deviced] Added device "http"...
D [16/Dec/2006:12:37:01 +0100] [cups-deviced] Added device "lpd"...
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "parallel:/dev/lp0"...
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "socket"...
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "usb://HP/LaserJet%201200"...
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "cups-pdf:/"...
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "epson:/dev/lp0"...
D [16/Dec/2006:12:37:02 +0100] PID 9758 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [16/Dec/2006:12:37:02 +0100] [cups-deviced] Added device "canon:/dev/lp0"...
D [16/Dec/2006:12:37:02 +0100] PID 9757 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [16/Dec/2006:12:37:02 +0100] [CGI] /usr/share/cups/drivers/pscript5.dll: No such file or directory
D [16/Dec/2006:12:37:02 +0100] [CGI] cgiCopyTemplateLang(tmpl="header.tmpl")
D [16/Dec/2006:12:37:02 +0100] [CGI] locale="en"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Template file is "/usr/share/cups/templates/header.tmpl"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 0...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{title}" at 205...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{refresh_page?" at 374, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 374...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{refresh_page}" at 424...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 427 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 427...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 428 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{refresh_page?", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{title}" at 671...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{title}" at 952...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SECTION=admin" at 1411, result=1...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1411...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1412 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1412...
D [16/Dec/2006:12:37:02 +0100] cupsdCloseClient: 9
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1415 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SECTION=admin", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SECTION=classes" at 1678, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1678...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1679 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1679...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1682 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SECTION=classes", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SECTION=help" at 1938, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1938...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1939 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1939...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1942 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SECTION=help", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SECTION=jobs" at 2206, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 2206...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2207 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 2207...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2210 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SECTION=jobs", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SECTION=printers" at 2464, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 2464...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2465 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 2465...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2468 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SECTION=printers", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2830 on EOF...
D [16/Dec/2006:12:37:02 +0100] [CGI] cgiCopyTemplateLang(tmpl="admin.tmpl")
D [16/Dec/2006:12:37:02 +0100] [CGI] locale="en"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Template file is "/usr/share/cups/templates/admin.tmpl"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{have_samba?" at 384, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 384...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 512 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 512...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 513 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{have_samba?", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{#device_uri=0" at 535, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 535...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 536 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 536...
D [16/Dec/2006:12:37:02 +0100] [CGI] Looping on "device_uri" at 586, count=3...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 586...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_options}" at 642...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_make_and_model}" at 772...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_info}" at 787...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 795 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 586...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_options}" at 642...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_make_and_model}" at 772...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_info}" at 787...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 795 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 586...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_options}" at 642...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_make_and_model}" at 772...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{device_info}" at 787...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 795 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished looping on "device_uri"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 801 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{#device_uri=0", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting "{SETTINGS_ERROR?" at 1850, result=0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Skip first part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1850...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{SETTINGS_MESSAGE}" at 1871...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{SETTINGS_ERROR}" at 1904...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 1918 on character ':'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Output second part...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 1918...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{?remote_printers}" at 2117...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{?share_printers}" at 2223...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{?remote_admin}" at 2337...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{?user_cancel_any}" at 2435...
D [16/Dec/2006:12:37:02 +0100] [CGI] "{?debug_logging}" at 2552...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2706 on character '}'...
D [16/Dec/2006:12:37:02 +0100] [CGI] Finished "{SETTINGS_ERROR?", out=0xa7ed6ee0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 2728 on EOF...
D [16/Dec/2006:12:37:02 +0100] [CGI] cgiCopyTemplateLang(tmpl="trailer.tmpl")
D [16/Dec/2006:12:37:02 +0100] [CGI] locale="en"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Template file is "/usr/share/cups/templates/trailer.tmpl"...
D [16/Dec/2006:12:37:02 +0100] [CGI] Starting at file position 0...
D [16/Dec/2006:12:37:02 +0100] [CGI] Returning at file position 614 on EOF...
D [16/Dec/2006:12:37:05 +0100] cupsdReadClient: 6 GET /admin?op=add-printer&PRINTER_NAME=HP_LaserJet_1200_USB_1&PRINTER_LOCATION=Local+Printer&PRINTER_INFO=HP+LaserJet+1200&DEVICE_URI=usb://HP/LaserJet%25201200|HP+LaserJet+1200 HTTP/1.1
D [16/Dec/2006:12:37:05 +0100] cupsdReadClient: 6 Browser asked for language "en-us.utf-8"...
D [16/Dec/2006:12:37:05 +0100] cupsdAuthorize: No authentication data provided.
D [16/Dec/2006:12:37:05 +0100] CGI /usr/lib/cups/cgi-bin/admin.cgi started - PID = 9769
I [16/Dec/2006:12:37:05 +0100] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9769)
D [16/Dec/2006:12:37:05 +0100] cupsdSendCommand: 6 file=7
D [16/Dec/2006:12:37:05 +0100] [CGI] admin.cgi started...
D [16/Dec/2006:12:37:05 +0100] [CGI] http=0x8076a90
D [16/Dec/2006:12:37:05 +0100] [CGI] op="add-printer"...
D [16/Dec/2006:12:37:05 +0100] [CGI] do_am_printer: DEVICE_URI="usb://HP/LaserJet%201200|HP LaserJet 1200"
D [16/Dec/2006:12:37:05 +0100] cupsdAcceptClient: 9 from localhost (Domain)
D [16/Dec/2006:12:37:05 +0100] cupsdReadClient: 9 POST / HTTP/1.1
D [16/Dec/2006:12:37:05 +0100] cupsdAuthorize: No authentication data provided.
D [16/Dec/2006:12:37:05 +0100] CUPS-Get-PPDs ipp://localhost/printers/
D [16/Dec/2006:12:37:05 +0100] CGI /usr/lib/cups/daemon/cups-driverd started - PID = 9770
I [16/Dec/2006:12:37:05 +0100] Started "/usr/lib/cups/daemon/cups-driverd" (pid=9770)
D [16/Dec/2006:12:37:05 +0100] cupsdSendCommand: 9 file=10
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Dymo/dymo.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/HP/deskjet2.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/HP/deskjet.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/HP/laserjet.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/stcolor2.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/epson24.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/epson9.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/stphoto2.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/stcolor.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Epson/stphoto.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Okidata/okidat24.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Okidata/okidata9.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Zebra/zebraep1.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Zebra/zebraep2.ppd"...
D [16/Dec/2006:12:37:07 +0100] [cups-driverd] Updating ppd "cups-included/Zebra/zebra.ppd"...
D [16/Dec/2006:12:37:14 +0100] cupsdAcceptClient: 11 from localhost:631 (IPv4)
D [16/Dec/2006:12:37:14 +0100] cupsdReadClient: 11 GET /admin/log/access_log HTTP/1.1
D [16/Dec/2006:12:37:14 +0100] cupsdReadClient: 11 Browser asked for language "en-us.utf-8"...
D [16/Dec/2006:12:37:14 +0100] cupsdAuthorize: username="root"
D [16/Dec/2006:12:37:14 +0100] write_file: 11 file=12
D [16/Dec/2006:12:38:17 +0100] cupsdCloseClient: 11
D [16/Dec/2006:12:39:00 +0100] cupsdAcceptClient: 11 from localhost:631 (IPv4)
D [16/Dec/2006:12:39:00 +0100] cupsdReadClient: 11 GET /admin/log/error_log HTTP/1.1
D [16/Dec/2006:12:39:00 +0100] cupsdReadClient: 11 Browser asked for language "en-us.utf-8"...
D [16/Dec/2006:12:39:00 +0100] cupsdAuthorize: username="root"
D [16/Dec/2006:12:39:00 +0100] write_file: 11 file=12
I [16/Dec/2006:12:39:40 +0100] Scheduler shutting down normally.
D [16/Dec/2006:12:39:40 +0100] cupsdCloseClient: 6
D [16/Dec/2006:12:39:40 +0100] cupsdCloseClient: 9
D [16/Dec/2006:12:39:40 +0100] cupsdCloseClient: 11
I [16/Dec/2006:12:39:40 +0100] Saving remote.cache...
I [16/Dec/2006:12:39:40 +0100] Saving job cache file "/var/cache/cups/job.cache"...
I [16/Dec/2006:12:39:41 +0100] Listening to 127.0.0.1:631 (IPv4)
I [16/Dec/2006:12:39:41 +0100] Listening to /var/run/cups/cups.sock (Domain)
I [16/Dec/2006:12:39:41 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [16/Dec/2006:12:39:41 +0100] Using default TempDir of /var/spool/cups/tmp...
I [16/Dec/2006:12:39:41 +0100] Cleaning out old temporary files in "/var/spool/cups/tmp"...
I [16/Dec/2006:12:39:41 +0100] Configured for up to 100 clients.
I [16/Dec/2006:12:39:41 +0100] Allowing up to 100 client connections per host.
I [16/Dec/2006:12:39:41 +0100] Using policy "default" as the default!
I [16/Dec/2006:12:39:41 +0100] Full reload is required.
I [16/Dec/2006:12:39:41 +0100] Loaded MIME database from '/etc/cups': 34 types, 39 filters...
D [16/Dec/2006:12:39:41 +0100] Loading printer bw_colorlaser...
D [16/Dec/2006:12:39:42 +0100] Loading printer colorlaser...
D [16/Dec/2006:12:39:42 +0100] Loading printer EPSON_Stylus_C82_USB_1...
D [16/Dec/2006:12:39:42 +0100] Loading printer EpsonUSB...
D [16/Dec/2006:12:39:42 +0100] Loading printer lj9000...
D [16/Dec/2006:12:39:42 +0100] Loading printer transparencies...
D [16/Dec/2006:12:39:42 +0100] Loading printer Walter...
I [16/Dec/2006:12:39:42 +0100] Loading job cache file "/var/cache/cups/job.cache"...
D [16/Dec/2006:12:39:42 +0100] Loading job 1 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 2 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 3 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 4 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 5 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 6 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 7 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 8 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 9 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 10 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 11 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 12 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 13 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 14 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 15 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 16 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 17 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 18 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 19 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 20 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 21 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 22 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 23 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 24 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 25 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 26 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 27 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 28 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 29 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 30 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 31 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 32 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 33 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 34 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 35 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 36 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 37 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 38 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 39 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 40 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 41 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 42 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 43 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 44 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 45 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 46 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 47 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 48 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 49 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 50 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 51 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 52 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 53 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 54 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 55 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 56 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 57 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 58 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 59 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 60 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 61 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 62 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 63 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 64 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 65 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 66 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 67 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 68 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 69 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 70 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 71 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 72 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 73 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 74 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 75 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 76 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 77 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 78 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 79 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 80 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 81 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 82 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 83 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 84 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 85 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 86 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 87 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 88 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 89 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 90 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 91 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 92 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 93 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 94 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 95 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 96 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 97 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 98 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 99 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 100 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 101 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 102 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 103 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 104 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 105 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 106 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 107 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 108 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 109 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 110 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 111 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 112 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 113 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 114 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 115 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 116 from cache...
D [16/Dec/2006:12:39:42 +0100] Loading job 117 from cache...
I [16/Dec/2006:12:39:42 +0100] Full reload complete.
I [16/Dec/2006:12:39:42 +0100] Listening to 127.0.0.1:631 on fd 0...
I [16/Dec/2006:12:39:42 +0100] Listening to /var/run/cups/cups.sock on fd 2...


More information about the Pkg-cups-devel mailing list