Running "podman images -a" is very slow

[Jacalz]

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

/kind bug

Description

Running the podman images -a command takes a very long time. With just two images, it takes several seconds and the time seems to scale with the amount of images on the system. I found this with containers/toolbox#1027 first and have now replicated with podman 4.0.3 on Fedora 36 beta.

Steps to reproduce the issue:

1. Set up any podman image. Doesn't seem to matter much which.
2. Run time podman images -a
3. Notice that it takes a very long time.

Describe the results you received:
On a machine with many images, it takes 35 seconds.

[jacob@localhost-live rymdport]$ time podman images -a
REPOSITORY                   TAG                IMAGE ID      CREATED            SIZE
docker.io/fyneio/fyne-cross  1.2-darwin         22f47e0d0137  About an hour ago  2.55 GB
<none>                       <none>             b2d5ef4f323f  About an hour ago  2 GB
<none>                       <none>             b2f1fc3874ed  About an hour ago  3.46 GB
<none>                       <none>             91b03921050c  2 hours ago        2.52 GB
<none>                       <none>             48a3814b4359  2 hours ago        2.42 GB
<none>                       <none>             5e5ad8cf4a6b  2 hours ago        2.42 GB
<none>                       <none>             5e7cbbd1de19  2 hours ago        2.28 GB
<none>                       <none>             0ccf8a18e406  2 hours ago        2.28 GB
<none>                       <none>             4381387f0afd  2 hours ago        2.28 GB
<none>                       <none>             b2b404b3f1cb  2 hours ago        1.54 GB
<none>                       <none>             097b75dd137e  2 hours ago        1.42 GB
<none>                       <none>             3a88c2b6994b  2 hours ago        1.42 GB
docker.io/fyneio/fyne-cross  1.2-windows        ef3940cf2de7  4 weeks ago        2.21 GB
docker.io/fyneio/fyne-cross  1.2-linux-arm64    45e79a9fa5d8  4 weeks ago        2.09 GB
docker.io/fyneio/fyne-cross  1.2-freebsd-arm64  5099e4221a66  4 weeks ago        4.17 GB
docker.io/fyneio/fyne-cross  1.2-freebsd-amd64  2befa59f85b3  4 weeks ago        4.26 GB
docker.io/fyneio/fyne-cross  1.2-base-llvm      e2d717b27fa9  4 weeks ago        1.42 GB
docker.io/fyneio/fyne-cross  1.2-base           b5fdf9337367  4 weeks ago        1.11 GB

real	0m35.463s
user	0m9.358s
sys	0m19.979s

Describe the results you expected:
Something that is a lot faster. Definitely less than or around a second.

Additional information you deem important (e.g. issue happens only occasionally):
See containers/toolbox#1027. There is a lot of information there.

Output of podman version:

Client:       Podman Engine
Version:      4.0.3
API Version:  4.0.3
Go Version:   go1.18
Built:        Fri Apr  1 20:21:54 2022
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.24.3
  cgroupControllers:
  - cpu
  - io
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-2.1.0-2.fc36.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.0, commit: '
  cpus: 8
  distribution:
    distribution: fedora
    variant: workstation
    version: "36"
  eventLogger: journald
  hostname: localhost-live.lan
  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.17.1-300.fc36.x86_64
  linkmode: dynamic
  logDriver: journald
  memFree: 286789632
  memTotal: 16731807744
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun-1.4.4-1.fc36.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.4.4
      commit: 6521fcc5806f20f6187eb933f9f45130c86da230
      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-0.2.beta.0.fc36.x86_64
    version: |-
      slirp4netns version 1.2.0-beta.0
      commit: 477db14a24ff1a3de3a705e51ca2c4c1fe3dda64
      libslirp: 4.6.1
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.5.3
  swapFree: 8097624064
  swapTotal: 8589930496
  uptime: 2h 11m 30.82s (Approximately 0.08 days)
plugins:
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  volume:
  - local
registries:
  search:
  - registry.fedoraproject.org
  - registry.access.redhat.com
  - docker.io
  - quay.io
store:
  configFile: /home/jacob/.config/containers/storage.conf
  containerStore:
    number: 0
    paused: 0
    running: 0
    stopped: 0
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /home/jacob/.local/share/containers/storage
  graphStatus:
    Backing Filesystem: btrfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Using metacopy: "false"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 18
  runRoot: /run/user/1000/containers
  volumePath: /home/jacob/.local/share/containers/storage/volumes
version:
  APIVersion: 4.0.3
  Built: 1648837314
  BuiltTime: Fri Apr  1 20:21:54 2022
  GitCommit: ""
  GoVersion: go1.18
  OsArch: linux/amd64
  Version: 4.0.3

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

podman-4.0.3-1.fc36.x86_64

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.):
On hardware, no virtual machines. The testing in this issue was created using a desktop workstation with 16GB RAM, an i7 3770 and a spinning 1TB HDD. Testing on containers/toolbox#1027 was done on a Dell Latitude 7490 laptop with 16GB RAM, an i5 8250U and a 500GB SATA M.2 SSD (which basically says that slow drives isn't the problem here).

[flouthoc]

Hi @Jacalz , I am not sure but I think @vrothberg has already fixed this. I'd request @vrothberg to confirm.

[vrothberg]

Performance regressions are hard to detect but it's the first report for 4.0.

@Jacalz, could you run podman --cpu-profile=/tmp/podman.prof images -a and upload the profile somewhere? This will help narrow down what's taking so much time.

[vrothberg]

Note that 3.4.4 still has this regression but a fix for Fedora 35 will arrive with Podman v3.4.5 (Cc @mheon). v4.0 has the fix.

Are you positive to have tested with v4.0? I am asking since containers/toolbox#1027 was filed with Podman v3.4.4.

[Luap99]

Looking at the image size you have very big images. Does podman images still calculates the size on the fly?

[rhatdan]

Yes I believe it does.

[Jacalz]

Are you positive to have tested with v4.0? I am asking since containers/toolbox#1027 was filed with Podman v3.4.4.

[Jacalz]

Sorry. Didn’t mean to close this.

Are you positive to have tested with v4.0? I am asking since containers/toolbox#1027 was filed with Podman v3.4.4.

Yes, I tested with the version mentioned in the description here (v4.0.4). I installed Fedora 35 Beta just to be able to get a newer release and open this issue.

[Jacalz]

I guess it could be that the images on the Fedora 35 machine make it slower because they aren’t the same as what I have on the laptop. I’ll try with only two smaller toolbox images and see if that makes a difference.

[vrothberg]

Thanks for checking. There are probably two separate issues:

1. podman images being slow on many images due to a performance regression: that one has been fixed
2. podman images being slow on even few big images: that is because computing the size is very expensive

For 2) we need to add a --no-size option.

[vrothberg]

@Jacalz, could you run podman --cpu-profile=/tmp/podman.prof images -a and upload the profile somewhere? This will help narrow down what's taking so much time.

@Jacalz could you share the CPU profile?

[Jacalz]

@Jacalz, could you run podman --cpu-profile=/tmp/podman.prof images -a and upload the profile somewhere? This will help narrow down what's taking so much time.

@Jacalz could you share the CPU profile?

Ah, sorry. I forgot about that. Will see if I can get that done later today :)

[vrothberg]

Thanks, @Jacalz!

I opened #13810 to add a --size flag to podman images that can be turned off by the user.

@giuseppe, did we ever consider/discuss computing the size of an image once at commit time and just return that?

[Jacalz]

There's the CPU profile for you @vrothberg. Sorry that it took some time. I was busy yesterday. podman-prof.zip

[vrothberg]

Thanks a lot, @Jacalz!

[vrothberg]

Yes, that confirms the suspicion. 85 percent of the time is spent calculating the size of each image in c/storage. #13810 may help toolbox as --size=false will not compute image sizes. But I would really like to store an image's size at commit time.

[HarryMichal]

Yes, that confirms the suspicion. 85 percent of the time is spent calculating the size of each image in c/storage. #13810 may help toolbox as --size=false will not compute image sizes. But I would really like to store an image's size at commit time.

We can always do a version check on Podman to get the optimal behaviour.