You CAN Make the Logs' Format Worse?!

Most of my customers have security compliance mandates that makes it necessary to offload their Linux auditd event-logs to an external/centralized logging-destination. One of my customers leverages a third-party tool to offload their EC2 logs directly to S3. However, because they use a common compliance-framework to guide their EC2s' hardening configurations, they had been configuring their systems to use the "normal" auditd dispatch plugin service, audisp. Unfortunately, prior my arrival, no one had actually bothered to validate their auditing configuration. Turns out, audisp was trying to off-host the event logs to a non-existent, centralized event-collector that didn't actually exist.

My "solution" to their problem was to simply eliminate the CM-automation that sets up the errant event-offloading. However, before I could suggest summarily nuking this automation-content, I had to verify that their S3-based logging solution was actually working. So, decided to cobble together a quick-n-dirty AWS CLI command – because their log-stream names are the same as the associated EC2s' instance-IDs, doing the quick test was easy:

$ aws logs filter-log-events\
  --log-group-name  \
  --log-stream-names $(
    curl -s http://169.254.169.254/latest/meta-data/instance-id
  )   --start-time $(
    date -d '-15 minutes' '+%s%N' | \
    cut -b 1-13
  )

To explain the above - particularly the nested subshells…

Executing:

curl -s http://169.254.169.254/latest/meta-data/instance-id

Makes use of the EC2 metadata service to return the EC2s own AWS instance-ID. Because it's being executed in a subshell – using the $( COMMAND ) notation – The instance's ID is returned as the value fed to the `--log-stream-names` command-option.

Similarly, executing:

date -d '-15 minutes' '+%s%N' | cut -b 1-13

Makes use of the `date` command to return an `aws logs` compatible time specification for use by the --start-time command-option. Specifically, it tells the date command, "take the time 15 minutes ago and convert it to milliseconds since epoch-time. Because the time-shifted, date-string is longer than what the  `aws logs` command-option expects, we use the `cut` command to truncate it to a compatible length. Ultimately, this will return output similar to:

{
  "logStreamName": "i-0a8b14c42b651476f",
  "timestamp": 1664815386793,
  "message": "{\"a0\":\"b75480\",\"a1\":\"0\",\"a2\":\"0\",\"a3\":\"7ffeb692d220\",\"arch\":\"c000003e\",\"auid\":\"239203505\",\"az\":\"us-gov-west-1a\",\"comm\":\"vim\",\"ec2_instance_id\":\"i-0a8b14c42b651476f\",\"egid\":\"239203505\",\"euid\":\"239203505\",\"exe\":\"/usr/bin/vim\",\"exit\":\"0\",\"fsgid\":\"239203505\",\"fsuid\":\"239203505\",\"gid\":\"239203505\",\"items\":\"2\",\"key\":\"delete\",\"log_file\":\"/var/log/audit/audit.log\",\"node\":\"ip-10-244-0-100.dev.ac2sp.army.mil\",\"pid\":\"10503\",\"ppid\":\"3961\",\"ses\":\"3\",\"sgid\":\"239203505\",\"subj\":\"staff_u:staff_r:staff_t:s0-s0:c0.c1023\",\"success\":\"yes\",\"suid\":\"239203505\",\"syscall\":\"84\",\"tty\":\"pts1\",\"type\":\"SYSCALL\",\"uid\":\"239203505\"}",
  "ingestionTime": 1664815388879,
  "eventId": "37126623743463896942643741908611915331411397433463734292"
}

Kind of horrible. But, you can extract the actual message payload with a tool like `jq` which will give you output like:

{
    "a0": "b75480",
    "a1": "0",
    "a2": "0",
    "a3": "7ffeb692d220",
    "arch": "c000003e",
    "auid": "239203505",
    "az": "us-gov-west-1a",
    "comm": "vim",
    "ec2_instance_id": "i-0a8b14c42b651476f",
    "egid": "239203505",
    "euid": "239203505",
    "exe": "/usr/bin/vim",
    "exit": "0",
    "fsgid": "239203505",
    "fsuid": "239203505",
    "gid": "239203505",
    "items": "2",
    "key": "delete",
    "log_file": "/var/log/audit/audit.log",
    "node": "ip-10-244-0-100.dev.ac2sp.army.mil",
    "pid": "10503",
    "ppid": "3961",
    "ses": "3",
    "sgid": "239203505",
    "subj": "staff_u:staff_r:staff_t:s0-s0:c0.c1023",
    "success": "yes",
    "suid": "239203505",
    "syscall": "84",
    "tty": "pts1",
    "type": "SYSCALL",
    "uid": "239203505"
}

Yeah… If you're familiar with audit.log output, that ain't normally what it looks like. Here, the OS's event-data has been intermingled with the CSP's event log-tracking data. Not great. Not something you can feed "as-is" to generic tools that expect to directly interact with auditd data (e.g., the tools in the policyutils RPMs). But, you can write filters to get it back into a tool-compatible format. But still, it manages to make an ugly log format markedly-uglier to deal with. So, uh, congratulations?