[CentOS] Xorg fills up /var/log/Xorg.0.log with AUDIT messages (up to system crash) [solved]

Fri Oct 4 11:48:01 UTC 2013
Frank Thommen <frank.thommen at embl-heidelberg.de>

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