After running oc cluster up and creating a pod/service, the newly created pod can't connect outbound to its own service IP:port

[jim-minter]

Running on the latest origin vagrant VM + dnf -y update, with latest origin master, after running oc cluster up and creating a pod/service, the newly created pod can't connect outbound to its own service IP:port.

Version

[root@openshiftdev ~]# uname -a
Linux openshiftdev 4.8.10-100.fc23.x86_64 #1 SMP Mon Nov 21 20:37:11 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
[root@openshiftdev ~]# docker version
Client:
 Version:         1.10.3
 API version:     1.22
 Package version: docker-1.10.3-45.gite03ddb8.fc23.x86_64
 Go version:      go1.5.4
 Git commit:      e03ddb8/1.10.3
 Built:           
 OS/Arch:         linux/amd64

Server:
 Version:         1.10.3
 API version:     1.22
 Package version: docker-1.10.3-45.gite03ddb8.fc23.x86_64
 Go version:      go1.5.4
 Git commit:      e03ddb8/1.10.3
 Built:           
 OS/Arch:         linux/amd64
[root@openshiftdev ~]# oc version
oc v1.5.0-alpha.0+7b90443-191
kubernetes v1.4.0+776c994
features: Basic-Auth

Server https://192.168.121.216:8443
openshift v1.5.0-alpha.0+3b2bbe5
kubernetes v1.4.0+776c994

Steps To Reproduce

1. oc cluster up
2. oc create -f examples/gitserver/gitserver-ephemeral.yaml
3. oc rsh git-1-XXXXX
4. sh-4.2$ curl git:8080/_/healthz

Current Result

hangs

Expected Result

outputs the text "ok"

Additional Information

[root@openshiftdev ~]# oc get pods -o wide
NAME          READY     STATUS    RESTARTS   AGE       IP           NODE
git-1-it8uk   1/1       Running   0          9m        172.17.0.3   192.168.121.216
[root@openshiftdev ~]# oc get svc
NAME      CLUSTER-IP       EXTERNAL-IP   PORT(S)    AGE
git       172.30.211.219   <none>        8080/TCP   9m

[root@openshiftdev ~]# curl 172.17.0.3:8080/_/healthz
ok
[root@openshiftdev ~]# curl 172.30.211.219:8080/_/healthz
ok
[root@openshiftdev ~]# oc rsh git-1-it8uk
sh-4.2$ curl -k https://172.30.0.1:443/healthz
ok
sh-4.2$ curl 172.17.0.3:8080/_/healthz
ok
sh-4.2$ curl 172.30.211.219:8080/_/healthz
<HANGS>

Two interesting additional pieces of information:

1. If I run ifconfig docker0 promisc on the host, things start working fully as expected
2. If I scale up to 2 pods providing the back end service, things "sort of" work, but with irregular long delays:

[root@openshiftdev ~]# oc scale dc/git --replicas=2
deploymentconfig "git" scaled
[root@openshiftdev ~]# oc rsh git-1-it8uk
sh-4.2$ time $ curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m3.072s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m1.052s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m3.092s
user	0m0.001s
sys	0m0.003s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.001s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.002s
sys	0m0.001s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m0.003s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m1.013s
user	0m0.001s
sys	0m0.002s
sh-4.2$ time curl 172.30.211.219:8080/_/healthz
ok
real	0m7.133s
user	0m0.000s
sys	0m0.003s

[jim-minter]

@knobunc do you have any advice on who could help with this?

[knobunc]

@jim-minter can you please grab a debug tar using the script referenced at https://docs.openshift.com/enterprise/3.2/admin_guide/sdn_troubleshooting.html#further-help

@danwinship can you think of anything funny that would happen in this case?

[jim-minter]

Please see https://dl.dropboxusercontent.com/u/13429758/openshift-sdn-debug-2016-12-02.tgz .

Hopefully it'll be useful - I don't know if openshift-sdn-debug is entirely geared up to run with oc cluster up installs.

[root@openshiftdev tmp]# ./debug.sh 192.168.121.214
Analyzing master

Analyzing 192.168.121.214 (192.168.121.214)
Could not find node-config.yaml from 'ps' or 'systemctl show'

Output is in openshift-sdn-debug-2016-12-02.tgz

[jim-minter]

Hmm, I had thought this affected both "oc cluster up" and "openshift start" type one-box setups, but it appears to be related specifically to "oc cluster up".

[csrwng]

From a networking point of view, the main difference is that one is running in a container (with --net=host and --privileged) and the other one is not.

[danwinship]

hm... "oc cluster up" doesn't work for me on F23. (looks like #9470).

Anyway, the issue is probably that we aren't setting --hairpin-mode to the right value, but I don't know how to override that when using "oc cluster up"...

[csrwng]

@danwinship is that a kubelet argument?

[danwinship]

yes

[jim-minter]

@danwinship I didn't realise how close I was with my comment about setting ifconfig docker0 promisc :-)
Are you able to say what value --hairpin-mode should be set to? Are there any circumstances under which it should be set differently to the mode you will be recommending?

[jim-minter]

from the server logs:

W1202 16:40:24.431687   16250 kubelet_network.go:71] Hairpin mode set to "promiscuous-bridge" but configureCBR0 is false, falling back to "hairpin-veth"
I1202 16:40:24.431739   16250 kubelet.go:513] Hairpin mode set to "hairpin-veth"

[jim-minter]

Previous comment is a red herring, I think.

When running via oc cluster up, cat /sys/devices/virtual/net/docker0/brif/veth*/hairpin_mode shows all 0s. When running via openshift start, all 1s.

[danwinship]

hairpin-veth sounds right... maybe dockermanager just isn't able to set it (doesn't have access to /sys/devices/virtual/net maybe?). Are there any other hairpin-related messages in the logs?

[jim-minter]

Aha!

5909 openat(AT_FDCWD, "/sys/devices/virtual/net/veth59a9a17/brport/hairpin_mode", O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC, 0644) = -1 EROFS (Read-only file system)

Will get a PR for that.

[jim-minter]

@danwinship @knobunc thanks for your help with this!

[jim-minter]

@csrwng can confirm a binds = append(binds, "/sys/devices/virtual/net:/sys/devices/virtual/net:rw") in func (h *Helper) Start solves this for me. In my case here opt.UseSharedVolume is false; under what conditions is opt.UseSharedVolume true , and will they also need this bind?

Also separately, briefly, what is the rationale behind the /rootfs bind?

[jim-minter]

hm... "oc cluster up" doesn't work for me on F23. (looks like #9470).

@danwinship please could you submit a new issue for this with versions used, --loglevel=5 and I'll take a look. I'd rather not see this drop if possible.

[csrwng]

@jim-minter I'm seeing this behavior again in recent versions of openshift. On linux, running ifconfig docker0 promisc does fix it. I have also verified that /sys/devices/virtual/net is getting mounted as read/write. On the Mac, it seems that I can't access any services from a pod.

@danwinship @knobunc do you have any suggestions for further debugging?

[jim-minter]

@csrwng getting an strace might show what's going on - you'll probably need to run strace -f -o <output_file> -p on the dockerd.

[jim-minter]

@csrwng (start the strace before running oc cluster up)

[danwinship]

or possibly even just --loglevel=5 logs. presumably it's failing to set hairpin mode again for some reason

[csrwng]

Here's the server log with --loglevel=5
https://gist.github.com/c0b522e4db7d1cfa4d1709dfedd394ac

The strace is here (I compressed it because it was 26 mb):
https://drive.google.com/open?id=0Bxi-kAIS_6Y7Sm1YR0VPNWxlQm8

[danwinship]

node logs, not master

[csrwng]

@danwinship it's all-in-one so it's both node and master

[csrwng]

Some additional info ... did an unscientific test on @bparees's machine (which has docker 1.10), and accessing the service works from the pod. So this seems broken only on 1.12 which is what I'm running on my RHEL box.

To summarize:
docker 1.10: everything works fine
docker 1.12: pods cannot access the service they expose themselves, but can access other svcs
docker 1.13 (Mac): pods cannot access any service

@jwhonce do you know of any changes in Docker that affect pod networking?

[danwinship]

Those logs are incomplete in some way... eg, there's nothing logged from kubelet.go (and in particular no line 'Hairpin mode set to "..."')

maybe relevant:

W0127 16:21:22.532293    5090 node.go:509] Failed to retrieve node info: nodes "10.13.137.84" not found
W0127 16:21:22.532366    5090 proxier.go:249] invalid nodeIP, initialize kube-proxy with 127.0.0.1 as nodeIP
W0127 16:21:22.532373    5090 proxier.go:254] clusterCIDR not specified, unable to distinguish between internal and external traffic

[csrwng]

let me try again

[csrwng]

Strange, if I don't set the --loglevel, then I get the log about the hairpin mode, otherwise I don't
Here's the log without specifying a loglevel
https://gist.github.com/e28ae799b819f22dc0b71a89cb7029b1

[jim-minter]

@csrwng on latest F25, docker-1.12.6-5.git037a2f5.fc25.x86_64, oc from https://github.com/openshift/origin/releases/download/v1.5.0-alpha.2/openshift-origin-client-tools-v1.5.0-alpha.2-e4b43ee-linux-64bit.tar.gz, it works for me. I also get the logs @danwinship notes.

Am going to need more info to reproduce here.

[csrwng]

ok, some more info ...
It looks like I was losing log entries because of the journald log driver. I switched my local driver to use json-file and now I see the hairpin mode log entry:
https://gist.github.com/318adfd57026d6055367407d0767c020

Right after starting the cluster,

cat /sys/devices/virtual/net/veth*/brport/hairpin_mode

is showing 0.

However, I exec'd into the origin container:

docker exec -ti origin bash

Then wrote a 1 to `/sys/devices/virtual/net/veth*/brport/hairpin_mode'
and checked it on the host, and it was set to 1 there as well. Then I tried accessing the docker-registry service from the docker-registry pod and that worked as well.

Somehow my kubelet is skipping the step of writing a 1 to that file.

[csrwng]

Found it. So the issue is that we're hard-coding docker's root directory /var/lib/docker and mounting it to the origin container. In my case, I am running docker-latest, and the root directory is /var/lib/docker-latest.

[csrwng]

cool, so that's an easy fix, now to figure out why it's completely broken on the mac :)

[csrwng]

So I found out that only Docker 1.13.0 is broken on the mac. Docker 1.13.1-rc1 is not. I thought it could be related to them changing the default policy for FORWARD from ACCEPT to DROP in the filter table. However the same policy is in place in 1.13.1-rc1 and that's working fine.

[msenmurugan]

@csrwng - I'm using OC client tool version 3.7 and latest docker version in RHEL. Please find the instructions that I have used to install the Docker and OC client

Docker Install
yum -y remove docker docker-common container-selinux
yum -y remove docker-selinux
yum install -y yum-utils
yum-config-manager --add-repo https://download.docker.com/linux/centos/docker-ce.repo
yum makecache fast
yum-config-manager --enable rhui-REGION-rhel-server-extras
yum install -y docker-ce
systemctl start docker
systemctl enable docker

OC client Install
curl -sSL https://github.com/openshift/origin/releases/download/v3.7.0/openshift-origin-client-tools-v3.7.0-7ed6862-linux-64bit.tar.gz -o oc-client.tar.gz
tar -zxvf oc-client.tar.gz
mv openshift-origin-client-tools-v3.7.0-7ed6862-linux-64bit/oc /usr/bin
rm -rf oc-client.tar.gz

After installing the clients, performed oc cluster up command and then added containers to the single node cluster. The containers within the host are unable to communicate with each other.

I'm getting the above issue. But when I incorporate @jim-minter comment i.e. adding the ifconfig docker0 promisc, it is working fine. So whether adding this line is the recommended approach or any permanent fix available.

[csrwng]

@msenmurugan that sounds like the original issue we had with the kubelet not able to update the virtual network device hairpin_mode, which is why we added this bind mount to the origin container:
https://github.com/openshift/origin/blob/master/pkg/oc/bootstrap/docker/openshift/helper.go#L298-L300
Can you run docker inspect origin (and include the output) while cluster up is running to see if that mount exists ?

[jim-minter]

I haven't been able to reproduce an issue using the latest AWS RHEL AMI and the instructions above. @msenmurugan when you say "The containers within the host are unable to communicate with each other", what are you trying to do, what are you expecting to happen, and what happens? If you're still having problems, I suggest opening a new issue.

$ cat >/etc/docker/daemon.json <<EOF
{
  "insecure-registries": ["172.30.0.0/16"]
}
EOF
$ service docker restart
$ oc cluster up --loglevel=2
$ oc login -u system:admin
$ oc project default
$ oc get pods -o wide
NAME                            READY     STATUS    RESTARTS   AGE       IP              NODE
docker-registry-1-wdnkw         1/1       Running   0          53s       172.17.0.5      localhost
persistent-volume-setup-gl8l5   1/1       Running   0          1m        172.17.0.2      localhost
router-1-k8tg9                  1/1       Running   0          52s       172.18.14.147   localhost
$ oc get svc
NAME              CLUSTER-IP    EXTERNAL-IP   PORT(S)                   AGE
docker-registry   172.30.1.1    <none>        5000/TCP                  2m
kubernetes        172.30.0.1    <none>        443/TCP,53/UDP,53/TCP     2m
router            172.30.34.4   <none>        80/TCP,443/TCP,1936/TCP   2m
$ oc rsh router-1-k8tg9
sh-4.2$ curl -D - 172.17.0.5:5000/healthz
HTTP/1.1 200 OK

sh-4.2$ curl -D - 172.30.1.1:5000/healthz
HTTP/1.1 200 OK

[garagatyi]

Hi. We've faced the same issue in Eclipse Che on OCP (docker-based OCP).
Exec'ing into origin container and changing veth* networks hairpin setting to 1 helps but we can not use it since our users create new OS projects which get hairpin=0.
Host system is Fedora 25
Openshift v3.7.0+7ed6862
Same behavior on our CI on Centos 7.x

Can you give any advice on how to nail down this issue?

[csrwng]

@garagatyi try bringing the cluster down and restarting Docker (not restarting the machine). There seems to be an issue with iptables and Docker when it's first brought up by systemd. If you restart Docker after your machine is running, it fixes itself.

[garagatyi]

Thank you for the suggestion but it didn't help.

[garagatyi]

BTW docker version is 17.09.1-ce

[jim-minter]

@msenmurugan and @garagatyi thank-you both for your report, I've now been able to reproduce this. It's a new issue in an old area; I have opened https://bugzilla.redhat.com/show_bug.cgi?id=1535510 to track.

[dlakatos847]

This issue is still present with Origin v3.11 running on Docker 19.03.1, OpenSuSE Tw. Not sure why this is closed. The workaround resolves the issue but seems like an ugly hack to me: sudo ip link set docker0 promisc on