'devspace enter' session is interrupted

[musicformellons]

Not sure whether this is a bug. Problem is somewhat similar to this issue, but I am not on windows (ubuntu). I have devspace (without helm) and exec into three processes (once with devspace dev and twice with devspace enter) into two containers. So:
A) one process on container A
B) two processes on container B

I lose contact (suddenly instead of terminal output I get a prompt) with (especially with B) quite often. Output seems to vary, e.g. last time I got:
errors.log:

{"level":"info","msg":"Sync started on /home/usr/api/trex \u003c-\u003e /home/usr (Pod: default/mymarkers-6cb47df99f-rv4ws)","time":"2019-03-27T22:48:43+01:00"}
{"level":"info","msg":"Opening shell to pod:container \u001b[1;37mmyapp-7cc4dc5c56-4hkvp\u001b[0m:\u001b[1;37mapp\u001b[0m","time":"2019-03-27T22:49:58+01:00"}
{"level":"fatal","msg":"[Sync] Fatal sync error: \n[Downstream] Stream closed unexpectedly. For more information check .devspace/logs/sync.log","time":"2019-03-28T08:04:50+01:00"}

sync.log:

{"container":"/home/usr","level":"info","local":"/home/usr/api/trex","msg":"[Upstream] Successfully processed 12 change(s)","pod":"mymarkers-6cb47df99f-rv4ws","time":"2019-03-27T22:48:45+01:00"}
{"container":"/home/usr","level":"info","local":"/home/usr/api/trex","msg":"[Sync] Sync stopped","pod":"mymarkers-6cb47df99f-rv4ws","time":"2019-03-28T08:04:50+01:00"}
{"container":"/home/usr","level":"error","local":"/home/usr/api/trex","msg":"Error: \n[Downstream] Stream closed unexpectedly, Stack: \n[Downstream] Stream closed unexpectedly\n/Users/travis/gopath/src/github.com/devspace-cloud/devspace/pkg/devspace/sync/downstream.go:187: \n/Users/travis/gopath/src/github.com/devspace-cloud/devspace/pkg/devspace/sync/downstream.go:114: ","pod":"mymarkers-6cb47df99f-rv4ws","time":"2019-03-28T08:04:50+01:00"}

What is causing this? Is it a loss of internet connection? That is odd, since when I disconnect my internet and reconnect it still can continue the sessions, so seems a slight internet connection disruption should cause no problems.

And furthermore: When getting the prompt and then devspace enter into the same container and trying to restart the service (server), it gives connection error as process seems to be still running in background. Can I somehow reattach to the (PID) process with a terminal screen?

[musicformellons]

In my errors.log I find in enormous amount of this type of error:

{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:50 socat[113437] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:50+01:00"}

And then at the end:

{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:50 socat[113437] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:50+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:50 socat[113438] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:50+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:51 socat[113500] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:51+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:51 socat[113503] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:51+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:52 socat[113507] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:53+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:53 socat[113508] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:53+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:54 socat[113537] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:54+01:00"}
{"level":"error","msg":"Runtime error occurred: an error occurred forwarding 9229 -\u003e 9229: error forwarding port 9229 to pod 38808f5233094765db6b8f626855bb061bc6998a94c1240e641e5573ee792e84, uid : exit status 1: 2019/03/28 15:25:54 socat[113538] E connect(5, AF=2 127.0.0.1:9229, 16): Connection refused\n","time":"2019-03-28T16:25:54+01:00"}
{"level":"error","msg":"Runtime error occurred: lost connection to pod","time":"2019-03-28T16:25:55+01:00"}
{"level":"error","msg":"Runtime error occurred: lost connection to pod","time":"2019-03-28T16:25:55+01:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-03-28T16:25:55+01:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-03-28T16:25:55+01:00"}
{"level":"error","msg":"Runtime error occurred: error creating error stream for port 9229 -\u003e 9229: Timeout occurred","time":"2019-03-28T16:26:25+01:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-03-28T16:27:54+01:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-03-28T16:27:54+01:00"}

Any suggestions how to solve the refusal of connection or is this 'normal'...?

[FabianKramm]

Thanks for opening this issue @musicformellons . I looked through your logs and usually I get the Stream closed unexpectedly when the container somehow crashes or restarts. The Runtime error occured logs are related to port forwarding, which seem to indicate that somehow the connection to the pod was interrupted, which is usually the case either because the pod seems to have restarted or because of an internet issue or sometimes also because of kubernetes itself.

@KaelBaldwin could solve the issues by upgrading his cluster to a newer version, because it seems that sometimes the connection disruption is caused by kubernetes itself (not sure why though, maybe a bug in kubectl or the api server itself). You can check if kubernetes is the problem by also running kubectl port-forward or kubectl exec along with the devspace commands, because the sync and port-forwarding are using essentially these commands internally. If they are also interrupted after a while, kubernetes seems to be the problem, otherwise there is an issue in devspace we somehow have to investigate.

Regarding your question:

Can I somehow reattach to the (PID) process with a terminal screen?

Unfortunately I don't think this is possible currently, kubernetes gives us no option to attach to a specific PID yet, so the only solution is to restart the server on devspace enter.

[musicformellons]

Ok, thanks for the pointers! I am upgrading my kubernetes right now, so maybe that helps. The error Runtime error occurred: an error occurred forwarding 9229 happens like twice every second. Within my cluster the 9229 port is not really necessary, but as far as I remember it used to be configured by Devspace for 'debugging / syncing'. However in current docs I do not find this any longer, so maybe I can just get rid of it?

[FabianKramm]

9229 is the node debugger port, which is only necessary if want to debug node applications locally. You can just delete that if you don't use it

[musicformellons]

'Debug node application locally', I suppose that means: I edit on my local machine and then it syncs my changes to my kubernetes cloud? That's essential to me.

My current portforwarding config:

  ports:
  - labelSelector:
      app: myapp-pod
    portMappings:
    - localPort: 8089
      remotePort: 8089
    - localPort: 8088
      remotePort: 8088
    - localPort: 9229
      remotePort: 9229
  - labelSelector:
      app: mymarkers-pod
    portMappings:
    - localPort: 8081
      remotePort: 8081
    - localPort: 8011
      remotePort: 8011
    - localPort: 8060
      remotePort: 8060
    - localPort: 9229
      remotePort: 9229

Does using 9229 on both pods give conflicts, or should that be ok?

[FabianKramm]

No with debug node applications locally I mean attaching a node debugger to your remotely running node application, I guess in your use case you just want to sync file changes which is not affected by this, so I think you can remove the 9229 port.

[musicformellons]

Ah, that makes sense! I will get rid of it!

My kubernetes is still updating..., as soon as I can test and see of things are then solved I will close this issue.

[musicformellons]

Seems solved.

[musicformellons]

Actually was not really solved... After updating Kubernetes and Devspace and change correct ports I still have basically the same behavior: My session is ended and I have to devspace purge and devspace dev to have a working session again. Only error log I find:
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-05-02T17:14:42+02:00"}

My pods seem to run fine, also after the ending of the devspace session...

[FabianKramm]

@musicformellons mhh that is odd, could you try to open a kubectl exec shell in parallel to see if that loses connection aswell? I don't think you have to run devspace purge everytime the terminal loses connection, you could just run ps aux in the new shell afterwards and kill the still running processes.

[musicformellons]

Ok, will test kubectl exec. Regarding your interesting suggestion on devspace purge probably being unnecessary: When I ps aux on my local machine I can not find 'what process to kill' (lsof -i does not return anything), which in a way makes sense as the connection seems dropped locally. When I try to devspace enter it works but when I start the server in my app it gives 'connection already in use error', and when I want to kill it there I do not have these tools installed in my container. So does not really work for me it seems.

[musicformellons]

I tried twice and both times the kubectl connection to the two pods also lost connection. Error logs in devspace:

{"level":"error","msg":"Runtime error occurred: lost connection to pod","time":"2019-05-06T01:32:46+02:00"}
{"level":"error","msg":"Runtime error occurred: lost connection to pod","time":"2019-05-06T01:33:12+02:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-05-06T07:41:34+02:00"}
{"level":"error","msg":"Runtime error occurred: write |1: broken pipe","time":"2019-05-06T07:41:34+02:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-05-06T07:41:34+02:00"}
{"level":"error","msg":"Runtime error occurred: EOF","time":"2019-05-06T07:41:34+02:00"}

[FabianKramm]

@musicformellons Thanks for testing that out! Unfortunately I don't think we can do much about this issue, because internally we just use the kubectl functionality. This seems to be more of a problem with the kubernetes client-go cli streaming functionality. The error logs also indicate that somehow the connection to the pod was lost, I cannot really tell why though.

[musicformellons]

As I am using Istio (on GKE) this might be related.

[LukasGentele]

@musicformellons Is this still an issue for you with the newest version of DevSpace CLI or can we close this issue?

[musicformellons]

It still is an issue...

[musicformellons]

Solved through issue #643 !! It works very well now, really happy this got resolved!

[FabianKramm]

Very glad it solved the issue!