Error parsing cgroup: expected 3 fields but got 1: /proc/214251/cgroup

[ttys3]

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

got error log

podman[242341]: time="2022-05-08T00:36:53+08:00" level=debug msg="Error parsing cgroup: expected 3 fields but got 1: /proc/214251/cgroup"

May 08 01:10:32 podman[309965]: time="2022-05-08T01:10:32+08:00" level=debug msg="Error parsing cgroup: expected 3 fields but got 1: /proc/281406/cgroup"

❯ cat /proc/214251/cgroup
0::/machine.slice/libpod-e927c9f745d3a75c0e8d7707b8987eff801bb7d58af9067359b18aa72c9c5047.scope/container


# the cgroup path is:
/sys/fs/cgroup/machine.slice/libpod-e927c9f745d3a75c0e8d7707b8987eff801bb7d58af9067359b18aa72c9c5047.scope/

❯ cat /proc/281406/cgroup
0::/libpod_parent/libpod-3733eaa47220f51a82a7aeeaf243947562ae4e136c5d29a02f09bd467be071f4

related code:

podman/libpod/container.go

Lines 972 to 1042 in a0ecb86

	// Read /proc/{PID}/cgroup and find the *longest* cgroup entry. That's
	// needed to account for hacks in cgroups v1, where each line in the
	// file could potentially point to a cgroup. The longest one, however,
	// is the libpod-specific one we're looking for.
	//
	// See #8397 on the need for the longest-path look up.
	//
	// And another workaround for containers running systemd as the payload.
	// containers running systemd moves themselves into a child subgroup of
	// the named systemd cgroup hierarchy. Ignore any named cgroups during
	// the lookup.
	// See #10602 for more details.
	procPath := fmt.Sprintf("/proc/%d/cgroup", c.state.PID)
	lines, err := ioutil.ReadFile(procPath)
	if err != nil {
	// If the file doesn't exist, it means the container could have been terminated
	// so report it.
	if os.IsNotExist(err) {
	return "", errors.Wrapf(define.ErrCtrStopped, "cannot get cgroup path unless container %s is running", c.ID())
	}
	return "", err
	}
	var cgroupPath string
	for _, line := range bytes.Split(lines, []byte("\n")) {
	// cgroups(7) nails it down to three fields with the 3rd
	// pointing to the cgroup's path which works both on v1 and v2.
	fields := bytes.Split(line, []byte(":"))
	if len(fields) != 3 {
	logrus.Debugf("Error parsing cgroup: expected 3 fields but got %d: %s", len(fields), procPath)
	continue
	}
	// Ignore named cgroups like name=systemd.
	if bytes.Contains(fields[1], []byte("=")) {
	continue
	}
	path := string(fields[2])
	if len(path) > len(cgroupPath) {
	cgroupPath = path
	}
	}
	if len(cgroupPath) == 0 {
	return "", errors.Errorf("could not find any cgroup in %q", procPath)
	}
	cgroupManager := c.CgroupManager()
	switch {
	case c.config.CgroupsMode == cgroupSplit:
	name := fmt.Sprintf("/libpod-payload-%s/", c.ID())
	if index := strings.LastIndex(cgroupPath, name); index >= 0 {
	return cgroupPath[:index+len(name)-1], nil
	}
	case cgroupManager == config.CgroupfsCgroupsManager:
	name := fmt.Sprintf("/libpod-%s/", c.ID())
	if index := strings.LastIndex(cgroupPath, name); index >= 0 {
	return cgroupPath[:index+len(name)-1], nil
	}
	case cgroupManager == config.SystemdCgroupsManager:
	// When running under systemd, try to detect the scope that was requested
	// to be created. It improves the heuristic since we report the first
	// cgroup that was created instead of the cgroup where PID 1 might have
	// moved to.
	name := fmt.Sprintf("/libpod-%s.scope/", c.ID())
	if index := strings.LastIndex(cgroupPath, name); index >= 0 {
	return cgroupPath[:index+len(name)-1], nil
	}
	}
	return cgroupPath, nil
	}

after adding some debug code, I got the log:

May 08 01:21:05 podman[357942]: time="2022-05-08T01:21:05+08:00" level=debug 
msg="Error parsing cgroup: expected 3 fields but got 1: /proc/358035/cgroup, 
line=[] 
lines=0::/libpod_parent/libpod-bbf58b236585fb1a687f2456aecb2b65b1456ab0b9ece71f9ad89fa055c393d5\n"

so the problem is, the Split got the last empty line. Cause the error

Steps to reproduce the issue:

Describe the results you received:

Describe the results you expected:

Additional information you deem important (e.g. issue happens only occasionally):

Output of podman version:

Client:       Podman Engine
Version:      4.1.0
API Version:  4.1.0
Go Version:   go1.18.1
Git Commit:   e4b03902052294d4f342a185bb54702ed5bed8b1
Built:        Sun May  8 00:52:12 2022
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.26.1
  cgroupControllers:
  - cpuset
  - cpu
  - io
  - memory
  - hugetlb
  - pids
  - rdma
  - misc
  cgroupManager: cgroupfs
  cgroupVersion: v2
  conmon:
    package: /usr/bin/conmon is owned by conmon 1:2.1.0-1
    path: /usr/bin/conmon
    version: 'conmon version 2.1.0, commit: '
  cpuUtilization:
    idlePercent: 96.15
    systemPercent: 1.27
    userPercent: 2.58
  cpus: 20
  distribution:
    distribution: arch
    version: unknown
  eventLogger: file
  hostname: wudeng
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 5.17.5-arch1-1
  linkmode: dynamic
  logDriver: k8s-file
  memFree: 2135126016
  memTotal: 33387921408
  networkBackend: cni
  ociRuntime:
    name: crun
    package: /usr/bin/crun is owned by crun 1.4.5-1
    path: /usr/bin/crun
    version: |-
      crun version 1.4.5
      commit: c381048530aa750495cf502ddb7181f2ded5b400
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    exists: true
    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: /etc/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: /usr/bin/slirp4netns is owned by slirp4netns 1.2.0-1
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.7.0
      SLIRP_CONFIG_VERSION_MAX: 4
      libseccomp: 2.5.4
  swapFree: 17179865088
  swapTotal: 17179865088
  uptime: 4h 43m 5.11s (Approximately 0.17 days)
plugins:
  log:
  - k8s-file
  - none
  - passthrough
  network:
  - bridge
  - macvlan
  - ipvlan
  volume:
  - local
registries:
  hub.k8s.lan:
    Blocked: false
    Insecure: true
    Location: hub.k8s.lan
    MirrorByDigestOnly: false
    Mirrors: null
    Prefix: hub.k8s.lan
    PullFromMirror: ""
  search:
  - docker.io
store:
  configFile: /etc/containers/storage.conf
  containerStore:
    number: 21
    paused: 0
    running: 20
    stopped: 1
  graphDriverName: overlay
  graphOptions:
    overlay.mountopt: nodev,metacopy=on
  graphRoot: /var/lib/containers/storage
  graphRootAllocated: 178534772736
  graphRootUsed: 139743010816
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "true"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 63
  runRoot: /run/containers/storage
  volumePath: /var/lib/containers/storage/volumes
version:
  APIVersion: 4.1.0
  Built: 1651942332
  BuiltTime: Sun May  8 00:52:12 2022
  GitCommit: e4b03902052294d4f342a185bb54702ed5bed8b1
  GoVersion: go1.18.1
  Os: linux
  OsArch: linux/amd64
  Version: 4.1.0

Package info (e.g. output of rpm -q podman or apt list podman):

build from source code

Have you tested with the latest version of Podman and have you checked the Podman Troubleshooting Guide? (https://github.com/containers/podman/blob/main/troubleshooting.md)

Yes

Additional environment details (AWS, VirtualBox, physical, etc.):