SELinux developers understand that a security-oriented subsystem such as SELinux can only succeed if it is capable of enhanced logging and—even—debugging. Every action that SELinux takes, as part of the LSM hooks that it implements, should be auditable. Denials (actions that SELinux prevents) should always be logged so that administrators can take due action. SELinux tuning and changes, such as loading new policies or altering SELinux Booleans, should always result in an audit event.
Following audit events
By default, SELinux will send its messages to the Linux audit subsystem (assuming the Linux kernel isconfigured with the audit subsystem enabled through theCONFIG_AUDITkernel configuration). There, the messages are picked up by the Linux audit daemon (auditd) and logged in the/var/log/audit/audit.logfile. Distributions and administrators can define additional handling rules by configuring the audit dispatcher process (audisp), which picks up audit events and dispatches them to one or more separate processes. The SELinux troubleshooting daemon (setroubleshootd), an optional service to provide help with troubleshooting SELinux events, uses this to get access to audit events.
The audit event flow is shown in this diagram:
With SELinux enabled, (almost) every permission check that results in a denial is logged. When Linux auditing is enabled, these denials are logged by the audit daemon in theaudit.logfile by default. If the audit daemon is unavailable, the events are stored in the Linux kernel message buffer, which we can consult using thedmesgcommand. The events in the kernel message buffer are also often captured through the system logger.
If the SELinuxtroubleshooting daemon is installed, then the audit daemon will, alongside its logging, also dispatch the events through the audit dispatch system toward thesedispatchcommand. This command will further handle the event and send it through D-Bus (a system bus implementation popular on Linux systems) to the SELinux troubleshooting daemon. This daemon will analyze the event and might suggest one or more fixes to the administrator. We will cover the SELinux troubleshooting daemon in theGetting help with denialssection.
Whenever SELinux verifies a particular access, it does not always go over the entire policy. Instead, ithas anaccess vector cache(AVC), in which it stores the results of previous access attempts. This cache ensures that SELinux can quickly react to activities without having a huge impact on performance. We notice the abbreviation of this cache as the message type for most SELinux events, as shown at the beginning of the following example:
type=AVC msg=audit(03/22/2020 12:15:38.557:2331): avc: denied { read } for pid=12569 comm="dmesg" name="xterm-256color" dev="sdb2" ino=131523 scontext=sysadm_u:sysadm_r:dmesg_t:s0-s0:c0.c1023 tcontext=system_u:object_r:etc_t:s0 tclass=file permissive=0When the Linux kernel checks a permission request, this request is represented as anaccess vector, and the cache is then consulted to quickly find the appropriate response. If the cache has the right access vector, then the decision is taken from the cache; otherwise, the SELinuxsubsystem consults the policy itself and updates the cache. Of course, SELinux invalidates the cache when a new policy is loaded or the policy is dynamically adjusted. This ensures that all permission checks are in line with the active policy.
This inner working of SELinux is less relevant to most administrators, but at least now we know where the termAVCcomes from.
Tuning the AVC
The AVCcan be slightly tuned, by setting the size of the cache or its related tables.
We can configure the cache size itself through the /sys/fs/selinux/avc/cache_thresholdpseudo-file (available if theCONFIG_SECURITY_SELINUX_AVC_STATSkernel configuration is set). For instance, to increase the cache size to 768 entries (the default is 512), the following command would be used:
# echo 768 > /sys/fs/selinux/avc/cache_thresholdTo confirm the cache threshold, read the file, as follows:
# cat /sys/fs/selinux/avc/cache_threshold
768The AVC hash statistics are available through the hash_stats pseudo-file, as illustrated in the following code snippet:
$ cat /sys/fs/selinux/avc/hash_stats
entries: 506
buckets used: 233/512
longest chain: 5If you suspect that lower system performance is due to SELinux, then we advise you to look at thelongest chainoutput inhash_stats. If it is longer than 10, then some performance impact can be expected, and updating the cache size might help.
Theavcstatcommand shows the evolution of the cache over time (the first number is the total since boot). When the number of cache misses is high or volatile, or the number of reclaims (obsoleting oldest cache entries and reusing them for new ones) is volatile, then the cache size might need to be increased. The command is illustrated in the following code snippet:
$ avcstat 5
lookups hits misses allocs reclaims frees
58396334 58382324 14010 14010 10736 13511
591 591 0 0 0 0
1657 1653 4 4 0 0Recent kernels also allow the number of buckets used through a kernel configuration parameter to be set (CONFIG_SECURITY_SELINUX_SIDTAB_HASH_BITS), and its cache statistics can be viewed through the /sys/fs/selinux/ss/sidtab_hash_stats pseudo-file, as illustrated in the following code snippet:
$ cat /sys/fs/selinux/ss/sidtab_hash_stats
entries: 285
buckets use: 55/512
longest chain: 3Another performance parameter is the size of the internal session ID (SID) (the internal identifier used to represent contexts) to the string cache. Sadly, we can only configure this parameter at kernel build time, using the CONFIG_SECURITY_SELINUX_SID2STR_CACHE_SIZE setting.
Uncovering more logging
There is an important SELinux policy directive that provides control over what is (not) audited, and that isdontaudit. Adontauditrule in the SELinux policy tells SELinux that an access denialshould not be logged. This is the only example where SELinux won’t log a denial—the SELinux policy writer has explicitly disabled the auditing of events. This is usually done to remove clutter from the logs and hide cosmetic denials that have no influence on the security of the system.
Theseinfoutility can tell us how many of these rules, as well as its sibling ruleauditallow(log events, even though they are allowed by the policy), are currently active, as illustrated in the following code snippet:
$ seinfo | grep -i audit
Auditallow: 1 Dontaudit: 5559
Auditallowxperm: 0 Dontauditxperm: 0Luckily, we can disable these dontaudit rules at will. Through the following semodule command, these rules are removed from the active policy:
# semodule –-disable_dontaudit –-buildThe arguments can also be abbreviated to -D and -B, respectively. To re-enable the dontaudit rules, just rebuild the policy like so:
# semodule -BDisabling the dontaudit rules can sometimes help in troubleshooting failures that do not result in any useful audit event. Generally speaking, though, audit events that policy writers mark as cosmetic are not the cause of a failure.
Configuring Linux auditing
SELinux will tryto use the audit subsystem when available and will fall back to regular system logging when it isn’t. This can either be because the Linux kernel audit subsystem is not configured or because the Linux audit daemon itself is not running.
For a Linux audit, we usually do not need to configure anything as SELinux AVC denials are logged by default. You will find the denials in the audit log file (/var/log/audit/audit.log), usually together with the system call and other event messages related to the same action, as illustrated in the following code snippet:
type=PROCTITLE msg=audit(...) : proctitle=ping 8.8.8.8
type=SYSCALL msg=audit(...) : arch=x86_64 syscall=socket success=no exit=EACCES(Permission denied) a0=inet a1=SOCK_DGRAM a2=icmp a3=0x7fffac013050 items=0 ppid=2685 pid=17292 auid=admin uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=tty1 ses=1 comm=ping exe=/bin/ping subj=sysadm_u:sysadm_r:ping_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(...) : avc: denied { create } for pid=17292 comm=ping scontext=sysadm_u:sysadm_r:ping_t:s0-s0:c0.c1023 tcontext=sysadm_u:sysadm_r:ping_t:s0-s0:c0.c1023 tclass=icmp_socket permissive=0 To configure the target log file for the audit system, use thelog_fileparameter in/etc/audit/auditd.conf.
To enable remote audit logging (to centralize audit events from multiple hosts on a single system), you have the option of either enabling syslog forwarding or enabling theaudisp-remoteplugin.
With syslog forwarding, the audit dispatch daemon is configured to send audit events to the local system logger as well. It is then up to the administrator to configure the local system logger to pass on events toward a remote system.
Edit the /etc/audit/plugins.d/syslog.conf file and set active to yes, as follows:
# vi /etc/audit/plugins.d/syslog.conf
active = yes
direction = out
path = /sbin/audisp-syslog
type = always
args = LOG_INFO
format = stringUsing the system logger to centralize audit events might not be the best option though, as system loggers generally use unencrypted—and often not even guaranteed—data delivery. With theaudisp-remoteplugin, we can even use an encrypted channel to send the audit events, and provide guaranteed delivery to a remoteauditdserver.
First, configurethe audit daemon on the target (log) server to accept audit logs from remote hosts by enabling the audit daemon to listen on port60. We also change the event formatting to an enriched value and add hostnames to the events so that we can distinguish events from multiple hosts, as follows:
auditd.conf
# vi /etc/audit/auditd.conf
tcp_listen_port = 60
log_format = ENRICHED
name_format = HOSTNAMENext, on the source systems, configure auditd.conf as shown in the previous code snippet, but without the port setting. Then, configure the audisp-remote plugin to connect to the target server’s audit daemon, as follows:
audisp-remote.conf
# vi /etc/audit/audisp-remote.conf
remote_server = <targethostname>
port = 60Finally, enable the audisp-remote plugin, as follows:
au-remote.conf
# vi /etc/audit/plugins.d/au-remote.conf
active = yesDon’t forget to restart the audit daemon so that the changes take effect.
We can only recommend you always use the Linux audit subsystem. Not only does it integrate nicely with troubleshooting utilities; it also allows administrators to use the audit tools to query the audit logs or even generate reports, such as withaureport, as illustrated in the following code snippet:
aureport
# aureport --avc --start recent
AVC Report
===============================================================
# date time comm subj syscall class permission obj result event
===============================================================
...
7. 03/21/2020 19:40:55 sudo sysadm_u:sysadm_r:sysadm_sudo_t:s0-s0:c0.c1023 257 dir search sysadm_u:sysadm_r:sysadm_t:s0-s0:c0.c1023 denied 1067
...
10. 03/21/2020 19:48:19 dmesg sysadm_u:sysadm_r:dmesg_t:s0-s0:c0.c1023 21 file read system_u:object_r:etc_t:s0 denied 1080The Linux audit system is an important aide for Linux administrators, and not just for SELinux troubleshooting. But next to the Linux audit system, events can also be directed toward the local system logger, as explained next.
Configuring the local system logger
When auditingis not enabled, or the Linux audit daemon is not running, then the system logger is responsible for capturing SELinux events. The system logger will log these events through the kernel logging facility (kern.*). Most system loggers will save these kernel log events in a general log file, such as/var/log/messages.
We can configure the system logger to direct SELinux AVC messages into its own log file, such as/var/log/avc.log. For instance, for thersyslogsystem logger, we can add in a configuration entry under/etc/rsyslog.dnamed99-selinux.conf, with the following content:
99-selinux.conf
# vi /etc/rsyslog.d/99-selinux.conf
:msg, contains, "avc: " -/var/log/avc.logAfter restarting the system logger, the AVC-related messages will show up in the/var/log/avc.logfile.
When the local system logger handles SELinux logging, an easy method to quickly obtain the latest AVC denials (or other messages) is through thedmesgcommand, as illustrated in the following code snippet:
# dmesg | grep avc | tailBe aware, though, that unlike the audit logs, many systems allow the dmesg content to be read by regular users. This might result in some information leakage to untrusted users. For this reason, some SELinux policies do not allow regular users to access the kernel ring buffer (and, as such, use dmesg) unless the user_dmesg SELinux Boolean is set to on, as illustrated in the following code snippet:
# setsebool user_dmesg onThe user_dmesg SELinux Boolean is not available on CentOS, though. There, only the standard unconfined user type and the administrative user type have access to the kernel ring buffer. To prevent other users from reading this information, you need to map these users to non-administrative SELinux users, such as user_u or (x)guest_u .
Reading SELinux denials
The one thing every one of us will have to do several times with SELinux systems is to read and interpretSELinux denial information. When SELinux prohibits access and there is nodontauditrule in place to hide it, SELinux will log it. If nothing is logged, it was probably not SELinux that was responsible for the failure. Remember: SELinuxcomes after Linuxdiscretionary access control(DAC) checks, so if a regular permission doesn’t allow a certain activity then SELinux is never consulted.
SELinux denial messages are logged the moment SELinux prevents some access from occurring. When SELinux is in enforcing mode, the application usually returns aPermission deniederror, although sometimes it might be a bit more obscure. An example of this can be seen in the following code snippet:
$ ls /proc/1
ls: cannot access '/proc/1': Permission denied
# ls -ldZ /proc/1
dr-xr-xr-x. 9 root system_u:system_r:init_t:s0 0 Mar 21 10:54 /proc/1So, what does a denial message look like? The following command output shows a denial from the audit subsystem, which we can query through the ausearch command:
# ausearch -m avc -ts recent -i
type=AVC msg=audit(03/22/2020 12:15:38.557:2331): avc: denied { read } for pid=12569 comm="dmesg" name="xterm-256color" dev="sdb2" ino=131523 scontext=sysadm_u:sysadm_r:dmesg_t:s0-s0:c0.c1023 tcontext=system_u:object_r:etc_t:s0 tclass=file permissive=0Let’s break up this denial into its individual components. The following list gives more information about each part of the preceding denials. As an administrator, knowing how to read denials is extremely important, so take enough time for this:
- SELinux action: The action that SELinux took or would take if run in
enforcingmode. Thisis usuallydenied, although some actions are explicitly marked to be audited as well and would result ingranted. Example:denied - Permissions: Thechecked permissions (action initiated by the process). This is usually a single permission, although it can sometimes be a set of permissions. Example:
{ read } - Process ID (PID): The IDof the process that was performing the action. Example:
pid=12569 - Process name: Theprocess name (command). It doesn’t display any arguments to the command, though. Example:
comm="dmesg" - Target name: Thename of the target (resource) that the process is performing an action on. If the target is a file, then the name is usually the filename or directory. Example:
name="xterm-256color" - Target device: Thedevice on which the target resource resides. Together with the next field (inode number) this allows us to uniquely identify the resource on a system. Example:
dev="sdb2" - Target file inode number: The inode number of the target file or directory. Togetherwith the device, this allows us to find the file on the filesystem.Example:
ino=131523 - Source context: Thecontext in which the process resides (the domain of the process). Example:
scontext=sysadm_u:sysadm_r:dmesg_t:s0-s0:c0.c1023 - Target context: Thecontext of the target resources. Example:
tcontext=system_u:object_r:etc_t:s0 - Object class: The class of the target object—for instance, a directory, file, socket, node, pipe, filedescriptor, filesystem, or capability. Example:
tclass=file - Permissive mode: The mode the domain was in when the action was executed. If set to
0, thenSELinux was in enforcing mode; otherwise, it was permissive (either for the system or for the given domain).Example:permissive=0
We can interpret the previous denial like so: SELinux has denied thedmesgcommand to read a file named “xterm-256color“. The file has inode number131523on device/dev/sdb2and is labeled asetc_t. Thedmesgcommand has PID12569and is labeled asdmesg_t. Thedmesg_tdomain was not in permissive mode.
Depending on the action and the target class, SELinux uses different fields to give all the informationwe need to troubleshoot a problem. Consider the following denial:
type=AVC msg=audit(03/22/20 18:12:52.177:2326): avc: denied { name_bind } for pid=15983 comm="nginx" src=89 scontext=system_u:system_r:httpd_t:s0 tcontext=system_u:object_r:reserved_port_t:s0 tclass=tcp_socket permissive=0The preceding denial came up because the nginx web server was configured to listen on a non-default port (89 instead of the default 80).
Identifying the problem is a matter of understanding how the operations work and properly reading the denials. The denial logs give us enough to get us started, giving a clear idea of what was denied.
Administrators might want to update the SELinux policy to allow a specific action (by adding anallowrule to the SELinux policy, as described further on in this book). This is, however, not always the right approach because other options exist and are usually better, such as these:
- Providing the right label on the target resource (usually the case when the target is a non-default port, non-default location, and so on)
- Switching Booleans (flags that manipulate the SELinux policy) to allow additional privileges
- Providing the right label on the source process (often the case when the acting application is not installed by the distribution package manager)
- Using the application as intended instead of through other means (as SELinux only allows expected behavior), such as starting a daemon through a service (
initscript or systemd unit) instead of through a command-line operation
If the preceding nginx example were a wanted configuration (using a non-default port), then we should label this port as a HyperText Transfer Protocol (HTTP) port and not allow the httpd_t domain to bind on (many) other ports.
Other SELinux-related event types
Although most SELinux log events are AVC-related, they aren’t the sole event types an administrator will have to deal with. Most audit events will show SELinux information as part of the event, even though SELinux has little to do with the event itself, but a few audit event types are directly concerned with SELinux.
Note:
A full list of all possible audit events is available in the linux/audit.h header file, located in /usr/include
USER_AVC
AUSER_AVCevent resembles regular AVC audit events, but now the source is a user spaceobject manager. These are applications that useSELinux policy rules, but they enforce these rules themselves rather than through the kernel.
The following example is such an event, generated by D-Bus:
type=USER_AVC msg=audit(03/22/2020 11:25:56.123:154) : pid=540 uid=dbus auid=unset ses=unset subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc: denied { acquire_svc } for service=com.redhat.tuned spid=1460 scontext=system_u:system_r:tuned_t:s0 tcontext=system_u:system_r:tunned_t:s0 tclass=dbus permissive=0 exe=/usr/bin/dbus-daemon sauid=dbus hostname=? addr=? terminal=?'The event has two parts. Everything up to the msg= string is information about the user space object manager that generated the event, and is the first part of the event. The true event itself (which is the second part) is stored within the msg= part and includes similar fields, as we already know from regular AVCs.
SELINUX_ERR
An SELINUX_ERR event comes up when SELinux detects a general policy violation rather than an access control violation. It cannot be resolved by SELinux policy writers by just allowing the operation. These events usually point to a misuse of applications and services that the policy is not tailored to accomplish, and an example is shown in the following code snippet:
type=PATH msg=audit(03/22/2020 12:25:53.104:2364) : item=0 name=/usr/sbin/rpc.nfsd inode=3019958 dev=08:12 mode=file,755 ouid=root ogid=root rdev=00:00 obj=system_u:object_r:nfsd_exec_t:s0 nametype=NORMAL cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=SELINUX_ERR msg=audit(03/22/2020 12:25:53.104:2364) : op=security_compute_sid invalid_context=sysadm_u:sysadm_r:nfsd_t:s0-s0:c0.c1023 scontext=sysadm_u:sysadm_r:sysadm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfsd_exec_t:s0 tclass=process In the preceding example, a user (running in the sysadm_t domain) was executing rpc.nfsd (with nfsd_exec_t as the label), and the policy wanted to transition to the nfsd_t domain. However, that resulted in a full context of sysadm_u:sysadm_r:nfsd_t:s0-s0:c0.c1023, which is not a valid context. The sysadm_r SELinux role does not support the nfsd_t domain.
MAC_POLICY_LOAD
A MAC_POLICY_LOAD event occurs whenever the system loads a new SELinux policy in memory. This occurs when the administrator loads a new or updated SELinux policy module, rebuilds the policy with the dontaudit rules disabled, or toggles an SELinux Boolean that the administrator wants to persist across reboots. Such an event is illustrated in the following code snippet:
type=MAC_POLICY_LOAD msg=audit(03/22/2020 12:28:17.077:2368) : auid=admin ses=1 lsm=selinux res=yesWhen a MAC_POLICY_LOAD event occurs, you might notice a subsequent USER_MAC_POLICY_LOAD event. This occurs when a user space object manager detects an update on the SELinux policy and takes action. Note that not all user space object managers will send out this event: some object managers will query the live policy and, as such, do not need to act when a new policy loads.
MAC_CONFIG_CHANGE
When anSELinux Boolean changes but doesn’t persist, then aMAC_CONFIG_CHANGEevent will be dispatched. This tells the administrator that the active policy has been instructed to change its behavior slightly, but within the bounds of the existing loaded policy. Such an event is illustrated in the following code snippet:
type=MAC_CONFIG_CHANGE msg=audit(03/22/2020 12:29:49.564:2370) : bool=virt_use_nfs val=0 old_val=1 auid=admin ses=1In the preceding example, the virt_use_nfs SELinux Boolean was changed from the value 1 (on) to 0 (off).
MAC_STATUS
A MAC_STATUS event shows up when the SELinux enforcement state has been changed. For instance, when an administrator uses setenforce 0 to put SELinux in permissive mode, then the following event occurs:
type=MAC_STATUS msg=audit(03/22/2020 12:30:45.200:2372) : enforcing=0 old_enforcing=1 auid=admin ses=1 enabled=1 old-enabled=1 lsm=selinux res=yesMAC_STATUS is also used to inform administrators when the SELinux state itself (enabled or disabled) is altered.
NetLabel events
NetLabel is aLinux kernel project to support labelednetwork packets, allowing security contexts such as SELinux contexts to be passed on between hosts. One of the protocols that the NetLabel implementationsupports in Linux isCommon IP Security Option(CIPSO) labeling.
The following audit events are related to the NetLabel capability:
MAC_UNLBL_STCADDandMAC_UNLBL_STCDELevents are triggered when a static label is added or removed. Static labeling means that if a packet is received or sent and it does not have a label, then this “default” static label is assigned.MAC_MAP_ADDandMAC_MAP_DELevents are triggered when a mapping between a labeling protocol (such as CIPSO) and its parameters against an LSM (SELinux) domain is added or removed from the configuration.MAC_CIPSOV4_ADDandMAC_CIPSOV4_DELevents are triggered when a CIPSO (IPv4) configuration is added or removed.
Labeled IPsec events
Anotherlabeled network protocol that Linux supportsislabeled IPsec, whereIPsecis short forInformation Protocol Security. Through this, the SELinux context of the source process (which iscommunicating over the IPsec tunnel toward a target resource) is known by the IPsec daemons at both ends of the tunnel. Furthermore, SELinux will contain rules about which domains can communicate over an IPsec tunneland which domains can communicatewith each other network-wise.
The following audit events are related to IPsec:
MAC_IPSEC_ADDSAandMAC_IPSEC_DELSAevents are used when a security association is added or removed (new IPsec tunnels are defined or deleted).MAC_IPSEC_ADDSPDandMAC_IPSEC_DELSPDevents are used when a security policy definition is added or removed. Security policies generally describe whether network packets need to be handled by IPsec and, if so, through which security association.- A
MAC_IPSEC_EVENTevent is a generic event for IPsec audit messages.
Using ausearch
Theausearchcommand, partof the Linux audit framework, is a frequently used command for querying audit events stored on the system. We already briefly covered it when taking a first look at an AVC denial, but only briefly mentioning it won’t do it justice.
Withausearch, we can search for events that originated during or after a selected time period. We used the-ts recent(time start) option in the past, which displays events that occurred during the past 10 minutes. The argument can also be a timestamp. Other supported shorthand values are listed as follows:
today, meaning starting at 1 second past midnight on the current dayyesterday, meaning starting at 1 second past midnight the previous daythis-week,this-month, orthis-year, meaning starting at 1 second past midnight on the first day of the current week, current month, or current yearcheckpoint, which uses the timestamp mentioned in a checkpoint file created in a previous runboot, which implies only events since the system booted should be shownweek-ago, meaning starting at 1 second after midnight exactly 7 days ago
The use of checkpoint is particularly useful when troubleshooting SELinux issues as it allows us to show denials (and other SELinux events) since the last invocation of the ausearch command. This is illustrated in the following code snippet:
# ausearch --checkpoint /root/ausearch-checkpoint.txt -ts checkpointThis allows administrators to perform minor tweaks and reproduce the problem and only see the events since then, instead of going through all events over and over again.
By default, theausearchcommand displays all events stored in the audit log. On busy systems, this can be very verbose and may result in unwanted events being displayed as well. Luckily, users can limit the type of events queried through theausearchcommand.
For SELinuxtroubleshooting, usingavc,user_avc,selinux_errlimits the events nicely to those needed for the job, as illustrated in the following code snippet:
# ausearch -m avc,user_avc,selinux_err -ts recentIf the numeric display of fields such as user IDs and timestamps is too confusing, then it is possible forausearchto look up and translate user IDs to usernames and timestamps to formatted time fields. Add the-ioption toausearchto have it interpret these fields and display the interpreted values instead.
In this article, we’ve seen how SELinux notifies the system about its actions through log events, and where these log events are stored. In the next section, we’ll look at how to act upon these events.
