All API servers (openshift-apiserver, oauth-server, oauth-apiserver) rely on the TCP stack to detect broken network connections to KAS. This can take up to 15 minutes. During that time our platform might be unavailable. There are already reported cases in which aggregated APIs (i.e. `openshift-apiserver`) were unable to establish a new connection to the Kube API for 15 minutes: - after "ungraceful termination" https://bugzilla.redhat.com/show_bug.cgi?id=1881878 - after a network error https://bugzilla.redhat.com/show_bug.cgi?id=1879232#c39) Detecting a broken connection should be quicker ideally it should take seconds not minutes.
@Xia I can share some ideas on how to verify the bug if you are interested.
Was occupied by other queued and rising work. So didn't work on this bug yet. Will try to look next day.
Lukasz Szaszkiewicz, would like to hear your ideas :) Currently I guess (not yet have time to try today): In terminals, ssh to masters from bastion, check crictl logs -f the_OAS_container. In other terminals, also ssh to masters from bastion, on all masters, meantime make kube-apiserver down by mv /etc/kubernetes/manifests/kube-apiserver-pod.yaml /tmp.
(In reply to Xingxing Xia from comment #4) > Lukasz Szaszkiewicz, would like to hear your ideas :) > Currently I guess (not yet have time to try today): > In terminals, ssh to masters from bastion, check crictl logs -f > the_OAS_container. > In other terminals, also ssh to masters from bastion, on all masters, > meantime make kube-apiserver down by mv > /etc/kubernetes/manifests/kube-apiserver-pod.yaml /tmp. Hi, sure. So I was able to reproduce the issue by blocking (iptables) communication between two components. For example to break communication between OAS and KAS you could. 1. Get SSH access to a master node 2. Get a pid of OAS (crictl ps, crictl inspect | grep "pid") 3. Get into OAS's network ns (nsenter -t $PID -n /bin/bash) 4. Block traffic from OAS to KAS (iptables -I FORWARD -p tcp --sport $PORT -s $IP -j DROP) 5. Withouth the fix OAS won't be able to open a new connection to KAS for ~15 minutes. You may observe slowness of the platform and gradual degradation. Don't forget that this BZ targets multiple servers (all susceptible) oauth-server, oauth-apiserver, kube-apiserver, openshift-apiserver. All share the same code. It would be nice if you could check oauth-server, oauth-apiserver and openshift-apiserver
Hi Lukasz, to ensure the 4.7 verification is correct. I first tried to reproduce in 4.6 env (4.6.0-0.nightly-2020-12-21-163117), take OAS for example: On one master (master-1): [root@wduan-1225a-dmt4h-master-1 ~]# crictl ps --name=openshift-apiserver$ CONTAINER IMAGE CREATED STATE NAME ATTEMPT POD ID 0bbc03b5398a5 8288a707532596804713c53b91ba049beb1dc516e105f7d5170f76e6d9462903 6 hours ago Running openshift-apiserver 0 1f8266e30ac65 [root@wduan-1225a-dmt4h-master-1 ~]# crictl inspect 0bbc03b5398a5 | grep pid "pid": 38684, [root@wduan-1225a-dmt4h-master-1 ~]# nsenter -t 38684 -n /bin/bash # I don't know what source port and IP you intended to mean for "--sport $PORT -s $IP", so I first tried OAS pod's port (and IP): [root@wduan-1225a-dmt4h-master-1 ~]# iptables -I FORWARD -p tcp --sport 8443 -j DROP However, I didn't see any abnormality, failure or slowness in the env by repeatedly checking COs, oc login and oc get project (I don't know that the concrete test for "Without the fix OAS won't be able to open a new connection to KAS for ~15 minutes", I just tried these OAS resource related commands) Then I tried KAS pod's port (and IP) together: [root@wduan-1225a-dmt4h-master-1 ~]# iptables -I FORWARD -p tcp --sport 6443 -j DROP Still didn't see any abnormality, failure or slowness. Then I tried above on evn all 3 masters, again still didn't see any abnormality, failure or slowness. Could you clarify more? Any incorrect steps of me? Thanks.
Today consulted network QE about nsenter and alternatives, e.g. networkpolicy (which proves not applicable because kube-apiserver uses host network), and iptables on masters in #forum-qe. Still not succeed in reproducing in 4.6. Hmm, will switch to just try regression test of case OCP-19941 "when 1 master is down the cluster should continue serving well without unavailable more than 1.5 min" to verify this bug.
Hi, # I don't know what source port and IP you intended to mean for "--sport $PORT -s $IP", so I first tried OAS pod's port (and IP): # [root@wduan-1225a-dmt4h-master-1 ~]# iptables -I FORWARD -p tcp --sport 8443 -j DROP Yeah, I meant OAS's port and IP. A Source port of 8443 seems incorrect. I would expect it to be "more random". For example: iptables -I FORWARD -p tcp --sport 58696 (you need to find the actual port) -s 10.128.0.63 -j DROP
Tried to reproduce in 4.6 (4.6.0-0.nightly-2021-01-10-033123) again: $ oc get po -o wide -n openshift-apiserver apiserver-857f8c5f76-v69hz 2/2 Running 0 6h10m 10.128.0.11 ip-10-0-208-199.us-east-2.compute.internal ... apiserver-857f8c5f76-v8s6m 2/2 Running 0 6h3m 10.130.0.6 ip-10-0-182-12.us-east-2.compute.internal ... apiserver-857f8c5f76-x6mdg 2/2 Running 0 6h7m 10.129.0.7 ip-10-0-140-246.us-east-2.compute.internal ... # on master ip-10-0-208-199 [root@ip-10-0-208-199 ~]# crictl ps --name=openshift-apiserver$ 2aaceadfed2ca 653a3c8eb75d54e75d8f375e4fc5e105ce9bd9127d1e6bb7a3e9c659e4ee0d08 7 hours ago Running openshift-apiserver 0 c64c4133469f1 [root@ip-10-0-208-199 ~]# crictl inspect 2aaceadfed2ca | grep pid "pid": 7343, [root@ip-10-0-208-199 ~]# nsenter -t 7343 -n /bin/bash [root@ip-10-0-208-199 ~]# netstat -n # many connections and random ports, not quite sure which port for --sport? see http://file.rdu.redhat.com/~xxia/nsenter_then_netstat-n.txt [root@ip-10-0-208-199 ~]# netstat -n | grep "172.30.0.1:443" tcp 0 0 10.128.0.11:43906 172.30.0.1:443 ESTABLISHED tcp 0 0 10.128.0.11:41206 172.30.0.1:443 ESTABLISHED # I chosen these ports [root@ip-10-0-208-199 ~]# iptables -I FORWARD -p tcp --sport 43906 -s 10.128.0.11 -j DROP [root@ip-10-0-208-199 ~]# iptables -I FORWARD -p tcp --sport 41206 -s 10.128.0.11 -j DROP ** Even I repeated above in all 3 masters, still didn't see any abnormality/slowness/failure ** ** Even later I tried without port `iptables -I FORWARD -p tcp -s <IP> -j DROP` on all 3 masters, still didn't reproduce any abnormality/slowness/failure ** Sorry bothering you a few times, thanks for your kind replies. Can I switch to just try regression test of case OCP-19941 to verify this bug as comment 9 mentions?
Sure, on the other hand, I reproduced it a few times. We could set up a debugging session and I could show you how I did that.
First test openshift-apiserver in old 4.6 (4.6.0-0.nightly-2021-01-12-112514) env which does not yet have the fix: Enter the master of one openshift-apiserver pod: [root@ip-10-0-198-250 ~]# crictl ps --name=openshift-apiserver$ ab3931ce6a1e6 653a3c8e... 2 hours ago Running openshift-apiserver 0 2c63d0d6c137c [root@ip-10-0-198-250 ~]# crictl inspect ab3931ce6a1e6 | grep pid "pid": 283501, [root@ip-10-0-198-250 ~]# nsenter -t 283501 -n /bin/bash [root@ip-10-0-198-250 ~]# export PS1='[\u@\h \D{%F %T %Z} \W]\$ ' [root@ip-10-0-198-250 2021-01-13 10:44:04 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.130.0.8:48646 172.30.0.1:443 ESTABLISHED 283548/cluster-kube keepalive (15.28/0/0) tcp 0 0 10.130.0.8:35432 172.30.0.1:443 ESTABLISHED 283501/openshift-ap keepalive (24.16/0/0) [root@ip-10-0-198-250 2021-01-13 10:44:35 UTC ~]# iptables -I INPUT -m state --state ESTABLISHED,RELATED -p tcp --dport 35432 -s 172.30. 0.1 -j DROP # note the connection changes to "on" at once [root@ip-10-0-198-250 2021-01-13 10:47:47 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.130.0.8:48646 172.30.0.1:443 ESTABLISHED 283548/cluster-kube keepalive (19.61/0/0) tcp 0 16875 10.130.0.8:35432 172.30.0.1:443 ESTABLISHED 283501/openshift-ap on (9.24/7/0) # repeately check, found "on" lasts about 15 mins! Only after so long time, then new connection "57780" shows up: [root@ip-10-0-198-250 2021-01-13 11:02:32 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.130.0.8:57794 172.30.0.1:443 TIME_WAIT - timewait (16.99/0/0) tcp 0 0 10.130.0.8:48646 172.30.0.1:443 ESTABLISHED 283548/cluster-kube keepalive (27.13/0/0) tcp 0 0 10.130.0.8:57780 172.30.0.1:443 ESTABLISHED 283501/openshift-ap keepalive (15.92/0/0) # In another terminal, run oc new-project repeatedly, will fail like: $ oc new-project xxia-proj Error from server (Timeout): Timeout: request did not complete within requested timeout 34s $ oc new-project xxia-proj Error from server (Timeout): the server was unable to return a response in the time allotted, but may still be processing the request (get projectrequests.project.openshift.io) # Only with above new connection showing up, it can succeed $ oc new-project xxia-proj Now using project "xxia-proj" on server "https://... Repate above in 4.7.0-0.nightly-2021-01-13-005809 env, the new connection can immediately show up, about within 30s. And oc new-project can succeed if tried then.
Then test oauth-openshift in old 4.6 (4.6.0-0.nightly-2021-01-12-112514) env which does not yet have the fix: [root@ip-10-0-198-250 2021-01-13 11:15:52 UTC ~]# crictl ps --name=oauth-openshift$ a05f6f5390e52 898f0701e52... 49 seconds ago Running oauth-openshift 0 2f6d83ad74238 [root@ip-10-0-198-250 2021-01-13 11:18:25 UTC ~]# crictl inspect a05f6f5390e52 | grep pid "pid": 422691, [root@ip-10-0-198-250 2021-01-13 11:18:52 UTC ~]# nsenter -t 422691 -n /bin/bash [root@ip-10-0-198-250 2021-01-13 11:19:15 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.130.0.9:49114 172.30.0.1:443 ESTABLISHED 422691/oauth-server keepalive (29.19/0/0) [root@ip-10-0-198-250 2021-01-13 11:19:26 UTC ~]# iptables -I INPUT -m state --state ESTABLISHED,RELATED -p tcp --dport 49114 -s 172.30. 0.1 -j DROP # repeately check, "on" status lasts long, new connection does not show up: [root@ip-10-0-198-250 2021-01-13 11:30:57 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 24399 10.130.0.9:49114 172.30.0.1:443 ESTABLISHED 422691/oauth-server on (37.28/13/0) # In another terminal, repeatedly run login, will fail: [xxia@pres 2021-01-13 19:20:00 CST my]$ oc login -u testuser-41 -p ... Unable to connect to the server: EOF [xxia@pres 2021-01-13 19:21:27 CST my]$ oc login -u testuser-41 -p ... Unable to connect to the server: EOF Only after more minutes, new connection shows up and login can work. # Repeat the test in 4.7 env, new connection can immediately show up and login can immediately come back to work: [root@xxia13dr-01130201-master-0 2021-01-13 11:25:30 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.128.0.93:54818 172.30.0.1:443 ESTABLISHED 365024/oauth-server keepalive (2.16/0/0) [root@xxia13dr-01130201-master-0 2021-01-13 11:25:35 UTC ~]# iptables -I INPUT -m state --state ESTABLISHED,RELATED -p tcp --dport 54818 -s 172.30.0.1 -j DROP [root@xxia13dr-01130201-master-0 2021-01-13 11:25:59 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 0 10.128.0.93:59298 172.30.0.1:443 ESTABLISHED 365024/oauth-server keepalive (0.50/0/0) [xxia@pres 2021-01-13 19:25:10 CST my]$ oc login -u testuser-41 -p ... Login successful.
Third, verify oauth-apiserver in 4.7: [root@xxia13dr-01130201-master-0 2021-01-13 11:31:22 UTC ~]# iptables -I INPUT -m state --state ESTABLISHED,RELATED -p tcp --dport 59888 -s 172.30.0.1 -j DROP [root@xxia13dr-01130201-master-0 2021-01-13 11:31:23 UTC ~]# netstat --tcp --numeric --program --timer --wide | grep "172.30.0.1" tcp 0 3652 10.128.0.57:59888 172.30.0.1:443 ESTABLISHED 60933/oauth-apiserv on (0.05/4/0) ... # In another terminal, run login, will fail at the beginning: [xxia@pres 2021-01-13 19:31:25 CST my]$ oc login -u testuser-41 -p ... Error from server (InternalError): Internal error occurred: unexpected response: 400 ... [xxia@pres 2021-01-13 19:32:39 CST my]$ oc login -u testuser-41 -p ... error: server_error The authorization server encountered an unexpected condition that prevented it from fulfilling the request. [xxia@pres 2021-01-13 19:32:41 CST my]$ oc login -u testuser-41 -p ... Error from server (InternalError): Internal error occurred: unexpected response: 500 # But after some time that is not as long as 15 mins, login can succeed: [xxia@pres 2021-01-13 19:32:49 CST my]$ oc login -u testuser-41 -p ... Login successful. But 19:32:49 - 11:31:23 = about 1.5 mins, a bit longer than above openshift-apiserver and oauth-openshift.
In summary, previous 3 comments verify openshift-apiserver, oauth-openshift, and oauth-apiserver in 4.7, they can detect broken connections to the kube apiserver immediately rather than long 15 minutes.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Moderate: OpenShift Container Platform 4.7.0 security, bug fix, and enhancement update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2020:5633