containers / podman

Podman: A tool for managing OCI containers and pods.
https://podman.io
Apache License 2.0
23.83k stars 2.42k forks source link

Healthchecks create vast volumes of audit entries under CIS rules for deletions #18380

Open nikgoodley-ibboost opened 1 year ago

nikgoodley-ibboost commented 1 year ago

Issue Description

The healthchecks (and conmon?) seem to be attempting invalid delete syscalls every iteration of the healthcheck. The adds a fair amount of noise (around 40% more) entries into /var/log/audit/audit.log with hundreds of MB of log entries per day for only one single basic healthcheck running on a 5s interval.

This may seem pedantic but due to established security audit rules it adds up to a lot of volume. We follow Linux hardening practices, which includes the following audit rules (as referenced, for example in the CIS RHEL audit rules https://www.tenable.com/audits/items/CIS_Red_Hat_EL7_STIG_v2.0.0_STIG.audit:41df435215c6a2bb28dc7d7665c637d9)

-a always,exit -F arch=b64 -S unlink -S unlinkat -S rename -S renameat -F auid>=1000 -F auid!=4294967295 -k delete
-a always,exit -F arch=b32 -S unlink -S unlinkat -S rename -S renameat -F auid>=1000 -F auid!=4294967295 -k delete

Whilst this is always going to be quite heavy in some situations, with most applications it's not material, and if a file has to be deleted, that's just how it is. However as 5 of of the audit entries every cycle actually relate to unsuccessful deletes for non-existent files, operations not expecting a directory and non-empty directories, it's hinting that a lot of the volume might be avoided by checking the state of the target directory/file. Of course generally minimising the footprint under typical CIS rules would be very much appreciated, but it's the volume of unsuccessful calls that caught the eye.

There seem to be two separate aspects with conmon and podman healthcheck both trying to delete a directory based on a UUID that is created but apparently deleted by some other step (presumably?). Later audit entries indicate things are cleaned up though the sequence isn't obvious to me.

Steps to reproduce the issue

Steps to reproduce the issue

  1. Using a basic RHEL 9.1 or equivalent distro, like AlmaLinux, install podman. For example, in AWS eu-west-2, using the AlmaLinux AMI ami-0287f6265489f6488
  2. Add in audit rules for deletes and reboot/restart auditd, e.g.
    -a always,exit -F arch=b64 -S unlink -S unlinkat -S rename -S renameat -F auid>=1000 -F auid!=4294967295 -k delete
    -a always,exit -F arch=b32 -S unlink -S unlinkat -S rename -S renameat -F auid>=1000 -F auid!=4294967295 -k delete
  3. As a non-root user run a container with a basic healthcheck, like podman run -itd --rm --name=busy --healthcheck-command '/bin/sh -c "hostname"' --healthcheck-interval 5s busybox
  4. Look at the recent delete calls e.g. for non-successful ones ausearch --start today -m syscall -sv no -i | tail -200

Describe the results you received

This is the interpreted audit output every healthcheck cycle (i.e. every 5 seconds in this example repro case).

The entries in audit.log create upwards of half a gigabute of log, per 5s-interval container healthcheck, per day.


type=PROCTITLE msg=audit(04/27/23 13:46:15.956:444) : proctitle=/usr/bin/conmon --api-version 1 -c ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9 -u fe34e2fa1292f0b16d7ab56c2
type=PATH msg=audit(04/27/23 13:46:15.956:444) : item=0 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/fe34e2fa1292f0b16d7ab56c250f9afc7ccb57d06c1f9a84be4d4da52670a974/ inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 13:46:15.956:444) : cwd=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/fe34e2fa1292f0b16d7ab56c250f9afc7ccb57d06c1f9a84be4d4da52670a974
type=SYSCALL msg=audit(04/27/23 13:46:15.956:444) : arch=x86_64 syscall=unlink success=no exit=ENOENT(No such file or directory) a0=0x55e468f04540 a1=0x80805 a2=0x0 a3=0x20 items=1 ppid=784 pid=12917 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=conmon exe=/usr/bin/conmon subj=unconfined_u:system_r:container_runtime_t:s0 key=delete
----
type=PROCTITLE msg=audit(04/27/23 13:46:15.977:447) : proctitle=/usr/bin/podman healthcheck run ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9
type=PATH msg=audit(04/27/23 13:46:15.977:447) : item=1 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/fe34e2fa1292f0b16d7ab56c250f9afc7ccb57d06c1f9a84be4d4da52670a974 inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=DELETE cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=PATH msg=audit(04/27/23 13:46:15.977:447) : item=0 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/ inode=3152623 dev=103:02 mode=dir,700 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 13:46:15.977:447) : cwd=/home/ec2-user
type=SYSCALL msg=audit(04/27/23 13:46:15.977:447) : arch=x86_64 syscall=unlinkat success=no exit=EISDIR(Is a directory) a0=AT_FDCWD a1=0xc000b96d00 a2=0x0 a3=0x7fd3dc0f0e98 items=2 ppid=784 pid=12907 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=podman exe=/usr/bin/podman subj=unconfined_u:system_r:container_runtime_t:s0-s0:c0.c1023 key=delete
----
type=PROCTITLE msg=audit(04/27/23 13:46:15.977:448) : proctitle=/usr/bin/podman healthcheck run ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9
type=PATH msg=audit(04/27/23 13:46:15.977:448) : item=1 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/fe34e2fa1292f0b16d7ab56c250f9afc7ccb57d06c1f9a84be4d4da52670a974 inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=DELETE cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=PATH msg=audit(04/27/23 13:46:15.977:448) : item=0 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/ inode=3152623 dev=103:02 mode=dir,700 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 13:46:15.977:448) : cwd=/home/ec2-user
type=SYSCALL msg=audit(04/27/23 13:46:15.977:448) : arch=x86_64 syscall=unlinkat success=no exit=ENOTEMPTY(Directory not empty) a0=AT_FDCWD a1=0xc000b96dd0 a2=0x200 a3=0x7fd3dc0f0e98 items=2 ppid=784 pid=12907 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=podman exe=/usr/bin/podman subj=unconfined_u:system_r:container_runtime_t:s0-s0:c0.c1023 key=delete
----
type=PROCTITLE msg=audit(04/27/23 13:46:15.977:449) : proctitle=/usr/bin/podman healthcheck run ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9
type=PATH msg=audit(04/27/23 13:46:15.977:449) : item=1 name=fe34e2fa1292f0b16d7ab56c250f9afc7ccb57d06c1f9a84be4d4da52670a974 inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=DELETE cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=PATH msg=audit(04/27/23 13:46:15.977:449) : item=0 name=/home/ec2-user inode=3152623 dev=103:02 mode=dir,700 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 13:46:15.977:449) : cwd=/home/ec2-user
type=SYSCALL msg=audit(04/27/23 13:46:15.977:449) : arch=x86_64 syscall=unlinkat success=no exit=EISDIR(Is a directory) a0=0xb a1=0xc00015c640 a2=0x0 a3=0x7fd403f11c58 items=2 ppid=784 pid=12907 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=podman exe=/usr/bin/podman subj=unconfined_u:system_r:container_runtime_t:s0-s0:c0.c1023 key=delete
----
type=PROCTITLE msg=audit(04/27/23 13:46:15.977:450) : proctitle=/usr/bin/podman healthcheck run ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9
type=PATH msg=audit(04/27/23 13:46:15.977:450) : item=1 name=exit inode=1111787 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=DELETE cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=PATH msg=audit(04/27/23 13:46:15.977:450) : item=0 name=/home/ec2-user inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 13:46:15.977:450) : cwd=/home/ec2-user
type=SYSCALL msg=audit(04/27/23 13:46:15.977:450) : arch=x86_64 syscall=unlinkat success=no exit=EISDIR(Is a directory) a0=0xc a1=0xc0009fa640 a2=0x0 a3=0x7fd3d6336b90 items=2 ppid=784 pid=12907 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=podman exe=/usr/bin/podman subj=unconfined_u:system_r:container_runtime_t:s0-s0:c0.c1023 key=delete

For conmon it seems to be looking for a UUID that exists transiently, i.e. repeatedly listingn the directory shows this did exist for a second

[ec2-user@ip-10-155-125-196 ~]$ ll /home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/
total 12
drwxr-xr-x. 3 ec2-user ec2-user   118 Apr 27 14:09 0abc0f1adc219cfc704628b52bad7ba570e200a5b9efe3251beab6ae3dc8118f
drwxr-xr-x. 2 ec2-user ec2-user     6 Apr 27 13:36 artifacts
srwx------. 1 ec2-user ec2-user     0 Apr 27 13:36 attach
-rw-r--r--. 1 ec2-user ec2-user 11169 Apr 27 13:36 config.json
prw-r--r--. 1 ec2-user ec2-user     0 Apr 27 13:36 ctl
drwxr-xr-x. 2 ec2-user ec2-user     6 Apr 27 13:36 secrets
drwx------. 2 ec2-user ec2-user     6 Apr 27 13:36 shm
prw-r--r--. 1 ec2-user ec2-user     0 Apr 27 13:36 winsz
[ec2-user@ip-10-155-125-196 ~]$ ll /home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/
total 12
drwxr-xr-x. 2 ec2-user ec2-user     6 Apr 27 13:36 artifacts
srwx------. 1 ec2-user ec2-user     0 Apr 27 13:36 attach
-rw-r--r--. 1 ec2-user ec2-user 11169 Apr 27 13:36 config.json
prw-r--r--. 1 ec2-user ec2-user     0 Apr 27 13:36 ctl
drwxr-xr-x. 2 ec2-user ec2-user     6 Apr 27 13:36 secrets
drwx------. 2 ec2-user ec2-user     6 Apr 27 13:36 shm
prw-r--r--. 1 ec2-user ec2-user     0 Apr 27 13:36 winsz

but audit suggests it's trying to delete it after its gone

----
type=PROCTITLE msg=audit(04/27/23 14:09:04.005:4580) : proctitle=/usr/bin/conmon --api-version 1 -c ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9 -u 0abc0f1adc219cfc704628b52
type=PATH msg=audit(04/27/23 14:09:04.005:4580) : item=0 name=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/0abc0f1adc219cfc704628b52bad7ba570e200a5b9efe3251beab6ae3dc8118f/ inode=39421 dev=103:02 mode=dir,755 ouid=ec2-user ogid=ec2-user rdev=00:00 obj=unconfined_u:object_r:data_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0
type=CWD msg=audit(04/27/23 14:09:04.005:4580) : cwd=/home/ec2-user/.local/share/containers/storage/overlay-containers/ac5742f1b5277fbca8e9aaad4c0b9a390dfac56909eb007269712ff1a7dd14d9/userdata/0abc0f1adc219cfc704628b52bad7ba570e200a5b9efe3251beab6ae3dc8118f
type=SYSCALL msg=audit(04/27/23 14:09:04.005:4580) : arch=x86_64 syscall=unlink success=no exit=ENOENT(No such file or directory) a0=0x558ed116d540 a1=0x80805 a2=0x0 a3=0x20 items=1 ppid=784 pid=16325 auid=ec2-user uid=ec2-user gid=ec2-user euid=ec2-user suid=ec2-user fsuid=ec2-user egid=ec2-user sgid=ec2-user fsgid=ec2-user tty=(none) ses=2 comm=conmon exe=/usr/bin/conmon subj=unconfined_u:system_r:container_runtime_t:s0 key=delete

Describe the results you expected

I expect containers running, essentially at idle, even with healthchecks to not create vast amounts of audit logs, or if it is to attempt to delete files, for them to be confirmed valid targets before attempting (if this is the reason for the multiple failed syscalls).

Given the need to run in compliant secure environments it would be much appreciated if the footprint of the healthchecks could be minimised.

podman info output

podman info
host:
  arch: amd64
  buildahVersion: 1.27.3
  cgroupControllers:
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-2.1.4-1.el9.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.4, commit: 24a4eb8c5272ea46c28889a24fc0a9ba1f4b0c74'
  cpuUtilization:
    idlePercent: 97.31
    systemPercent: 0.61
    userPercent: 2.08
  cpus: 2
  distribution:
    distribution: '"almalinux"'
    version: "9.1"
  eventLogger: journald
  hostname: ip-10-155-125-196.eu-west-2.compute.internal
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
  kernel: 5.14.0-162.6.1.el9_1.x86_64
  linkmode: dynamic
  logDriver: journald
  memFree: 3339182080
  memTotal: 4038189056
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun-1.5-1.el9.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.5
      commit: 54ebb8ca8bf7e6ddae2eb919f5b82d1d96863dea
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    path: /run/user/1000/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: true
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns-1.2.0-2.el9_0.x86_64
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.4.0
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.5.2
  swapFree: 0
  swapTotal: 0
  uptime: 0h 39m 37.00s
plugins:
  authorization: null
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  volume:
  - local
registries:
  search:
  - registry.access.redhat.com
  - registry.redhat.io
  - docker.io
store:
  configFile: /home/ec2-user/.config/containers/storage.conf
  containerStore:
    number: 1
    paused: 0
    running: 1
    stopped: 0
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /home/ec2-user/.local/share/containers/storage
  graphRootAllocated: 4281335808
  graphRootUsed: 1067921408
  graphStatus:
    Backing Filesystem: xfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Using metacopy: "false"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 1
  runRoot: /run/user/1000/containers
  volumePath: /home/ec2-user/.local/share/containers/storage/volumes
version:
  APIVersion: 4.2.0
  Built: 1677571395
  BuiltTime: Tue Feb 28 08:03:15 2023
  GitCommit: ""
  GoVersion: go1.18.9
  Os: linux
  OsArch: linux/amd64
  Version: 4.2.0

Podman in a container

No

Privileged Or Rootless

Rootless

Upstream Latest Release

No

Additional environment details

This example is on AWS as described above but seems general

Additional information

So far it looks like this is the behaviour of every healthcheck but we run strictly rootless at the moment.

github-actions[bot] commented 1 year ago

A friendly reminder that this issue had no activity for 30 days.

rhatdan commented 1 year ago

@mheon PTAL

mheon commented 1 year ago

The ENOENT bit is entirely normal? Podman's daemonless model means we often have multiple processes racing to do the same things, which we handle internally - hence no errors to the user. Logging these to audit will, indeed, produce rather stupendous volumes of logs, but that seems a logical result of an audit rule that logs every delete event from users?

EISDIR is more concerning, that sounds like something is coded wrong somewhere, I can take a look.

nikgoodley-ibboost commented 1 year ago

Thanks Matt. Completely agree about the volume of audited calls for deletions being a natural consequence, I was more giving the context for why something that due its nature we'd want to run frequently has an impact (for reference the CIS benchmark rule is 4.1.4 on the RHEL 8 version page 308+ in https://github.com/cismirror/old-benchmarks-archive/blob/master/CIS_Red_Hat_Enterprise_Linux_8_Benchmark_v1.0.0.pdf). I'd love not to have to follow that rule, but in many cases we're obliged to.

Thanks for the comment on EISDIR. I had assumed these were all related, which is why I thought it worth listing all. On ENOENT (and ENOTEMPTY which I'm not sure if you noticed) though, could well be I misunderstand the point on racing but don't they suggest either it's trying to delete something without checking it's there (which could be considered moot, I know but seems a natural and trivial safeguard that would have the benefit of not creating a commonly audited syscall), or it's trying the wrong operation given the object type?

In the particular use case we had, the boxes are essentially static content servers and so we see essentially no change in state beyond logs and it just so happened the healthcheck was responsible for the vast majority of total change in the system and it wasn't obvious why there's a need to be working with temporary overlay structures for something like a basic curl or hostname (I say this ignorant of internal mechanics).

If that's intentional and the best way to do it, no problems, it was just the fact that there were also these multiple delete failures suggesting something was off so if there was a chance to reduce the audit load at the same time it would be a bonus.

mheon commented 1 year ago

On ENOENT meaning we're not checking for existence - that's generally correct. Even if we did check, the file could be removed from under us between the check and the removal, so we have to check/handle ENOENT in the code anyways - it's generally easier to not check for existence at all, and just handle ENOENT.

I think we have to perform a directory removal when cleaning up an exec session, which seems like the likely cause of the EISDIR/ENOTEMPTY errors, I'll look into that.

nikgoodley-ibboost commented 1 year ago

Fair enough, understood on that aspect, thanks

github-actions[bot] commented 1 year ago

A friendly reminder that this issue had no activity for 30 days.

rhatdan commented 1 year ago

@mheon any update on this?