Auditd Daemon

The audit daemon is a simplified version of its desktop
counterpart designed to gather the audit logs from the
audit kernel subsystem. The audit subsystem of the kernel
includes Linux Security Modules (LSM) messages as well.

To enable the audit subsystem, you must add this to your
kernel config:
CONFIG_AUDIT=y

To enable a LSM, you must consult that LSM's documentation, the
example below is for SELinux:
CONFIG_SECURITY_SELINUX=y

This does not include possible dependencies that may need to be
satisfied for that particular LSM.

# Log Compression instead of Chatty in Android S

## The problem

* Log buffer space is precious, but suffers from the tragedy of the commons
* Log spam fills the buffers making them less useful in logcat/bugreports
* “Spam” is often in the eye of the beholder: which messages are important depends on what you’re trying to debug

## The idea

* Chatty isn’t helping as much as we’d hoped, and is surprisingly expensive
* Compress logs to make more efficient use of the buffer
* Address the root cause of log spam at its source:
    * Do not hide log spam at runtime, which de-incentivize fixes
    * Add presubmit coverage similar to SELinux violations to keep log spam down

---

## Chatty in Theory

* Delete messages classified as spam to extend the range of logs from other sources
* “Spam” defined as:
    * Logs from UIDs whose logs consume over 12.5% of a log buffer
    * Back-to-back exact duplicate messages

## Chatty in Practice

* Developer confusion about missing and de-duplicated logs
* Lowered incentive to fix the root cause of bad logging behavior
* High CPU overhead
* Memory usage greatly exceeds configured buffer size
* Only marginal increase in log range

---

## Log Compression in Theory

* Store many more logs in the same log buffer size => better for diagnosis
* Memory usage stays below configured log size => better system health
* No gaps in logs, no de-duplicated logs => no developer confusion
* No hiding bad behavior => increased accountability/incentive to fix root causes

## Log Compression Preliminary Results

* Captured 2, 5 day periods of full time personal usage of Pixel 4 and replayed the logs offline
* Compression vs Chatty:
    * **3.5x more log messages on average**
    * **50% less CPU usage**
    * **50% less memory usage**

---

## Log Messages in 1MB

* The number of log messages still available in logcat after ‘Message Count’ messages have been logged to a 1MB log buffer
* Note: ‘Simple’ is the Chatty code without log spam detection and without de-duplication.

![Total Log Count](doc_images/total_log_count.png)

---

## CPU Time

* Total CPU time on ARM64 (Walleye) and 32bit x86 (Cuttlefish)
* X axis represents different log buffer size configurations.
    * Chatty uses significantly more CPU time at 1MB (the default Pixel configuration)
    * Chatty scales poorly with increased log buffer sizes
* Note: “simple” isn’t “compression without actually compressing”, it’s “chatty without doing the chatty elimination”, which is why “simple” is more expensive than “compression” on walleye.

![CPU Time Walleye](doc_images/cpu_walleye.png)
![CPU Time Cuttlefish](doc_images/cpu_cuttlefish.png)

---

## Memory Usage

* The memory used by ‘Message Count’ messages, on both Walleye and Cuttlefish
* Note: Chatty does not consider the metadata (UID, PID, timestamp, etc) in its calculation of log buffer size, so a 1MB log buffer will consume more than 1MB.  Note that there are 8 log buffers, 5 of which are typically filled.

![Memory Usage](doc_images/memory_usage.png)

The properties that logd and friends react to are:

name                       type default  description
ro.logd.auditd             bool   true   Enable selinux audit daemon
ro.logd.auditd.dmesg       bool   true   selinux audit messages sent to dmesg.
ro.logd.auditd.main        bool   true   selinux audit messages sent to main.
ro.logd.auditd.events      bool   true   selinux audit messages sent to events.
persist.logd.security      bool   false  Enable security buffer.
ro.organization_owned      bool   false  Override persist.logd.security to false
ro.logd.kernel             bool  svelte+ Enable klogd daemon
logd.statistics            bool  svelte+ Enable logcat -S statistics.
ro.debuggable              number        if not "1", logd.statistics &
                                         ro.logd.kernel default false.
logd.logpersistd.enable    bool   auto   Safe to start logpersist daemon service
logd.logpersistd          string persist Enable logpersist daemon, "logcatd"
                                         turns on logcat -f in logd context.
					 Responds to logcatd, clear and stop.
logd.logpersistd.buffer          persist logpersistd buffers to collect
logd.logpersistd.size            persist logpersistd size in MB
logd.logpersistd.rotate_kbytes   	 persist logpersistd outout file size in KB.
persist.logd.logpersistd   string        Enable logpersist daemon, "logcatd"
                                         turns on logcat -f in logd context.
persist.logd.logpersistd.buffer    all   logpersistd buffers to collect
persist.logd.logpersistd.size      256   logpersistd size in MB
persist.logd.logpersistd.count     256   sets max number of rotated logs to <count>.
persist.logd.logpersistd.rotate_kbytes   1024  logpersistd output file size in KB
persist.logd.size          number  ro    Global default size of the buffer for
                                         all log ids at initial startup, at
                                         runtime use: logcat -b all -G <value>
ro.logd.size               number svelte default for persist.logd.size. Larger
                                         platform default sizes than 256KB are
                                         known to not scale well under log spam
                                         pressure. Address the spam first,
                                         resist increasing the log buffer.
persist.logd.size.<buffer> number  ro    Size of the buffer for <buffer> log
ro.logd.size.<buffer>      number svelte default for persist.logd.size.<buffer>
ro.config.low_ram          bool   false  if true, logd.statistics,
                                         ro.logd.kernel default false,
                                         logd.size 64K instead of 256K.
persist.logd.filter        string        Pruning filter to optimize content.
                                         At runtime use: logcat -P "<string>"
ro.logd.filter       string "~! ~1000/!" default for persist.logd.filter.
                                         This default means to prune the
                                         oldest entries of chattiest UID, and
                                         the chattiest PID of system
                                         (1000, or AID_SYSTEM).
log.tag                   string persist The global logging level, VERBOSE,
                                         DEBUG, INFO, WARN, ERROR, ASSERT or
                                         SILENT. Only the first character is
                                         the key character.
persist.log.tag            string build  default for log.tag
log.tag.<tag>             string persist The <tag> specific logging level.
persist.log.tag.<tag>      string build  default for log.tag.<tag>

logd.buffer_type           string (empty) The log buffer type: 'simple' or
                                          'serialized' (default: 'serialized').

NB:
- auto - managed by /init
- svelte - see ro.config.low_ram for details.
- svelte+ - If empty, default to true if `ro.config.low_ram == false && ro.debuggable == true`
- ro - <base property> temporary override, ro.<base property> platform default.
- persist - <base property> override, persist.<base property> platform default.
- build - VERBOSE for native, DEBUG for jvm isLoggable, or developer option.
- number - support multipliers (K or M) for convenience. Range is limited
  to between 64K and 256M for log buffer sizes. Individual log buffer ids
  such as main, system, ... override global default.
- Pruning filter rules are specified as UID, UID/PID or /PID. A '~' prefix indicates that elements
  matching the rule should be pruned with higher priority otherwise they're pruned with lower
  priority. All other pruning activity is oldest first. Special case ~! represents an automatic
  pruning for the noisiest UID as determined by the current statistics.  Special case ~1000/!
  represents pruning of the worst PID within AID_SYSTEM when AID_SYSTEM is the noisiest UID.

logd can record and replay log messages for offline analysis.

Recording Messages
------------------

logd has a `RecordingLogBuffer` buffer that records messages to /data/misc/logd/recorded-messages.
It stores messages in memory until that file is accessible, in order to capture all messages since
the beginning of boot.  It is only meant for logging developers to use and must be manually enabled
in by adding `RecordingLogBuffer.cpp` to `Android.bp` and setting
`log_buffer = new SimpleLogBuffer(&reader_list, &log_tags, &log_statistics);` in `main.cpp`.

Recording messages may delay the Log() function from completing and it is highly recommended to make
the logd socket in `liblog` blocking, by removing `SOCK_NONBLOCK` from the `socket()` call in
`liblog/logd_writer.cpp`.

Replaying Messages
------------------

Recorded messages can be replayed offline with the `replay_messages` tool.  It runs on host and
device and supports the following options:

1. `interesting` - this prints 'interesting' statistics for each of the log buffer types (simple,
   serialized).  The statistics are:
    1. Log Entry Count
    2. Size (the uncompressed size of the log messages in bytes)
    3. Overhead (the total cost of the log messages in memory in bytes)
    4. Range (the range of time that the logs cover in seconds)
2. `memory_usage BUFFER_TYPE` - this prints the memory usage (sum of private dirty pages of the
  `replay_messages` process).  Note that the input file is mmap()'ed as RO/Shared so it does not
  appear in these dirty pages, and a baseline is taken before allocating the log buffers, so only
  their contributions are measured.  The tool outputs the memory usage every 100,000 messages.
3. `latency BUFFER_TYPE` - this prints statistics of the latency of the Log() function for the given
  buffer type.  It specifically prints the 1st, 2nd, and 3rd quartiles; the 95th, 99th, and 99.99th
  percentiles; and the maximum latency.
4. `print_logs BUFFER_TYPE [buffers] [print_point]` - this prints the logs as processed by the given
  buffer_type from the buffers specified by `buffers` starting after the number of logs specified by
  `print_point` have been logged.  This acts as if a user called `logcat` immediately after the
  specified logs have been logged.  It additionally prints the statistics from `logcat -S` after the
  logs.
  `buffers` is a comma separated list of the numeric buffer id values from `<android/log.h>`.  For
  example, `0,1,3` represents the main, radio, and system buffers.  It can can also be `all`.
  `print_point` is an positive integer.  If it is unspecified, logs are printed after the entire
  input file is consumed.
5. `nothing BUFFER_TYPE` - this does nothing other than read the input file and call Log() for the
  given buffer type.  This is used for profiling CPU usage of strictly the log buffer.