Frank Thommen
2013-Oct-03 15:15 UTC
[CentOS] Xorg fills up /var/log/Xorg.0.log with AUDIT messages (up to system crash)
Hi,
on a CentOS 6.4-workstation we have the problem, that Xorg fills up
/var/log/Xorg.0.log with AUDIT messages faster than one can read. Within
four hours the logfile grew to 160 MB and usually within 1-2 days
applications and sometimes the OS crash because /var becomes full.
Here a small extract of /var/log/Xorg.0.log:
[...]
[ 24272.458] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.487] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24951 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.490] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.500] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected
[ 24272.516] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24948 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.516] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected
from local host ( uid=9435 gid=577 pid=24952 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.521] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.549] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24957 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.552] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.564] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected
[ 24272.575] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24954 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.577] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected
from local host ( uid=9435 gid=577 pid=24958 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.585] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.612] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24963 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.616] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.628] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected
[ 24272.630] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24960 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.633] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected
from local host ( uid=9435 gid=577 pid=24964 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.644] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.673] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24969 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.679] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[ 24272.691] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected
[ 24272.692] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected
from local host ( uid=9435 gid=577 pid=24966 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.697] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected
from local host ( uid=9435 gid=577 pid=24970 )
Auth name: MIT-MAGIC-COOKIE-1 ID: 572
[ 24272.711] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected
[...]
The client numbers are just a small repeating set, but trying to find
the associated processes through the pids fails, because when the
logfile entry is written, the processes are already gone. For sure
these messages are associated with "something" the user(s) do, because
as soon as nobody is logged in, these messages stop. We have lots of
CentOS 6 machines, but this is the only one with such an issue, even
though there are more or less the same applications running on all machines.
Xorg is running with the following options (CentOS 6 default settings):
/usr/bin/Xorg :0 -nr -verbose -audit 4 -auth
/var/run/gdm/auth-for-gdm-jQ4DVP/database -nolisten tcp vt1
Questions:
* How can one find out which processes are responsible for these
audit messages?
* How can I stop auditing completely? With CentOS 5 Xorg ran
with "audit 0" and I was unable to find the place where the
audit level is set.
* (more generally) What's auditing good/used for anyway?
Any hint is appreciated.
Cheers
frank
[cross-posted on lopsa-tech maillist]
Frank Thommen
2013-Oct-04 11:48 UTC
[CentOS] Xorg fills up /var/log/Xorg.0.log with AUDIT messages (up to system crash) [solved]
Problem solved: A user had configured his "preferred browser" to be Thunderbird(!). As soon as he clicked on a link in an email, he ended in an endless loop with TB trying to open the link with the "preferred browser" (aka itself) again and again. This resulted in 40 MB audit loglines/hour in /var/log/Xorg.0.log. Cheers frank On 03.10.13 17:15, Frank Thommen wrote:> Hi, > > on a CentOS 6.4-workstation we have the problem, that Xorg fills up > /var/log/Xorg.0.log with AUDIT messages faster than one can read. Within > four hours the logfile grew to 160 MB and usually within 1-2 days > applications and sometimes the OS crash because /var becomes full. > > Here a small extract of /var/log/Xorg.0.log: > > [...] > [ 24272.458] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.487] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24951 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.490] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.500] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected > [ 24272.516] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24948 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.516] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected > from local host ( uid=9435 gid=577 pid=24952 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.521] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.549] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24957 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.552] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.564] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected > [ 24272.575] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24954 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.577] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected > from local host ( uid=9435 gid=577 pid=24958 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.585] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.612] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24963 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.616] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.628] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected > [ 24272.630] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24960 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.633] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected > from local host ( uid=9435 gid=577 pid=24964 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.644] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.673] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24969 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.679] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [ 24272.691] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 disconnected > [ 24272.692] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 connected > from local host ( uid=9435 gid=577 pid=24966 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.697] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 30 connected > from local host ( uid=9435 gid=577 pid=24970 ) > Auth name: MIT-MAGIC-COOKIE-1 ID: 572 > [ 24272.711] AUDIT: Wed Oct 2 15:41:44 2013: 2625: client 28 disconnected > [...] > > The client numbers are just a small repeating set, but trying to find > the associated processes through the pids fails, because when the > logfile entry is written, the processes are already gone. For sure > these messages are associated with "something" the user(s) do, because > as soon as nobody is logged in, these messages stop. We have lots of > CentOS 6 machines, but this is the only one with such an issue, even > though there are more or less the same applications running on all machines. > > > Xorg is running with the following options (CentOS 6 default settings): > /usr/bin/Xorg :0 -nr -verbose -audit 4 -auth > /var/run/gdm/auth-for-gdm-jQ4DVP/database -nolisten tcp vt1 > > > Questions: > > * How can one find out which processes are responsible for these > audit messages? > > * How can I stop auditing completely? With CentOS 5 Xorg ran > with "audit 0" and I was unable to find the place where the > audit level is set. > > * (more generally) What's auditing good/used for anyway? > > > Any hint is appreciated. > > Cheers > frank > > [cross-posted on lopsa-tech maillist] > _______________________________________________ > CentOS mailing list > CentOS at centos.org > http://lists.centos.org/mailman/listinfo/centos >-- Frank Thommen - Structures IT Management and Support - EMBL Heidelberg frank.thommen at embl-heidelberg.de - +49 6221 387 8353