pasta: downloading from remote server, traffic comes to a halt followed by high cpu usage

nd2408 commented 1 year ago

Issue Description

$ pasta --version
pasta 0^20230222.g4ddbcb9-1.fc37.x86_64

the container is downloading ~1MB chunks over TCP -> TLS -> NNTP, starts out fine but quickly comes to a halt:
as it starts coming to a halt, the pasta process is maxing out a thread:
eventually, the pasta process goes back down to zero percent and if you leave it alone, it'll continue the same pattern after a few minutes:
if you up the concurrent connections from 2 to 100, the problem occurs faster
however, dropping the MTU down to 1500 appears to fix the issue

if this is not a bug, can an additional "WARNING" be added to the documentation explaining why? because at first glance, it reads like slirp4netns and pasta use the same default MTU, so you shouldn't need to adjust it.

Steps to reproduce the issue

$ cat ~/.config/containers/systemd/sabznbd.container
# https://hub.docker.com/r/linuxserver/sabnzbd
# https://github.com/linuxserver/docker-sabnzbd

[Unit]
Description=%N container

[Container]
Image=lscr.io/linuxserver/sabnzbd:latest
User=%U
Group=%G
RemapUsers=keep-id

# VOLUMES
Volume=%h/.podman/%N/config:/config:Z
Volume=%h/.podman/%N/downloads:/downloads:z
Volume=%h/.podman/%N/incomplete:/incomplete:z

# NETWORK
Network=pasta
PublishPort=8001:8080/tcp

# LABELS
Label=io.containers.autoupdate=registry

# ENV VARS
Environment=PUID=%U
Environment=PGID=%G
Environment=TZ=Etc/UTC

[Service]
Restart=always

[Install]
# Start by default on boot
WantedBy=multi-user.target default.target

Describe the results you received

Network=slirp4netns:mtu=65520 - works
Network=pasta:--mtu,65520 - causes the issues above
Network=pasta:--mtu,1500 - works

Describe the results you expected

the same as slirp4netns with default options, which works fine.

podman info output

$ podman info
host:
  arch: amd64
  buildahVersion: 1.29.0
  cgroupControllers:
  - cpu
  - io
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-2.1.6-3.fc37.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.6, commit: '
  cpuUtilization:
    idlePercent: 44.04
    systemPercent: 12.52
    userPercent: 43.44
  cpus: 24
  distribution:
    distribution: fedora
    variant: workstation
    version: "37"
  eventLogger: journald
  hostname: something
  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: 6.1.14-200.fc37.x86_64
  linkmode: dynamic
  logDriver: journald
  memFree: 13910327296
  memTotal: 67343822848
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun-1.8.1-1.fc37.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.8.1
      commit: f8a096be060b22ccd3d5f3ebe44108517fbf6c30
      rundir: /run/user/1000/crun
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +LIBKRUN +WASM:wasmedge +YAJL
  os: linux
  remoteSocket:
    exists: true
    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
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: true
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns-1.2.0-8.fc37.x86_64
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.7.0
      SLIRP_CONFIG_VERSION_MAX: 4
      libseccomp: 2.5.3
  swapFree: 8589930496
  swapTotal: 8589930496
  uptime: 68h 9m 57.00s (Approximately 2.83 days)
plugins:
  authorization: null
  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/user/.config/containers/storage.conf
  containerStore:
    number: 2
    paused: 0
    running: 2
    stopped: 0
  graphDriverName: btrfs
  graphOptions: {}
  graphRoot: /home/user/.local/share/containers/storage
  graphRootAllocated: 999111524352
  graphRootUsed: 363246858240
  graphStatus:
    Build Version: Btrfs v6.1.3
    Library Version: "102"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 5
  runRoot: /run/user/1000/containers
  transientStore: false
  volumePath: /home/user/.local/share/containers/storage/volumes
version:
  APIVersion: 4.4.2
  Built: 1677669779
  BuiltTime: Wed Mar  1 07:22:59 2023
  GitCommit: ""
  GoVersion: go1.19.6
  Os: linux
  OsArch: linux/amd64
  Version: 4.4.2

Podman in a container

No

Privileged Or Rootless

Rootless

Upstream Latest Release

Yes

Additional environment details

No response

Additional information

Additional information like issue happens only occasionally or issue happens with a particular architecture or on a particular setting

Luap99 commented 1 year ago

Sounds like a bug, I suggest you bring this issue up upstream as I don't think podman can do much about it, we could set a different mtu but I would like to avoid that and just follow the default from pasta.

see https://passt.top/passt/bugs and https://passt.top/passt/lists

cc @sbrivio-rh

sbrivio-rh commented 1 year ago

Thanks @Luap99 for the Cc:! We can also follow up here even if it's clearly a bug in pasta and not in Podman, is that okay?

@nd2408 the 64 KiB MTU should be always fine, unlike with slirp4netns, so if that's causing problems, we have a problem we need to fix.

I haven't tried to reproduce the issue yet. Meanwhile, two things would be helpful:

strace from the misbehaving process when it's using a full CPU thread, half a second would be enough. You need to run that (something like strace -p $(pidof pasta) 2>strace.log) as root, pasta won't let unprivileged users trace its system calls
debug log from pasta that you can get with --net=pasta:-d,-l,/tmp/pasta.log

Thanks!

Luap99 commented 1 year ago

We can also follow up here even if it's clearly a bug in pasta and not in Podman, is that okay?

yes, easier for me to keep track as well

nd2408 commented 1 year ago

forgot to mention that this is bleeding over from /r/podman and that @TomSweeneyRedHat suggested i submit an issue here.

@sbrivio-rh i had to bump up the --log-size, tons of spam but hopefully a few seconds of runtime is enough:

15.7990:          TCP: index 86, timer expires in 2.000s
15.7990:          TCP: index 86, timer expires in 2.000s
15.7990:          TCP: index 86, timer expires in 2.000s
15.7991:          TCP: index 86, timer expires in 2.000s
15.7991:          TCP: index 86, timer expires in 2.000s
15.7991:          TCP: index 86, timer expires in 2.000s
15.7991:          TCP: index 86, timer expires in 2.000s

pasta.log

i'll try the strace here in a bit

sbrivio-rh commented 1 year ago

forgot to mention that this is bleeding over from /r/podman and that @TomSweeneyRedHat suggested i submit an issue here.

By the way, pasta has been available on Fedora for quite a while now, https://bodhi.fedoraproject.org/updates/?packages=passt

sbrivio-rh commented 1 year ago

...and it's available on Ubuntu too, see https://packages.ubuntu.com/lunar/passt

nd2408 commented 1 year ago

pasta-strace.log

5981 occurrences of:

read(11, 0x55aac3d00036, 8388554)       = -1 EAGAIN (Resource temporarily unavailable)

sbrivio-rh commented 1 year ago

pasta-strace.log

Thanks a lot!

5981 occurrences of:

read(11, 0x55aac3d00036, 8388554)       = -1 EAGAIN (Resource temporarily unavailable)

That, by itself, is not an issue -- we don't keep reading if the socket has no frames available, but we read as much data as possible, until we hit EAGAIN.

I'm still trying to figure out what the problem is here, so I have a few more questions:

is there a way I can set up something similar to your NNTP application?
could you check if this happens also with the most recent Fedora 37 package available (sudo dnf upgrade --enablerepo=updates-testing --refresh --advisory=FEDORA-2023-ae66901b6a)? That includes a few fixes, even though I'm not sure yet if any of that is relevant here.
you shared a chart with "pasta" and "slirp4netns" labels: does that represent network usage? From that, I would infer that with pasta you're only able to download a small part of the ~1 MiB chunks, is that correct?
if you have the chance, could you please also retry with the MTU set to smaller values (I'd be particularly interested in ~65000 and ~32000)? I suspect you're hitting some corner case with a particular TCP segment size, that's why I'm asking.

Thanks again!

nd2408 commented 1 year ago

could you check if this happens also with the most recent Fedora 37 package available

$ pasta --version
pasta 0^20230227.gc538ee8-1.fc37.x86_64

Network=pasta - not working, same as before

I suspect you're hitting some corner case with a particular TCP segment size, that's why I'm asking.

Network=pasta:--mtu,65000 - works, Network=pasta:--mtu,32000 - works, ~1MB/s faster than 65000, also more consistent

you might be onto something

you shared a chart with "pasta" and "slirp4netns" labels: does that represent network usage? From that, I would infer that with pasta you're only able to download a small part of the ~1 MiB chunks, is that correct?

exactly, it's from the web ui, just shows network speed for the past ~5min.

is there a way I can set up something similar to your NNTP application?

yea, i was thinking we should chat out-of-band so i can get you setup with a proper environment. do you have a preferred email or does passt-sec@passt.top work?

sbrivio-rh commented 1 year ago

Network=pasta:--mtu,65000 - works, Network=pasta:--mtu,32000 - works, ~1MB/s faster than 65000, also more consistent

Hah, interesting.

yea, i was thinking we should chat out-of-band so i can get you setup with a proper environment. do you have a preferred email or does passt-sec@passt.top work?

You can just use sbrivio@redhat.com. Thanks. By the way, I'm also on IRC (sbrivio) at #passt or #podman on libera.chat, same nick on OFTC.

nd2408 commented 1 year ago

You can just use sbrivio@redhat.com.

look out for subject: "podman issue #17703"

sbrivio-rh commented 1 year ago

Patch posted: https://archives.passt.top/passt-dev/20230308211628.2282752-1-sbrivio@redhat.com/

sbrivio-rh commented 1 year ago

Fixed in upstream release 2023_03_09.7c7625d, upcoming packages passt-0^20230309.g7c7625d-1.fc37 (Fedora 37), 0.0~git20230309.7c7625d-1 (Debian unstable)

containers / podman