RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1496176 - Format of docker audit log is malformed
Summary: Format of docker audit log is malformed
Keywords:
Status: CLOSED EOL
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: docker-latest
Version: 7.4
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Tom Sweeney
QA Contact: atomic-bugs@redhat.com
Maxim Svistunov
URL:
Whiteboard:
Depends On:
Blocks: 1523470
TreeView+ depends on / blocked
 
Reported: 2017-09-26 15:23 UTC by Josef Karasek
Modified: 2019-04-10 13:03 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Release Note
Doc Text:
The hostname field in the audit log had a '?' instead of the containers id or hostname in it. This has been corrected. In addition a new field ctr_id_short in the audit log now shows the 12 character version of the container when the log entry involves a container operation.
Clone Of:
Environment:
Last Closed: 2019-04-10 13:03:06 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Josef Karasek 2017-09-26 15:23:21 UTC
Description of problem:
Current format of audit logs is extremely difficult to consume.
Some keys are duplicates and some are misleading - they match
to wrong keys in the linux-audit dictionary[1].

Version-Release number of selected component (if applicable):


How reproducible:
Always


Steps to Reproduce:
1. sudo tail -f /var/log/audit/audit.log
2. issue some run command, e.g. docker run --rm centos sleep 1
3.

Actual results:
type=VIRT_CONTROL msg=audit(1506438193.448:1155): pid=1182 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:container_runtime_t:s0 msg='reason=api hostname=b73554cf14b9 op=start vm=centos:7 vm-pid=0 user=origin auid=1000 exe=sleep  exe="/usr/bin/dockerd-current" hostname=? addr=? terminal=? res=success'

JSON generated by aushape:
{
    "serial":1155,
    "time":"2017-09-26T17:03:13.448+02:00",
    "data":{
        "virt_control":{
            "pid":["1182"],
            "uid":["root","0"],
            "auid":["unset","4294967295"],
            "ses":["unset","4294967295"],
            "subj":["system_u:system_r:container_runtime_t:s0"],
            "reason":["api"],
            "hostname":["b73554cf14b9"],
            "op":["start"],
            "vm":["�"],
            "vm-pid":["0"],
            "user":["origin"],
            "auid":["origin","1000"],
            "exe":["sleep"],
            "exe":["/usr/bin/dockerd-current"],
            "hostname":["?"],
            "addr":["?"],
            "terminal":["?"],
            "res":["success"]
        }
    }
}


Expected results:
Parseable document, where keys are unique and correspond with the audit dictionary.

Additional info:
[1] https://github.com/linux-audit/audit-documentation/blob/master/specs/fields/field-dictionary.csv
https://github.com/linux-audit/audit-documentation/wiki/SPEC-Virtualization-Manager-Guest-Lifecycle-Events
https://libvirt.org/auditlog.html
https://github.com/Scribery/aushape

Comment 2 Josef Karasek 2017-10-10 12:20:01 UTC
Additional notes:

*On rhel7.4 docker-1.12.6-55.gitc4618fb.el7.x86_64, the `msg.hostname` field is never set. Its value is always '?'. In both (ambiguous) occurrences.

*On fedora 26 docker-1.13.1-22.gitb5e3294.fc26.x86_64 the first `msg.hostname` field contains container id. Knowing on which container given action occurred is crucial for our cause.

Comment 3 Josef Karasek 2017-10-11 08:50:42 UTC
Ideally we would be able to consume something like this from audit logs:
'{
  "time": "2017-09-25T06:45:23.246000+00:00",
  "systemd": {
    "t": {
      "PID": "1182",
      "UID": "0",
      "AUDIT_LOGINUID": "4294967295",
      "AUDIT_SESSION": "4294967295",
      "SELINUX_CONTEXT": "system_u:system_r:container_runtime_t:s0",
      "EXE": "\"/usr/bin/dockerd-current\""
    }
  },
  "docker": {
    "sauid": "1000",
    "container_id_short": "1235c5a6476b",
    "container_image": "centos:7",
    "pid": "10657",
    "user": "origin",
    "reason": "api",
    "operation": "resize",
    "result": "success",
    "command": "sleep"
  }
}'

Comment 4 Daniel Walsh 2017-10-11 12:02:52 UTC
Tom can you take a look at this?

Comment 5 Tom Sweeney 2017-10-16 19:29:13 UTC
I'm still looking at this, but I think this is not a RHEL Docker issue, but instead a Docker/Docker configuration issue.  I've seen this same issue on Fedora and Ubuntu.  Here's an Ubuntu snippet from audit.log:

type=PROCTITLE msg=audit(1508177281.669:88): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F
type=USER_END msg=audit(1508177281.733:89): pid=3962 uid=0 auid=1000 ses=1 msg='op=PAM:session_close acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/tty1 res=success'
type=CRED_DISP msg=audit(1508177281.733:90): pid=3962 uid=0 auid=1000 ses=1 msg='op=PAM:setcred acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/tty1 res=success'

I don't know if/how you can configure docker to make more detailed used of the audit.log, but I am going to dig further.  To date I've not had much luck finding relative information about this in the Docker documents.

Comment 8 Josef Karasek 2017-12-11 12:02:12 UTC
This definitely is a bug - docker audit log component outputs a '?' (question mark) in stead of container ID. Thus the value of audit logs is minimal - there is no way how to tie these log messages to their origin.

I suspect this variable[0] is never set, even though docker daemon knows ID's of container it's running.

[0] https://github.com/projectatomic/docker/blob/docker-1.12.6/api/server/middleware/audit_linux.go#L279

Comment 9 Daniel Walsh 2017-12-11 18:17:19 UTC
Tom can you look at adding the container id to the audit log?

Comment 10 Jeff Cantrill 2018-01-08 15:49:46 UTC
Dan, bump....to see if anyone has investigated.

Comment 11 Daniel Walsh 2018-01-08 16:13:29 UTC
I have asked Tom to look into this.  I just pinged him via email and will raise the priority.

Comment 12 Tom Sweeney 2018-01-09 23:20:45 UTC
Just a quick update.  I unfortunately had an issue with my build/test environment that took a while to fix.  I've just done so and it looks like the parsing that pulls out the containerID from the passed in URL is not working.  The container that is passed into the audit logging routine from that parsing is always nil, thus the "?".

I'm finally set to make some progress debugging, hope to have a better update tomorrow.

Comment 13 Tom Sweeney 2018-01-10 20:37:36 UTC
I found the issue.  Long story short we were initializing the pointer to the Docker daemon that the Audit logging was using after we initialized Audit logging itself.  So Audit was never able to resolve the containers.

I think most of the fields that you need are now taken care of.  If you find otherwise, please let us know.

FYI, the PR is at:  https://github.com/projectatomic/docker/pull/292.  This is aimed for Docker 1.12.6, I'll add the change to 1.13 after this one makes it's ways through the review process.

Comment 14 Tom Sweeney 2018-01-13 20:51:23 UTC
Added 3 more PRs.  Two to make the change in docker-1.13.1 and another for docker-1.13.1-rhel.  The third tweaks dockerd/daemon.go to have the audit initialization code be similar in all three versions.  No functional change for the 3rd one.

https://github.com/projectatomic/docker/pull/293
https://github.com/projectatomic/docker/pull/294
https://github.com/projectatomic/docker/pull/295

Comment 15 Lokesh Mandvekar 2019-04-10 13:03:06 UTC
docker-latest is EOL. Closing...


Note You need to log in before you can comment on or make changes to this bug.