High pasta and rootlessport CPU load

[pwige]

Issue Description

I'm encountering unexpectedly high CPU load from pasta and rootlessport when running certain network operations.
Scenario 1 – Downloading large files:
Downloading Hetzner test files (although any large file download should do) from within a rootless container.
Scenario 2 – Wireguard VPN server:
Hosting a Wireguard server in a rootless container using the docker.io/linuxserver/wireguard image.

Steps to reproduce the issue

Steps to reproduce the issue:
Scenario 1:

1. Run rootless container and download the test file to tmpfs:

   podman container run \
       --interactive \
       --tty 
       --rm \
       --tmpfs /mnt \
       --workdir /mnt \
       debian /bin/bash -c 'apt update && apt install -y wget && wget https://ash-speed.hetzner.com/10GB.bin'
   

2. Monitor download speed reported by wget and CPU usage reported by htop.
   If Hetzner's Ashburn datacenter is far from you, check their other locations and modify the URL's subdomain as needed.

Scenario 2:

1. Create a custom network.

   podman network create testnet
   

2. Spawn a Wireguard server in a rootless container.

   podman container run \
       --deattach \
       --rm \
       --cap-add NET_RAW \
       --cap-add NET_ADMIN \
       --sysctl net.ipv4.conf.all.forwarding=1 \
       --env PEERS=1 \
       --network=testnet \
       --publish 51820:51820/udp \
       docker.io/linuxserver/wireguard
   

3. Install the client profile on a separate device using either the QR code provided in the server container's log or the peer1.conf file stored within the container itself.
4. Run a speedtest first with multiple connections and then with only a single connection enabled.
5. Observe CPU load via htop.

Describe the results you received

Scenario 1:
When downloading Hetzner test files with wget in a rootless container I reach consistent download speeds of around ~43MiB/s, but htop reports the pasta process using ~40-43% CPU load.

Scenario 2:
Running a network speedtest on the client using results in extremely slow network speeds reported on the client and very high CPU load on the server. htop shows 90-100% CPU load from the pasta process and 10-17% CPU load from several rootlessport processes.

Wireguard's poor performance renders it essentially unusable. I was told the CPU load is unexpectedly high and that I should raise a bug report here. Please let me know if what I am encountering is actually to be expected from rootless containers.

Describe the results you expected

I expected less severe CPU load from the rootless networking backend and better performance/network speeds via the Wireguard VPN tunnel.

podman info output

host:
  arch: amd64
  buildahVersion: 1.37.1
  cgroupControllers:
  - cpu
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-1:2.1.12-1
    path: /usr/bin/conmon
    version: 'conmon version 2.1.12, commit: e8896631295ccb0bfdda4284f1751be19b483264'
  cpuUtilization:
    idlePercent: 96.76
    systemPercent: 2.25
    userPercent: 0.99
  cpus: 4
  databaseBackend: sqlite
  distribution:
    distribution: arch
    version: unknown
  eventLogger: journald
  freeLocks: 2046
  hostname: fern
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1003
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    - container_id: 65537
      host_id: 165536
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1001
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    - container_id: 65537
      host_id: 165536
      size: 65536
  kernel: 6.10.5-arch1-1
  linkmode: dynamic
  logDriver: journald
  memFree: 15708397568
  memTotal: 16651931648
  networkBackend: netavark
  networkBackendInfo:
    backend: netavark
    dns:
      package: aardvark-dns-1.12.1-1
      path: /usr/lib/podman/aardvark-dns
      version: aardvark-dns 1.12.1
    package: netavark-1.12.2-1
    path: /usr/lib/podman/netavark
    version: netavark 1.12.2
  ociRuntime:
    name: crun
    package: crun-1.16.1-1
    path: /usr/bin/crun
    version: |-
      crun version 1.16.1
      commit: afa829ca0122bd5e1d67f1f38e6cc348027e3c32
      rundir: /run/user/1001/crun
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  pasta:
    executable: /usr/bin/pasta
    package: passt-2024_08_14.61c0b0d-1
    version: |
      pasta 2024_08_14.61c0b0d
      Copyright Red Hat
      GNU General Public License, version 2 or later
        <https://www.gnu.org/licenses/old-licenses/gpl-2.0.html>
      This is free software: you are free to change and redistribute it.
      There is NO WARRANTY, to the extent permitted by law.
  remoteSocket:
    exists: false
    path: /run/user/1001/podman/podman.sock
  rootlessNetworkCmd: pasta
  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: /etc/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: ""
    package: ""
    version: ""
  swapFree: 6442446848
  swapTotal: 6442446848
  uptime: 0h 31m 3.00s
  variant: ""
plugins:
  authorization: null
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  - ipvlan
  volume:
  - local
registries: {}
store:
  configFile: /home/containers/.config/containers/storage.conf
  containerStore:
    number: 1
    paused: 0
    running: 1
    stopped: 0
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /storage/containers/storage
  graphRootAllocated: 6001156685824
  graphRootUsed: 94199808
  graphStatus:
    Backing Filesystem: btrfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Supports shifting: "false"
    Supports volatile: "true"
    Using metacopy: "false"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 3
  runRoot: /run/user/1001/containers
  transientStore: false
  volumePath: /storage/containers/storage/volumes
version:
  APIVersion: 5.2.1
  Built: 1723672228
  BuiltTime: Wed Aug 14 17:50:28 2024
  GitCommit: d0582c9e1e6c80cc08c3f042b91993c853ddcbc6
  GoVersion: go1.23.0
  Os: linux
  OsArch: linux/amd64
  Version: 5.2.1

Podman in a container

No

Privileged Or Rootless

Rootless

Upstream Latest Release

Yes

Additional environment details

Running a fresh Arch installation on an Intel NUC5i7RYH, which is connected to my home's router via ethernet. No other services or containers running during testing.

Additional information

The experience I described above is consistent.

[sbrivio-rh]

Thanks for reporting this!

Scenario 2: Running a network speedtest on the client using results in extremely slow network speeds reported on the client and very high CPU load on the server. htop shows 90-100% CPU load from the pasta process and 10-17% CPU load from several rootlessport processes.

I wouldn't expect rootlessport processes to be around in this case. How many are running? Can you have a look at their command line? I'm wondering if there's some unintended loop between port mappings or suchlike.

[sbrivio-rh]

About Scenario 1: I can reproduce something similar, in my case downloading from the fsn1 Hetzner area. I download at approximately 1gbps (110MB/s) and pasta uses approximately 70% of a CPU thread (wget is at ~50%).

The good news is that with higher transfer rates I get, on the same system, approximately 14gbps at 100% CPU thread load, and if I CPU-starve pasta with the test file download, I get approximately the same transfer rates. That is, if we have bigger chunks of data to transfer (because we have less CPU time), the CPU load doesn't increase linearly, so I don't see a practical issue with it.

Anyway, this is what perf:

$ perf record -g ./pasta --config-net
# wget https://fsn1-speed.hetzner.com/1GB.bin -O /dev/null
--2024-08-21 10:07:11--  https://fsn1-speed.hetzner.com/1GB.bin
Resolving fsn1-speed.hetzner.com (fsn1-speed.hetzner.com)... 2a01:4f8:0:a232::2, 78.46.170.2
Connecting to fsn1-speed.hetzner.com (fsn1-speed.hetzner.com)|2a01:4f8:0:a232::2|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 1073741824 (1.0G) [application/octet-stream]
Saving to: ‘/dev/null’

/dev/null           100%[===================>]   1.00G   109MB/s    in 9.4s    

2024-08-21 10:07:21 (109 MB/s) - ‘/dev/null’ saved [1073741824/1073741824]

# 
logout
[ perf record: Woken up 18 times to write data ]
[ perf record: Captured and wrote 5.080 MB perf.data (37680 samples) ]
$ perf report

says about it:

Samples: 37K of event 'cycles', Event count (approx.): 30751209003
  Children      Self  Command     Shared Object         Symbol
-   80.23%     0.56%  passt.avx2  [kernel.kallsyms]     [k] entry_SYSCALL_64_af◆
     79.67% entry_SYSCALL_64_after_hwframe                                     ▒
      - do_syscall_64                                                          ▒
         + 20.90% do_writev                                                    ▒
         + 19.63% __sys_recvmsg                                                ▒
         + 13.53% __x64_sys_epoll_wait                                         ▒
         + 5.35% ksys_read                                                     ▒
         + 4.93% __x64_sys_epoll_ctl                                           ▒
         + 4.01% __x64_sys_timerfd_settime                                     ▒
         + 3.86% __x64_sys_recvfrom                                            ▒
         + 3.29% syscall_trace_enter.constprop.0                               ▒
         + 2.75% syscall_exit_to_user_mode                                     ▒

do_writev() is the system call writing to the tap interface of the container (we have to write one frame at a time, because tap gives us a file descriptor, not a socket), and __sys_recvmsg() are the reads from the socket.

There isn't much we can do about that, except for a planned VDUSE ¹ ² back-end. At that point, we'll get rid of those system calls and just "move" data between a shared memory ring and sockets.

The rest is something we could probably try to improve on in the shorter term, for example by trying to get bigger chunks of data at a time and reducing the wakeup frequency (__x64_sys_epoll_wait() and friends). I tried this:

diff --git a/tcp_buf.c b/tcp_buf.c
index c31e9f3..c15de64 100644
--- a/tcp_buf.c
+++ b/tcp_buf.c
@@ -477,6 +477,11 @@ int tcp_buf_data_from_sock(struct ctx *c, struct tcp_tap_conn *conn)
 		len = recvmsg(s, &mh_sock, MSG_PEEK);
 	while (len < 0 && errno == EINTR);
 
+	if (len > (1 << 16)) {
+		int lowat = 1 << 17;
+		setsockopt(s, SOL_SOCKET, SO_RCVLOWAT, &lowat, sizeof(lowat));
+	}
+
 	if (len < 0)
 		goto err;
 

CPU load is 15-18% at the same transfer rate. The transfer hangs at the end (this would need the same adaptive logic we have in tcp_splice.c), and we substantially decrease overhead from wakeups and bookkeeping:

  Children      Self  Command     Shared Object         Symbol
-   91.64%     0.12%  passt.avx2  [kernel.kallsyms]     [k] entry_SYSCALL_64_af◆
     91.53% entry_SYSCALL_64_after_hwframe                                     ▒
      - do_syscall_64                                                          ▒
         + 36.24% __sys_recvmsg                                                ▒
         + 24.94% ksys_read                                                    ▒
         + 20.90% do_writev                                                    ▒
         + 3.35% __x64_sys_epoll_wait                                          ▒
         + 1.93% __x64_sys_recvfrom                                            ▒
         + 1.08% __x64_sys_timerfd_settime                                     ▒
           0.73% syscall_exit_to_user_mode                                     ▒
           0.62% syscall_trace_enter.constprop.0                               ▒
           0.51% __x64_sys_setsockopt                                          ▒

So this is something we could consider, even though, again, that CPU load shouldn't look that scary, because it's quite adaptive.

I didn't look into Scenario 2 yet.

[pwige]

I wouldn't expect rootlessport processes to be around in this case. How many are running? Can you have a look at their command line? I'm wondering if there's some unintended loop between port mappings or suchlike.

After rebooting my system to start with a clean slate, I started my Wireguard container and observed eight rootlessport and six rootlessport-child processes spawn. I spent some time on the client using the network: Opening webpages, downloading Hetzner test files, etc. After several minutes I noticed that a couple more rootlessport processes had appeared, bringing the total number to ten. All of the rootlessport and rootlessport-child processes were reaped once I stopped the container.

As an additional piece of info, I am using Quadlet (systemctl --user start wireguard) to manage this container.

# wireguard.container
[Unit]
Description=Wireguard server quadlet

[Container]
Image=docker.io/linuxserver/wireguard:latest
AddCapability=NET_ADMIN
AddCapability=NET_RAW
Sysctl=net.ipv4.conf.all.forwarding=1
Environment=PEERS=1
Environment=INTERNAL_SUBNET=10.30.0.0/24
# Volume=wireguard-config.volume:/config
Network=wireguard.network
PublishPort=51820:51820/udp

[Service]
Restart=always

[Install]
WantedBy=multi-user.target default.target

No options aside from the heading ([Network]) are provided in the wireguard.network file.

[kalelkenobi]

jumping in to say that I'm experiencing the exact same issue, running almost an identical configuration as OP (I'm also using Quadlet to run the VPN container). Feels good not to be alone, this thing was driving me crazy. As a piece of additional information that could help zero in on this, I'll say that I've been running this configuration for more than 4 month now and the issue started only recently (the last month or so).
Here's my podman info:

host:
  arch: amd64
  buildahVersion: 1.37.1
  cgroupControllers:
  - cpu
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-2.1.12-1.fc40.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.12, commit: '
  cpuUtilization:
    idlePercent: 98.31
    systemPercent: 1.14
    userPercent: 0.55
  cpus: 4
  databaseBackend: sqlite
  distribution:
    distribution: fedora
    variant: cloud
    version: "40"
  eventLogger: journald
  freeLocks: 2040
  hostname: hekate
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1001
      size: 1
    - container_id: 1
      host_id: 589824
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1001
      size: 1
    - container_id: 1
      host_id: 589824
      size: 65536
  kernel: 6.10.6-200.fc40.x86_64
  linkmode: dynamic
  logDriver: journald
  memFree: 933859328
  memTotal: 6203207680
  networkBackend: netavark
  networkBackendInfo:
    backend: netavark
    dns:
      package: aardvark-dns-1.12.1-1.fc40.x86_64
      path: /usr/libexec/podman/aardvark-dns
      version: aardvark-dns 1.12.1
    package: netavark-1.12.2-1.fc40.x86_64
    path: /usr/libexec/podman/netavark
    version: netavark 1.12.2
  ociRuntime:
    name: crun
    package: crun-1.15-1.fc40.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.15
      commit: e6eacaf4034e84185fd8780ac9262bbf57082278
      rundir: /run/user/1001/crun
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +LIBKRUN +WASM:wasmedge +YAJL
  os: linux
  pasta:
    executable: /usr/bin/pasta
    package: passt-0^20240814.g61c0b0d-1.fc40.x86_64
    version: |
      pasta 0^20240814.g61c0b0d-1.fc40.x86_64
      Copyright Red Hat
      GNU General Public License, version 2 or later
        <https://www.gnu.org/licenses/old-licenses/gpl-2.0.html>
      This is free software: you are free to change and redistribute it.
      There is NO WARRANTY, to the extent permitted by law.
  remoteSocket:
    exists: true
    path: /run/user/1001/podman/podman.sock
  rootlessNetworkCmd: pasta
  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: ""
    package: ""
    version: ""
  swapFree: 6202322944
  swapTotal: 6202322944
  uptime: 24h 59m 31.00s (Approximately 1.00 days)
  variant: ""
plugins:
  authorization: null
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  - ipvlan
  volume:
  - local
registries:
  search:
  - registry.fedoraproject.org
  - registry.access.redhat.com
  - docker.io
store:
  configFile: /home/podman/.config/containers/storage.conf
  containerStore:
    number: 4
    paused: 0
    running: 4
    stopped: 0
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /home/podman/.local/share/containers/storage
  graphRootAllocated: 428340129792
  graphRootUsed: 24915517440
  graphStatus:
    Backing Filesystem: btrfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Supports shifting: "false"
    Supports volatile: "true"
    Using metacopy: "false"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 6
  runRoot: /run/user/1001/containers
  transientStore: false
  volumePath: /home/podman/.local/share/containers/storage/volumes
version:
  APIVersion: 5.2.1
  Built: 1723593600
  BuiltTime: Wed Aug 14 02:00:00 2024
  GitCommit: ""
  GoVersion: go1.22.5
  Os: linux
  OsArch: linux/amd64
  Version: 5.2.1

please let me know if there's anything else I can provide to help with this.

[sbrivio-rh]

I'll say that I've been running this configuration for more than 4 month now and the issue started only recently (the last month or so)

Do you happen to know starting from which version of Podman and pasta (the package is named passt) you are seeing this?

[kalelkenobi]

I'll say that I've been running this configuration for more than 4 month now and the issue started only recently (the last month or so)

Do you happen to know starting from which version of Podman and pasta (the package is named passt) you are seeing this?

I started noticing the issue around the beginning of August. Looking at my DNF history I can make some educated guesses.
it could be either this update (applied the 25 of July):

Packages Altered:
    Upgrade  podman-5:5.2.0~rc2-1.fc40.x86_64            @updates-testing
    Upgraded podman-5:5.1.2-1.fc40.x86_64                @@System

or this one (August 4th):

Packages Altered:
    Upgrade  aardvark-dns-2:1.12.1-1.fc40.x86_64        @updates-testing
    Upgraded aardvark-dns-2:1.11.0-3.fc40.x86_64        @@System
    Upgrade  glibc-2.39-22.fc40.x86_64                  @updates-testing
    Upgraded glibc-2.39-17.fc40.x86_64                  @@System
    Upgrade  glibc-common-2.39-22.fc40.x86_64           @updates-testing
    Upgraded glibc-common-2.39-17.fc40.x86_64           @@System
    Upgrade  glibc-gconv-extra-2.39-22.fc40.x86_64      @updates-testing
    Upgraded glibc-gconv-extra-2.39-17.fc40.x86_64      @@System
    Upgrade  glibc-langpack-en-2.39-22.fc40.x86_64      @updates-testing
    Upgraded glibc-langpack-en-2.39-17.fc40.x86_64      @@System
    Upgrade  glibc-locale-source-2.39-22.fc40.x86_64    @updates-testing
    Upgraded glibc-locale-source-2.39-17.fc40.x86_64    @@System
    Upgrade  glibc-minimal-langpack-2.39-22.fc40.x86_64 @updates-testing
    Upgraded glibc-minimal-langpack-2.39-17.fc40.x86_64 @@System
    Upgrade  libgcc-14.2.1-1.fc40.x86_64                @updates-testing
    Upgraded libgcc-14.1.1-7.fc40.x86_64                @@System
    Upgrade  libgomp-14.2.1-1.fc40.x86_64               @updates-testing
    Upgraded libgomp-14.1.1-7.fc40.x86_64               @@System
    Upgrade  libstdc++-14.2.1-1.fc40.x86_64             @updates-testing
    Upgraded libstdc++-14.1.1-7.fc40.x86_64             @@System
    Upgrade  netavark-2:1.12.1-1.fc40.x86_64            @updates-testing
    Upgraded netavark-2:1.11.0-3.fc40.x86_64            @@System
    Upgrade  podman-5:5.2.0-1.fc40.x86_64               @updates-testing
    Upgraded podman-5:5.2.0~rc2-1.fc40.x86_64           @@System

The only update I see for passt seems too recent (16th of August)

[kalelkenobi]

my bad. There was another update on the 28 of July. Sorry I missed it.

Packages Altered:
    Upgrade       passt-0^20240726.g57a21d2-1.fc40.x86_64                   @updates-testing
    Upgraded      passt-0^20240624.g1ee2eca-1.fc40.x86_64                   @@System
    Upgrade       passt-selinux-0^20240726.g57a21d2-1.fc40.noarch           @updates-testing
    Upgraded      passt-selinux-0^20240624.g1ee2eca-1.fc40.noarch           @@System

the one before was of on June the 25th, but it feels too early and the the one after that was on August 9 (too late).
hope this helps

[sbrivio-rh]

Any chance you could try downgrading to passt-0^20240624.g1ee2eca-1.fc40.x86_64 just for a quick test and see if that helps with CPU load?

[kalelkenobi]

Any chance you could try downgrading to passt-0^20240624.g1ee2eca-1.fc40.x86_64 just for a quick test and see if that helps with CPU load?

I can't seem to find the old package. Not easily at least. do you know where I can get it?

[kalelkenobi]

I managed to dowgrade to passt 0^20240326.g4988e2b-1.fc40.x86_64 and the issue seems in fact mostly resolved. I still see a lot of rootlessport processes (see below), but CPU usage has improved greatly and the server is back to being usable.

podman      1138  0.5  0.4  72424 27420 ?        Ss   14:16   0:01 /usr/bin/pasta --config-net --address 10.0.2.0 --netmask 24 --gateway 10.0.2.2 --dns-forward 10.0.2.3 --pid /run/user/1001/containers/networks/rootless-netns/rootless-netns-conn.pid -t none -u none -T none -U none --no-map-gw --quiet --netns /run/user/1001/containers/networks/rootless-netns/rootless-netns
podman      1263  0.0  0.0 1745796 5268 ?        Sl   14:16   0:00 rootlessport
podman      1273  0.0  0.0 1598332 4836 ?        Sl   14:16   0:00 rootlessport-child
podman      1377  1.0  0.0 1819784 5696 ?        Sl   14:16   0:02 rootlessport
podman      1382  0.0  0.0 1524344 4988 ?        Sl   14:16   0:00 rootlessport-child

[kalelkenobi]

It is notably better, but I can't say for certain that it is back to "normal". I will have to invest some more time checking and testing.

[sbrivio-rh]

I can't seem to find the old package. Not easily at least. do you know where I can get it?

I'm not sure how you solved this, and for how long Fedora packages are retained, but we keep a permanent mirror of Copr builds (including Fedora packages) at https://passt.top/builds/copr/.

I managed to dowgrade to passt 0^20240326.g4988e2b-1.fc40.x86_64 and the issue seems in fact mostly resolved.

It is notably better, but I can't say for certain that it is back to "normal". I will have to invest some more time checking and testing.

Thanks, this is extremely helpful.