search

tailscale / tailscale

The easiest, most secure way to use WireGuard and 2FA.
https://tailscale.com
BSD 3-Clause "New" or "Revised" License
18.77k stars 1.46k forks source link

TLS handshake timeout for Kubernetes connection via k8s operator using as API server proxy #9976

Open thoongnv opened 11 months ago

thoongnv commented 11 months ago

What is the issue?

I usually got this error when running: kubectl get pods -A

Unable to connect to the server: net/http: TLS handshake timeout

Some of the operator logs

2023/10/26 03:14:25 http: TLS handshake error from IP:55290: Get "http://local-tailscaled.sock/localapi/v0/cert/tailscale-operator.tail***.ts.net?type=pair": context deadline exceeded
2023/10/26 03:14:25 http: TLS handshake error from IP:55366: Get "http://local-tailscaled.sock/localapi/v0/cert/tailscale-operator.tail***.ts.net?type=pair": context deadline exceeded
2023/10/26 03:17:12 http: TLS handshake error from IP:56556: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
2023/10/26 03:17:17 http: TLS handshake error from IP:39810: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded

Well, the above command sometimes worked to list all pods, but I saw the error very often.

Steps to reproduce

I followed this doc to set up the API server proxy to my managed Kubernetes on Digital Ocean.

I also tried to change the images tag in operator.yaml to :latest, remove the device with tag k8s:operator/ delete -f operator.yaml then re-deployed but it didn't work.

Are there any recent changes that introduced the issue?

No response

OS

macOS

OS version

Sonoma 14.0

Tailscale version

1.50.1

Other software

tailscale operator on k8s using:

tailscale on Macbook using: brew install tailscale (I also tried Tailscale app on Apple Store)

~./kube/config file

apiVersion: v1
clusters:
- cluster:
    server: https://tailscale-operator.tail***.ts.net
  name: tailscale-operator.tail***.ts.net
contexts:
- context:
    cluster: tailscale-operator.tail***.ts.net
    user: tailscale-auth
  name: tailscale-operator.tail***.ts.net
current-context: tailscale-operator.tail***.ts.net
kind: Config
users:
- name: tailscale-auth
  user:
    token: unused

Bug report

BUG-19512032024612d062e77c962b028843905af21fc0cb6ee45d1ebefc61baa9eb-20231026034042Z-a65cdadf38d3178b

irbekrm commented 10 months ago

Hi, thank you for opening the issue. It would be good to see the full operator logs from when it started up to when you attempted to access kube apiserver resources using the proxy (you can increase the log level by setting OPPERATOR_LOGGING env var on the operator Deployment to debug). Also:

Any other information that could help to reproduce the issue would be helpful too. We do test it on DO and haven't seen this problem.

thoongnv commented 10 months ago

Hi @irbekrm

Thank you for the reply, here is my Deployment config with allocated resources and use as apiserver proxy:

apiVersion: apps/v1
kind: Deployment
metadata:
  name: operator
  namespace: tailscale
spec:
  replicas: 1
  strategy:
    type: Recreate
  selector:
    matchLabels:
      app: operator
  template:
    metadata:
      labels:
        app: operator
    spec:
      serviceAccountName: operator
      volumes:
      - name: oauth
        secret:
          secretName: operator-oauth
      containers:
        - name: operator
          image: tailscale/k8s-operator:unstable-v1.53
          resources:
            requests:
              cpu: 500m
              memory: 100Mi
          env:
            - name: OPERATOR_HOSTNAME
              value: my-k8s-operator
            - name: OPERATOR_SECRET
              value: operator
            - name: OPERATOR_LOGGING
              value: debug
            - name: OPERATOR_NAMESPACE
              valueFrom:
                fieldRef:
                  fieldPath: metadata.namespace
            - name: CLIENT_ID_FILE
              value: /oauth/client_id
            - name: CLIENT_SECRET_FILE
              value: /oauth/client_secret
            - name: PROXY_IMAGE
              value: tailscale/tailscale:unstable
            - name: PROXY_TAGS
              value: tag:my-k8s
            - name: APISERVER_PROXY
              value: "true"
            - name: PROXY_FIREWALL_MODE
              value: auto
          volumeMounts:
          - name: oauth
            mountPath: /oauth
            readOnly: true

and some of the kubectl logs -n tailscale -l app=operator -f:

{"level":"debug","ts":"2023-11-13T09:16:52Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/13 09:16:52 http: TLS handshake error from 100.x.x.x:59644: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-13T09:16:52Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59644 > 100.y.y.y:443} 52 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-13T09:17:01Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.x.x.x:59510 derp=2 derpdist=2v4:3ms,9v4:47ms,17v4:9ms"}
{"level":"debug","ts":"2023-11-13T09:17:02Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending keepalive packet"}
{"level":"debug","ts":"2023-11-13T09:17:27Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.x.x.x:59510 derp=2 derpdist=1v4:71ms,2v4:5ms,3v4:211ms,4v4:148ms,5v4:183ms,6v4:218ms,7v4:115ms,8v4:137ms,9v4:47ms,10v4:24ms,11v4:198ms,12v4:51ms,13v4:28ms,14v4:156ms,16v4:106ms,17v4:11ms,18v4:136ms,19v4:179ms,20v4:164ms,21v4:65ms,22v4:163ms,24v4:57ms"}
{"level":"debug","ts":"2023-11-13T09:17:51Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.x.x.x:59510 derp=2 derpdist=2v4:3ms,10v4:22ms,17v4:9ms"}
^L{"level":"debug","ts":"2023-11-13T09:18:42Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Received handshake initiation"}
{"level":"debug","ts":"2023-11-13T09:18:42Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending handshake response"}
{"level":"debug","ts":"2023-11-13T09:18:42Z","logger":"tailscaled","msg":"[v1] peer keys: [tDd7B]"}
{"level":"debug","ts":"2023-11-13T09:18:42Z","logger":"tailscaled","msg":"[v1] v1.53.100-tfdbe511c4 peers: 25432/265176"}
{"level":"debug","ts":"2023-11-13T09:18:42Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59676 > 100.y.y.y:443} 64 tcp ok\n"}
{"level":"debug","ts":"2023-11-13T09:18:43Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59676 > 100.y.y.y:443} 52 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-13T09:18:43Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59676 > 100.y.y.y:443} 352 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-13T09:18:50Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.x.x.x:59510 derp=2 derpdist=2v4:4ms,17v4:10ms"}
{"level":"debug","ts":"2023-11-13T09:18:53Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/13 09:18:53 http: TLS handshake error from 100.x.x.x:59676: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-13T09:18:53Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59676 > 100.y.y.y:443} 52 tcp non-syn\n"}

the operator pod got restarted a few times (on yaml config changes) and here is the error logs

{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] using fake (no-op) tun device"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] using fake (no-op) OS network configurator"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] using fake (no-op) DNS configurator"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"dns: using dns.noopManager"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"link state: interfaces.State{defaultRoute=eth0 ifs={eth0:[10.244.14.10/32 llu6]} v4=true v6=false}"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"magicsock: [warning] failed to force-set UDP read buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"magicsock: [warning] failed to force-set UDP write buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"magicsock: [warning] failed to force-set UDP read buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"magicsock: [warning] failed to force-set UDP write buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] magicsock: peermtu: peer MTU status is false"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] using BPF disco receiver for IPv4"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] using BPF disco receiver for IPv6"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"magicsock: disco key = d:ecd35cd9acbbxxx"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Creating WireGuard device..."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Bringing WireGuard device up..."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"wg: [v2] UDP bind has been updated"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"wg: [v2] Interface state was Down, requested Up, now Up"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Bringing router up..."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] warning: fakeRouter.Up: not implemented."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Clearing router settings..."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"[v1] warning: fakeRouter.Set: not implemented."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Starting network monitor..."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"Engine created."}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"wg: [v2] Routine: receive incoming mkReceiveFunc - started"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"wg: [v2] Routine: receive incoming mkReceiveFunc - started"}
{"level":"debug","ts":"2023-11-13T09:11:01Z","logger":"tailscaled","msg":"wg: [v2] Routine: receive incoming receiveDERP - started"}
{"level":"fatal","ts":"2023-11-13T09:11:06Z","logger":"startup","msg":"starting tailscale server: tsnet: NewLocalBackend: calling ReadState on state store: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded","stacktrace":"main.initTSNet\n\ttailscale.com/cmd/k8s-operator/operator.go:130\nmain.main\n\ttailscale.com/cmd/k8s-operator/operator.go:80\nruntime.main\n\truntime/proc.go:267"}

{"level":"debug","ts":"2023-11-13T09:27:26Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/13 09:27:26 http: TLS handshake error from 100.x.x.x:59759: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-13T09:27:40Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/13 09:27:40 http: TLS handshake error from 100.x.x.x:59764: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-13T09:27:40Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:59764 > 100.y.y.y:443} 40 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-13T09:27:40Z","logger":"tailscaled","msg":"[v1] v1.53.100-tfdbe511c4 peers: 36116/345660"}
{"level":"debug","ts":"2023-11-13T09:27:41Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.184.227.48:59510 derp=2 derpdist=2v4:3ms,10v4:22ms,17v4:9ms"}
{"level":"debug","ts":"2023-11-13T09:27:45Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/13 09:27:45 http: TLS handshake error from 100.x.x.x:59765: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-13T09:27:55Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending keepalive packet"}
{"level":"debug","ts":"2023-11-13T09:28:04Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.184.227.48:59510 derp=2 derpdist=1v4:71ms,2v4:6ms,3v4:183ms,4v4:149ms,5v4:181ms,6v4:221ms,7v4:114ms,8v4:140ms,9v4:48ms,10v4:25ms,11v4:198ms,12v4:56ms,13v4:31ms,14v4:155ms,16v4:75ms,17v4:11ms,18v4:136ms,19v4:162ms,20v4:164ms,21v4:66ms,22v4:162ms,24v4:58ms"}
{"level":"debug","ts":"2023-11-13T09:28:26Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.184.227.48:59510 derp=2 derpdist=2v4:3ms,10v4:22ms,17v4:9ms"}
{"level":"debug","ts":"2023-11-13T09:28:47Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.184.227.48:59510 derp=2 derpdist=2v4:3ms,10v4:22ms,17v4:9ms"}
{"level":"debug","ts":"2023-11-13T09:29:36Z","logger":"tailscaled","msg":"wg: [v2] Received message with unknown type"}
{"level":"debug","ts":"2023-11-13T09:29:36Z","logger":"tailscaled","msg":"[v1] peer keys: [tDd7B]"}
{"level":"debug","ts":"2023-11-13T09:29:36Z","logger":"tailscaled","msg":"[v1] v1.53.100-tfdbe511c4 peers: 36372/345980"}
{"level":"debug","ts":"2023-11-13T09:29:51Z","logger":"tailscaled","msg":"magicsock: closing connection to derp-3 (idle), age 3m15s"}
{"level":"debug","ts":"2023-11-13T09:29:51Z","logger":"tailscaled","msg":"magicsock: 1 active derp conns: derp-2=cr18m0s,wr10m0s"}

{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] magicsock: got updated network map; 4 peers"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] wgcfg: skipped unselected default routes from: \"my-droplet\" ([Vy7c0])"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] magicsock: peermtu: peer MTU status is false"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] wgengine: Reconfig done"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] authReconfig: ra=true dns=true 0x03: <nil>"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] netmap diff: (none)"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] magicsock: got updated network map; 4 peers"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] wgcfg: skipped unselected default routes from: \"my-droplet\" ([Vy7c0])"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] magicsock: peermtu: peer MTU status is false"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] wgengine: Reconfig done"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"[v1] authReconfig: ra=true dns=true 0x03: <nil>"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Received handshake initiation"}
{"level":"debug","ts":"2023-11-14T02:53:41Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending handshake response"}
{"level":"debug","ts":"2023-11-14T02:53:42Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:54434 > 100.y.y.y:443} 40 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-14T02:53:46Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:53:51Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:53:55Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending keepalive packet"}
{"level":"debug","ts":"2023-11-14T02:53:56Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:01Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:06Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:11Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:16Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:21Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:26Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:31Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T02:54:36Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
{"level":"debug","ts":"2023-11-14T03:02:41Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Removing all keys, since we haven't received a new one in 540 seconds"}

{"level":"debug","ts":"2023-11-14T03:10:42Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:57067 > 100.y.y.y:443} 64 tcp ok\n"}
{"level":"debug","ts":"2023-11-14T03:10:42Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:57067 > 100.y.y.y:443} 52 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-14T03:10:42Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:57067 > 100.y.y.y:443} 352 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-14T03:10:43Z","logger":"tailscaled","msg":"magicsock: derp-3 connected; connGen=1"}
{"level":"debug","ts":"2023-11-14T03:10:52Z","logger":"tailscaled","msg":"cert(\"my-k8s-operator.tailxxxx.ts.net\"): getCertPEM: Get \"https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator\": context deadline exceeded"}
2023/11/14 03:10:52 http: TLS handshake error from 100.x.x.x:57067: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded
{"level":"debug","ts":"2023-11-14T03:10:52Z","logger":"tailscaled","msg":"Accept: TCP{100.x.x.x:57067 > 100.y.y.y:443} 52 tcp non-syn\n"}
{"level":"debug","ts":"2023-11-14T03:10:53Z","logger":"service-reconciler","msg":"starting reconcile","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:10:53Z","logger":"service-reconciler","msg":"service is being deleted or is (no longer) referring to Tailscale ingress/egress, ensuring any created resources are cleaned up","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:10:53Z","logger":"service-reconciler","msg":"no finalizer, nothing to do","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:10:53Z","logger":"service-reconciler","msg":"reconcile finished","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:11:03Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Sending keepalive packet"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"magicsock: closing connection to derp-3 (idle), age 1m0s"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"magicsock: 1 active derp conns: derp-2=cr18h0m0s,wr17h52m0s"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"netcheck: [v1] report: udp=true v6=false v6os=true mapvarydest=false hair=false portmap= v4a=137.184.227.48:59510 derp=2 derpdist=1v4:75ms,2v4:6ms,3v4:184ms,4v4:155ms,5v4:181ms,6v4:217ms,7v4:107ms,8v4:138ms,9v4:47ms,10v4:25ms,11v4:194ms,12v4:50ms,13v4:28ms,14v4:156ms,16v4:76ms,17v4:11ms,18v4:138ms,19v4:159ms,20v4:166ms,21v4:66ms,22v4:161ms,24v4:59ms"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"magicsock: adding connection to derp-3 for [tDd7B]"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"magicsock: 2 active derp conns: derp-2=cr18h0m0s,wr17h52m0s derp-3=cr0s,wr0s"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"[v1] v1.53.100-tfdbe511c4 peers: 75712/122720"}
{"level":"debug","ts":"2023-11-14T03:11:42Z","logger":"tailscaled","msg":"derphttp.Client.Recv: connecting to derp-3 (sin)"}
{"level":"debug","ts":"2023-11-14T03:11:43Z","logger":"tailscaled","msg":"magicsock: derp-3 connected; connGen=1"}
{"level":"debug","ts":"2023-11-14T03:11:56Z","logger":"tailscaled","msg":"wg: [v2] Received message with unknown type"}
{"level":"debug","ts":"2023-11-14T03:12:14Z","logger":"service-reconciler","msg":"starting reconcile","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:14Z","logger":"service-reconciler","msg":"service is being deleted or is (no longer) referring to Tailscale ingress/egress, ensuring any created resources are cleaned up","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:14Z","logger":"service-reconciler","msg":"no finalizer, nothing to do","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:14Z","logger":"service-reconciler","msg":"reconcile finished","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:16Z","logger":"service-reconciler","msg":"starting reconcile","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:16Z","logger":"service-reconciler","msg":"service is being deleted or is (no longer) referring to Tailscale ingress/egress, ensuring any created resources are cleaned up","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:16Z","logger":"service-reconciler","msg":"no finalizer, nothing to do","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:16Z","logger":"service-reconciler","msg":"reconcile finished","service-ns":"kube-system","service-name":"kube-dns"}
{"level":"debug","ts":"2023-11-14T03:12:42Z","logger":"tailscaled","msg":"magicsock: closing connection to derp-3 (idle), age 1m0s"}
{"level":"debug","ts":"2023-11-14T03:12:42Z","logger":"tailscaled","msg":"magicsock: 1 active derp conns: derp-2=cr18h1m0s,wr17h53m0s"}
{"level":"debug","ts":"2023-11-14T03:19:42Z","logger":"tailscaled","msg":"wg: [v2] [tDd7B] - Removing all keys, since we haven't received a new one in 540 seconds"}
thoongnv commented 10 months ago

it seems worked fine recently, there is no timeout occurred

irbekrm commented 10 months ago

2023/11/13 09:18:53 http: TLS handshake error from 100.x.x.x:59676: 500 Internal Server Error: Get "https://kubernetes.default.svc/api/v1/namespaces/tailscale/secrets/operator": context deadline exceeded

This is Tailscale operator connecting to Kubernetes api-server. There may have been an api-server issue at that time, perhaps an overload of requests? If this occurs again, it would be good to check api-server logs if you have access to those or try to verify that that api-server is healthy at that point. Perhaps you deploy a larger amount of infrastructure at once?

ruhatch commented 4 months ago

In case any one else runs into this, it helped me to restart the operator with kubectl rollout restart deployment operator -n tailscale

CobyPear commented 1 week ago

I am using the k8s operator and the ingress class for a bunch of services on my cluster and after a few weeks of uptime I started getting a lot of these TLS handshake and getCertPEM errors. I can open a new issue as I am not using the operator for API server proxy, but my errors are the same.