containers / podman

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

Hard to get container logs (using journalctl) using quadlet kube unit with passthrough - 4.4.1-rhel #18682

Closed void-spark closed 1 year ago

void-spark commented 1 year ago

Issue Description

When using quadlet with a kube unit on 4.4.1-rhel, which forces --log-driver passthrough (which also seems to be recommended for running under systemd), container log entries are passed via stdout to systemd. But somehow the setup with quadlet .kube results in neither of the fields that journalctl -u checks having the unit name: "_SYSTEMD_SLICE" : "machine-libpod_pod_8a3046eac4cf9a98bff90e8de88a7cae529fa6d2a04983358a7ef523282119f5.slice", "_SYSTEMD_UNIT" : "libpod-880dad3c30ef460805d64e04d6c47560bfaa7e7e4ff28806aba710b48f4aa9c7.scope", It seems that SYSLOG_IDENTIFIER is set to the unit name for some reason, so to get all logs for the unit (what's logged by podman process, and the container stdout) I can do this: journalctl -f _SYSTEMD_UNIT=myservice.service + SYSLOG_IDENTIFIER=myservice But that's not great :)

I tried using LogExtraFields to set a marker for the unit, but I found out that actually works by matching against the unit name, so it's also ignored for those container log messages.

The fields are obviously set by systemd, and I'm guessing they reflect some special voodoo (to me :) ) that podman does with the containers, I don't know enough to say if this is a bug/issue with systemd, or with how journalctl looks at log records, or a inconvenient result of some good choices in how podman sets things up.

The workaround would be to switch back to --log-driver journald, which for this version means not using quadlet, since it's hardcoded (next version I could).

rpm -q podman: podman-4.4.1-9.el9_2.x86_64

Note: On RH 9.2 now, so podman 4.4.1 from the 4.4.1-rhel branch. Red hat doesn't offer a newer version of podman than that to test with. For tests I'm using Rocky, but it should be/seems to be identical to RH

Steps to reproduce the issue

Steps to reproduce the issue

  1. Make sure you're on a 'redhat' flavour with podman 4.4.1 2.Create a simple quadlet kube file + kubernetes yaml 3.start the quadlet unit, try to get the container logs with journalctl -u

Describe the results you received

No container logs when using journalctl -u

Describe the results you expected

Container logs when using journalctl -u

podman info output

host:
  arch: amd64
  buildahVersion: 1.29.0
  cgroupControllers:
  - cpuset
  - cpu
  - cpuacct
  - blkio
  - memory
  - devices
  - freezer
  - net_cls
  - perf_event
  - net_prio
  - hugetlb
  - pids
  - rdma
  - misc
  cgroupManager: systemd
  cgroupVersion: v1
  conmon:
    package: conmon-2.1.7-1.el9_2.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.7, commit: e6cdc9a4d6319e039efa13e532c1e58b713c904d'
  cpuUtilization:
    idlePercent: 99.52
    systemPercent: 0.24
    userPercent: 0.23
  cpus: 12
  distribution:
    distribution: '"rocky"'
    version: "9.2"
  eventLogger: journald
  hostname: HUMBLE
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 5.15.90.1-microsoft-standard-WSL2
  linkmode: dynamic
  logDriver: journald
  memFree: 386420736
  memTotal: 16553975808
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun-1.8.4-1.el9_2.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.8.4
      commit: 5a8fa99a5e41facba2eda4af12fa26313918805b
      rundir: /run/user/0/crun
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    path: /run/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: false
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns-1.2.0-3.el9.x86_64
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.4.0
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.5.2
  swapFree: 4294430720
  swapTotal: 4294967296
  uptime: 3h 40m 46.00s (Approximately 0.12 days)
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: /etc/containers/storage.conf
  containerStore:
    number: 3
    paused: 0
    running: 3
    stopped: 0
  graphDriverName: overlay
  graphOptions:
    overlay.mountopt: nodev,metacopy=on
  graphRoot: /var/lib/containers/storage
  graphRootAllocated: 1081101176832
  graphRootUsed: 945954816
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "true"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 10
  runRoot: /run/containers/storage
  transientStore: false
  volumePath: /var/lib/containers/storage/volumes
version:
  APIVersion: 4.4.1
  Built: 1683632637
  BuiltTime: Tue May  9 13:43:57 2023
  GitCommit: ""
  GoVersion: go1.19.6
  Os: linux
  OsArch: linux/amd64
  Version: 4.4.1

Podman in a container

No

Privileged Or Rootless

Privileged

Upstream Latest Release

No

Additional environment details

WSL2 for tests

Additional information

No response

giuseppe commented 1 year ago

that is expected with passthrough, the unit name is the one used for the container scope. With the journald driver, conmon takes care to forward the logs to journald and we have the possibility to set these fields, but that cannot be done with passthrough since the container std streams communicate directly with systemd

void-spark commented 1 year ago

I guess creating the machine-libpod_pod_8a3046eac4cf9a98bff90e8de88a7cae529fa6d2a04983358a7ef523282119f5.slice slice is just part of how kube play works, right? :)

Luap99 commented 1 year ago

Yes this is how it works. Note that we changed the default back in v4.5 to the journald driver. And also podman logs will be able to read quadlet logs when log-driver passthrough is used.

void-spark commented 1 year ago

I wonder if it's better to suggest journald to be the default, it does add far more (and more useful) fields to the log. I'm guessing that systemd pretty much doesn't see the processes in the container as part of the unit anymore, since they are in a cgroups slice unrelated to it, which you also see in status: image

It does still log the stdout since it's connected, but with the details from the process in the container, which it no longer see as part of the unit, something like that.. :)