kubectl icon indicating copy to clipboard operation
kubectl copied to clipboard

port-forward dropping the connection for certain type of files

Open dvaldivia opened this issue 2 years ago • 25 comments

We are seeing a problem where kubectl port-forward is dropping the connection after serving a particular type of file, in this case a video, strangely enough, when we serve videos from non static files (copying a stream of bytes from MinIO for example) the pipe never breaks, file size makes no difference.

I created a repo with a reproduction case at https://github.com/dvaldivia/gofileserve

Steps to reproduction

1. Deploy the app in your kubernetes cluster

kubectl apply -f kubernetes/deployment.yaml

2. Port Forward to this service

kubectl port-forward svc/gofileserve 4001:4000

3. On another terminal, try to get Spinning-Cat.mp4

curl http://localhost:4001/assets/media/Spinning-Cat.mp4

You'll see how the port-forward breaks, and no request will work afterwards

➜ kubectl port-forward svc/gofileserve 4001:4000
Forwarding from 127.0.0.1:4001 -> 4000
Forwarding from [::1]:4001 -> 4000
Handling connection for 4001
E0210 13:22:27.776615   61159 portforward.go:379] error copying from remote stream to local connection: readfrom tcp4 127.0.0.1:4001->127.0.0.1:52390: write tcp4 127.0.0.1:4001->127.0.0.1:52390: write: broken pipe

if you restart the port-forward and you try to get other static files, like hello.json the pipe will never break

➜ curl http://localhost:4001/assets/hello.json
{
  "hello": "world"
}

So for this particular type of file being returned something cracks inside kubectl port-forward

dvaldivia avatar Feb 10 '23 22:02 dvaldivia

/triage accepted /assign @brianpursley

mpuckett159 avatar Mar 01 '23 17:03 mpuckett159

It looks like curl is the one breaking the pipe.

When I run your curl command, I get this warning and it exits with exit code 23:

$ curl http://localhost:4001/assets/media/Spinning-Cat.mp4
Warning: Binary output can mess up your terminal. Use "--output -" to tell 
Warning: curl to output it to your terminal anyway, or consider "--output 
Warning: <FILE>" to save to a file.
$ echo $?
23

curl gives you a couple of options:

  1. You can use the --output flag with a filename, like curl http://localhost:4001/assets/media/Spinning-Cat.mp4 --output Spinning-Cat.mp4
  2. If you really want the binary output to go to stdout, you can use --output - like this: curl http://localhost:4001/assets/media/Spinning-Cat.mp4 --output -. I'd imagine you use this if you want to pipe the output to another process.

When I did option 1, it works:

$ curl http://localhost:4001/assets/media/Spinning-Cat.mp4 --output Spinning-Cat.mp4
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1427k  100 1427k    0     0   138M      0 --:--:-- --:--:-- --:--:--  154M
$ ls -la Spinning-Cat.mp4 
-rw-rw-r-- 1 bpursley bpursley 1461984 Mar  1 21:43 Spinning-Cat.mp4

I did however notice that once you get the broken pipe, kubectl's port forwarding seems to get into some weird random (?) timeout state until you restart port forwarding. It just doesn't recover well from errors (and it doesn't exit either). If port forward cannot recover from an error, it should exit with a non-zero exit code, not keep running in some semi-operable state.

Example output of this weird timeout state:

$ kubectl port-forward svc/gofileserve 4001:4000
Forwarding from 127.0.0.1:4001 -> 4000
Forwarding from [::1]:4001 -> 4000
Handling connection for 4001
E0301 21:28:52.072825   20184 portforward.go:378] error copying from remote stream to local connection: readfrom tcp4 127.0.0.1:4001->127.0.0.1:54100: write tcp4 127.0.0.1:4001->127.0.0.1:54100: write: broken pipe
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
E0301 21:31:05.071949   20184 portforward.go:346] error creating error stream for port 4001 -> 4000: Timeout occurred
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
E0301 21:31:48.082873   20184 portforward.go:346] error creating error stream for port 4001 -> 4000: Timeout occurred
Handling connection for 4001
E0301 21:32:00.898307   20184 portforward.go:346] error creating error stream for port 4001 -> 4000: Timeout occurred
Handling connection for 4001
Handling connection for 4001
Handling connection for 4001
E0301 21:32:14.506840   20184 portforward.go:346] error creating error stream for port 4001 -> 4000: Timeout occurred
Handling connection for 4001
E0301 21:32:32.954398   20184 portforward.go:346] error creating error stream for port 4001 -> 4000: Timeout occurred

brianpursley avatar Mar 02 '23 02:03 brianpursley

I encountered a similar problem on mac M1, where the websocket protocol was running on the forwarding port. There will be no forwarding interruption for the same service on the linux arm64 version of kubectl

E0310 15:49:30.434931   37797 portforward.go:406] an error occurred forwarding 7070 -> 7070: error forwarding port 7070 to pod 36a7b2dfefae7f1a5efdb5c2d4302f308373e04573ec4cf5fb7ad62f7e8be944, uid : failed to execute portforward in network namespace "/var/run/netns/cni-748379a4-44d1-3802-107a-8bc98f3e1fb4": readfrom tcp4 127.0.0.1:46016->127.0.0.1:7070: write tcp4 127.0.0.1:46016->127.0.0.1:7070: write: broken pipe
E0310 15:49:30.438039   37797 portforward.go:234] lost connection to pod

vangie avatar Mar 10 '23 08:03 vangie

@brianpursley I don't think it's curl alone, we noticed this happening when our web-app attempted to load a video for a background animation, so I think it has to do more with the content being returned than anything

dvaldivia avatar Mar 30 '23 05:03 dvaldivia

Sorry for not bringing any concrete evidence, but I'm experiencing the same problem while port fowarding kafka-ui, it's just doing boring rest calls under the hood. Using a mac M1 as well if that matters.

andreldm avatar May 11 '23 13:05 andreldm

I'm also having this issue with Apache Superset on M1 Mac.

mooshmoosh avatar Jul 07 '23 06:07 mooshmoosh

https://github.com/containerd/containerd/pull/8418 <- there might be a fix in the pipeline for this, as per this comment

ravindk89 avatar Jul 10 '23 14:07 ravindk89

I'm also having this issue with Apache Superset on M1 Mac.

Same here - M1 as well FWIW

john-ramsey avatar Jul 31 '23 00:07 john-ramsey

Same here for Grafana UI on Mac M1

gusandrioli avatar Aug 16 '23 23:08 gusandrioli

seems to be an issue happening on Apple Silicon mainly

dvaldivia avatar Aug 16 '23 23:08 dvaldivia

Apple Silicon, grafana-ui, but also cockroach-ui triggers this for me. For local clusters via docker-desktop, but also remote x86 clusters.

On kubernetes-cli 1.27.4 this hangs after the first problem, on 1.28.2 this seems to at least recover after such a problem. So still excessive logging, but better behavior?

Do you guys consider this problem solved with that, or is the logging (see collapsed section) something you also want to fix?

Logs
❯ kubectl port-forward svc/rancher-monitoring-grafana 8080:80
Forwarding from 127.0.0.1:8080 -> 8080
Forwarding from [::1]:8080 -> 8080
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
E0920 15:38:56.723419   70989 portforward.go:381] error copying from remote stream to local connection: readfrom tcp6 [::1]:8080->[::1]:58214: write tcp6 [::1]:8080->[::1]:58214: write: broken pipe
E0920 15:38:56.723658   70989 portforward.go:394] error copying from local connection to remote stream: read tcp6 [::1]:8080->[::1]:58214: read: connection reset by peer
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
E0920 15:39:04.363633   70989 portforward.go:381] error copying from remote stream to local connection: readfrom tcp6 [::1]:8080->[::1]:58221: write tcp6 [::1]:8080->[::1]:58221: write: broken pipe
Handling connection for 8080
Handling connection for 8080
Handling connection for 8080
E0920 15:39:26.930397   70989 portforward.go:370] error creating forwarding stream for port 8080 -> 8080: Timeout occurred
E0920 15:39:31.194304   70989 portforward.go:370] error creating forwarding stream for port 8080 -> 8080: Timeout occurred
Handling connection for 8080
E0920 15:39:39.843494   70989 portforward.go:347] error creating error stream for port 8080 -> 8080: Timeout occurred
Handling connection for 8080
E0920 15:39:40.720737   70989 portforward.go:370] error creating forwarding stream for port 8080 -> 8080: Timeout occurred
Handling connection for 8080
E0920 15:40:09.845963   70989 portforward.go:347] error creating error stream for port 8080 -> 8080: Timeout occurred
Handling connection for 8080
E0920 15:40:10.730176   70989 portforward.go:370] error creating forwarding stream for port 8080 -> 8080: Timeout occurred
Handling connection for 8080

dwt avatar Sep 20 '23 13:09 dwt

This issue happens on windows too for us.

debarshibasak avatar Oct 26 '23 06:10 debarshibasak

I have the same issue with Postgres and pgadmin4. and doing a while true ; do nc -vz 127.0.0.1 8080 ; sleep 7 ; done did not help

hadifarnoud avatar Nov 22 '23 09:11 hadifarnoud

Still an issue

allanrogerr avatar May 08 '24 16:05 allanrogerr

https://github.com/containerd/containerd/issues/9875 maybe related? It seems like attempts to fix this have been ongoing.

ravindk89 avatar May 08 '24 16:05 ravindk89