search

openyurtio / openyurt

OpenYurt - Extending your native Kubernetes to edge(project under CNCF)
https://openyurt.io
Apache License 2.0
1.7k stars 401 forks source link

[BUG] kubectl exec failed with unable to upgrade connection after OpenYurt install #1024

Closed fujitatomoya closed 1 year ago

fujitatomoya commented 2 years ago

What happened:

kubectl exec (or kubectl port-forward / istionctl ps) fails with the following error. Only master control-plane node can reproduce this issue.

root@control-plane:~# kubectl exec --stdin --tty ubuntu22-deamonset-5q6rg -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

What you expected to happen:

kubectl exec (or kubectl port-forward / istionctl ps) succeeds w/o any error.

How to reproduce it (as minimally and precisely as possible):

  1. Setup Kubernetes Cluster with flannel, only control-plane is necesvirtualizedsary.
  2. OpenYurt v1.0 manual setting
  3. execute kubectl exec for any container running on control-plane.

Anything else we need to know?:

Environment:

root@ceci-control-plane:~# cat /etc/os-release 
NAME="Ubuntu"
VERSION="20.04.5 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.5 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
root@ceci-control-plane:~# uname -a
Linux ceci-control-plane 5.4.0-126-generic #142-Ubuntu SMP Fri Aug 26 12:12:57 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

others

/kind bug

fujitatomoya commented 2 years ago

Okay now i can see the specific operation to cause this problem.

root@ceci-control-plane:~# kubectl get pods
NAME                       READY   STATUS    RESTARTS   AGE
ubuntu22-deamonset-4vfhr   1/1     Running   0          24m
root@ceci-control-plane:~# while true; do kubectl exec --stdin --tty ubuntu22-deamonset-4vfhr -- date; done
...
Fri Oct  7 21:36:12 UTC 2022
Fri Oct  7 21:36:12 UTC 2022
Fri Oct  7 21:36:12 UTC 2022
Fri Oct  7 21:36:12 UTC 2022
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
root@control-plane:/openyurt-v1.0.0# helm install openyurt -n kube-system ./charts/openyurt/

until then, kubectl exec kept working w/o error.

rambohe-ch commented 2 years ago

@fujitatomoya Thank you for raising issue about yurt-tunnel. it looks like that yurt-tunnel-agent on edge nodes failed to connect yurt-tunnel-server on the cloud node.

would you be able to upload the detail logs of yurt-tunnel-agent?

Hyan1996 commented 2 years ago

I had the same issue,here is logs of yurt-tunnel-agent

root@ubuntu:/home/hyan# kubectl get pod -A -o wide 
NAMESPACE     NAME                                      READY   STATUS    RESTARTS       AGE    IP               NODE     NOMINATED NODE   READINESS GATES
default       ubuntu22-deamonset-gbzfd                  1/1     Running   0              29m    10.244.0.235     ubuntu   <none>           <none>
default       ubuntu22-deamonset-tnd8r                  1/1     Running   0              29m    10.244.1.3       edge     <none>           <none>
kube-system   coredns-cpqv7                             1/1     Running   1 (119m ago)   146m   10.244.0.230     ubuntu   <none>           <none>
kube-system   coredns-vvn5d                             1/1     Running   0              42m    10.244.1.2       edge     <none>           <none>
kube-system   etcd-ubuntu                               1/1     Running   6 (119m ago)   47m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-apiserver-ubuntu                     1/1     Running   1 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-controller-manager-ubuntu            1/1     Running   2 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-flannel-ds-amd64-5rzbg               1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   kube-flannel-ds-amd64-mpfm2               1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-proxy-j7xdn                          1/1     Running   0              38m    192.168.17.130   edge     <none>           <none>
kube-system   kube-proxy-v9fh6                          1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-scheduler-ubuntu                     1/1     Running   6 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-app-manager-6fd8dcd6b4-nkb8p         1/1     Running   0              110m   10.244.0.233     ubuntu   <none>           <none>
kube-system   yurt-controller-manager-555c46c7f-p9pmr   1/1     Running   0              117m   192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-hub-edge                             1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-agent-jxvml                   1/1     Running   0              25m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-dns-9cbd69765-bwtm5           1/1     Running   1 (119m ago)   153m   10.244.0.228     ubuntu   <none>           <none>
kube-system   yurt-tunnel-server-6bffb656d4-cn6sj       1/1     Running   0              25m    192.168.17.129   ubuntu   <none>           <none>

root@ubuntu:/home/hyan# kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-agent-jxvml
I1011 07:23:14.130222       1 start.go:49] yurttunnel-agent version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T07:04:23Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
I1011 07:23:14.130862       1 options.go:148] ipv4=192.168.17.130&host=edge is set for agent identifies
I1011 07:23:14.130901       1 options.go:153] neither --kube-config nor --apiserver-addr is set, will use /etc/kubernetes/kubelet.conf as the kubeconfig
I1011 07:23:14.130914       1 options.go:157] create the clientset based on the kubeconfig(/etc/kubernetes/kubelet.conf).
I1011 07:23:14.143869       1 start.go:86] yurttunnel-server address: 192.168.17.129:31008
W1011 07:23:14.144021       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-agent/pki/yurttunnel-agent-current.pem", ("", "") or ("/var/lib/yurttunnel-agent/pki", "/var/lib/yurttunnel-agent/pki"), will regenerate it
I1011 07:23:14.144131       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:14.144257       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:14.158919       1 csr.go:262] certificate signing request csr-nmjdh is approved, waiting to be issued
I1011 07:23:14.165987       1 csr.go:258] certificate signing request csr-nmjdh is issued
I1011 07:23:15.167736       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-08-11 07:36:47.167659663 +0000 UTC
I1011 07:23:15.167790       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 7296h13m31.999872356s for next certificate rotation
I1011 07:23:16.168229       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-07-25 18:10:44.921425722 +0000 UTC
I1011 07:23:16.168253       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6898h47m28.753175256s for next certificate rotation
I1011 07:23:19.145255       1 start.go:105] certificate yurttunnel-agent ok
I1011 07:23:19.145373       1 anpagent.go:57] start serving grpc request redirected from yurttunnel-server: 192.168.17.129:31008
I1011 07:23:19.145494       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="127.0.0.1:10266"
E1011 07:23:19.146274       1 clientset.go:156] "cannot sync once" err="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 192.168.17.129:31008: connect: connection refused\""
I1011 07:23:24.362289       1 client.go:224] "Connect to" server="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362304       1 clientset.go:190] "sync added client connecting to proxy server" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362344       1 client.go:326] "Start serving" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:24:35.635173       1 client.go:412] received dial request to tcp:192.168.17.130:10250 with random=1874068156324778273 and connID=1

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-server-6bffb656d4-cn6sj
Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)
rambohe-ch commented 2 years ago

I had the same issue,here is logs of yurt-tunnel-agent

root@ubuntu:/home/hyan# kubectl get pod -A -o wide 
NAMESPACE     NAME                                      READY   STATUS    RESTARTS       AGE    IP               NODE     NOMINATED NODE   READINESS GATES
default       ubuntu22-deamonset-gbzfd                  1/1     Running   0              29m    10.244.0.235     ubuntu   <none>           <none>
default       ubuntu22-deamonset-tnd8r                  1/1     Running   0              29m    10.244.1.3       edge     <none>           <none>
kube-system   coredns-cpqv7                             1/1     Running   1 (119m ago)   146m   10.244.0.230     ubuntu   <none>           <none>
kube-system   coredns-vvn5d                             1/1     Running   0              42m    10.244.1.2       edge     <none>           <none>
kube-system   etcd-ubuntu                               1/1     Running   6 (119m ago)   47m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-apiserver-ubuntu                     1/1     Running   1 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-controller-manager-ubuntu            1/1     Running   2 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-flannel-ds-amd64-5rzbg               1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   kube-flannel-ds-amd64-mpfm2               1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-proxy-j7xdn                          1/1     Running   0              38m    192.168.17.130   edge     <none>           <none>
kube-system   kube-proxy-v9fh6                          1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-scheduler-ubuntu                     1/1     Running   6 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-app-manager-6fd8dcd6b4-nkb8p         1/1     Running   0              110m   10.244.0.233     ubuntu   <none>           <none>
kube-system   yurt-controller-manager-555c46c7f-p9pmr   1/1     Running   0              117m   192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-hub-edge                             1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-agent-jxvml                   1/1     Running   0              25m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-dns-9cbd69765-bwtm5           1/1     Running   1 (119m ago)   153m   10.244.0.228     ubuntu   <none>           <none>
kube-system   yurt-tunnel-server-6bffb656d4-cn6sj       1/1     Running   0              25m    192.168.17.129   ubuntu   <none>           <none>

root@ubuntu:/home/hyan# kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-agent-jxvml
I1011 07:23:14.130222       1 start.go:49] yurttunnel-agent version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T07:04:23Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
I1011 07:23:14.130862       1 options.go:148] ipv4=192.168.17.130&host=edge is set for agent identifies
I1011 07:23:14.130901       1 options.go:153] neither --kube-config nor --apiserver-addr is set, will use /etc/kubernetes/kubelet.conf as the kubeconfig
I1011 07:23:14.130914       1 options.go:157] create the clientset based on the kubeconfig(/etc/kubernetes/kubelet.conf).
I1011 07:23:14.143869       1 start.go:86] yurttunnel-server address: 192.168.17.129:31008
W1011 07:23:14.144021       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-agent/pki/yurttunnel-agent-current.pem", ("", "") or ("/var/lib/yurttunnel-agent/pki", "/var/lib/yurttunnel-agent/pki"), will regenerate it
I1011 07:23:14.144131       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:14.144257       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:14.158919       1 csr.go:262] certificate signing request csr-nmjdh is approved, waiting to be issued
I1011 07:23:14.165987       1 csr.go:258] certificate signing request csr-nmjdh is issued
I1011 07:23:15.167736       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-08-11 07:36:47.167659663 +0000 UTC
I1011 07:23:15.167790       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 7296h13m31.999872356s for next certificate rotation
I1011 07:23:16.168229       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-07-25 18:10:44.921425722 +0000 UTC
I1011 07:23:16.168253       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6898h47m28.753175256s for next certificate rotation
I1011 07:23:19.145255       1 start.go:105] certificate yurttunnel-agent ok
I1011 07:23:19.145373       1 anpagent.go:57] start serving grpc request redirected from yurttunnel-server: 192.168.17.129:31008
I1011 07:23:19.145494       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="127.0.0.1:10266"
E1011 07:23:19.146274       1 clientset.go:156] "cannot sync once" err="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 192.168.17.129:31008: connect: connection refused\""
I1011 07:23:24.362289       1 client.go:224] "Connect to" server="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362304       1 clientset.go:190] "sync added client connecting to proxy server" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362344       1 client.go:326] "Start serving" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:24:35.635173       1 client.go:412] received dial request to tcp:192.168.17.130:10250 with random=1874068156324778273 and connID=1

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-server-6bffb656d4-cn6sj
Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)

@Hyan1996 Thanks for your feedback. it seems that your yurt-tunnel-agent works well, how about upload detail logs of yurt-tunnel-server?

Hyan1996 commented 2 years ago

I had the same issue,here is logs of yurt-tunnel-agent

root@ubuntu:/home/hyan# kubectl get pod -A -o wide 
NAMESPACE     NAME                                      READY   STATUS    RESTARTS       AGE    IP               NODE     NOMINATED NODE   READINESS GATES
default       ubuntu22-deamonset-gbzfd                  1/1     Running   0              29m    10.244.0.235     ubuntu   <none>           <none>
default       ubuntu22-deamonset-tnd8r                  1/1     Running   0              29m    10.244.1.3       edge     <none>           <none>
kube-system   coredns-cpqv7                             1/1     Running   1 (119m ago)   146m   10.244.0.230     ubuntu   <none>           <none>
kube-system   coredns-vvn5d                             1/1     Running   0              42m    10.244.1.2       edge     <none>           <none>
kube-system   etcd-ubuntu                               1/1     Running   6 (119m ago)   47m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-apiserver-ubuntu                     1/1     Running   1 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-controller-manager-ubuntu            1/1     Running   2 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-flannel-ds-amd64-5rzbg               1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   kube-flannel-ds-amd64-mpfm2               1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-proxy-j7xdn                          1/1     Running   0              38m    192.168.17.130   edge     <none>           <none>
kube-system   kube-proxy-v9fh6                          1/1     Running   1 (119m ago)   162m   192.168.17.129   ubuntu   <none>           <none>
kube-system   kube-scheduler-ubuntu                     1/1     Running   6 (119m ago)   46m    192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-app-manager-6fd8dcd6b4-nkb8p         1/1     Running   0              110m   10.244.0.233     ubuntu   <none>           <none>
kube-system   yurt-controller-manager-555c46c7f-p9pmr   1/1     Running   0              117m   192.168.17.129   ubuntu   <none>           <none>
kube-system   yurt-hub-edge                             1/1     Running   0              42m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-agent-jxvml                   1/1     Running   0              25m    192.168.17.130   edge     <none>           <none>
kube-system   yurt-tunnel-dns-9cbd69765-bwtm5           1/1     Running   1 (119m ago)   153m   10.244.0.228     ubuntu   <none>           <none>
kube-system   yurt-tunnel-server-6bffb656d4-cn6sj       1/1     Running   0              25m    192.168.17.129   ubuntu   <none>           <none>

root@ubuntu:/home/hyan# kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-agent-jxvml
I1011 07:23:14.130222       1 start.go:49] yurttunnel-agent version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T07:04:23Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
I1011 07:23:14.130862       1 options.go:148] ipv4=192.168.17.130&host=edge is set for agent identifies
I1011 07:23:14.130901       1 options.go:153] neither --kube-config nor --apiserver-addr is set, will use /etc/kubernetes/kubelet.conf as the kubeconfig
I1011 07:23:14.130914       1 options.go:157] create the clientset based on the kubeconfig(/etc/kubernetes/kubelet.conf).
I1011 07:23:14.143869       1 start.go:86] yurttunnel-server address: 192.168.17.129:31008
W1011 07:23:14.144021       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-agent/pki/yurttunnel-agent-current.pem", ("", "") or ("/var/lib/yurttunnel-agent/pki", "/var/lib/yurttunnel-agent/pki"), will regenerate it
I1011 07:23:14.144131       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:14.144257       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:14.158919       1 csr.go:262] certificate signing request csr-nmjdh is approved, waiting to be issued
I1011 07:23:14.165987       1 csr.go:258] certificate signing request csr-nmjdh is issued
I1011 07:23:15.167736       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-08-11 07:36:47.167659663 +0000 UTC
I1011 07:23:15.167790       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 7296h13m31.999872356s for next certificate rotation
I1011 07:23:16.168229       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:14 +0000 UTC, rotation deadline is 2023-07-25 18:10:44.921425722 +0000 UTC
I1011 07:23:16.168253       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6898h47m28.753175256s for next certificate rotation
I1011 07:23:19.145255       1 start.go:105] certificate yurttunnel-agent ok
I1011 07:23:19.145373       1 anpagent.go:57] start serving grpc request redirected from yurttunnel-server: 192.168.17.129:31008
I1011 07:23:19.145494       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="127.0.0.1:10266"
E1011 07:23:19.146274       1 clientset.go:156] "cannot sync once" err="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 192.168.17.129:31008: connect: connection refused\""
I1011 07:23:24.362289       1 client.go:224] "Connect to" server="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362304       1 clientset.go:190] "sync added client connecting to proxy server" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:23:24.362344       1 client.go:326] "Start serving" serverID="0b402520-bd84-45c2-82cf-2150400ca03d"
I1011 07:24:35.635173       1 client.go:412] received dial request to tcp:192.168.17.130:10250 with random=1874068156324778273 and connID=1

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-server-6bffb656d4-cn6sj
Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)

@Hyan1996 Thanks for your feedback. it seems that your yurt-tunnel-agent works well, how about upload detail logs of yurt-tunnel-server?

its right at the end above 

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-server-6bffb656d4-cn6sj
Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)
rambohe-ch commented 2 years ago

@Hyan1996

The following log appears to be from kube-apiserver, how about upload the entire log of yurt-tunenl-server?

Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)

Hyan1996 commented 2 years ago

Is this one?

root@ubuntu:/home/hyan# docker ps | grep yurt-tunnel-server
a095a9346115   6a2597bae8cd                       "yurt-tunnel-server …"   3 hours ago      Up 3 hours                k8s_yurt-tunnel-server_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0
cc680c7cf560   k8s.gcr.io/pause:3.5               "/pause"                 3 hours ago      Up 3 hours                k8s_POD_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0

root@ubuntu:/home/hyan# docker logs a095a9346115
I1011 07:23:14.001585       1 start.go:53] yurttunnel-server version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T06:59:22Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
W1011 07:23:14.001950       1 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
I1011 07:23:14.003414       1 options.go:168] yurttunnel server config: &config.Config{EgressSelectorEnabled:false, EnableIptables:true, EnableDNSController:true, IptablesSyncPeriod:60, IPFamily:0x1, DNSSyncPeriod:1800, CertDNSNames:[]string{}, CertIPs:[]net.IP{}, CertDir:"", ListenAddrForAgent:"192.168.17.129:10262", ListenAddrForMaster:"192.168.17.129:10263", ListenInsecureAddrForMaster:"192.168.17.129:10264", ListenMetaAddr:"192.168.17.129:10265", RootCert:(*x509.CertPool)(0xc0003d0ff0), Client:(*kubernetes.Clientset)(0xc0003f4420), SharedInformerFactory:(*informers.sharedInformerFactory)(0xc000401220), ServerCount:1, ProxyStrategy:"destHost", InterceptorServerUDSFile:""}
I1011 07:23:14.010254       1 leaderelection.go:248] attempting to acquire leader lease kube-system/tunnel-dns-controller...
E1011 07:23:14.019938       1 iptables.go:216] failed to delete rule that nat chain OUTPUT jumps to TUNNEL-PORT: error checking rule: exit status 2: iptables v1.8.7 (legacy): Couldn't load target `TUNNEL-PORT':No such file or directory

Try `iptables -h' or 'iptables --help' for more information.
I1011 07:23:19.031543       1 certmanager.go:105] subject of tunnel server certificate, ips=192.168.17.129,10.100.165.142,127.0.0.1,::1,192.168.17.129,10.101.31.78, dnsNames=[]string{"ubuntu", "x-tunnel-server-svc", "x-tunnel-server-svc.kube-system", "x-tunnel-server-svc.kube-system.svc", "x-tunnel-server-svc.kube-system.svc.cluster.local", "x-tunnel-server-internal-svc", "x-tunnel-server-internal-svc.kube-system", "x-tunnel-server-internal-svc.kube-system.svc", "x-tunnel-server-internal-svc.kube-system.svc.cluster.local"}
W1011 07:23:19.031746       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031787       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate rotation is enabled
W1011 07:23:19.031807       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-proxy-client-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031811       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:19.031975       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Rotating certificates
I1011 07:23:19.032744       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:19.040573       1 handler.go:43] enqueue node add event for ubuntu
I1011 07:23:19.040685       1 handler.go:43] enqueue node add event for edge
I1011 07:23:19.043118       1 handler.go:141] enqueue service add event for kube-system/x-tunnel-server-internal-svc
I1011 07:23:19.060992       1 handler.go:175] handle configmap add event for kube-system/yurt-tunnel-server-cfg to update localhost ports
I1011 07:23:19.061037       1 handler.go:93] enqueue configmap add event for kube-system/yurt-tunnel-server-cfg
I1011 07:23:19.063376       1 csr.go:258] certificate signing request csr-p4bvr is issued
I1011 07:23:19.063705       1 csr.go:258] certificate signing request csr-9825q is issued
I1011 07:23:19.154175       1 iptables.go:539] dnat ports changed, []
I1011 07:23:20.065125       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-08-22 04:48:08.961956739 +0000 UTC
I1011 07:23:20.065168       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 7557h24m48.896791344s for next certificate rotation
I1011 07:23:20.065467       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-09 10:41:44.097151555 +0000 UTC
I1011 07:23:20.065488       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6507h18m24.031665623s for next certificate rotation
I1011 07:23:21.066851       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-21 14:13:00.024350979 +0000 UTC
I1011 07:23:21.066881       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 6798h49m38.957472512s for next certificate rotation
I1011 07:23:21.066927       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-17 00:32:35.517136256 +0000 UTC
I1011 07:23:21.066931       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6689h9m14.45020571s for next certificate rotation
I1011 07:23:24.033625       1 anpserver.go:107] start handling request from interceptor
I1011 07:23:24.033683       1 wraphandler.go:67] add localHostProxyMiddleware into wrap handler
I1011 07:23:24.033709       1 tracereq.go:80] 2 informer synced in traceReqMiddleware
I1011 07:23:24.033882       1 wraphandler.go:67] add TraceReqMiddleware into wrap handler
I1011 07:23:24.033927       1 anpserver.go:195] start handling connection from agents
I1011 07:23:24.034048       1 anpserver.go:143] start handling https request from master at 192.168.17.129:10263
I1011 07:23:24.034076       1 anpserver.go:157] start handling http request from master at 192.168.17.129:10264
I1011 07:23:24.034217       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="192.168.17.129:10265"
I1011 07:23:24.382343       1 server.go:616] "Connect request from agent" agentID="edge"
I1011 07:23:24.382388       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="192.168.17.130"
I1011 07:23:24.382399       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="edge"
I1011 07:23:27.056742       1 tracereq.go:134] start handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:41544 to 192.168.17.129:10250
E1011 07:23:27.057088       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:23:27.057287       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:23:27.057316       1 tracereq.go:138] stop handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 552.399µs
I1011 07:23:31.183919       1 leaderelection.go:258] successfully acquired lease kube-system/tunnel-dns-controller
I1011 07:23:31.184142       1 dns.go:177] starting tunnel dns controller
I1011 07:23:31.184184       1 shared_informer.go:240] Waiting for caches to sync for tunnel-dns-controller
I1011 07:23:31.184201       1 shared_informer.go:247] Caches are synced for tunnel-dns-controller 
I1011 07:23:31.185679       1 dns.go:301] sync tunnel server service as whole
I1011 07:23:31.185920       1 handler.go:166] adding node dns record for ubuntu
I1011 07:23:31.187044       1 dns.go:310] sync dns record as whole
I1011 07:23:31.188912       1 handler.go:166] adding node dns record for edge
I1011 07:23:31.195635       1 dns.go:310] sync dns record as whole
I1011 07:23:31.589090       1 dns.go:301] sync tunnel server service as whole
I1011 07:24:19.175752       1 iptables.go:539] dnat ports changed, []
I1011 07:24:35.655119       1 tracereq.go:134] start handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, from 192.168.17.129:52134 to 192.168.17.130:10250
I1011 07:24:35.657050       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=1
I1011 07:24:35.668732       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=1
I1011 07:24:35.669001       1 tracereq.go:138] stop handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, request handling lasts 13.723697ms
E1011 07:24:35.671454       1 server.go:725] "send to client stream failure" err="write unix /tmp/interceptor-proxier.sock->@: use of closed network connection"
I1011 07:24:35.671603       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=1
I1011 07:25:19.176798       1 iptables.go:539] dnat ports changed, []
I1011 07:26:19.176846       1 iptables.go:539] dnat ports changed, []
I1011 07:27:19.174502       1 iptables.go:539] dnat ports changed, []
I1011 07:28:19.174140       1 iptables.go:539] dnat ports changed, []
I1011 07:29:19.173890       1 iptables.go:539] dnat ports changed, []
I1011 07:30:19.174425       1 iptables.go:539] dnat ports changed, []
I1011 07:31:19.176723       1 iptables.go:539] dnat ports changed, []
I1011 07:32:19.176180       1 iptables.go:539] dnat ports changed, []
I1011 07:33:19.175818       1 iptables.go:539] dnat ports changed, []
I1011 07:34:19.174512       1 iptables.go:539] dnat ports changed, []
I1011 07:35:19.175420       1 iptables.go:539] dnat ports changed, []
I1011 07:36:19.172322       1 iptables.go:539] dnat ports changed, []
I1011 07:37:08.439621       1 tracereq.go:134] start handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, from 127.0.0.1:41546 to 192.168.17.129:10250
E1011 07:37:08.440174       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:37:08.440298       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:37:08.440332       1 tracereq.go:138] stop handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, request handling lasts 377.833µs
I1011 07:37:19.176492       1 iptables.go:539] dnat ports changed, []
I1011 07:38:19.177410       1 iptables.go:539] dnat ports changed, []
I1011 07:39:19.174137       1 iptables.go:539] dnat ports changed, []
I1011 07:40:19.174732       1 iptables.go:539] dnat ports changed, []
I1011 07:41:19.174043       1 iptables.go:539] dnat ports changed, []
I1011 07:42:19.173167       1 iptables.go:539] dnat ports changed, []
I1011 07:43:19.177473       1 iptables.go:539] dnat ports changed, []
I1011 07:44:19.176754       1 iptables.go:539] dnat ports changed, []
I1011 07:45:19.176027       1 iptables.go:539] dnat ports changed, []
I1011 07:46:19.174254       1 iptables.go:539] dnat ports changed, []
I1011 07:47:19.175489       1 iptables.go:539] dnat ports changed, []
I1011 07:48:19.176148       1 iptables.go:539] dnat ports changed, []
I1011 07:49:19.177092       1 iptables.go:539] dnat ports changed, []
I1011 07:50:19.177197       1 iptables.go:539] dnat ports changed, []
I1011 07:51:19.175556       1 iptables.go:539] dnat ports changed, []
I1011 07:52:19.206353       1 iptables.go:539] dnat ports changed, []
I1011 07:53:19.180040       1 iptables.go:539] dnat ports changed, []
I1011 07:53:31.196887       1 dns.go:301] sync tunnel server service as whole
I1011 07:53:31.198200       1 dns.go:310] sync dns record as whole
I1011 07:54:19.179793       1 iptables.go:539] dnat ports changed, []
I1011 07:55:19.175251       1 iptables.go:539] dnat ports changed, []
I1011 07:56:19.220992       1 iptables.go:539] dnat ports changed, []
I1011 07:57:19.182224       1 iptables.go:539] dnat ports changed, []
I1011 07:58:19.181208       1 iptables.go:539] dnat ports changed, []
I1011 07:59:19.174329       1 iptables.go:539] dnat ports changed, []
I1011 08:00:19.179526       1 iptables.go:539] dnat ports changed, []
I1011 08:01:19.531627       1 iptables.go:539] dnat ports changed, []
I1011 08:01:51.833081       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52136 to 192.168.17.130:10250
I1011 08:01:51.835056       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=2
I1011 08:01:51.864152       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 31.04399ms
I1011 08:01:51.864366       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=2
I1011 08:01:51.865011       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=2
I1011 08:02:03.548768       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52138 to 192.168.17.130:10250
I1011 08:02:03.550111       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=3
I1011 08:02:03.578705       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 29.896018ms
I1011 08:02:03.578922       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=3
I1011 08:02:03.579613       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=3
I1011 08:02:19.179441       1 iptables.go:539] dnat ports changed, []
I1011 08:02:31.321059       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52142 to 192.168.17.130:10250
I1011 08:02:31.322523       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=4
I1011 08:02:31.339072       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 17.985703ms
I1011 08:02:31.339263       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=4
I1011 08:02:31.340053       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=4
I1011 08:03:19.179216       1 iptables.go:539] dnat ports changed, []
I1011 08:04:19.183658       1 iptables.go:539] dnat ports changed, []
I1011 08:05:19.175553       1 iptables.go:539] dnat ports changed, []
I1011 08:06:19.179421       1 iptables.go:539] dnat ports changed, []
I1011 08:07:19.198128       1 iptables.go:539] dnat ports changed, []
I1011 08:08:19.177387       1 iptables.go:539] dnat ports changed, []
I1011 08:09:19.177117       1 iptables.go:539] dnat ports changed, []
I1011 08:10:19.177726       1 iptables.go:539] dnat ports changed, []
I1011 08:11:19.174797       1 iptables.go:539] dnat ports changed, []
I1011 08:12:19.197116       1 iptables.go:539] dnat ports changed, []
I1011 08:13:19.199297       1 iptables.go:539] dnat ports changed, []
I1011 08:14:19.180268       1 iptables.go:539] dnat ports changed, []
I1011 08:15:19.180924       1 iptables.go:539] dnat ports changed, []
I1011 08:16:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 08:17:19.176916       1 iptables.go:539] dnat ports changed, []
I1011 08:18:19.176084       1 iptables.go:539] dnat ports changed, []
I1011 08:19:19.180304       1 iptables.go:539] dnat ports changed, []
I1011 08:20:19.177434       1 iptables.go:539] dnat ports changed, []
I1011 08:21:19.179631       1 iptables.go:539] dnat ports changed, []
I1011 08:22:19.178435       1 iptables.go:539] dnat ports changed, []
I1011 08:23:19.175058       1 iptables.go:539] dnat ports changed, []
I1011 08:23:31.205337       1 dns.go:301] sync tunnel server service as whole
I1011 08:23:31.207910       1 dns.go:310] sync dns record as whole
I1011 08:24:19.177869       1 iptables.go:539] dnat ports changed, []
I1011 08:25:19.193670       1 iptables.go:539] dnat ports changed, []
I1011 08:26:19.177393       1 iptables.go:539] dnat ports changed, []
I1011 08:27:19.178744       1 iptables.go:539] dnat ports changed, []
I1011 08:28:19.179923       1 iptables.go:539] dnat ports changed, []
I1011 08:29:19.176710       1 iptables.go:539] dnat ports changed, []
I1011 08:30:19.176490       1 iptables.go:539] dnat ports changed, []
I1011 08:31:19.177187       1 iptables.go:539] dnat ports changed, []
I1011 08:32:19.176354       1 iptables.go:539] dnat ports changed, []
I1011 08:33:19.183060       1 iptables.go:539] dnat ports changed, []
I1011 08:34:19.176584       1 iptables.go:539] dnat ports changed, []
I1011 08:35:19.176450       1 iptables.go:539] dnat ports changed, []
I1011 08:36:19.177009       1 iptables.go:539] dnat ports changed, []
I1011 08:37:19.178339       1 iptables.go:539] dnat ports changed, []
I1011 08:38:19.179235       1 iptables.go:539] dnat ports changed, []
I1011 08:39:19.176771       1 iptables.go:539] dnat ports changed, []
I1011 08:40:19.175344       1 iptables.go:539] dnat ports changed, []
I1011 08:41:19.176535       1 iptables.go:539] dnat ports changed, []
I1011 08:42:19.176892       1 iptables.go:539] dnat ports changed, []
I1011 08:43:19.176377       1 iptables.go:539] dnat ports changed, []
I1011 08:44:19.177715       1 iptables.go:539] dnat ports changed, []
I1011 08:45:19.179103       1 iptables.go:539] dnat ports changed, []
I1011 08:46:19.179105       1 iptables.go:539] dnat ports changed, []
I1011 08:47:19.179544       1 iptables.go:539] dnat ports changed, []
I1011 08:48:19.179320       1 iptables.go:539] dnat ports changed, []
I1011 08:49:19.178770       1 iptables.go:539] dnat ports changed, []
I1011 08:50:19.183371       1 iptables.go:539] dnat ports changed, []
I1011 08:51:19.183916       1 iptables.go:539] dnat ports changed, []
I1011 08:52:19.177069       1 iptables.go:539] dnat ports changed, []
I1011 08:53:19.177503       1 iptables.go:539] dnat ports changed, []
I1011 08:53:31.220276       1 dns.go:301] sync tunnel server service as whole
I1011 08:53:31.222252       1 dns.go:310] sync dns record as whole
I1011 08:54:19.179932       1 iptables.go:539] dnat ports changed, []
I1011 08:55:19.180744       1 iptables.go:539] dnat ports changed, []
I1011 08:56:19.181121       1 iptables.go:539] dnat ports changed, []
I1011 08:57:19.179438       1 iptables.go:539] dnat ports changed, []
I1011 08:58:19.181572       1 iptables.go:539] dnat ports changed, []
I1011 08:59:19.197308       1 iptables.go:539] dnat ports changed, []
I1011 09:00:19.177977       1 iptables.go:539] dnat ports changed, []
I1011 09:01:19.177990       1 iptables.go:539] dnat ports changed, []
I1011 09:02:19.181674       1 iptables.go:539] dnat ports changed, []
I1011 09:03:19.176509       1 iptables.go:539] dnat ports changed, []
I1011 09:04:19.179804       1 iptables.go:539] dnat ports changed, []
I1011 09:05:19.179780       1 iptables.go:539] dnat ports changed, []
I1011 09:06:19.179632       1 iptables.go:539] dnat ports changed, []
I1011 09:07:19.177821       1 iptables.go:539] dnat ports changed, []
I1011 09:08:19.182061       1 iptables.go:539] dnat ports changed, []
I1011 09:09:19.182311       1 iptables.go:539] dnat ports changed, []
I1011 09:10:19.179218       1 iptables.go:539] dnat ports changed, []
I1011 09:11:19.179125       1 iptables.go:539] dnat ports changed, []
I1011 09:12:19.178195       1 iptables.go:539] dnat ports changed, []
I1011 09:13:19.182649       1 iptables.go:539] dnat ports changed, []
I1011 09:14:19.181041       1 iptables.go:539] dnat ports changed, []
I1011 09:15:19.183101       1 iptables.go:539] dnat ports changed, []
I1011 09:16:19.187040       1 iptables.go:539] dnat ports changed, []
I1011 09:17:19.183544       1 iptables.go:539] dnat ports changed, []
I1011 09:18:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 09:19:19.182356       1 iptables.go:539] dnat ports changed, []
I1011 09:20:19.180889       1 iptables.go:539] dnat ports changed, []
I1011 09:21:19.181620       1 iptables.go:539] dnat ports changed, []
I1011 09:22:19.180250       1 iptables.go:539] dnat ports changed, []
I1011 09:23:19.183037       1 iptables.go:539] dnat ports changed, []
I1011 09:23:31.227156       1 dns.go:301] sync tunnel server service as whole
I1011 09:23:31.230608       1 dns.go:310] sync dns record as whole
I1011 09:24:19.179920       1 iptables.go:539] dnat ports changed, []
I1011 09:25:19.182038       1 iptables.go:539] dnat ports changed, []
I1011 09:26:19.181332       1 iptables.go:539] dnat ports changed, []
I1011 09:27:19.182114       1 iptables.go:539] dnat ports changed, []
I1011 09:28:19.178484       1 iptables.go:539] dnat ports changed, []
I1011 09:29:19.180852       1 iptables.go:539] dnat ports changed, []
I1011 09:30:19.177830       1 iptables.go:539] dnat ports changed, []
I1011 09:31:19.184896       1 iptables.go:539] dnat ports changed, []
I1011 09:32:19.183521       1 iptables.go:539] dnat ports changed, []
I1011 09:33:19.178906       1 iptables.go:539] dnat ports changed, []
I1011 09:34:19.179613       1 iptables.go:539] dnat ports changed, []
I1011 09:35:19.180510       1 iptables.go:539] dnat ports changed, []
I1011 09:36:19.176730       1 iptables.go:539] dnat ports changed, []
I1011 09:37:19.179345       1 iptables.go:539] dnat ports changed, []
I1011 09:38:19.181372       1 iptables.go:539] dnat ports changed, []
I1011 09:39:19.179186       1 iptables.go:539] dnat ports changed, []
I1011 09:40:19.181759       1 iptables.go:539] dnat ports changed, []
I1011 09:41:19.181811       1 iptables.go:539] dnat ports changed, []
I1011 09:42:19.180120       1 iptables.go:539] dnat ports changed, []
I1011 09:43:19.186947       1 iptables.go:539] dnat ports changed, []
I1011 09:44:19.195637       1 iptables.go:539] dnat ports changed, []
I1011 09:45:19.182809       1 iptables.go:539] dnat ports changed, []
I1011 09:46:19.181136       1 iptables.go:539] dnat ports changed, []
I1011 09:47:19.180399       1 iptables.go:539] dnat ports changed, []
I1011 09:48:19.177773       1 iptables.go:539] dnat ports changed, []
I1011 09:49:19.175869       1 iptables.go:539] dnat ports changed, []
I1011 09:50:19.175571       1 iptables.go:539] dnat ports changed, []
I1011 09:51:19.176799       1 iptables.go:539] dnat ports changed, []
I1011 09:52:19.179724       1 iptables.go:539] dnat ports changed, []
I1011 09:53:19.176958       1 iptables.go:539] dnat ports changed, []
I1011 09:53:31.235445       1 dns.go:301] sync tunnel server service as whole
I1011 09:53:31.241397       1 dns.go:310] sync dns record as whole
I1011 09:54:19.177902       1 iptables.go:539] dnat ports changed, []
I1011 09:55:19.181559       1 iptables.go:539] dnat ports changed, []
I1011 09:56:19.175555       1 iptables.go:539] dnat ports changed, []
I1011 09:57:19.176113       1 iptables.go:539] dnat ports changed, []
I1011 09:58:19.178323       1 iptables.go:539] dnat ports changed, []
I1011 09:59:19.177297       1 iptables.go:539] dnat ports changed, []
rambohe-ch commented 2 years ago

Is this one?

root@ubuntu:/home/hyan# docker ps | grep yurt-tunnel-server
a095a9346115   6a2597bae8cd                       "yurt-tunnel-server …"   3 hours ago      Up 3 hours                k8s_yurt-tunnel-server_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0
cc680c7cf560   k8s.gcr.io/pause:3.5               "/pause"                 3 hours ago      Up 3 hours                k8s_POD_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0

root@ubuntu:/home/hyan# docker logs a095a9346115
I1011 07:23:14.001585       1 start.go:53] yurttunnel-server version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T06:59:22Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
W1011 07:23:14.001950       1 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
I1011 07:23:14.003414       1 options.go:168] yurttunnel server config: &config.Config{EgressSelectorEnabled:false, EnableIptables:true, EnableDNSController:true, IptablesSyncPeriod:60, IPFamily:0x1, DNSSyncPeriod:1800, CertDNSNames:[]string{}, CertIPs:[]net.IP{}, CertDir:"", ListenAddrForAgent:"192.168.17.129:10262", ListenAddrForMaster:"192.168.17.129:10263", ListenInsecureAddrForMaster:"192.168.17.129:10264", ListenMetaAddr:"192.168.17.129:10265", RootCert:(*x509.CertPool)(0xc0003d0ff0), Client:(*kubernetes.Clientset)(0xc0003f4420), SharedInformerFactory:(*informers.sharedInformerFactory)(0xc000401220), ServerCount:1, ProxyStrategy:"destHost", InterceptorServerUDSFile:""}
I1011 07:23:14.010254       1 leaderelection.go:248] attempting to acquire leader lease kube-system/tunnel-dns-controller...
E1011 07:23:14.019938       1 iptables.go:216] failed to delete rule that nat chain OUTPUT jumps to TUNNEL-PORT: error checking rule: exit status 2: iptables v1.8.7 (legacy): Couldn't load target `TUNNEL-PORT':No such file or directory

Try `iptables -h' or 'iptables --help' for more information.
I1011 07:23:19.031543       1 certmanager.go:105] subject of tunnel server certificate, ips=192.168.17.129,10.100.165.142,127.0.0.1,::1,192.168.17.129,10.101.31.78, dnsNames=[]string{"ubuntu", "x-tunnel-server-svc", "x-tunnel-server-svc.kube-system", "x-tunnel-server-svc.kube-system.svc", "x-tunnel-server-svc.kube-system.svc.cluster.local", "x-tunnel-server-internal-svc", "x-tunnel-server-internal-svc.kube-system", "x-tunnel-server-internal-svc.kube-system.svc", "x-tunnel-server-internal-svc.kube-system.svc.cluster.local"}
W1011 07:23:19.031746       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031787       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate rotation is enabled
W1011 07:23:19.031807       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-proxy-client-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031811       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:19.031975       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Rotating certificates
I1011 07:23:19.032744       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:19.040573       1 handler.go:43] enqueue node add event for ubuntu
I1011 07:23:19.040685       1 handler.go:43] enqueue node add event for edge
I1011 07:23:19.043118       1 handler.go:141] enqueue service add event for kube-system/x-tunnel-server-internal-svc
I1011 07:23:19.060992       1 handler.go:175] handle configmap add event for kube-system/yurt-tunnel-server-cfg to update localhost ports
I1011 07:23:19.061037       1 handler.go:93] enqueue configmap add event for kube-system/yurt-tunnel-server-cfg
I1011 07:23:19.063376       1 csr.go:258] certificate signing request csr-p4bvr is issued
I1011 07:23:19.063705       1 csr.go:258] certificate signing request csr-9825q is issued
I1011 07:23:19.154175       1 iptables.go:539] dnat ports changed, []
I1011 07:23:20.065125       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-08-22 04:48:08.961956739 +0000 UTC
I1011 07:23:20.065168       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 7557h24m48.896791344s for next certificate rotation
I1011 07:23:20.065467       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-09 10:41:44.097151555 +0000 UTC
I1011 07:23:20.065488       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6507h18m24.031665623s for next certificate rotation
I1011 07:23:21.066851       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-21 14:13:00.024350979 +0000 UTC
I1011 07:23:21.066881       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 6798h49m38.957472512s for next certificate rotation
I1011 07:23:21.066927       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-17 00:32:35.517136256 +0000 UTC
I1011 07:23:21.066931       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6689h9m14.45020571s for next certificate rotation
I1011 07:23:24.033625       1 anpserver.go:107] start handling request from interceptor
I1011 07:23:24.033683       1 wraphandler.go:67] add localHostProxyMiddleware into wrap handler
I1011 07:23:24.033709       1 tracereq.go:80] 2 informer synced in traceReqMiddleware
I1011 07:23:24.033882       1 wraphandler.go:67] add TraceReqMiddleware into wrap handler
I1011 07:23:24.033927       1 anpserver.go:195] start handling connection from agents
I1011 07:23:24.034048       1 anpserver.go:143] start handling https request from master at 192.168.17.129:10263
I1011 07:23:24.034076       1 anpserver.go:157] start handling http request from master at 192.168.17.129:10264
I1011 07:23:24.034217       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="192.168.17.129:10265"
I1011 07:23:24.382343       1 server.go:616] "Connect request from agent" agentID="edge"
I1011 07:23:24.382388       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="192.168.17.130"
I1011 07:23:24.382399       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="edge"
I1011 07:23:27.056742       1 tracereq.go:134] start handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:41544 to 192.168.17.129:10250
E1011 07:23:27.057088       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:23:27.057287       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:23:27.057316       1 tracereq.go:138] stop handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 552.399µs
I1011 07:23:31.183919       1 leaderelection.go:258] successfully acquired lease kube-system/tunnel-dns-controller
I1011 07:23:31.184142       1 dns.go:177] starting tunnel dns controller
I1011 07:23:31.184184       1 shared_informer.go:240] Waiting for caches to sync for tunnel-dns-controller
I1011 07:23:31.184201       1 shared_informer.go:247] Caches are synced for tunnel-dns-controller 
I1011 07:23:31.185679       1 dns.go:301] sync tunnel server service as whole
I1011 07:23:31.185920       1 handler.go:166] adding node dns record for ubuntu
I1011 07:23:31.187044       1 dns.go:310] sync dns record as whole
I1011 07:23:31.188912       1 handler.go:166] adding node dns record for edge
I1011 07:23:31.195635       1 dns.go:310] sync dns record as whole
I1011 07:23:31.589090       1 dns.go:301] sync tunnel server service as whole
I1011 07:24:19.175752       1 iptables.go:539] dnat ports changed, []
I1011 07:24:35.655119       1 tracereq.go:134] start handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, from 192.168.17.129:52134 to 192.168.17.130:10250
I1011 07:24:35.657050       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=1
I1011 07:24:35.668732       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=1
I1011 07:24:35.669001       1 tracereq.go:138] stop handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, request handling lasts 13.723697ms
E1011 07:24:35.671454       1 server.go:725] "send to client stream failure" err="write unix /tmp/interceptor-proxier.sock->@: use of closed network connection"
I1011 07:24:35.671603       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=1
I1011 07:25:19.176798       1 iptables.go:539] dnat ports changed, []
I1011 07:26:19.176846       1 iptables.go:539] dnat ports changed, []
I1011 07:27:19.174502       1 iptables.go:539] dnat ports changed, []
I1011 07:28:19.174140       1 iptables.go:539] dnat ports changed, []
I1011 07:29:19.173890       1 iptables.go:539] dnat ports changed, []
I1011 07:30:19.174425       1 iptables.go:539] dnat ports changed, []
I1011 07:31:19.176723       1 iptables.go:539] dnat ports changed, []
I1011 07:32:19.176180       1 iptables.go:539] dnat ports changed, []
I1011 07:33:19.175818       1 iptables.go:539] dnat ports changed, []
I1011 07:34:19.174512       1 iptables.go:539] dnat ports changed, []
I1011 07:35:19.175420       1 iptables.go:539] dnat ports changed, []
I1011 07:36:19.172322       1 iptables.go:539] dnat ports changed, []
I1011 07:37:08.439621       1 tracereq.go:134] start handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, from 127.0.0.1:41546 to 192.168.17.129:10250
E1011 07:37:08.440174       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:37:08.440298       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:37:08.440332       1 tracereq.go:138] stop handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, request handling lasts 377.833µs
I1011 07:37:19.176492       1 iptables.go:539] dnat ports changed, []
I1011 07:38:19.177410       1 iptables.go:539] dnat ports changed, []
I1011 07:39:19.174137       1 iptables.go:539] dnat ports changed, []
I1011 07:40:19.174732       1 iptables.go:539] dnat ports changed, []
I1011 07:41:19.174043       1 iptables.go:539] dnat ports changed, []
I1011 07:42:19.173167       1 iptables.go:539] dnat ports changed, []
I1011 07:43:19.177473       1 iptables.go:539] dnat ports changed, []
I1011 07:44:19.176754       1 iptables.go:539] dnat ports changed, []
I1011 07:45:19.176027       1 iptables.go:539] dnat ports changed, []
I1011 07:46:19.174254       1 iptables.go:539] dnat ports changed, []
I1011 07:47:19.175489       1 iptables.go:539] dnat ports changed, []
I1011 07:48:19.176148       1 iptables.go:539] dnat ports changed, []
I1011 07:49:19.177092       1 iptables.go:539] dnat ports changed, []
I1011 07:50:19.177197       1 iptables.go:539] dnat ports changed, []
I1011 07:51:19.175556       1 iptables.go:539] dnat ports changed, []
I1011 07:52:19.206353       1 iptables.go:539] dnat ports changed, []
I1011 07:53:19.180040       1 iptables.go:539] dnat ports changed, []
I1011 07:53:31.196887       1 dns.go:301] sync tunnel server service as whole
I1011 07:53:31.198200       1 dns.go:310] sync dns record as whole
I1011 07:54:19.179793       1 iptables.go:539] dnat ports changed, []
I1011 07:55:19.175251       1 iptables.go:539] dnat ports changed, []
I1011 07:56:19.220992       1 iptables.go:539] dnat ports changed, []
I1011 07:57:19.182224       1 iptables.go:539] dnat ports changed, []
I1011 07:58:19.181208       1 iptables.go:539] dnat ports changed, []
I1011 07:59:19.174329       1 iptables.go:539] dnat ports changed, []
I1011 08:00:19.179526       1 iptables.go:539] dnat ports changed, []
I1011 08:01:19.531627       1 iptables.go:539] dnat ports changed, []
I1011 08:01:51.833081       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52136 to 192.168.17.130:10250
I1011 08:01:51.835056       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=2
I1011 08:01:51.864152       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 31.04399ms
I1011 08:01:51.864366       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=2
I1011 08:01:51.865011       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=2
I1011 08:02:03.548768       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52138 to 192.168.17.130:10250
I1011 08:02:03.550111       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=3
I1011 08:02:03.578705       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 29.896018ms
I1011 08:02:03.578922       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=3
I1011 08:02:03.579613       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=3
I1011 08:02:19.179441       1 iptables.go:539] dnat ports changed, []
I1011 08:02:31.321059       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52142 to 192.168.17.130:10250
I1011 08:02:31.322523       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=4
I1011 08:02:31.339072       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 17.985703ms
I1011 08:02:31.339263       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=4
I1011 08:02:31.340053       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=4
I1011 08:03:19.179216       1 iptables.go:539] dnat ports changed, []
I1011 08:04:19.183658       1 iptables.go:539] dnat ports changed, []
I1011 08:05:19.175553       1 iptables.go:539] dnat ports changed, []
I1011 08:06:19.179421       1 iptables.go:539] dnat ports changed, []
I1011 08:07:19.198128       1 iptables.go:539] dnat ports changed, []
I1011 08:08:19.177387       1 iptables.go:539] dnat ports changed, []
I1011 08:09:19.177117       1 iptables.go:539] dnat ports changed, []
I1011 08:10:19.177726       1 iptables.go:539] dnat ports changed, []
I1011 08:11:19.174797       1 iptables.go:539] dnat ports changed, []
I1011 08:12:19.197116       1 iptables.go:539] dnat ports changed, []
I1011 08:13:19.199297       1 iptables.go:539] dnat ports changed, []
I1011 08:14:19.180268       1 iptables.go:539] dnat ports changed, []
I1011 08:15:19.180924       1 iptables.go:539] dnat ports changed, []
I1011 08:16:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 08:17:19.176916       1 iptables.go:539] dnat ports changed, []
I1011 08:18:19.176084       1 iptables.go:539] dnat ports changed, []
I1011 08:19:19.180304       1 iptables.go:539] dnat ports changed, []
I1011 08:20:19.177434       1 iptables.go:539] dnat ports changed, []
I1011 08:21:19.179631       1 iptables.go:539] dnat ports changed, []
I1011 08:22:19.178435       1 iptables.go:539] dnat ports changed, []
I1011 08:23:19.175058       1 iptables.go:539] dnat ports changed, []
I1011 08:23:31.205337       1 dns.go:301] sync tunnel server service as whole
I1011 08:23:31.207910       1 dns.go:310] sync dns record as whole
I1011 08:24:19.177869       1 iptables.go:539] dnat ports changed, []
I1011 08:25:19.193670       1 iptables.go:539] dnat ports changed, []
I1011 08:26:19.177393       1 iptables.go:539] dnat ports changed, []
I1011 08:27:19.178744       1 iptables.go:539] dnat ports changed, []
I1011 08:28:19.179923       1 iptables.go:539] dnat ports changed, []
I1011 08:29:19.176710       1 iptables.go:539] dnat ports changed, []
I1011 08:30:19.176490       1 iptables.go:539] dnat ports changed, []
I1011 08:31:19.177187       1 iptables.go:539] dnat ports changed, []
I1011 08:32:19.176354       1 iptables.go:539] dnat ports changed, []
I1011 08:33:19.183060       1 iptables.go:539] dnat ports changed, []
I1011 08:34:19.176584       1 iptables.go:539] dnat ports changed, []
I1011 08:35:19.176450       1 iptables.go:539] dnat ports changed, []
I1011 08:36:19.177009       1 iptables.go:539] dnat ports changed, []
I1011 08:37:19.178339       1 iptables.go:539] dnat ports changed, []
I1011 08:38:19.179235       1 iptables.go:539] dnat ports changed, []
I1011 08:39:19.176771       1 iptables.go:539] dnat ports changed, []
I1011 08:40:19.175344       1 iptables.go:539] dnat ports changed, []
I1011 08:41:19.176535       1 iptables.go:539] dnat ports changed, []
I1011 08:42:19.176892       1 iptables.go:539] dnat ports changed, []
I1011 08:43:19.176377       1 iptables.go:539] dnat ports changed, []
I1011 08:44:19.177715       1 iptables.go:539] dnat ports changed, []
I1011 08:45:19.179103       1 iptables.go:539] dnat ports changed, []
I1011 08:46:19.179105       1 iptables.go:539] dnat ports changed, []
I1011 08:47:19.179544       1 iptables.go:539] dnat ports changed, []
I1011 08:48:19.179320       1 iptables.go:539] dnat ports changed, []
I1011 08:49:19.178770       1 iptables.go:539] dnat ports changed, []
I1011 08:50:19.183371       1 iptables.go:539] dnat ports changed, []
I1011 08:51:19.183916       1 iptables.go:539] dnat ports changed, []
I1011 08:52:19.177069       1 iptables.go:539] dnat ports changed, []
I1011 08:53:19.177503       1 iptables.go:539] dnat ports changed, []
I1011 08:53:31.220276       1 dns.go:301] sync tunnel server service as whole
I1011 08:53:31.222252       1 dns.go:310] sync dns record as whole
I1011 08:54:19.179932       1 iptables.go:539] dnat ports changed, []
I1011 08:55:19.180744       1 iptables.go:539] dnat ports changed, []
I1011 08:56:19.181121       1 iptables.go:539] dnat ports changed, []
I1011 08:57:19.179438       1 iptables.go:539] dnat ports changed, []
I1011 08:58:19.181572       1 iptables.go:539] dnat ports changed, []
I1011 08:59:19.197308       1 iptables.go:539] dnat ports changed, []
I1011 09:00:19.177977       1 iptables.go:539] dnat ports changed, []
I1011 09:01:19.177990       1 iptables.go:539] dnat ports changed, []
I1011 09:02:19.181674       1 iptables.go:539] dnat ports changed, []
I1011 09:03:19.176509       1 iptables.go:539] dnat ports changed, []
I1011 09:04:19.179804       1 iptables.go:539] dnat ports changed, []
I1011 09:05:19.179780       1 iptables.go:539] dnat ports changed, []
I1011 09:06:19.179632       1 iptables.go:539] dnat ports changed, []
I1011 09:07:19.177821       1 iptables.go:539] dnat ports changed, []
I1011 09:08:19.182061       1 iptables.go:539] dnat ports changed, []
I1011 09:09:19.182311       1 iptables.go:539] dnat ports changed, []
I1011 09:10:19.179218       1 iptables.go:539] dnat ports changed, []
I1011 09:11:19.179125       1 iptables.go:539] dnat ports changed, []
I1011 09:12:19.178195       1 iptables.go:539] dnat ports changed, []
I1011 09:13:19.182649       1 iptables.go:539] dnat ports changed, []
I1011 09:14:19.181041       1 iptables.go:539] dnat ports changed, []
I1011 09:15:19.183101       1 iptables.go:539] dnat ports changed, []
I1011 09:16:19.187040       1 iptables.go:539] dnat ports changed, []
I1011 09:17:19.183544       1 iptables.go:539] dnat ports changed, []
I1011 09:18:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 09:19:19.182356       1 iptables.go:539] dnat ports changed, []
I1011 09:20:19.180889       1 iptables.go:539] dnat ports changed, []
I1011 09:21:19.181620       1 iptables.go:539] dnat ports changed, []
I1011 09:22:19.180250       1 iptables.go:539] dnat ports changed, []
I1011 09:23:19.183037       1 iptables.go:539] dnat ports changed, []
I1011 09:23:31.227156       1 dns.go:301] sync tunnel server service as whole
I1011 09:23:31.230608       1 dns.go:310] sync dns record as whole
I1011 09:24:19.179920       1 iptables.go:539] dnat ports changed, []
I1011 09:25:19.182038       1 iptables.go:539] dnat ports changed, []
I1011 09:26:19.181332       1 iptables.go:539] dnat ports changed, []
I1011 09:27:19.182114       1 iptables.go:539] dnat ports changed, []
I1011 09:28:19.178484       1 iptables.go:539] dnat ports changed, []
I1011 09:29:19.180852       1 iptables.go:539] dnat ports changed, []
I1011 09:30:19.177830       1 iptables.go:539] dnat ports changed, []
I1011 09:31:19.184896       1 iptables.go:539] dnat ports changed, []
I1011 09:32:19.183521       1 iptables.go:539] dnat ports changed, []
I1011 09:33:19.178906       1 iptables.go:539] dnat ports changed, []
I1011 09:34:19.179613       1 iptables.go:539] dnat ports changed, []
I1011 09:35:19.180510       1 iptables.go:539] dnat ports changed, []
I1011 09:36:19.176730       1 iptables.go:539] dnat ports changed, []
I1011 09:37:19.179345       1 iptables.go:539] dnat ports changed, []
I1011 09:38:19.181372       1 iptables.go:539] dnat ports changed, []
I1011 09:39:19.179186       1 iptables.go:539] dnat ports changed, []
I1011 09:40:19.181759       1 iptables.go:539] dnat ports changed, []
I1011 09:41:19.181811       1 iptables.go:539] dnat ports changed, []
I1011 09:42:19.180120       1 iptables.go:539] dnat ports changed, []
I1011 09:43:19.186947       1 iptables.go:539] dnat ports changed, []
I1011 09:44:19.195637       1 iptables.go:539] dnat ports changed, []
I1011 09:45:19.182809       1 iptables.go:539] dnat ports changed, []
I1011 09:46:19.181136       1 iptables.go:539] dnat ports changed, []
I1011 09:47:19.180399       1 iptables.go:539] dnat ports changed, []
I1011 09:48:19.177773       1 iptables.go:539] dnat ports changed, []
I1011 09:49:19.175869       1 iptables.go:539] dnat ports changed, []
I1011 09:50:19.175571       1 iptables.go:539] dnat ports changed, []
I1011 09:51:19.176799       1 iptables.go:539] dnat ports changed, []
I1011 09:52:19.179724       1 iptables.go:539] dnat ports changed, []
I1011 09:53:19.176958       1 iptables.go:539] dnat ports changed, []
I1011 09:53:31.235445       1 dns.go:301] sync tunnel server service as whole
I1011 09:53:31.241397       1 dns.go:310] sync dns record as whole
I1011 09:54:19.177902       1 iptables.go:539] dnat ports changed, []
I1011 09:55:19.181559       1 iptables.go:539] dnat ports changed, []
I1011 09:56:19.175555       1 iptables.go:539] dnat ports changed, []
I1011 09:57:19.176113       1 iptables.go:539] dnat ports changed, []
I1011 09:58:19.178323       1 iptables.go:539] dnat ports changed, []
I1011 09:59:19.177297       1 iptables.go:539] dnat ports changed, []

@Hyan1996 Thank you for your feedback. as you failed to execute command kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date, but i can not search any info of ubuntu22-deamonset-gbzfd in your yurt-tunnel-server log.

it seems that yurt-tunnel-server have not received the exec request from kube-apiserver, this means that exec request hasn't been forwarded to yurt-tunnel-server by kube-apiserver.

maybe there are some problems in your kube-apiserver configuration, please check the tutorial here: https://openyurt.io/docs/installation/manually-setup/#23-adjust-kube-apiserver

fujitatomoya commented 2 years ago

it looks like that yurt-tunnel-agent on edge nodes failed to connect yurt-tunnel-server on the cloud node.

why? i can reproduce this issue on master node as openyurt cloud, which is tagged with openyurt.io/is-edge-worker=false as described in https://openyurt.io/docs/installation/manually-setup/#11-label-cloud-nodes. I think yurt-tunnel-agent has nothing to do with this failure because it should not be used for this request? (actually i cannot even see the yurt-tunnel-agent pods in the cluster.)

root@ceci-control-plane:~# kubectl get node -o wide
NAME                 STATUS   ROLES                  AGE     VERSION    INTERNAL-IP     EXTERNAL-IP   OS-IMAGE             KERNEL-VERSION      CONTAINER-RUNTIME
ceci-control-plane   Ready    control-plane,master   6m46s   v1.22.13   192.168.56.20   <none>        Ubuntu 20.04.5 LTS   5.4.0-126-generic   docker://19.3.11
root@ceci-control-plane:~# kubectl get nodes --show-labels
NAME                 STATUS   ROLES                  AGE     VERSION    LABELS
ceci-control-plane   Ready    control-plane,master   5m33s   v1.22.13   apps.openyurt.io/desired-nodepool=master,apps.openyurt.io/nodepool=master,beta.kubernetes.io/arch=amd64,beta.kubernetes.io/os=linux,ceci/container-registry=valid,ceci/istio-control-pane=valid,kubernetes.io/arch=amd64,kubernetes.io/hostname=ceci-control-plane,kubernetes.io/os=linux,node-role.kubernetes.io/control-plane=,node-role.kubernetes.io/master=,node.kubernetes.io/exclude-from-external-load-balancers=,openyurt.io/is-edge-worker=false
root@ceci-control-plane:~# kubectl get pods -A | grep tunnel
kube-system    yurt-tunnel-dns-9cbd69765-gjf86                  1/1     Running   0               5m26s
kube-system    yurt-tunnel-server-6bffb656d4-tktf5              1/1     Running   0               4m19s

the same comment goes to https://github.com/openyurtio/openyurt/issues/1024#issuecomment-1274294001

root@ubuntu:/home/hyan# kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

this is the pod deployed on master node (OpenYurt cloud), why yurt-tunnel-agent is related?

root@ubuntu:/home/hyan# kubectl logs -n kube-system yurt-tunnel-server-6bffb656d4-cn6sj
Error from server (ServiceUnavailable): the server is currently unable to handle the request ( pods/log yurt-tunnel-server-6bffb656d4-cn6sj)

instead, this is the exact problem here.

it seems that yurt-tunnel-server have not received the exec request from kube-apiserver, this means that exec request hasn't been forwarded to yurt-tunnel-server by kube-apiserver.

i think the procedure is correct and aligned with document, https://openyurt.io/docs/installation/openyurt-prepare/#3-kube-apiserver-adjustment

root@ceci-control-plane:~# cat /etc/kubernetes/manifests/kube-apiserver.yaml
apiVersion: v1
kind: Pod
metadata:
  annotations:
    kubeadm.kubernetes.io/kube-apiserver.advertise-address.endpoint: 192.168.56.20:6443
  creationTimestamp: null
  labels:
    component: kube-apiserver
    tier: control-plane
  name: kube-apiserver
  namespace: kube-system
spec:
  dnsPolicy: "None"
  dnsConfig:
    nameservers:
      - 10.107.95.75
    searches:
      - kube-system.svc.cluster.local
      - svc.cluster.local
      - cluster.local
    options:
      - name: ndots
        value: "5"
  containers:
  - command:
    - kube-apiserver
    - --advertise-address=192.168.56.20
    - --allow-privileged=true
...
    - --kubelet-preferred-address-types=Hostname,InternalIP,ExternalIP
...

could you provide how to debug this issue?

fujitatomoya commented 2 years ago

@rambohe-ch

I can reproduce this issue using vagrant / virtualbox environment which has two network interfaces as below.

enp0s3: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.0.2.15  netmask 255.255.255.0  broadcast 10.0.2.255
        inet6 fe80::3:d8ff:fe7e:4a4e  prefixlen 64  scopeid 0x20<link>
        ether 02:03:d8:7e:4a:4e  txqueuelen 1000  (Ethernet)
        RX packets 669011  bytes 971473845 (971.4 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 267247  bytes 17307397 (17.3 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

enp0s8: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.56.20  netmask 255.255.255.0  broadcast 192.168.56.255
        inet6 fe80::a00:27ff:fe3f:5b9b  prefixlen 64  scopeid 0x20<link>
        ether 08:00:27:3f:5b:9b  txqueuelen 1000  (Ethernet)
        RX packets 4  bytes 1066 (1.0 KB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 15  bytes 1186 (1.1 KB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

So that we use the following option to specify the network interface to start kubernetes via kubeadm and kubectl.

I think this could be related to the issue?

Hyan1996 commented 2 years ago

Is this one?

root@ubuntu:/home/hyan# docker ps | grep yurt-tunnel-server
a095a9346115   6a2597bae8cd                       "yurt-tunnel-server …"   3 hours ago      Up 3 hours                k8s_yurt-tunnel-server_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0
cc680c7cf560   k8s.gcr.io/pause:3.5               "/pause"                 3 hours ago      Up 3 hours                k8s_POD_yurt-tunnel-server-6bffb656d4-cn6sj_kube-system_798aa75c-fd5b-4e23-9bd4-59e12263d8e1_0

root@ubuntu:/home/hyan# docker logs a095a9346115
I1011 07:23:14.001585       1 start.go:53] yurttunnel-server version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T06:59:22Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
W1011 07:23:14.001950       1 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
I1011 07:23:14.003414       1 options.go:168] yurttunnel server config: &config.Config{EgressSelectorEnabled:false, EnableIptables:true, EnableDNSController:true, IptablesSyncPeriod:60, IPFamily:0x1, DNSSyncPeriod:1800, CertDNSNames:[]string{}, CertIPs:[]net.IP{}, CertDir:"", ListenAddrForAgent:"192.168.17.129:10262", ListenAddrForMaster:"192.168.17.129:10263", ListenInsecureAddrForMaster:"192.168.17.129:10264", ListenMetaAddr:"192.168.17.129:10265", RootCert:(*x509.CertPool)(0xc0003d0ff0), Client:(*kubernetes.Clientset)(0xc0003f4420), SharedInformerFactory:(*informers.sharedInformerFactory)(0xc000401220), ServerCount:1, ProxyStrategy:"destHost", InterceptorServerUDSFile:""}
I1011 07:23:14.010254       1 leaderelection.go:248] attempting to acquire leader lease kube-system/tunnel-dns-controller...
E1011 07:23:14.019938       1 iptables.go:216] failed to delete rule that nat chain OUTPUT jumps to TUNNEL-PORT: error checking rule: exit status 2: iptables v1.8.7 (legacy): Couldn't load target `TUNNEL-PORT':No such file or directory

Try `iptables -h' or 'iptables --help' for more information.
I1011 07:23:19.031543       1 certmanager.go:105] subject of tunnel server certificate, ips=192.168.17.129,10.100.165.142,127.0.0.1,::1,192.168.17.129,10.101.31.78, dnsNames=[]string{"ubuntu", "x-tunnel-server-svc", "x-tunnel-server-svc.kube-system", "x-tunnel-server-svc.kube-system.svc", "x-tunnel-server-svc.kube-system.svc.cluster.local", "x-tunnel-server-internal-svc", "x-tunnel-server-internal-svc.kube-system", "x-tunnel-server-internal-svc.kube-system.svc", "x-tunnel-server-internal-svc.kube-system.svc.cluster.local"}
W1011 07:23:19.031746       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031787       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate rotation is enabled
W1011 07:23:19.031807       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-proxy-client-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1011 07:23:19.031811       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1011 07:23:19.031975       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Rotating certificates
I1011 07:23:19.032744       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1011 07:23:19.040573       1 handler.go:43] enqueue node add event for ubuntu
I1011 07:23:19.040685       1 handler.go:43] enqueue node add event for edge
I1011 07:23:19.043118       1 handler.go:141] enqueue service add event for kube-system/x-tunnel-server-internal-svc
I1011 07:23:19.060992       1 handler.go:175] handle configmap add event for kube-system/yurt-tunnel-server-cfg to update localhost ports
I1011 07:23:19.061037       1 handler.go:93] enqueue configmap add event for kube-system/yurt-tunnel-server-cfg
I1011 07:23:19.063376       1 csr.go:258] certificate signing request csr-p4bvr is issued
I1011 07:23:19.063705       1 csr.go:258] certificate signing request csr-9825q is issued
I1011 07:23:19.154175       1 iptables.go:539] dnat ports changed, []
I1011 07:23:20.065125       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-08-22 04:48:08.961956739 +0000 UTC
I1011 07:23:20.065168       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 7557h24m48.896791344s for next certificate rotation
I1011 07:23:20.065467       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-09 10:41:44.097151555 +0000 UTC
I1011 07:23:20.065488       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6507h18m24.031665623s for next certificate rotation
I1011 07:23:21.066851       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-21 14:13:00.024350979 +0000 UTC
I1011 07:23:21.066881       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 6798h49m38.957472512s for next certificate rotation
I1011 07:23:21.066927       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 07:18:19 +0000 UTC, rotation deadline is 2023-07-17 00:32:35.517136256 +0000 UTC
I1011 07:23:21.066931       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6689h9m14.45020571s for next certificate rotation
I1011 07:23:24.033625       1 anpserver.go:107] start handling request from interceptor
I1011 07:23:24.033683       1 wraphandler.go:67] add localHostProxyMiddleware into wrap handler
I1011 07:23:24.033709       1 tracereq.go:80] 2 informer synced in traceReqMiddleware
I1011 07:23:24.033882       1 wraphandler.go:67] add TraceReqMiddleware into wrap handler
I1011 07:23:24.033927       1 anpserver.go:195] start handling connection from agents
I1011 07:23:24.034048       1 anpserver.go:143] start handling https request from master at 192.168.17.129:10263
I1011 07:23:24.034076       1 anpserver.go:157] start handling http request from master at 192.168.17.129:10264
I1011 07:23:24.034217       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="192.168.17.129:10265"
I1011 07:23:24.382343       1 server.go:616] "Connect request from agent" agentID="edge"
I1011 07:23:24.382388       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="192.168.17.130"
I1011 07:23:24.382399       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc000028540} agentID="edge"
I1011 07:23:27.056742       1 tracereq.go:134] start handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:41544 to 192.168.17.129:10250
E1011 07:23:27.057088       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:23:27.057287       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:23:27.057316       1 tracereq.go:138] stop handling request POST https://192.168.17.129:10250/exec/default/ubuntu22-deamonset-gbzfd/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 552.399µs
I1011 07:23:31.183919       1 leaderelection.go:258] successfully acquired lease kube-system/tunnel-dns-controller
I1011 07:23:31.184142       1 dns.go:177] starting tunnel dns controller
I1011 07:23:31.184184       1 shared_informer.go:240] Waiting for caches to sync for tunnel-dns-controller
I1011 07:23:31.184201       1 shared_informer.go:247] Caches are synced for tunnel-dns-controller 
I1011 07:23:31.185679       1 dns.go:301] sync tunnel server service as whole
I1011 07:23:31.185920       1 handler.go:166] adding node dns record for ubuntu
I1011 07:23:31.187044       1 dns.go:310] sync dns record as whole
I1011 07:23:31.188912       1 handler.go:166] adding node dns record for edge
I1011 07:23:31.195635       1 dns.go:310] sync dns record as whole
I1011 07:23:31.589090       1 dns.go:301] sync tunnel server service as whole
I1011 07:24:19.175752       1 iptables.go:539] dnat ports changed, []
I1011 07:24:35.655119       1 tracereq.go:134] start handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, from 192.168.17.129:52134 to 192.168.17.130:10250
I1011 07:24:35.657050       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=1
I1011 07:24:35.668732       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=1
I1011 07:24:35.669001       1 tracereq.go:138] stop handling request GET https://192.168.17.130:10250/containerLogs/kube-system/yurt-tunnel-agent-jxvml/yurt-tunnel-agent, request handling lasts 13.723697ms
E1011 07:24:35.671454       1 server.go:725] "send to client stream failure" err="write unix /tmp/interceptor-proxier.sock->@: use of closed network connection"
I1011 07:24:35.671603       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=1
I1011 07:25:19.176798       1 iptables.go:539] dnat ports changed, []
I1011 07:26:19.176846       1 iptables.go:539] dnat ports changed, []
I1011 07:27:19.174502       1 iptables.go:539] dnat ports changed, []
I1011 07:28:19.174140       1 iptables.go:539] dnat ports changed, []
I1011 07:29:19.173890       1 iptables.go:539] dnat ports changed, []
I1011 07:30:19.174425       1 iptables.go:539] dnat ports changed, []
I1011 07:31:19.176723       1 iptables.go:539] dnat ports changed, []
I1011 07:32:19.176180       1 iptables.go:539] dnat ports changed, []
I1011 07:33:19.175818       1 iptables.go:539] dnat ports changed, []
I1011 07:34:19.174512       1 iptables.go:539] dnat ports changed, []
I1011 07:35:19.175420       1 iptables.go:539] dnat ports changed, []
I1011 07:36:19.172322       1 iptables.go:539] dnat ports changed, []
I1011 07:37:08.439621       1 tracereq.go:134] start handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, from 127.0.0.1:41546 to 192.168.17.129:10250
E1011 07:37:08.440174       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1011 07:37:08.440298       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1011 07:37:08.440332       1 tracereq.go:138] stop handling request GET https://192.168.17.129:10250/containerLogs/kube-system/yurt-tunnel-server-6bffb656d4-cn6sj/yurt-tunnel-server, request handling lasts 377.833µs
I1011 07:37:19.176492       1 iptables.go:539] dnat ports changed, []
I1011 07:38:19.177410       1 iptables.go:539] dnat ports changed, []
I1011 07:39:19.174137       1 iptables.go:539] dnat ports changed, []
I1011 07:40:19.174732       1 iptables.go:539] dnat ports changed, []
I1011 07:41:19.174043       1 iptables.go:539] dnat ports changed, []
I1011 07:42:19.173167       1 iptables.go:539] dnat ports changed, []
I1011 07:43:19.177473       1 iptables.go:539] dnat ports changed, []
I1011 07:44:19.176754       1 iptables.go:539] dnat ports changed, []
I1011 07:45:19.176027       1 iptables.go:539] dnat ports changed, []
I1011 07:46:19.174254       1 iptables.go:539] dnat ports changed, []
I1011 07:47:19.175489       1 iptables.go:539] dnat ports changed, []
I1011 07:48:19.176148       1 iptables.go:539] dnat ports changed, []
I1011 07:49:19.177092       1 iptables.go:539] dnat ports changed, []
I1011 07:50:19.177197       1 iptables.go:539] dnat ports changed, []
I1011 07:51:19.175556       1 iptables.go:539] dnat ports changed, []
I1011 07:52:19.206353       1 iptables.go:539] dnat ports changed, []
I1011 07:53:19.180040       1 iptables.go:539] dnat ports changed, []
I1011 07:53:31.196887       1 dns.go:301] sync tunnel server service as whole
I1011 07:53:31.198200       1 dns.go:310] sync dns record as whole
I1011 07:54:19.179793       1 iptables.go:539] dnat ports changed, []
I1011 07:55:19.175251       1 iptables.go:539] dnat ports changed, []
I1011 07:56:19.220992       1 iptables.go:539] dnat ports changed, []
I1011 07:57:19.182224       1 iptables.go:539] dnat ports changed, []
I1011 07:58:19.181208       1 iptables.go:539] dnat ports changed, []
I1011 07:59:19.174329       1 iptables.go:539] dnat ports changed, []
I1011 08:00:19.179526       1 iptables.go:539] dnat ports changed, []
I1011 08:01:19.531627       1 iptables.go:539] dnat ports changed, []
I1011 08:01:51.833081       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52136 to 192.168.17.130:10250
I1011 08:01:51.835056       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=2
I1011 08:01:51.864152       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 31.04399ms
I1011 08:01:51.864366       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=2
I1011 08:01:51.865011       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=2
I1011 08:02:03.548768       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52138 to 192.168.17.130:10250
I1011 08:02:03.550111       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=3
I1011 08:02:03.578705       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 29.896018ms
I1011 08:02:03.578922       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=3
I1011 08:02:03.579613       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=3
I1011 08:02:19.179441       1 iptables.go:539] dnat ports changed, []
I1011 08:02:31.321059       1 tracereq.go:134] start handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, from 192.168.17.129:52142 to 192.168.17.130:10250
I1011 08:02:31.322523       1 tunnel.go:128] "Starting proxy to host" host="192.168.17.130:10250" agentID="edge" connectionID=4
I1011 08:02:31.339072       1 tracereq.go:138] stop handling request POST https://192.168.17.130:10250/portForward/istio-system/istiod-857cb8c78d-z6rzc, request handling lasts 17.985703ms
I1011 08:02:31.339263       1 tunnel.go:141] "EOF from host" host="192.168.17.130:10250" agentID="edge" connID=4
I1011 08:02:31.340053       1 server.go:290] "Remove frontend for agent" agentID="edge" connectionID=4
I1011 08:03:19.179216       1 iptables.go:539] dnat ports changed, []
I1011 08:04:19.183658       1 iptables.go:539] dnat ports changed, []
I1011 08:05:19.175553       1 iptables.go:539] dnat ports changed, []
I1011 08:06:19.179421       1 iptables.go:539] dnat ports changed, []
I1011 08:07:19.198128       1 iptables.go:539] dnat ports changed, []
I1011 08:08:19.177387       1 iptables.go:539] dnat ports changed, []
I1011 08:09:19.177117       1 iptables.go:539] dnat ports changed, []
I1011 08:10:19.177726       1 iptables.go:539] dnat ports changed, []
I1011 08:11:19.174797       1 iptables.go:539] dnat ports changed, []
I1011 08:12:19.197116       1 iptables.go:539] dnat ports changed, []
I1011 08:13:19.199297       1 iptables.go:539] dnat ports changed, []
I1011 08:14:19.180268       1 iptables.go:539] dnat ports changed, []
I1011 08:15:19.180924       1 iptables.go:539] dnat ports changed, []
I1011 08:16:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 08:17:19.176916       1 iptables.go:539] dnat ports changed, []
I1011 08:18:19.176084       1 iptables.go:539] dnat ports changed, []
I1011 08:19:19.180304       1 iptables.go:539] dnat ports changed, []
I1011 08:20:19.177434       1 iptables.go:539] dnat ports changed, []
I1011 08:21:19.179631       1 iptables.go:539] dnat ports changed, []
I1011 08:22:19.178435       1 iptables.go:539] dnat ports changed, []
I1011 08:23:19.175058       1 iptables.go:539] dnat ports changed, []
I1011 08:23:31.205337       1 dns.go:301] sync tunnel server service as whole
I1011 08:23:31.207910       1 dns.go:310] sync dns record as whole
I1011 08:24:19.177869       1 iptables.go:539] dnat ports changed, []
I1011 08:25:19.193670       1 iptables.go:539] dnat ports changed, []
I1011 08:26:19.177393       1 iptables.go:539] dnat ports changed, []
I1011 08:27:19.178744       1 iptables.go:539] dnat ports changed, []
I1011 08:28:19.179923       1 iptables.go:539] dnat ports changed, []
I1011 08:29:19.176710       1 iptables.go:539] dnat ports changed, []
I1011 08:30:19.176490       1 iptables.go:539] dnat ports changed, []
I1011 08:31:19.177187       1 iptables.go:539] dnat ports changed, []
I1011 08:32:19.176354       1 iptables.go:539] dnat ports changed, []
I1011 08:33:19.183060       1 iptables.go:539] dnat ports changed, []
I1011 08:34:19.176584       1 iptables.go:539] dnat ports changed, []
I1011 08:35:19.176450       1 iptables.go:539] dnat ports changed, []
I1011 08:36:19.177009       1 iptables.go:539] dnat ports changed, []
I1011 08:37:19.178339       1 iptables.go:539] dnat ports changed, []
I1011 08:38:19.179235       1 iptables.go:539] dnat ports changed, []
I1011 08:39:19.176771       1 iptables.go:539] dnat ports changed, []
I1011 08:40:19.175344       1 iptables.go:539] dnat ports changed, []
I1011 08:41:19.176535       1 iptables.go:539] dnat ports changed, []
I1011 08:42:19.176892       1 iptables.go:539] dnat ports changed, []
I1011 08:43:19.176377       1 iptables.go:539] dnat ports changed, []
I1011 08:44:19.177715       1 iptables.go:539] dnat ports changed, []
I1011 08:45:19.179103       1 iptables.go:539] dnat ports changed, []
I1011 08:46:19.179105       1 iptables.go:539] dnat ports changed, []
I1011 08:47:19.179544       1 iptables.go:539] dnat ports changed, []
I1011 08:48:19.179320       1 iptables.go:539] dnat ports changed, []
I1011 08:49:19.178770       1 iptables.go:539] dnat ports changed, []
I1011 08:50:19.183371       1 iptables.go:539] dnat ports changed, []
I1011 08:51:19.183916       1 iptables.go:539] dnat ports changed, []
I1011 08:52:19.177069       1 iptables.go:539] dnat ports changed, []
I1011 08:53:19.177503       1 iptables.go:539] dnat ports changed, []
I1011 08:53:31.220276       1 dns.go:301] sync tunnel server service as whole
I1011 08:53:31.222252       1 dns.go:310] sync dns record as whole
I1011 08:54:19.179932       1 iptables.go:539] dnat ports changed, []
I1011 08:55:19.180744       1 iptables.go:539] dnat ports changed, []
I1011 08:56:19.181121       1 iptables.go:539] dnat ports changed, []
I1011 08:57:19.179438       1 iptables.go:539] dnat ports changed, []
I1011 08:58:19.181572       1 iptables.go:539] dnat ports changed, []
I1011 08:59:19.197308       1 iptables.go:539] dnat ports changed, []
I1011 09:00:19.177977       1 iptables.go:539] dnat ports changed, []
I1011 09:01:19.177990       1 iptables.go:539] dnat ports changed, []
I1011 09:02:19.181674       1 iptables.go:539] dnat ports changed, []
I1011 09:03:19.176509       1 iptables.go:539] dnat ports changed, []
I1011 09:04:19.179804       1 iptables.go:539] dnat ports changed, []
I1011 09:05:19.179780       1 iptables.go:539] dnat ports changed, []
I1011 09:06:19.179632       1 iptables.go:539] dnat ports changed, []
I1011 09:07:19.177821       1 iptables.go:539] dnat ports changed, []
I1011 09:08:19.182061       1 iptables.go:539] dnat ports changed, []
I1011 09:09:19.182311       1 iptables.go:539] dnat ports changed, []
I1011 09:10:19.179218       1 iptables.go:539] dnat ports changed, []
I1011 09:11:19.179125       1 iptables.go:539] dnat ports changed, []
I1011 09:12:19.178195       1 iptables.go:539] dnat ports changed, []
I1011 09:13:19.182649       1 iptables.go:539] dnat ports changed, []
I1011 09:14:19.181041       1 iptables.go:539] dnat ports changed, []
I1011 09:15:19.183101       1 iptables.go:539] dnat ports changed, []
I1011 09:16:19.187040       1 iptables.go:539] dnat ports changed, []
I1011 09:17:19.183544       1 iptables.go:539] dnat ports changed, []
I1011 09:18:19.179458       1 iptables.go:539] dnat ports changed, []
I1011 09:19:19.182356       1 iptables.go:539] dnat ports changed, []
I1011 09:20:19.180889       1 iptables.go:539] dnat ports changed, []
I1011 09:21:19.181620       1 iptables.go:539] dnat ports changed, []
I1011 09:22:19.180250       1 iptables.go:539] dnat ports changed, []
I1011 09:23:19.183037       1 iptables.go:539] dnat ports changed, []
I1011 09:23:31.227156       1 dns.go:301] sync tunnel server service as whole
I1011 09:23:31.230608       1 dns.go:310] sync dns record as whole
I1011 09:24:19.179920       1 iptables.go:539] dnat ports changed, []
I1011 09:25:19.182038       1 iptables.go:539] dnat ports changed, []
I1011 09:26:19.181332       1 iptables.go:539] dnat ports changed, []
I1011 09:27:19.182114       1 iptables.go:539] dnat ports changed, []
I1011 09:28:19.178484       1 iptables.go:539] dnat ports changed, []
I1011 09:29:19.180852       1 iptables.go:539] dnat ports changed, []
I1011 09:30:19.177830       1 iptables.go:539] dnat ports changed, []
I1011 09:31:19.184896       1 iptables.go:539] dnat ports changed, []
I1011 09:32:19.183521       1 iptables.go:539] dnat ports changed, []
I1011 09:33:19.178906       1 iptables.go:539] dnat ports changed, []
I1011 09:34:19.179613       1 iptables.go:539] dnat ports changed, []
I1011 09:35:19.180510       1 iptables.go:539] dnat ports changed, []
I1011 09:36:19.176730       1 iptables.go:539] dnat ports changed, []
I1011 09:37:19.179345       1 iptables.go:539] dnat ports changed, []
I1011 09:38:19.181372       1 iptables.go:539] dnat ports changed, []
I1011 09:39:19.179186       1 iptables.go:539] dnat ports changed, []
I1011 09:40:19.181759       1 iptables.go:539] dnat ports changed, []
I1011 09:41:19.181811       1 iptables.go:539] dnat ports changed, []
I1011 09:42:19.180120       1 iptables.go:539] dnat ports changed, []
I1011 09:43:19.186947       1 iptables.go:539] dnat ports changed, []
I1011 09:44:19.195637       1 iptables.go:539] dnat ports changed, []
I1011 09:45:19.182809       1 iptables.go:539] dnat ports changed, []
I1011 09:46:19.181136       1 iptables.go:539] dnat ports changed, []
I1011 09:47:19.180399       1 iptables.go:539] dnat ports changed, []
I1011 09:48:19.177773       1 iptables.go:539] dnat ports changed, []
I1011 09:49:19.175869       1 iptables.go:539] dnat ports changed, []
I1011 09:50:19.175571       1 iptables.go:539] dnat ports changed, []
I1011 09:51:19.176799       1 iptables.go:539] dnat ports changed, []
I1011 09:52:19.179724       1 iptables.go:539] dnat ports changed, []
I1011 09:53:19.176958       1 iptables.go:539] dnat ports changed, []
I1011 09:53:31.235445       1 dns.go:301] sync tunnel server service as whole
I1011 09:53:31.241397       1 dns.go:310] sync dns record as whole
I1011 09:54:19.177902       1 iptables.go:539] dnat ports changed, []
I1011 09:55:19.181559       1 iptables.go:539] dnat ports changed, []
I1011 09:56:19.175555       1 iptables.go:539] dnat ports changed, []
I1011 09:57:19.176113       1 iptables.go:539] dnat ports changed, []
I1011 09:58:19.178323       1 iptables.go:539] dnat ports changed, []
I1011 09:59:19.177297       1 iptables.go:539] dnat ports changed, []

@Hyan1996 Thank you for your feedback. as you failed to execute command kubectl exec --stdin --tty ubuntu22-deamonset-gbzfd -- date, but i can not search any info of ubuntu22-deamonset-gbzfd in your yurt-tunnel-server log.

it seems that yurt-tunnel-server have not received the exec request from kube-apiserver, this means that exec request hasn't been forwarded to yurt-tunnel-server by kube-apiserver.

maybe there are some problems in your kube-apiserver configuration, please check the tutorial here: https://openyurt.io/docs/installation/manually-setup/#23-adjust-kube-apiserver

Okay, I will check it carefully

fujitatomoya commented 2 years ago

@rambohe-ch CC: @Hyan1996

i have the similar log as below.

yurt-tunnel-server log via docker command since kubectl exec does not work
```bash root@ceci-control-plane:~# docker logs 3589b7d00d76 I1011 21:22:45.605232 1 start.go:53] yurttunnel-server version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T06:59:22Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"} W1011 21:22:45.605665 1 client_config.go:615] Neither --kubeconfig nor --master was specified. Using the inClusterConfig. This might not work. I1011 21:22:45.606242 1 options.go:168] yurttunnel server config: &config.Config{EgressSelectorEnabled:false, EnableIptables:true, EnableDNSController:true, IptablesSyncPeriod:60, IPFamily:0x1, DNSSyncPeriod:1800, CertDNSNames:[]string{}, CertIPs:[]net.IP{}, CertDir:"", ListenAddrForAgent:"192.168.56.20:10262", ListenAddrForMaster:"192.168.56.20:10263", ListenInsecureAddrForMaster:"192.168.56.20:10264", ListenMetaAddr:"192.168.56.20:10265", RootCert:(*x509.CertPool)(0xc00050e5a0), Client:(*kubernetes.Clientset)(0xc000552420), SharedInformerFactory:(*informers.sharedInformerFactory)(0xc000521540), ServerCount:1, ProxyStrategy:"destHost", InterceptorServerUDSFile:""} I1011 21:22:45.606392 1 leaderelection.go:248] attempting to acquire leader lease kube-system/tunnel-dns-controller... E1011 21:22:45.613328 1 iptables.go:216] failed to delete rule that nat chain OUTPUT jumps to TUNNEL-PORT: error checking rule: exit status 2: iptables v1.8.7 (legacy): Couldn't load target `TUNNEL-PORT':No such file or directory Try `iptables -h' or 'iptables --help' for more information. I1011 21:22:45.613566 1 leaderelection.go:258] successfully acquired lease kube-system/tunnel-dns-controller I1011 21:22:45.613633 1 dns.go:177] starting tunnel dns controller I1011 21:22:45.613645 1 shared_informer.go:240] Waiting for caches to sync for tunnel-dns-controller I1011 21:22:50.644029 1 certmanager.go:105] subject of tunnel server certificate, ips=192.168.56.20,10.106.10.108,127.0.0.1,::1,192.168.56.20,10.111.117.235, dnsNames=[]string{"ceci-control-plane", "x-tunnel-server-svc", "x-tunnel-server-svc.kube-system", "x-tunnel-server-svc.kube-system.svc", "x-tunnel-server-svc.kube-system.svc.cluster.local", "x-tunnel-server-internal-svc", "x-tunnel-server-internal-svc.kube-system", "x-tunnel-server-internal-svc.kube-system.svc", "x-tunnel-server-internal-svc.kube-system.svc.cluster.local"} W1011 21:22:50.644136 1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it I1011 21:22:50.644158 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate rotation is enabled W1011 21:22:50.644243 1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-proxy-client-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it I1011 21:22:50.644626 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled I1011 21:22:50.644572 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Rotating certificates I1011 21:22:50.644930 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates I1011 21:22:50.658593 1 handler.go:175] handle configmap add event for kube-system/yurt-tunnel-server-cfg to update localhost ports I1011 21:22:50.658669 1 handler.go:93] enqueue configmap add event for kube-system/yurt-tunnel-server-cfg I1011 21:22:50.659602 1 handler.go:141] enqueue service add event for kube-system/x-tunnel-server-internal-svc I1011 21:22:50.666714 1 handler.go:43] enqueue node add event for ceci-control-plane I1011 21:22:50.714889 1 shared_informer.go:247] Caches are synced for tunnel-dns-controller I1011 21:22:50.722755 1 dns.go:301] sync tunnel server service as whole I1011 21:22:50.722952 1 dns.go:301] sync tunnel server service as whole I1011 21:22:50.723336 1 dns.go:310] sync dns record as whole I1011 21:22:50.843611 1 iptables.go:539] dnat ports changed, [] I1011 21:22:51.824137 1 dns.go:310] sync dns record as whole I1011 21:22:52.827279 1 handler.go:166] adding node dns record for ceci-control-plane I1011 21:22:54.286974 1 csr.go:262] certificate signing request csr-btpv7 is approved, waiting to be issued I1011 21:22:54.287101 1 csr.go:262] certificate signing request csr-cscdw is approved, waiting to be issued I1011 21:22:54.299710 1 csr.go:258] certificate signing request csr-cscdw is issued I1011 21:22:54.299784 1 csr.go:258] certificate signing request csr-btpv7 is issued I1011 21:22:55.301195 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 21:17:54 +0000 UTC, rotation deadline is 2023-07-31 23:57:03.090488227 +0000 UTC I1011 21:22:55.301470 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 7034h34m7.789029956s for next certificate rotation I1011 21:22:55.301592 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 21:17:54 +0000 UTC, rotation deadline is 2023-08-22 18:47:43.961956739 +0000 UTC I1011 21:22:55.301776 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 7557h24m48.660312785s for next certificate rotation I1011 21:22:55.656690 1 anpserver.go:107] start handling request from interceptor I1011 21:22:55.656712 1 wraphandler.go:67] add localHostProxyMiddleware into wrap handler I1011 21:22:55.656717 1 tracereq.go:80] 2 informer synced in traceReqMiddleware I1011 21:22:55.656720 1 wraphandler.go:67] add TraceReqMiddleware into wrap handler I1011 21:22:55.656869 1 anpserver.go:195] start handling connection from agents I1011 21:22:55.656977 1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="192.168.56.20:10265" I1011 21:22:55.657174 1 anpserver.go:143] start handling https request from master at 192.168.56.20:10263 I1011 21:22:55.657208 1 anpserver.go:157] start handling http request from master at 192.168.56.20:10264 I1011 21:22:56.302937 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-11 21:17:54 +0000 UTC, rotation deadline is 2023-07-10 00:41:19.097151555 +0000 UTC I1011 21:22:56.303258 1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6507h18m22.793919364s for next certificate rotation I1011 21:22:56.304972 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-11 21:17:54 +0000 UTC, rotation deadline is 2023-07-22 04:12:35.024350979 +0000 UTC I1011 21:22:56.305037 1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 6798h49m38.719320354s for next certificate rotation I1011 21:23:50.891671 1 iptables.go:539] dnat ports changed, [] I1011 21:24:50.883735 1 iptables.go:539] dnat ports changed, [] I1011 21:25:45.194209 1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/portForward/istio-system/istiod-857cb8c78d-clnzl, from 127.0.0.1:54892 to 192.168.56.20:10250 E1011 21:25:45.194343 1 tunnel.go:74] "currently no tunnels available" err="No backend available" E1011 21:25:45.194424 1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe I1011 21:25:45.194432 1 tracereq.go:138] stop handling request POST https://192.168.56.20:10250/portForward/istio-system/istiod-857cb8c78d-clnzl, request handling lasts 208.978µs I1011 21:25:50.887218 1 iptables.go:539] dnat ports changed, [] I1011 21:26:50.900531 1 iptables.go:539] dnat ports changed, [] I1011 21:27:50.894141 1 iptables.go:539] dnat ports changed, [] I1011 21:28:50.879483 1 iptables.go:539] dnat ports changed, [] I1011 21:29:50.891830 1 iptables.go:539] dnat ports changed, [] I1011 21:30:50.883975 1 iptables.go:539] dnat ports changed, [] I1011 21:31:50.881979 1 iptables.go:539] dnat ports changed, [] I1011 21:32:50.885465 1 iptables.go:539] dnat ports changed, [] I1011 21:33:50.862708 1 iptables.go:539] dnat ports changed, [] I1011 21:34:50.859434 1 iptables.go:539] dnat ports changed, [] I1011 21:35:50.883501 1 iptables.go:539] dnat ports changed, [] I1011 21:36:50.888370 1 iptables.go:539] dnat ports changed, [] I1011 21:37:50.857378 1 iptables.go:539] dnat ports changed, [] I1011 21:38:50.860794 1 iptables.go:539] dnat ports changed, [] I1011 21:39:50.873206 1 iptables.go:539] dnat ports changed, [] I1011 21:40:50.877419 1 iptables.go:539] dnat ports changed, [] I1011 21:41:50.875745 1 iptables.go:539] dnat ports changed, [] I1011 21:42:50.894386 1 iptables.go:539] dnat ports changed, [] I1011 21:43:50.885943 1 iptables.go:539] dnat ports changed, [] I1011 21:44:50.862821 1 iptables.go:539] dnat ports changed, [] I1011 21:45:50.885236 1 iptables.go:539] dnat ports changed, [] I1011 21:46:50.859970 1 iptables.go:539] dnat ports changed, [] I1011 21:47:50.899124 1 iptables.go:539] dnat ports changed, [] I1011 21:48:50.868317 1 iptables.go:539] dnat ports changed, [] I1011 21:49:50.876486 1 iptables.go:539] dnat ports changed, [] I1011 21:50:50.884066 1 iptables.go:539] dnat ports changed, [] I1011 21:51:50.885450 1 iptables.go:539] dnat ports changed, [] I1011 21:52:50.878801 1 iptables.go:539] dnat ports changed, [] I1011 21:52:51.618992 1 dns.go:301] sync tunnel server service as whole I1011 21:52:52.220572 1 dns.go:310] sync dns record as whole I1011 21:53:50.896603 1 iptables.go:539] dnat ports changed, [] I1011 21:54:50.897095 1 iptables.go:539] dnat ports changed, [] I1011 21:55:50.873703 1 iptables.go:539] dnat ports changed, [] I1011 21:56:50.882590 1 iptables.go:539] dnat ports changed, [] I1011 21:57:50.882685 1 iptables.go:539] dnat ports changed, [] I1011 21:58:50.879705 1 iptables.go:539] dnat ports changed, [] I1011 21:59:50.866631 1 iptables.go:539] dnat ports changed, [] I1011 22:00:50.883265 1 iptables.go:539] dnat ports changed, [] I1011 22:01:50.865158 1 iptables.go:539] dnat ports changed, [] I1011 22:02:50.862105 1 iptables.go:539] dnat ports changed, [] I1011 22:03:50.860594 1 iptables.go:539] dnat ports changed, [] I1011 22:04:50.879113 1 iptables.go:539] dnat ports changed, [] I1011 22:05:50.875383 1 iptables.go:539] dnat ports changed, [] I1011 22:06:50.874933 1 iptables.go:539] dnat ports changed, [] I1011 22:07:50.878735 1 iptables.go:539] dnat ports changed, [] I1011 22:08:50.891313 1 iptables.go:539] dnat ports changed, [] I1011 22:09:50.897435 1 iptables.go:539] dnat ports changed, [] I1011 22:10:50.889087 1 iptables.go:539] dnat ports changed, [] I1011 22:11:50.890815 1 iptables.go:539] dnat ports changed, [] I1011 22:12:50.873906 1 iptables.go:539] dnat ports changed, [] I1011 22:13:50.879344 1 iptables.go:539] dnat ports changed, [] I1011 22:14:50.919193 1 iptables.go:539] dnat ports changed, [] I1011 22:15:50.883186 1 iptables.go:539] dnat ports changed, [] I1011 22:16:50.881518 1 iptables.go:539] dnat ports changed, [] I1011 22:17:50.892419 1 iptables.go:539] dnat ports changed, [] I1011 22:18:50.857655 1 iptables.go:539] dnat ports changed, [] I1011 22:19:50.877414 1 iptables.go:539] dnat ports changed, [] I1011 22:20:50.870505 1 iptables.go:539] dnat ports changed, [] I1011 22:21:50.880774 1 iptables.go:539] dnat ports changed, [] I1011 22:22:50.877726 1 iptables.go:539] dnat ports changed, [] I1011 22:22:51.649184 1 dns.go:301] sync tunnel server service as whole I1011 22:22:52.249229 1 dns.go:310] sync dns record as whole I1011 22:23:50.885464 1 iptables.go:539] dnat ports changed, [] I1011 22:24:50.897450 1 iptables.go:539] dnat ports changed, [] I1011 22:25:50.869964 1 iptables.go:539] dnat ports changed, [] I1011 22:26:50.863487 1 iptables.go:539] dnat ports changed, [] I1011 22:27:50.877533 1 iptables.go:539] dnat ports changed, [] I1011 22:28:50.886378 1 iptables.go:539] dnat ports changed, [] I1011 22:29:50.888118 1 iptables.go:539] dnat ports changed, [] I1011 22:30:50.859340 1 iptables.go:539] dnat ports changed, [] I1011 22:31:50.897446 1 iptables.go:539] dnat ports changed, [] I1011 22:32:50.860242 1 iptables.go:539] dnat ports changed, [] I1011 22:33:50.900654 1 iptables.go:539] dnat ports changed, [] I1011 22:34:50.887377 1 iptables.go:539] dnat ports changed, [] I1011 22:35:50.879697 1 iptables.go:539] dnat ports changed, [] I1011 22:36:50.875067 1 iptables.go:539] dnat ports changed, [] I1011 22:37:50.903046 1 iptables.go:539] dnat ports changed, [] I1011 22:38:50.887863 1 iptables.go:539] dnat ports changed, [] I1011 22:39:50.885441 1 iptables.go:539] dnat ports changed, [] I1011 22:40:50.885774 1 iptables.go:539] dnat ports changed, [] I1011 22:41:50.863919 1 iptables.go:539] dnat ports changed, [] I1011 22:42:50.895883 1 iptables.go:539] dnat ports changed, [] I1011 22:43:50.884095 1 iptables.go:539] dnat ports changed, [] I1011 22:44:50.954725 1 iptables.go:539] dnat ports changed, [] I1011 22:45:50.897888 1 iptables.go:539] dnat ports changed, [] I1011 22:46:50.881036 1 iptables.go:539] dnat ports changed, [] I1011 22:47:50.895249 1 iptables.go:539] dnat ports changed, [] I1011 22:48:50.891139 1 iptables.go:539] dnat ports changed, [] I1011 22:49:50.876437 1 iptables.go:539] dnat ports changed, [] I1011 22:50:50.888594 1 iptables.go:539] dnat ports changed, [] I1011 22:51:50.892891 1 iptables.go:539] dnat ports changed, [] I1011 22:52:50.880624 1 iptables.go:539] dnat ports changed, [] I1011 22:52:51.658263 1 dns.go:301] sync tunnel server service as whole I1011 22:52:52.263686 1 dns.go:310] sync dns record as whole I1011 22:53:50.910420 1 iptables.go:539] dnat ports changed, [] I1011 22:54:50.893346 1 iptables.go:539] dnat ports changed, [] I1011 22:55:50.868008 1 iptables.go:539] dnat ports changed, [] I1011 22:56:50.870024 1 iptables.go:539] dnat ports changed, [] I1011 22:57:50.875466 1 iptables.go:539] dnat ports changed, [] I1011 22:58:50.893980 1 iptables.go:539] dnat ports changed, [] I1011 22:59:50.892155 1 iptables.go:539] dnat ports changed, [] I1011 23:00:50.884918 1 iptables.go:539] dnat ports changed, [] I1011 23:01:50.885573 1 iptables.go:539] dnat ports changed, [] I1011 23:02:50.889206 1 iptables.go:539] dnat ports changed, [] I1011 23:03:50.916662 1 iptables.go:539] dnat ports changed, [] I1011 23:04:50.889459 1 iptables.go:539] dnat ports changed, [] I1011 23:05:50.871592 1 iptables.go:539] dnat ports changed, [] I1011 23:06:50.880636 1 iptables.go:539] dnat ports changed, [] I1011 23:07:50.871149 1 iptables.go:539] dnat ports changed, [] I1011 23:08:50.874505 1 iptables.go:539] dnat ports changed, [] I1011 23:09:50.883934 1 iptables.go:539] dnat ports changed, [] I1011 23:10:50.900764 1 iptables.go:539] dnat ports changed, [] I1011 23:11:50.857653 1 iptables.go:539] dnat ports changed, [] I1011 23:12:50.899835 1 iptables.go:539] dnat ports changed, [] I1011 23:13:50.858857 1 iptables.go:539] dnat ports changed, [] I1011 23:14:50.857349 1 iptables.go:539] dnat ports changed, [] I1011 23:15:50.856677 1 iptables.go:539] dnat ports changed, [] I1011 23:16:50.895780 1 iptables.go:539] dnat ports changed, [] I1011 23:17:50.885560 1 iptables.go:539] dnat ports changed, [] I1011 23:18:50.909927 1 iptables.go:539] dnat ports changed, [] I1011 23:19:50.885198 1 iptables.go:539] dnat ports changed, [] I1011 23:20:50.873774 1 iptables.go:539] dnat ports changed, [] I1011 23:21:50.885008 1 iptables.go:539] dnat ports changed, [] I1011 23:22:50.867680 1 iptables.go:539] dnat ports changed, [] I1011 23:22:51.678820 1 dns.go:301] sync tunnel server service as whole I1011 23:22:52.288876 1 dns.go:310] sync dns record as whole I1011 23:23:50.892304 1 iptables.go:539] dnat ports changed, [] I1011 23:24:50.882338 1 iptables.go:539] dnat ports changed, [] I1011 23:25:50.915383 1 iptables.go:539] dnat ports changed, [] I1011 23:26:50.882923 1 iptables.go:539] dnat ports changed, [] I1011 23:27:50.891933 1 iptables.go:539] dnat ports changed, [] I1011 23:28:50.880926 1 iptables.go:539] dnat ports changed, [] I1011 23:29:50.892324 1 iptables.go:539] dnat ports changed, [] I1011 23:30:50.894234 1 iptables.go:539] dnat ports changed, [] I1011 23:31:50.910786 1 iptables.go:539] dnat ports changed, [] I1011 23:32:50.879517 1 iptables.go:539] dnat ports changed, [] I1011 23:33:50.881807 1 iptables.go:539] dnat ports changed, [] I1011 23:34:50.917304 1 iptables.go:539] dnat ports changed, [] I1011 23:35:50.876401 1 iptables.go:539] dnat ports changed, [] I1011 23:36:50.886275 1 iptables.go:539] dnat ports changed, [] I1011 23:37:50.881901 1 iptables.go:539] dnat ports changed, [] I1011 23:38:50.858213 1 iptables.go:539] dnat ports changed, [] I1011 23:39:50.860965 1 iptables.go:539] dnat ports changed, [] I1011 23:40:50.859724 1 iptables.go:539] dnat ports changed, [] I1011 23:41:50.860904 1 iptables.go:539] dnat ports changed, [] I1011 23:42:50.894145 1 iptables.go:539] dnat ports changed, [] I1011 23:43:50.868430 1 iptables.go:539] dnat ports changed, [] I1011 23:44:50.859424 1 iptables.go:539] dnat ports changed, [] I1011 23:45:50.873135 1 iptables.go:539] dnat ports changed, [] I1011 23:46:50.873506 1 iptables.go:539] dnat ports changed, [] I1011 23:47:50.878387 1 iptables.go:539] dnat ports changed, [] I1011 23:48:50.858861 1 iptables.go:539] dnat ports changed, [] I1011 23:49:50.882507 1 iptables.go:539] dnat ports changed, [] I1011 23:50:50.875248 1 iptables.go:539] dnat ports changed, [] I1011 23:51:50.860818 1 iptables.go:539] dnat ports changed, [] I1011 23:52:50.879371 1 iptables.go:539] dnat ports changed, [] I1011 23:52:51.694028 1 dns.go:301] sync tunnel server service as whole I1011 23:52:52.308009 1 dns.go:310] sync dns record as whole I1011 23:53:50.880862 1 iptables.go:539] dnat ports changed, [] I1011 23:54:50.879089 1 iptables.go:539] dnat ports changed, [] I1011 23:55:50.860886 1 iptables.go:539] dnat ports changed, [] I1011 23:56:50.862495 1 iptables.go:539] dnat ports changed, [] I1011 23:57:50.860379 1 iptables.go:539] dnat ports changed, [] I1011 23:58:50.895503 1 iptables.go:539] dnat ports changed, [] I1011 23:59:50.860369 1 iptables.go:539] dnat ports changed, [] I1012 00:00:50.876299 1 iptables.go:539] dnat ports changed, [] I1012 00:01:50.886199 1 iptables.go:539] dnat ports changed, [] I1012 00:02:50.888942 1 iptables.go:539] dnat ports changed, [] I1012 00:03:50.890277 1 iptables.go:539] dnat ports changed, [] I1012 00:04:50.875401 1 iptables.go:539] dnat ports changed, [] I1012 00:05:50.901518 1 iptables.go:539] dnat ports changed, [] I1012 00:06:50.902022 1 iptables.go:539] dnat ports changed, [] I1012 00:07:50.868505 1 iptables.go:539] dnat ports changed, [] I1012 00:08:50.894081 1 iptables.go:539] dnat ports changed, [] I1012 00:09:50.891265 1 iptables.go:539] dnat ports changed, [] I1012 00:10:50.874595 1 iptables.go:539] dnat ports changed, [] I1012 00:11:50.904223 1 iptables.go:539] dnat ports changed, [] I1012 00:12:50.910932 1 iptables.go:539] dnat ports changed, [] I1012 00:13:50.881245 1 iptables.go:539] dnat ports changed, [] I1012 00:14:50.892050 1 iptables.go:539] dnat ports changed, [] I1012 00:15:50.892467 1 iptables.go:539] dnat ports changed, [] I1012 00:16:50.900959 1 iptables.go:539] dnat ports changed, [] I1012 00:17:50.904623 1 iptables.go:539] dnat ports changed, [] I1012 00:18:50.881801 1 iptables.go:539] dnat ports changed, [] I1012 00:19:50.880743 1 iptables.go:539] dnat ports changed, [] I1012 00:20:50.886667 1 iptables.go:539] dnat ports changed, [] I1012 00:21:50.888158 1 iptables.go:539] dnat ports changed, [] I1012 00:22:50.879559 1 iptables.go:539] dnat ports changed, [] I1012 00:22:51.707701 1 dns.go:301] sync tunnel server service as whole I1012 00:22:52.323222 1 dns.go:310] sync dns record as whole I1012 00:23:50.893108 1 iptables.go:539] dnat ports changed, [] I1012 00:24:50.889536 1 iptables.go:539] dnat ports changed, [] I1012 00:25:50.897899 1 iptables.go:539] dnat ports changed, [] I1012 00:26:50.881364 1 iptables.go:539] dnat ports changed, [] I1012 00:27:50.883610 1 iptables.go:539] dnat ports changed, [] I1012 00:28:50.885105 1 iptables.go:539] dnat ports changed, [] I1012 00:29:50.893123 1 iptables.go:539] dnat ports changed, [] I1012 00:30:50.877276 1 iptables.go:539] dnat ports changed, [] I1012 00:31:50.875348 1 iptables.go:539] dnat ports changed, [] I1012 00:32:50.884399 1 iptables.go:539] dnat ports changed, [] I1012 00:33:50.883357 1 iptables.go:539] dnat ports changed, [] I1012 00:34:50.878809 1 iptables.go:539] dnat ports changed, [] I1012 00:35:50.875026 1 iptables.go:539] dnat ports changed, [] I1012 00:36:50.880417 1 iptables.go:539] dnat ports changed, [] I1012 00:37:50.890315 1 iptables.go:539] dnat ports changed, [] I1012 00:38:50.885525 1 iptables.go:539] dnat ports changed, [] I1012 00:39:50.883124 1 iptables.go:539] dnat ports changed, [] I1012 00:40:50.874139 1 iptables.go:539] dnat ports changed, [] I1012 00:41:50.877528 1 iptables.go:539] dnat ports changed, [] I1012 00:42:50.899310 1 iptables.go:539] dnat ports changed, [] I1012 00:43:50.878627 1 iptables.go:539] dnat ports changed, [] I1012 00:44:50.886515 1 iptables.go:539] dnat ports changed, [] I1012 00:45:50.866231 1 iptables.go:539] dnat ports changed, [] I1012 00:46:50.880511 1 iptables.go:539] dnat ports changed, [] I1012 00:47:50.892186 1 iptables.go:539] dnat ports changed, [] I1012 00:48:50.911409 1 iptables.go:539] dnat ports changed, [] I1012 00:49:50.886608 1 iptables.go:539] dnat ports changed, [] I1012 00:50:50.888038 1 iptables.go:539] dnat ports changed, [] I1012 00:51:50.856846 1 iptables.go:539] dnat ports changed, [] I1012 00:52:50.878530 1 iptables.go:539] dnat ports changed, [] I1012 00:52:51.727913 1 dns.go:301] sync tunnel server service as whole I1012 00:52:52.357136 1 dns.go:310] sync dns record as whole I1012 00:53:50.888129 1 iptables.go:539] dnat ports changed, [] I1012 00:54:50.897082 1 iptables.go:539] dnat ports changed, [] I1012 00:55:50.890832 1 iptables.go:539] dnat ports changed, [] I1012 00:56:50.884254 1 iptables.go:539] dnat ports changed, [] I1012 00:57:50.887240 1 iptables.go:539] dnat ports changed, [] I1012 00:58:50.881351 1 iptables.go:539] dnat ports changed, [] I1012 00:59:50.877059 1 iptables.go:539] dnat ports changed, [] I1012 01:00:50.900163 1 iptables.go:539] dnat ports changed, [] I1012 01:01:50.885410 1 iptables.go:539] dnat ports changed, [] I1012 01:02:50.898438 1 iptables.go:539] dnat ports changed, [] I1012 01:03:50.882383 1 iptables.go:539] dnat ports changed, [] I1012 01:04:50.892045 1 iptables.go:539] dnat ports changed, [] I1012 01:05:50.882333 1 iptables.go:539] dnat ports changed, [] I1012 01:06:50.878323 1 iptables.go:539] dnat ports changed, [] I1012 01:07:50.884528 1 iptables.go:539] dnat ports changed, [] I1012 01:08:50.878916 1 iptables.go:539] dnat ports changed, [] I1012 01:09:50.881944 1 iptables.go:539] dnat ports changed, [] I1012 01:10:50.886233 1 iptables.go:539] dnat ports changed, [] I1012 01:11:50.896304 1 iptables.go:539] dnat ports changed, [] I1012 01:12:50.897740 1 iptables.go:539] dnat ports changed, [] I1012 01:13:50.895274 1 iptables.go:539] dnat ports changed, [] I1012 01:14:50.890653 1 iptables.go:539] dnat ports changed, [] I1012 01:15:50.888539 1 iptables.go:539] dnat ports changed, [] I1012 01:16:50.889816 1 iptables.go:539] dnat ports changed, [] I1012 01:17:50.890793 1 iptables.go:539] dnat ports changed, [] I1012 01:18:50.884815 1 iptables.go:539] dnat ports changed, [] I1012 01:19:50.875803 1 iptables.go:539] dnat ports changed, [] I1012 01:20:50.891827 1 iptables.go:539] dnat ports changed, [] I1012 01:21:50.886468 1 iptables.go:539] dnat ports changed, [] I1012 01:22:50.880123 1 iptables.go:539] dnat ports changed, [] I1012 01:22:51.755673 1 dns.go:301] sync tunnel server service as whole I1012 01:22:52.383149 1 dns.go:310] sync dns record as whole I1012 01:23:50.906330 1 iptables.go:539] dnat ports changed, [] I1012 01:24:50.911209 1 iptables.go:539] dnat ports changed, [] I1012 01:25:50.876496 1 iptables.go:539] dnat ports changed, [] I1012 01:26:50.955015 1 iptables.go:539] dnat ports changed, [] I1012 01:27:50.888904 1 iptables.go:539] dnat ports changed, [] I1012 01:28:50.875000 1 iptables.go:539] dnat ports changed, [] I1012 01:29:50.871138 1 iptables.go:539] dnat ports changed, [] I1012 01:30:50.879726 1 iptables.go:539] dnat ports changed, [] I1012 01:31:50.886473 1 iptables.go:539] dnat ports changed, [] I1012 01:32:50.882174 1 iptables.go:539] dnat ports changed, [] I1012 01:33:50.883642 1 iptables.go:539] dnat ports changed, [] I1012 01:34:50.883098 1 iptables.go:539] dnat ports changed, [] I1012 01:35:50.885552 1 iptables.go:539] dnat ports changed, [] I1012 01:36:50.883383 1 iptables.go:539] dnat ports changed, [] I1012 01:37:50.899823 1 iptables.go:539] dnat ports changed, [] I1012 01:38:50.908116 1 iptables.go:539] dnat ports changed, [] I1012 01:39:50.883195 1 iptables.go:539] dnat ports changed, [] I1012 01:40:50.882540 1 iptables.go:539] dnat ports changed, [] I1012 01:41:50.882545 1 iptables.go:539] dnat ports changed, [] I1012 01:42:50.895955 1 iptables.go:539] dnat ports changed, [] I1012 01:43:50.889633 1 iptables.go:539] dnat ports changed, [] I1012 01:44:50.888289 1 iptables.go:539] dnat ports changed, [] I1012 01:45:50.883420 1 iptables.go:539] dnat ports changed, [] I1012 01:46:50.888074 1 iptables.go:539] dnat ports changed, [] I1012 01:47:50.887832 1 iptables.go:539] dnat ports changed, [] I1012 01:48:50.882372 1 iptables.go:539] dnat ports changed, [] I1012 01:49:50.882489 1 iptables.go:539] dnat ports changed, [] I1012 01:50:50.902750 1 iptables.go:539] dnat ports changed, [] I1012 01:51:50.895715 1 iptables.go:539] dnat ports changed, [] I1012 01:52:50.892113 1 iptables.go:539] dnat ports changed, [] I1012 01:52:51.771628 1 dns.go:301] sync tunnel server service as whole I1012 01:52:52.406193 1 dns.go:310] sync dns record as whole I1012 01:53:50.885573 1 iptables.go:539] dnat ports changed, [] I1012 01:54:50.889141 1 iptables.go:539] dnat ports changed, [] I1012 01:55:50.892833 1 iptables.go:539] dnat ports changed, [] I1012 01:56:50.913835 1 iptables.go:539] dnat ports changed, [] I1012 01:57:50.887467 1 iptables.go:539] dnat ports changed, [] I1012 01:58:50.892850 1 iptables.go:539] dnat ports changed, [] I1012 01:59:50.919410 1 iptables.go:539] dnat ports changed, [] I1012 02:00:50.886809 1 iptables.go:539] dnat ports changed, [] I1012 02:01:50.881848 1 iptables.go:539] dnat ports changed, [] I1012 02:02:50.875461 1 iptables.go:539] dnat ports changed, [] I1012 02:03:50.888444 1 iptables.go:539] dnat ports changed, [] I1012 02:04:50.893052 1 iptables.go:539] dnat ports changed, [] I1012 02:05:50.875283 1 iptables.go:539] dnat ports changed, [] I1012 02:06:50.897222 1 iptables.go:539] dnat ports changed, [] I1012 02:07:50.878806 1 iptables.go:539] dnat ports changed, [] I1012 02:08:50.875321 1 iptables.go:539] dnat ports changed, [] I1012 02:09:50.881305 1 iptables.go:539] dnat ports changed, [] I1012 02:10:50.880012 1 iptables.go:539] dnat ports changed, [] I1012 02:11:50.879375 1 iptables.go:539] dnat ports changed, [] I1012 02:12:50.878680 1 iptables.go:539] dnat ports changed, [] I1012 02:13:50.884927 1 iptables.go:539] dnat ports changed, [] I1012 02:14:50.896877 1 iptables.go:539] dnat ports changed, [] I1012 02:15:50.889204 1 iptables.go:539] dnat ports changed, [] I1012 02:16:50.895005 1 iptables.go:539] dnat ports changed, [] I1012 02:17:50.884829 1 iptables.go:539] dnat ports changed, [] I1012 02:18:50.895271 1 iptables.go:539] dnat ports changed, [] I1012 02:19:50.892461 1 iptables.go:539] dnat ports changed, [] I1012 02:20:50.863600 1 iptables.go:539] dnat ports changed, [] I1012 02:21:50.908280 1 iptables.go:539] dnat ports changed, [] I1012 02:22:50.899377 1 iptables.go:539] dnat ports changed, [] I1012 02:22:51.796800 1 dns.go:301] sync tunnel server service as whole I1012 02:22:52.431441 1 dns.go:310] sync dns record as whole I1012 02:23:50.891044 1 iptables.go:539] dnat ports changed, [] I1012 02:24:50.882339 1 iptables.go:539] dnat ports changed, [] I1012 02:25:50.891400 1 iptables.go:539] dnat ports changed, [] I1012 02:26:50.905254 1 iptables.go:539] dnat ports changed, [] I1012 02:27:50.903198 1 iptables.go:539] dnat ports changed, [] I1012 02:28:50.885227 1 iptables.go:539] dnat ports changed, [] I1012 02:29:50.908008 1 iptables.go:539] dnat ports changed, [] I1012 02:30:50.890490 1 iptables.go:539] dnat ports changed, [] I1012 02:31:50.887926 1 iptables.go:539] dnat ports changed, [] I1012 02:32:50.890443 1 iptables.go:539] dnat ports changed, [] I1012 02:33:50.962521 1 iptables.go:539] dnat ports changed, [] I1012 02:34:50.894566 1 iptables.go:539] dnat ports changed, [] I1012 02:35:50.884867 1 iptables.go:539] dnat ports changed, [] I1012 02:36:50.858606 1 iptables.go:539] dnat ports changed, [] I1012 02:37:50.877044 1 iptables.go:539] dnat ports changed, [] I1012 02:38:50.903090 1 iptables.go:539] dnat ports changed, [] I1012 02:39:50.897804 1 iptables.go:539] dnat ports changed, [] I1012 02:40:50.910059 1 iptables.go:539] dnat ports changed, [] I1012 02:41:50.901360 1 iptables.go:539] dnat ports changed, [] I1012 02:42:50.881192 1 iptables.go:539] dnat ports changed, [] I1012 02:43:50.879951 1 iptables.go:539] dnat ports changed, [] I1012 02:44:50.900577 1 iptables.go:539] dnat ports changed, [] I1012 02:45:50.892508 1 iptables.go:539] dnat ports changed, [] I1012 02:46:50.888331 1 iptables.go:539] dnat ports changed, [] I1012 02:47:50.905915 1 iptables.go:539] dnat ports changed, [] I1012 02:48:50.891950 1 iptables.go:539] dnat ports changed, [] I1012 02:49:50.906675 1 iptables.go:539] dnat ports changed, [] I1012 02:50:50.893312 1 iptables.go:539] dnat ports changed, [] I1012 02:51:50.885523 1 iptables.go:539] dnat ports changed, [] I1012 02:52:50.885440 1 iptables.go:539] dnat ports changed, [] I1012 02:52:51.803169 1 dns.go:301] sync tunnel server service as whole I1012 02:52:52.457301 1 dns.go:310] sync dns record as whole I1012 02:53:50.887929 1 iptables.go:539] dnat ports changed, [] I1012 02:54:50.908825 1 iptables.go:539] dnat ports changed, [] I1012 02:55:50.872979 1 iptables.go:539] dnat ports changed, [] I1012 02:56:50.876766 1 iptables.go:539] dnat ports changed, [] I1012 02:57:50.881722 1 iptables.go:539] dnat ports changed, [] I1012 02:58:50.874552 1 iptables.go:539] dnat ports changed, [] I1012 02:59:50.886777 1 iptables.go:539] dnat ports changed, [] I1012 03:00:50.894977 1 iptables.go:539] dnat ports changed, [] I1012 03:01:50.880531 1 iptables.go:539] dnat ports changed, [] I1012 03:02:50.875596 1 iptables.go:539] dnat ports changed, [] I1012 03:03:50.891983 1 iptables.go:539] dnat ports changed, [] I1012 03:04:50.882357 1 iptables.go:539] dnat ports changed, [] I1012 03:05:50.895093 1 iptables.go:539] dnat ports changed, [] I1012 03:06:50.910263 1 iptables.go:539] dnat ports changed, [] I1012 03:07:50.888135 1 iptables.go:539] dnat ports changed, [] I1012 03:08:50.894820 1 iptables.go:539] dnat ports changed, [] I1012 03:09:50.886478 1 iptables.go:539] dnat ports changed, [] I1012 03:10:50.911418 1 iptables.go:539] dnat ports changed, [] I1012 03:11:50.887464 1 iptables.go:539] dnat ports changed, [] I1012 03:12:50.873897 1 iptables.go:539] dnat ports changed, [] I1012 03:13:50.882097 1 iptables.go:539] dnat ports changed, [] I1012 03:14:50.883353 1 iptables.go:539] dnat ports changed, [] I1012 03:15:50.884449 1 iptables.go:539] dnat ports changed, [] I1012 03:16:50.873691 1 iptables.go:539] dnat ports changed, [] I1012 03:17:50.886065 1 iptables.go:539] dnat ports changed, [] I1012 03:18:51.049188 1 iptables.go:539] dnat ports changed, [] I1012 03:19:50.893636 1 iptables.go:539] dnat ports changed, [] I1012 03:20:50.888209 1 iptables.go:539] dnat ports changed, [] I1012 03:21:50.885441 1 iptables.go:539] dnat ports changed, [] I1012 03:22:50.891358 1 iptables.go:539] dnat ports changed, [] I1012 03:22:51.819531 1 dns.go:301] sync tunnel server service as whole I1012 03:22:52.484744 1 dns.go:310] sync dns record as whole I1012 03:23:50.899690 1 iptables.go:539] dnat ports changed, [] I1012 03:24:50.887250 1 iptables.go:539] dnat ports changed, [] I1012 03:25:50.889444 1 iptables.go:539] dnat ports changed, [] I1012 03:26:50.879254 1 iptables.go:539] dnat ports changed, [] I1012 03:27:50.910318 1 iptables.go:539] dnat ports changed, [] I1012 03:28:50.890374 1 iptables.go:539] dnat ports changed, [] I1012 03:29:50.888149 1 iptables.go:539] dnat ports changed, [] I1012 03:30:50.880439 1 iptables.go:539] dnat ports changed, [] I1012 03:31:50.882843 1 iptables.go:539] dnat ports changed, [] I1012 03:32:50.881673 1 iptables.go:539] dnat ports changed, [] I1012 03:33:50.901961 1 iptables.go:539] dnat ports changed, [] I1012 03:34:50.914953 1 iptables.go:539] dnat ports changed, [] I1012 03:35:50.900894 1 iptables.go:539] dnat ports changed, [] I1012 03:36:50.891615 1 iptables.go:539] dnat ports changed, [] I1012 03:37:50.896377 1 iptables.go:539] dnat ports changed, [] I1012 03:38:50.868678 1 iptables.go:539] dnat ports changed, [] I1012 03:39:50.881059 1 iptables.go:539] dnat ports changed, [] I1012 03:40:50.888202 1 iptables.go:539] dnat ports changed, [] I1012 03:41:50.899432 1 iptables.go:539] dnat ports changed, [] I1012 03:42:50.964513 1 iptables.go:539] dnat ports changed, [] I1012 03:43:50.899919 1 iptables.go:539] dnat ports changed, [] I1012 03:44:50.876666 1 iptables.go:539] dnat ports changed, [] I1012 03:45:50.887063 1 iptables.go:539] dnat ports changed, [] I1012 03:46:50.888146 1 iptables.go:539] dnat ports changed, [] I1012 03:47:50.869578 1 iptables.go:539] dnat ports changed, [] I1012 03:48:50.879810 1 iptables.go:539] dnat ports changed, [] I1012 03:49:50.884300 1 iptables.go:539] dnat ports changed, [] I1012 03:50:50.898956 1 iptables.go:539] dnat ports changed, [] I1012 03:51:50.893869 1 iptables.go:539] dnat ports changed, [] I1012 03:52:50.886287 1 iptables.go:539] dnat ports changed, [] I1012 03:52:51.826522 1 dns.go:301] sync tunnel server service as whole I1012 03:52:52.507061 1 dns.go:310] sync dns record as whole I1012 03:53:50.967515 1 iptables.go:539] dnat ports changed, [] I1012 03:54:50.881087 1 iptables.go:539] dnat ports changed, [] I1012 03:55:50.887408 1 iptables.go:539] dnat ports changed, [] I1012 03:56:50.875625 1 iptables.go:539] dnat ports changed, [] I1012 03:57:50.893249 1 iptables.go:539] dnat ports changed, [] I1012 03:58:50.879069 1 iptables.go:539] dnat ports changed, [] I1012 03:59:50.889724 1 iptables.go:539] dnat ports changed, [] I1012 04:00:50.875362 1 iptables.go:539] dnat ports changed, [] I1012 04:01:50.908457 1 iptables.go:539] dnat ports changed, [] I1012 04:02:50.893962 1 iptables.go:539] dnat ports changed, [] I1012 04:03:50.890206 1 iptables.go:539] dnat ports changed, [] I1012 04:04:50.891900 1 iptables.go:539] dnat ports changed, [] I1012 04:05:50.881507 1 iptables.go:539] dnat ports changed, [] I1012 04:06:50.909338 1 iptables.go:539] dnat ports changed, [] I1012 04:07:50.884468 1 iptables.go:539] dnat ports changed, [] I1012 04:08:50.886725 1 iptables.go:539] dnat ports changed, [] I1012 04:09:50.891370 1 iptables.go:539] dnat ports changed, [] I1012 04:10:50.863731 1 iptables.go:539] dnat ports changed, [] I1012 04:11:50.891001 1 iptables.go:539] dnat ports changed, [] I1012 04:12:50.894819 1 iptables.go:539] dnat ports changed, [] I1012 04:13:50.900710 1 iptables.go:539] dnat ports changed, [] I1012 04:14:50.889719 1 iptables.go:539] dnat ports changed, [] I1012 04:15:50.889619 1 iptables.go:539] dnat ports changed, [] I1012 04:16:50.880878 1 iptables.go:539] dnat ports changed, [] I1012 04:17:50.905002 1 iptables.go:539] dnat ports changed, [] I1012 04:18:50.868840 1 iptables.go:539] dnat ports changed, [] I1012 04:19:50.890603 1 iptables.go:539] dnat ports changed, [] I1012 04:20:50.902442 1 iptables.go:539] dnat ports changed, [] I1012 04:21:50.881281 1 iptables.go:539] dnat ports changed, [] I1012 04:22:50.889786 1 iptables.go:539] dnat ports changed, [] I1012 04:22:51.855334 1 dns.go:301] sync tunnel server service as whole I1012 04:22:52.538466 1 dns.go:310] sync dns record as whole I1012 04:23:50.884944 1 iptables.go:539] dnat ports changed, [] I1012 04:24:50.868751 1 iptables.go:539] dnat ports changed, [] I1012 04:25:50.863670 1 iptables.go:539] dnat ports changed, [] I1012 04:26:50.888544 1 iptables.go:539] dnat ports changed, [] I1012 04:27:50.900671 1 iptables.go:539] dnat ports changed, [] I1012 04:28:50.895972 1 iptables.go:539] dnat ports changed, [] I1012 04:29:50.859840 1 iptables.go:539] dnat ports changed, [] I1012 04:30:50.881556 1 iptables.go:539] dnat ports changed, [] I1012 04:31:50.883992 1 iptables.go:539] dnat ports changed, [] I1012 04:32:50.893438 1 iptables.go:539] dnat ports changed, [] I1012 04:33:50.886181 1 iptables.go:539] dnat ports changed, [] I1012 04:34:50.887144 1 iptables.go:539] dnat ports changed, [] I1012 04:35:50.892046 1 iptables.go:539] dnat ports changed, [] I1012 04:36:50.898113 1 iptables.go:539] dnat ports changed, [] I1012 04:37:50.882414 1 iptables.go:539] dnat ports changed, [] I1012 04:38:50.901461 1 iptables.go:539] dnat ports changed, [] I1012 04:39:50.879401 1 iptables.go:539] dnat ports changed, [] I1012 04:40:50.881544 1 iptables.go:539] dnat ports changed, [] I1012 04:41:50.892653 1 iptables.go:539] dnat ports changed, [] I1012 04:42:50.886568 1 iptables.go:539] dnat ports changed, [] I1012 04:43:50.875186 1 iptables.go:539] dnat ports changed, [] I1012 04:44:50.878585 1 iptables.go:539] dnat ports changed, [] I1012 04:45:50.892947 1 iptables.go:539] dnat ports changed, [] I1012 04:46:50.890135 1 iptables.go:539] dnat ports changed, [] I1012 04:47:50.865309 1 iptables.go:539] dnat ports changed, [] I1012 04:48:50.877282 1 iptables.go:539] dnat ports changed, [] I1012 04:49:50.913508 1 iptables.go:539] dnat ports changed, [] I1012 04:50:50.874788 1 iptables.go:539] dnat ports changed, [] I1012 04:51:50.879715 1 iptables.go:539] dnat ports changed, [] I1012 04:52:50.889949 1 iptables.go:539] dnat ports changed, [] I1012 04:52:51.874106 1 dns.go:301] sync tunnel server service as whole I1012 04:52:52.566686 1 dns.go:310] sync dns record as whole I1012 04:53:50.901366 1 iptables.go:539] dnat ports changed, [] I1012 04:54:50.886659 1 iptables.go:539] dnat ports changed, [] I1012 04:55:50.888495 1 iptables.go:539] dnat ports changed, [] I1012 04:56:50.896743 1 iptables.go:539] dnat ports changed, [] I1012 04:57:50.889914 1 iptables.go:539] dnat ports changed, [] ```
rambohe-ch commented 2 years ago

could you provide how to debug this issue?

@fujitatomoya Thanks for your reply. i can give some short descriptions about kubectl exec troubleshooting.

  1. for pods on cloud nodes, kubectl exec command don't need to go through yurt-tunnel. only pods on edge nodes, yurt-tunnel will be involved.
  2. kube-apiserver will resolve hostname by yurt-tunnel-dns pod that dns records come from kube-system/yurt-tunnel-nodes configmap which managed by yurt-tunnel-server. if hostname resolution failed(for example: hostname for cloud nodes are resolved to ClusterIP of yurt-tunnel service), the reason maybe as following:
    • kube-apiserver have used yurt-tunnel-dns pod or not
    • dns records in kube-system/yurt-tunnel-nodes configmap is correct or not
  3. then if kubectl exec for edge nodes failed to go through yurt-tunnel, you can check the following items:
    • check the log of yurt-tunnel-server whether received the kubectl exec request or not
    • yurt-tunnel-agent connected with yurt-tunnel-server or not, check logs of yurt-tunnel-agent.
rambohe-ch commented 2 years ago

I think this could be related to the issue?

  • Requesting edge node (success)

    • kubectl exec -> kube-apiserver -> yurt-tunnel-server -> yurt-tunnel-agent -> kubelet

  • Requesting cloud node (this issue, the request is not via tunnel?)

    • kubectl exec -> kube-apiserver -> xxx broken pipe

@fujitatomoya yes, kubectl exec for cloud nodes, the request will forwarded to cloud nodes directly instead of going through yurt-tunnel. In OpenYurt cluster, cloud nodes should connect with K8s control-plane by intranet, so control-plane components of OpenYurt can work with K8s well.

fujitatomoya commented 2 years ago

@rambohe-ch thanks for the info, i will try to take a look.

this problem only happens if we do the operation to install openyurt with helm install openyurt -n kube-system ./charts/openyurt/.

So probably it would be helpful to how exactly we can debug this or where exactly to take a look? And it is really easy to reproduce this issue using virtualbox.

rambohe-ch commented 1 year ago

@rambohe-ch thanks for the info, i will try to take a look.

this problem only happens if we do the operation to install openyurt with helm install openyurt -n kube-system ./charts/openyurt/.

So probably it would be helpful to how exactly we can debug this or where exactly to take a look? And it is really easy to reproduce this issue using virtualbox.

@fujitatomoya I have updated FAQ tutorial about how to troubleshoot yurt-tunnel problems. the detail link is here: https://openyurt.io/docs/faq#yurt-tunnel

fujitatomoya commented 1 year ago

@rambohe-ch thanks for the information, we will definitely look into that.

FengGaoCSC commented 1 year ago

@rambohe-ch thanks for the info, i will try to take a look. this problem only happens if we do the operation to install openyurt with helm install openyurt -n kube-system ./charts/openyurt/. So probably it would be helpful to how exactly we can debug this or where exactly to take a look? And it is really easy to reproduce this issue using virtualbox.

@fujitatomoya I have updated FAQ tutorial about how to troubleshoot yurt-tunnel problems. the detail link is here: https://openyurt.io/docs/faq#yurt-tunnel

@rambohe-ch @fujitatomoya

I could reproduce this issue and remove the pki and seems it work for a while and then failed again, please look at the following logs

then will check https://openyurt.io/docs/faq#yurt-tunnel for debuging 

root@ceci-control-plane:/vagrant# kubectl get pod -A
NAMESPACE      NAME                                             READY   STATUS    RESTARTS       AGE
default        container-registry-deployment-6c64f9b5d9-w6pcw   2/2     Running   0              14h
default        ubuntu22-deamonset-7mrsl                         2/2     Running   14 (30m ago)   14h
istio-system   istio-egressgateway-6854f6dc6f-csbdf             1/1     Running   0              14h
istio-system   istio-ingressgateway-7c7c7b5bf9-8gmpj            1/1     Running   0              14h
istio-system   istiod-857cb8c78d-vpdcf                          1/1     Running   0              14h
kube-flannel   kube-flannel-ds-gbvts                            1/1     Running   0              14h
kube-system    coredns-gbxhj                                    1/1     Running   0              14h
kube-system    etcd-ceci-control-plane                          1/1     Running   2              14h
kube-system    kube-apiserver-ceci-control-plane                1/1     Running   0              14h
kube-system    kube-controller-manager-ceci-control-plane       1/1     Running   1              14h
kube-system    kube-proxy-nw8fk                                 1/1     Running   0              14h
kube-system    kube-scheduler-ceci-control-plane                1/1     Running   4 (14h ago)    14h
kube-system    yurt-app-manager-6fd8dcd6b4-9cb68                1/1     Running   0              14h
kube-system    yurt-controller-manager-555c46c7f-z6hbr          1/1     Running   0              14h
kube-system    yurt-tunnel-dns-9cbd69765-zz4jg                  1/1     Running   0              14h
kube-system    yurt-tunnel-server-6bffb656d4-bqs7q              1/1     Running   0              14h 

root@ceci-control-plane:/vagrant# kubectl exec --stdin --tty ubuntu22-deamonset-7mrsl -- date
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

root@ceci-control-plane:/vagrant# rm -rf  /var/lib/yurttunnel-server/
root@ceci-control-plane:/vagrant# kubectl delete pod -n kube-system yurt-tunnel-server-6bffb656d4-bqs7q
pod "yurt-tunnel-server-6bffb656d4-bqs7q" deleted
root@ceci-control-plane:/vagrant# while true; do kubectl exec --stdin --tty ubuntu22-deamonset-7mrsl -- date; done
...
Tue Oct 18 01:11:16 UTC 2022
Tue Oct 18 01:11:16 UTC 2022
Tue Oct 18 01:11:16 UTC 2022
Tue Oct 18 01:11:16 UTC 2022
Tue Oct 18 01:11:16 UTC 2022
Tue Oct 18 01:11:17 UTC 2022
Tue Oct 18 01:11:17 UTC 2022
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
error: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

[root@ceci-control-plane:/vagrant/ceci-work/istio-1.15.0#](mailto:root@ceci-control-plane:/vagrant/ceci-work/istio-1.15.0#) istioctl ps

Error: failure running port forward process: failure running port forward process: error upgrading connection: unable to upgrade connection: fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe

the following is the yurt-tunnel-server's log 

root@ceci-control-plane:/home/vagrant# docker logs 3d538ab2c69e
I1018 02:16:20.669627       1 start.go:53] yurttunnel-server version: projectinfo.Info{GitVersion:"v0.7.0", GitCommit:"68a18ee", BuildDate:"2022-05-30T06:59:22Z", GoVersion:"go1.17.1", Compiler:"gc", Platform:"linux/amd64"}
W1018 02:16:20.671166       1 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
I1018 02:16:20.681717       1 options.go:168] yurttunnel server config: &config.Config{EgressSelectorEnabled:false, EnableIptables:true, EnableDNSController:true, IptablesSyncPeriod:60, IPFamily:0x1, DNSSyncPeriod:1800, CertDNSNames:[]string{}, CertIPs:[]net.IP{}, CertDir:"", ListenAddrForAgent:"192.168.56.20:10262", ListenAddrForMaster:"192.168.56.20:10263", ListenInsecureAddrForMaster:"192.168.56.20:10264", ListenMetaAddr:"192.168.56.20:10265", RootCert:(*x509.CertPool)(0xc0000b64b0), Client:(*kubernetes.Clientset)(0xc00058e160), SharedInformerFactory:(*informers.sharedInformerFactory)(0xc00009cf50), ServerCount:1, ProxyStrategy:"destHost", InterceptorServerUDSFile:""}
I1018 02:16:20.682256       1 leaderelection.go:248] attempting to acquire leader lease kube-system/tunnel-dns-controller...
E1018 02:16:20.695820       1 iptables.go:216] failed to delete rule that nat chain OUTPUT jumps to TUNNEL-PORT: error checking rule: exit status 2: iptables v1.8.7 (legacy): Couldn't load target `TUNNEL-PORT':No such file or directory

Try `iptables -h' or 'iptables --help' for more information.
I1018 02:16:25.737013       1 certmanager.go:105] subject of tunnel server certificate, ips=192.168.56.20,10.111.1.98,127.0.0.1,::1,192.168.56.20,10.108.221.173, dnsNames=[]string{"ceci-control-plane", "x-tunnel-server-svc", "x-tunnel-server-svc.kube-system", "x-tunnel-server-svc.kube-system.svc", "x-tunnel-server-svc.kube-system.svc.cluster.local", "x-tunnel-server-internal-svc", "x-tunnel-server-internal-svc.kube-system", "x-tunnel-server-internal-svc.kube-system.svc", "x-tunnel-server-internal-svc.kube-system.svc.cluster.local"}
W1018 02:16:25.737089       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1018 02:16:25.737104       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate rotation is enabled
W1018 02:16:25.737127       1 filestore_wrapper.go:49] unexpected error occurred when loading the certificate: no cert/key files read at "/var/lib/yurttunnel-server/pki/yurttunnel-server-proxy-client-current.pem", ("", "") or ("/var/lib/yurttunnel-server/pki", "/var/lib/yurttunnel-server/pki"), will regenerate it
I1018 02:16:25.737138       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate rotation is enabled
I1018 02:16:25.737656       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Rotating certificates
I1018 02:16:25.738445       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Rotating certificates
I1018 02:16:25.749905       1 handler.go:43] enqueue node add event for ceci-control-plane
I1018 02:16:25.749983       1 handler.go:43] enqueue node add event for ceci-worker1
I1018 02:16:25.761736       1 handler.go:175] handle configmap add event for kube-system/yurt-tunnel-server-cfg to update localhost ports
I1018 02:16:25.761801       1 handler.go:141] enqueue service add event for kube-system/x-tunnel-server-internal-svc
I1018 02:16:25.762638       1 handler.go:93] enqueue configmap add event for kube-system/yurt-tunnel-server-cfg
I1018 02:16:25.765539       1 csr.go:258] certificate signing request csr-5r56f is issued
I1018 02:16:25.802597       1 csr.go:258] certificate signing request csr-cg4s6 is issued
I1018 02:16:25.851417       1 iptables.go:539] dnat ports changed, []
I1018 02:16:26.767055       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-18 02:11:25 +0000 UTC, rotation deadline is 2023-08-28 23:41:14.961956739 +0000 UTC
I1018 02:16:26.767193       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 7557h24m48.194773142s for next certificate rotation
I1018 02:16:26.815035       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-18 02:11:25 +0000 UTC, rotation deadline is 2023-07-16 05:34:50.097151555 +0000 UTC
I1018 02:16:26.815098       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6507h18m23.282062159s for next certificate rotation
I1018 02:16:27.767939       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Certificate expiration is 2023-10-18 02:11:25 +0000 UTC, rotation deadline is 2023-07-28 09:06:06.024350979 +0000 UTC
I1018 02:16:27.767974       1 certificate_manager.go:270] kubernetes.io/kubelet-serving: Waiting 6798h49m38.256380505s for next certificate rotation
I1018 02:16:27.816734       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Certificate expiration is 2023-10-18 02:11:25 +0000 UTC, rotation deadline is 2023-07-23 19:25:41.517136256 +0000 UTC
I1018 02:16:27.816763       1 certificate_manager.go:270] kubernetes.io/kube-apiserver-client: Waiting 6689h9m13.700375899s for next certificate rotation
I1018 02:16:30.742028       1 anpserver.go:107] start handling request from interceptor
I1018 02:16:30.742102       1 wraphandler.go:67] add localHostProxyMiddleware into wrap handler
I1018 02:16:30.742152       1 tracereq.go:80] 2 informer synced in traceReqMiddleware
I1018 02:16:30.742165       1 wraphandler.go:67] add TraceReqMiddleware into wrap handler
I1018 02:16:30.742530       1 anpserver.go:143] start handling https request from master at 192.168.56.20:10263
I1018 02:16:30.742648       1 anpserver.go:157] start handling http request from master at 192.168.56.20:10264
I1018 02:16:30.742710       1 anpserver.go:195] start handling connection from agents
I1018 02:16:30.743477       1 util.go:75] "start handling meta requests(metrics/pprof)" server endpoint="192.168.56.20:10265"
I1018 02:16:33.801248       1 server.go:616] "Connect request from agent" agentID="ceci-worker1"
I1018 02:16:33.801439       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc0004fa9c0} agentID="192.168.56.21"
I1018 02:16:33.801488       1 backend_manager.go:184] "Register backend for agent" connection=&{ServerStream:0xc0004fa9c0} agentID="ceci-worker1"
I1018 02:16:37.036090       1 leaderelection.go:258] successfully acquired lease kube-system/tunnel-dns-controller
I1018 02:16:37.036584       1 dns.go:177] starting tunnel dns controller
I1018 02:16:37.037309       1 shared_informer.go:240] Waiting for caches to sync for tunnel-dns-controller
I1018 02:16:37.037425       1 shared_informer.go:247] Caches are synced for tunnel-dns-controller 
I1018 02:16:37.043398       1 dns.go:301] sync tunnel server service as whole
I1018 02:16:37.044085       1 handler.go:166] adding node dns record for ceci-control-plane
I1018 02:16:37.045738       1 dns.go:310] sync dns record as whole
I1018 02:16:37.049394       1 handler.go:166] adding node dns record for ceci-worker1
I1018 02:16:37.066579       1 dns.go:310] sync dns record as whole
I1018 02:16:37.480458       1 dns.go:301] sync tunnel server service as whole
I1018 02:16:42.451452       1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250
E1018 02:16:42.451807       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1018 02:16:42.451943       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1018 02:16:42.451963       1 tracereq.go:138] stop handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 495.59µs
I1018 02:16:42.526629       1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46072 to 192.168.56.20:10250
........
rambohe-ch commented 1 year ago

E1018 02:16:42.451807 1 tunnel.go:74] "currently no tunnels available" err="No backend available"

@FengGaoCSC It seems that yurt-tunnel-agent on edge node can not connect with yurt-tunnel-server, how about remove certificates in /var/lib/yurt-tunnel-agent folder and recreate yurt-tunnel-agent? and then check yurt-tunnel-agent can work correctly or not.

FengGaoCSC commented 1 year ago

I1018 02:16:42.451452 1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250 E1018 02:16:42.451807 1 tunnel.go:74] "currently no tunnels available" err="No backend available"

@rambohe-ch

and another question, I check the log of yurt-tunel-server according the FAQ of https://openyurt.io/docs/faq#yurt-tunnel.

I1018 02:16:42.451452       1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250
E1018 02:16:42.451807       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1018 02:16:42.451943       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1018 02:16:42.451963       1 tracereq.go:138] stop handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 495.59µs

root@ceci-control-plane:/home/vagrant# kubectl get pod -A -o wide
NAMESPACE      NAME                                             READY   STATUS    RESTARTS      AGE     IP              NODE                 NOMINATED NODE   READINESS GATES
default        ubuntu22-deamonset-9rm4d                         1/2     Running   4 (35m ago)   4h37m   10.244.1.3      ceci-worker1         <none>           <none>
default        ubuntu22-deamonset-vkksr                         2/2     Running   4 (37m ago)   4h37m   10.244.0.14     ceci-control-plane   <none>           <none>

root@ceci-control-plane:/home/vagrant# kubectl get node -o wide
NAME                 STATUS   ROLES                  AGE     VERSION    INTERNAL-IP     EXTERNAL-IP   OS-IMAGE             KERNEL-VERSION      CONTAINER-RUNTIME
ceci-control-plane   Ready    control-plane,master   20h     v1.22.13   192.168.56.20   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11
ceci-worker1         Ready    <none>                 5h14m   v1.22.13   192.168.56.21   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11

We can see that pod ubuntu22-deamonset-vkksr on the cloud side, but exec command forward to yurt-tunnel-server with 127.0.0.1:46062 to 192.168.56.20:10250 (API server), according FAQ of https://openyurt.io/docs/faq#yurt-tunnel, it was not correct , is it?

rambohe-ch commented 1 year ago

I1018 02:16:42.451452 1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250 E1018 02:16:42.451807 1 tunnel.go:74] "currently no tunnels available" err="No backend available"

@rambohe-ch

and another question, I check the log of yurt-tunel-server according the FAQ of https://openyurt.io/docs/faq#yurt-tunnel.

I1018 02:16:42.451452       1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250
E1018 02:16:42.451807       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1018 02:16:42.451943       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1018 02:16:42.451963       1 tracereq.go:138] stop handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 495.59µs

root@ceci-control-plane:/home/vagrant# kubectl get pod -A -o wide
NAMESPACE      NAME                                             READY   STATUS    RESTARTS      AGE     IP              NODE                 NOMINATED NODE   READINESS GATES
default        ubuntu22-deamonset-9rm4d                         1/2     Running   4 (35m ago)   4h37m   10.244.1.3      ceci-worker1         <none>           <none>
default        ubuntu22-deamonset-vkksr                         2/2     Running   4 (37m ago)   4h37m   10.244.0.14     ceci-control-plane   <none>           <none>

root@ceci-control-plane:/home/vagrant# kubectl get node -o wide
NAME                 STATUS   ROLES                  AGE     VERSION    INTERNAL-IP     EXTERNAL-IP   OS-IMAGE             KERNEL-VERSION      CONTAINER-RUNTIME
ceci-control-plane   Ready    control-plane,master   20h     v1.22.13   192.168.56.20   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11
ceci-worker1         Ready    <none>                 5h14m   v1.22.13   192.168.56.21   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11

We can see that pod ubuntu22-deamonset-vkksr on the cloud side, but exec command forward to yurt-tunnel-server with 127.0.0.1:46062 to 192.168.56.20:10250 (API server), according FAQ of https://openyurt.io/docs/faq#yurt-tunnel, it was not correct , is it?

@FengGaoCSC yes, as the design of yurt-tunnel, yurt-tunnel-agent don't run on cloud nodes, so traffic from kube-apiserver will be forwarded to kubelet on cloud node directly.

FengGaoCSC commented 1 year ago

I1018 02:16:42.451452 1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250 E1018 02:16:42.451807 1 tunnel.go:74] "currently no tunnels available" err="No backend available"

@rambohe-ch and another question, I check the log of yurt-tunel-server according the FAQ of https://openyurt.io/docs/faq#yurt-tunnel.

I1018 02:16:42.451452       1 tracereq.go:134] start handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, from 127.0.0.1:46062 to 192.168.56.20:10250
E1018 02:16:42.451807       1 tunnel.go:74] "currently no tunnels available" err="No backend available"
E1018 02:16:42.451943       1 interceptor.go:136] fail to setup the tunnel: fail to setup TLS handshake through the Tunnel: write unix @->/tmp/interceptor-proxier.sock: write: broken pipe
I1018 02:16:42.451963       1 tracereq.go:138] stop handling request POST https://192.168.56.20:10250/exec/default/ubuntu22-deamonset-vkksr/ubuntu22?command=date&input=1&output=1&tty=1, request handling lasts 495.59µs

root@ceci-control-plane:/home/vagrant# kubectl get pod -A -o wide
NAMESPACE      NAME                                             READY   STATUS    RESTARTS      AGE     IP              NODE                 NOMINATED NODE   READINESS GATES
default        ubuntu22-deamonset-9rm4d                         1/2     Running   4 (35m ago)   4h37m   10.244.1.3      ceci-worker1         <none>           <none>
default        ubuntu22-deamonset-vkksr                         2/2     Running   4 (37m ago)   4h37m   10.244.0.14     ceci-control-plane   <none>           <none>

root@ceci-control-plane:/home/vagrant# kubectl get node -o wide
NAME                 STATUS   ROLES                  AGE     VERSION    INTERNAL-IP     EXTERNAL-IP   OS-IMAGE             KERNEL-VERSION      CONTAINER-RUNTIME
ceci-control-plane   Ready    control-plane,master   20h     v1.22.13   192.168.56.20   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11
ceci-worker1         Ready    <none>                 5h14m   v1.22.13   192.168.56.21   <none>        Ubuntu 20.04.5 LTS   5.4.0-128-generic   docker://19.3.11

We can see that pod ubuntu22-deamonset-vkksr on the cloud side, but exec command forward to yurt-tunnel-server with 127.0.0.1:46062 to 192.168.56.20:10250 (API server), according FAQ of https://openyurt.io/docs/faq#yurt-tunnel, it was not correct , is it?

@FengGaoCSC yes, as the design of yurt-tunnel, yurt-tunnel-agent don't run on cloud nodes, so traffic from kube-apiserver will be forwarded to kubelet on cloud node directly.

@rambohe-ch then can you estimate what condition will cause this issue? very appreciate. regards

rambohe-ch commented 1 year ago

then can you estimate what condition will cause this issue? very appreciate. regards

@FengGaoCSC It seems that configuration of kube-apiserver is not correct. you can check the points as the following red arrow. image

FengGaoCSC commented 1 year ago

then can you estimate what condition will cause this issue? very appreciate. regards

@FengGaoCSC It seems that configuration of kube-apiserver is not correct. you can check the points as the following red arrow. !

thanks, will check it

fujitatomoya commented 1 year ago

We can see that pod ubuntu22-deamonset-vkksr on the cloud side, but exec command forward to yurt-tunnel-server with 127.0.0.1:46062 to 192.168.56.20:10250 (API server), according FAQ of https://openyurt.io/docs/faq#yurt-tunnel, it was not correct , is it?

https://github.com/openyurtio/openyurt/issues/1024#issuecomment-1281924238

i believe this is exactly the problem here. Under some circumstances, even on pods running on cloud side will request the tunneling like this. And that leads to the failure and this problem. This seems to be bug for user perspective since we just do the installation procedure.

as the design of yurt-tunnel, yurt-tunnel-agent don't run on cloud nodes, so traffic from kube-apiserver will be forwarded to kubelet on cloud node directly.

the question is why this is happening?

rambohe-ch commented 1 year ago

We can see that pod ubuntu22-deamonset-vkksr on the cloud side, but exec command forward to yurt-tunnel-server with 127.0.0.1:46062 to 192.168.56.20:10250 (API server), according FAQ of https://openyurt.io/docs/faq#yurt-tunnel, it was not correct , is it?

#1024 (comment)

i believe this is exactly the problem here. Under some circumstances, even on pods running on cloud side will request the tunneling like this. And that leads to the failure and this problem. This seems to be bug for user perspective since we just do the installation procedure.

as the design of yurt-tunnel, yurt-tunnel-agent don't run on cloud nodes, so traffic from kube-apiserver will be forwarded to kubelet on cloud node directly.

the question is why this is happening?

@fujitatomoya The original definition for Cloud Node that nodes can connect K8s control-plane components through intranet network(for example: in the same VPC), and Cloud Node is used for running OpenYurt control-plane components(like yurt-controller-manager, yurt-tunnel-server). so traffic for kubectl logs/exec from kube-apiserver to Cloud Node doesn't need to go through yurt-tunnel.

If you want to use tunnel for Cloud Node, you can join the the node as Edge Node, then yurt-tunnel-agent and yurthub with Edge working mode will be configured automatically.

fujitatomoya commented 1 year ago

@rambohe-ch yeah, thanks for the comments.

as far as i can see, there are some cases that that goes through tunnel or not unexpectedly. i believe that those unexpected problems are related to host system configuration especially networks. we are now trying to get to the root cause.

rambohe-ch commented 1 year ago

@rambohe-ch yeah, thanks for the comments.

as far as i can see, there are some cases that that goes through tunnel or not unexpectedly. i believe that those unexpected problems are related to host system configuration especially networks. we are not trying to get to the root case.

@fujitatomoya ok, i can give some hints how to debug why traffic does not go through cloud node directly from kube-apiserver.

  1. nsenter into network and mount namespace of kube-apiserver pod
  2. check the contents of /etc/resolv.conf file for kube-apiserver, make sure the name server is the ClusterIP of yurt-tunnel-dns service
  3. ping {yurt-tunne-dns podIP}, make sure kube-apiserver can access dns pod.
  4. dig {hostname} to check dns resolution can work or not
fujitatomoya commented 1 year ago

@rambohe-ch

i found that there is configuration in /etc/hosts on cloud master node InternalIP is 192.168.56.20.

root@ceci-control-plane:~# cat /etc/hosts
127.0.0.1   localhost

# The following lines are desirable for IPv6 capable hosts
::1 ip6-localhost   ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts

127.0.1.1   ceci-control-plane  ceci-control-plane   ### This is the problem
192.168.56.20 ceci-control-plane

with above configuration, openyurt sees that hostname ceci-control-plane is 127.0.1.1, and there is no such IP information in the cluster system. So it expects that is edge node via open-yurt-tunneling, and there will be no response since there is no openyurt-tunnel-agent on this cloud master. eventually pipeline cannot work.

if we comment out 127.0.1.1 ceci-control-plane ceci-control-plane it works.

rambohe-ch commented 1 year ago

@rambohe-ch

i found that there is configuration in /etc/hosts on cloud master node InternalIP is 192.168.56.20.

root@ceci-control-plane:~# cat /etc/hosts
127.0.0.1 localhost

# The following lines are desirable for IPv6 capable hosts
::1   ip6-localhost   ip6-loopback
fe00::0   ip6-localnet
ff00::0   ip6-mcastprefix
ff02::1   ip6-allnodes
ff02::2   ip6-allrouters
ff02::3   ip6-allhosts

127.0.1.1 ceci-control-plane  ceci-control-plane   ### This is the problem
192.168.56.20 ceci-control-plane

with above configuration, openyurt sees that hostname ceci-control-plane is 127.0.1.1, and there is no such IP information in the cluster system. So it expects that is edge node via open-yurt-tunneling, and there will be no response since there is no openyurt-tunnel-agent on this cloud master. eventually pipeline cannot work.

if we comment out 127.0.1.1 ceci-control-plane ceci-control-plane it works.

@fujitatomoya Thanks for your feedback. I am glad that you have solved the problem of dns, and yurt-tunnel worked now.

btw: it looks like there are some unexpected configurations in kube-apiserver.yaml that lead to 127.0.0.1 ceci-control-plane ceci-control-plane setting in /etc/hosts file.

you can dive into the code for creating /etc/hosts file in here: https://github.com/kubernetes/kubernetes/blob/master/pkg/kubelet/kubelet_pods.go#L330-L348 and find the root reason.

fujitatomoya commented 1 year ago

btw: it looks like there are some unexpected configurations in kube-apiserver.yaml that lead to 127.0.0.1 ceci-control-plane ceci-control-plane setting in /etc/hosts file.

yeah, right.

according to https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=719621 and https://askubuntu.com/questions/754213/what-is-difference-between-localhost-address-127-0-0-1-and-127-0-1-1,

this 127.0.1.1 IP address is assigned by Ubuntu Desktop, and if it does not have permanent IP, it will be assigned. Debian, then Ubuntu, choose to define 127.0.1.1 for mapping the IP address of hostname in case that you have no network for GNOME.

eventually, request to kubelet will try to use tunneling since OpenYurt does not have this IP information, so it just expects this as edge environment via tunneling. and then there will be no tunneling agent deployed because this is actually on cloud, so pipeline cannot work.

btw, this could be one of the case study or faq for openyurt setting manual. i am willing to make contribution on this, do you guys have FAQ section for the install manual doc?

fujitatomoya commented 1 year ago

@rambohe-ch you can remove kind/bug from this one, instead, add kind/document?

rambohe-ch commented 1 year ago

btw, this could be one of the case study or faq for openyurt setting manual. i am willing to make contribution on this, do you guys have FAQ section for the install manual doc?

@fujitatomoya yes, it's a good idea to add this case in the OpenYurt tutorial. Maybe this case can be added in the https://openyurt.io/docs/faq tutorial, and the reference link can be added in the https://openyurt.io/docs/installation/manually-setup tutorial.

fujitatomoya commented 1 year ago

@rambohe-ch got it, will do accordingly.

fujitatomoya commented 1 year ago

@rambohe-ch can you take a look at https://github.com/openyurtio/openyurt.io/pull/238?

rambohe-ch commented 1 year ago

@rambohe-ch can you take a look at openyurtio/openyurt.io#238?

@fujitatomoya Thank you for updating faq tutorial, and i have merged this pull request. by the way, i will update the chinese faq tutorial soon.

fujitatomoya commented 1 year ago

Yeah, that is something i cannot help, maybe i should start studying ... 😅

fujitatomoya commented 1 year ago

@rambohe-ch i will close this one in favor of https://github.com/openyurtio/openyurt.io/pull/238