Description of problem: Recently, audit began spamming my virtual consoles with messages such as: [47362.898982] audit: type=1100 audit(1494446835.336:711): pid=14799 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:authentication grantors=pam_unix acct="disciple" exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47362.902650] audit: type=1101 audit(1494446835.339:712): pid=14799 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="disciple" exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47362.914368] audit: type=1103 audit(1494446835.351:713): pid=14799 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_unix acct="disciple" exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47362.915133] audit: type=1006 audit(1494446835.352:714): pid=14799 uid=0 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 old-auid=4294967295 auid=1000 tty=tty3 old-ses=4294967295 ses=10 res=1 [47362.959012] audit: type=2300 audit(1494446835.396:715): pid=14799 uid=0 auid=1000 ses=10 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='pam: default-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 selected-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47362.999942] audit: type=1105 audit(1494446835.435:716): pid=14799 uid=0 auid=1000 ses=10 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_lastlog acct="disciple" exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47363.000156] audit: type=1110 audit(1494446835.435:717): pid=14799 uid=0 auid=1000 ses=10 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_unix acct="disciple" exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' [47363.000288] audit: type=1112 audit(1494446835.436:718): pid=14799 uid=0 auid=1000 ses=10 subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=login id=1000 exe="/usr/bin/login" hostname=arcusix.nonus-porta.net addr=? terminal=tty3 res=success' I don't know if this is an issue with audit itself, or something else. I've just started experiencing this in the past weeks. Version-Release number of selected component (if applicable): audit-2.7.6-1.fc25 How reproducible: Always. Steps to Reproduce: 1. Log into a virtual console. 2. Observe immediately there are audit messages being output concerning the fact you just logged on. 3. Observe there are more messages being output when running a command via sudo, e.g. a script that requires elevated privileges to gather information. Observe in that case the audit output is mixed in between regular lines of output to stdout, which is not optimal. Actual results: As above. Expected results: Not being subjected to many lines of undesired audit output. (It violates the "principle of least surprise", which I'm a big fan of: don't change the default behaviour of a program in ways that will surprise or confound a user, especially in a CLI environment.)
I have no idea how this is happening. Audit events are read from the kernel into auditd and it writes them to disk. It never writes to consoles.
Actually, auditd writes to stderr if its launched with the '-f' command line option.
My environments are mostly stock Fedora 25 in terms of configuration. auditd isn't launched with the -f command line option (unless ps is lying to me). My auditd service file is: $ more auditd.service [Unit] Description=Security Auditing Service DefaultDependencies=no ## If auditd.conf has tcp_listen_port enabled, copy this file to ## /etc/systemd/system/auditd.service and add network-online.target ## to the next line so it waits for the network to start before launching. After=local-fs.target systemd-tmpfiles-setup.service Conflicts=shutdown.target Before=sysinit.target shutdown.target RefuseManualStop=yes ConditionKernelCommandLine=!audit=0 Documentation=man:auditd(8) https://github.com/linux-audit/audit-documentation [Service] Type=forking PIDFile=/var/run/auditd.pid ExecStart=/sbin/auditd ## To not use augenrules, copy this file to /etc/systemd/system/auditd.service ## and comment/delete the next line and uncomment the auditctl line. ## NOTE: augenrules expect any rules to be added to /etc/audit/rules.d/ ExecStartPost=-/sbin/augenrules --load #ExecStartPost=-/sbin/auditctl -R /etc/audit/audit.rules ExecReload=/bin/kill -HUP $MAINPID # By default we don't clear the rules on exit. To enable this, uncomment # the next line after copying the file to /etc/systemd/system/auditd.service #ExecStopPost=/sbin/auditctl -R /etc/audit/audit-stop.rules [Install] WantedBy=multi-user.target
What happens if you stop journald or rsyslog? Auditd doesn't write to anything but the disk.
I rebooted before experimenting with stopping journald, and whatever was going on ended after the reboot. I can't duplicate this anymore. I have no idea why it was happening and then stopped (at least for now), since I haven't made any configuration changes of late, and the package updates applied recently all seem to be completely unrelated. Looking back two boots ago, I can see it wasn't happening then, either, so it was specific to one time, it seems: Kernel 4.10.14, up for a few days: $ journalctl -k -b -2 | grep audit | wc 55 1034 14428 Kernel 4.10.15, up for a couple of days: $ journalctl -k -b -1 | grep audit | wc 668 12179 182114 Kernel 4.10.15, up since this morning (with a bunch of logins, as per usual): $ journalctl -k | grep audit | wc 42 797 11077 This can be closed if need be, and I'll reopen if I experience this again. Thanks for your quick response!
OK. Thanks for checking on this. I will close it as the code that writes to the logging file hasn't changed much in a year. I'd almost bet it was journald related since it spams syslog with audit events.