Bug 206075 - CUPS flooding access_log
CUPS flooding access_log
Status: CLOSED DUPLICATE of bug 205619
Product: Fedora
Classification: Fedora
Component: cups (Show other bugs)
5
All Linux
medium Severity medium
: ---
: ---
Assigned To: Tim Waugh
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2006-09-11 16:02 EDT by Glenn Zazulia
Modified: 2007-11-30 17:11 EST (History)
0 users

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2006-10-23 08:46:33 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Glenn Zazulia 2006-09-11 16:02:51 EDT
Description of problem:

I think since upgrading cups and/or related packages in a recent "yum update", I
noticed that cups is flooding its access_log with lines such as the following at
a rate of about 5000 lines/minute:

localhost - - [11/Sep/2006:12:15:24 -0600] "POST / HTTP/1.1" 200 129
CUPS-Get-Printers successful-ok

As you can imagine, this will (and did) fill up a 2-3 GB filesystem fairly quickly.

I'm running cups 1.2.3 on FC5 with a local usb printer configured and working.
I'm also using samba 3.0.23a and had suspected that my observed cups problem may
be caused by interactions with samba (because whenever I stop cups during these
log floods, I see an smbd write failure in the system logs).  However, I found a
reference on the CUPS site that indicates that the problem is actually due to
eggcups (rpm desktop-printing).  I have tried using both the default cupsd.conf
configuration file that is distributed with the latest rpm as well as the
previous version that I was successfully using on an earlier FC4 system.

A recent search turned up the following reported related bug fix for debian:
http://svn.debian.org/wsvn/pkg-cups...n/?rev=154&sc=1

Another related posting was found on the CUPS site: 
http://cups.org/newsgroups.php?s1+gcups.bugs+v4+T0+Qaccess_log+flood

Version-Release number of selected component (if applicable):

desktop-printing-0.19-6
cups-1.2.2-1.8
hal-cups-utils-0.5.5-1.2.fc5.2
samba-3.0.23a-1.fc5.1

How reproducible:
Very

Steps to Reproduce:
1. tail -f /var/log/cups/access_log &
2. service cups start
3. wait a few minutes and watch the resulting flood of log entries
  
Actual results:
The /var/log/cups/access_log file starts growing very rapidly.

Expected results:
The log file shouldn't grow so rapidly (~ 10K/sec or .75 GB/day).

Additional info:
Comment 1 Tim Waugh 2006-09-12 04:50:13 EDT
This: http://cups.org/newsgroups.php?s1+gcups.bugs+v4+T0+Qaccess_log+flood
is not related.  It refers to the polling mode of eggcups, which is a fallback
used only when D-BUS is unavailable.  This polling mode does not cause 5000
lines/minute logging.

This URL: http://svn.debian.org/wsvn/pkg-cups...n/?rev=154&sc=1
seems incomplete, so I cannot comment on it.

Looks like this bug is a duplicate of another one that has been reported (bug
#205619), but just to be sure: do you see high CPU load when this occurs?
Comment 2 Glenn Zazulia 2006-09-12 12:51:47 EDT
I have more information.  In fact, I seem to have solved my problem.  First,
though, to answer your question:  yes, I was seeing high CPU load (the cups
process was hogging around 90% of the CPU) when this occured, and I needed to
stop the cups service in order to free up the CPU and stop the logging, of
course.  Also, certain client commands like "lpq" or the "Default Print" applet
(/usr/bin/gnome-default-printer) would hang and need to be killed.

Now, what I did to set things right:  I removed my previous PRD file(s) from
/etc/cups/ppd and cleared out the /etc/cups/printers.conf and then
re-added/configured my printer using the web-based admin interface
(http://localhost:631).  I also restored my cupsd.conf file to match the default
version that comes with the rpm distribution, though the various cupsd.conf
settings tried were never the cause of the problem.  I'm fairly certain that the
previous PRD file was the culprit.  I had upgraded systems from FC4 and at the
same time upgraded hardware (though kept the same architecture).  The printer is
the same, but it is now connected over USB instead of the parallel port.

Since fixing the PRD, the access_log now shows only one record every 5 minutes
or so (not consistently, but varying from maybe 3-10 minutes).  I assume this is
due to the normal behavior of samba and/or eggcups, etc.  Printing is working
fine both locally and over samba (ie. from remote Windows clients).

So, all is well now.  (Of course, it's probably still worth looking into the
prevention of run-away log floods -- even due to misconfigurations.)
Comment 3 Glenn Zazulia 2006-09-12 13:04:00 EDT
Sorry, one last side-note:  the reason I didn't immediately think to replace the
PRD file is that the printer was actually working fine for some time after
setting up my FC5 system -- I had been printing successfully both locally and
over samba.  Then on 9/7/06, when I last ran a "yum update" and upgraded cups to
version 1.2.3, I started noticing the problem with the cups access_log filling
up my /var filesystem.
Comment 4 Tim Waugh 2006-10-23 08:46:33 EDT
This was a known problem in CUPS-1.2.3 and has been fixed since then.

*** This bug has been marked as a duplicate of 205619 ***

Note You need to log in before you can comment on or make changes to this bug.