Error when creating any istio gateway: context deadline exceeded

[Rob_Kenefeck]

Installing Istio using istioctl I spotted that 3 resource were not getting created correctly due to timeout. meshexpansion-gateway meshexpansion-vs-istiod and meshexpansion-dr-istiod, all with the same context deadline exceeded error. After uninstalling istio and removing the istio-system namespace the problem still occurs. When I tried to create a non istio-system gateway, that fails with the same error.

Extracted the resources to manually add them, and got the same error. Attempted using the v1beta1 api instead and still get the same error.

I’ve run it in --v=8 to extract the debug of what is happening, and replaced my master ip address just in case

I found some old topics similar to this but noting that related. Has anyone seen this and know how I might resolve?

I0804 00:07:43.490388    8704 round_trippers.go:423] Request Headers:
I0804 00:07:43.491889    8704 round_trippers.go:426]     Accept: application/json
I0804 00:07:43.493389    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:07:43.623891    8704 round_trippers.go:441] Response Status: 404 Not Found in 130 milliseconds
I0804 00:07:43.626393    8704 round_trippers.go:444] Response Headers:
I0804 00:07:43.626393    8704 round_trippers.go:447]     Audit-Id: 64646deb-39e9-45b7-a955-4bb87b3b027e
I0804 00:07:43.627910    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:07:43.627950    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:07:43.628391    8704 round_trippers.go:447]     Content-Length: 268
I0804 00:07:43.628391    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:07:43 GMT
I0804 00:07:43.628891    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"gateways.networking.istio.io \"meshexpansion-gateway\" not found","reason":"NotFound","details":{"name":"meshexpansion-gateway","group":"networking.istio.io","kind":"gateways"},"code":404}
I0804 00:07:43.628891    8704 round_trippers.go:416] GET https://192.168.192.168/api/v1/namespaces/istio-system
I0804 00:07:43.628891    8704 round_trippers.go:423] Request Headers:
I0804 00:07:43.629391    8704 round_trippers.go:426]     Accept: application/json
I0804 00:07:43.629391    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:07:43.768892    8704 round_trippers.go:441] Response Status: 200 OK in 139 milliseconds
I0804 00:07:43.784392    8704 round_trippers.go:444] Response Headers:
I0804 00:07:43.796391    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:07:43.800394    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:07:43.803394    8704 round_trippers.go:447]     Content-Length: 301
I0804 00:07:43.803894    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:07:43 GMT
I0804 00:07:43.804892    8704 round_trippers.go:447]     Audit-Id: e4c92aab-97e1-4ccf-bb2e-3545f765c247
I0804 00:07:43.804892    8704 request.go:947] Response Body: {"kind":"Namespace","apiVersion":"v1","metadata":{"name":"istio-system","selfLink":"/api/v1/namespaces/istio-system","uid":"e9222517-8c9c-4cea-8c68-094645a81cd3","resourceVersion":"25205892","creationTimestamp":"2020-08-03T13:48:35Z"},"spec":{"finalizers":["kubernetes"]},"status":{"phase":"Active"}}
I0804 00:07:43.804892    8704 request.go:947] Request Body: {"apiVersion":"networking.istio.io/v1beta1","kind":"Gateway","metadata":{"annotations":{"kubectl.kubernetes.io/last-applied-configuration":"{\"apiVersion\":\"networking.istio.io/v1beta1\",\"kind\":\"Gateway\",\"metadata\":{\"annotations\":{},\"labels\":{\"release\":\"istio\"},\"name\":\"meshexpansion-gateway\",\"namespace\":\"istio-system\"},\"spec\":{\"selector\":{\"istio\":\"ingressgateway\"},\"servers\":[{\"hosts\":[\"*\"],\"port\":{\"name\":\"tcp-istiod\",\"number\":15012,\"protocol\":\"TCP\"}},{\"hosts\":[\"*\"],\"port\":{\"name\":\"tcp-istiodwebhook\",\"number\":15017,\"protocol\":\"TCP\"}}]}}\n"},"labels":{"release":"istio"},"name":"meshexpansion-gateway","namespace":"istio-system"},"spec":{"selector":{"istio":"ingressgateway"},"servers":[{"hosts":["*"],"port":{"name":"tcp-istiod","number":15012,"protocol":"TCP"}},{"hosts":["*"],"port":{"name":"tcp-istiodwebhook","number":15017,"protocol":"TCP"}}]}}
I0804 00:07:43.805392    8704 round_trippers.go:416] POST https://192.168.192.168/apis/networking.istio.io/v1beta1/namespaces/istio-system/gateways
I0804 00:07:43.805392    8704 round_trippers.go:423] Request Headers:
I0804 00:07:43.806392    8704 round_trippers.go:426]     Accept: application/json
I0804 00:07:43.842894    8704 round_trippers.go:426]     Content-Type: application/json
I0804 00:07:43.842894    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:14.066829    8704 round_trippers.go:441] Response Status: 500 Internal Server Error in 30223 milliseconds
I0804 00:08:14.066829    8704 round_trippers.go:444] Response Headers:
I0804 00:08:14.066829    8704 round_trippers.go:447]     Content-Length: 118
I0804 00:08:14.067338    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:14 GMT
I0804 00:08:14.067338    8704 round_trippers.go:447]     Audit-Id: 5c833d60-b3f7-4234-acc9-6d45ae44d824
I0804 00:08:14.067338    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:14.067338    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:14.068340    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"context deadline exceeded","code":500}
I0804 00:08:14.074838    8704 round_trippers.go:416] GET https://192.168.192.168/apis/networking.istio.io/v1beta1/namespaces/istio-system/virtualservices/meshexpansion-vs-istiod
I0804 00:08:14.074838    8704 round_trippers.go:423] Request Headers:
I0804 00:08:14.075338    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:14.075338    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:14.203363    8704 round_trippers.go:441] Response Status: 404 Not Found in 128 milliseconds
I0804 00:08:14.203363    8704 round_trippers.go:444] Response Headers:
I0804 00:08:14.205529    8704 round_trippers.go:447]     Audit-Id: 43330e62-4458-42df-9086-a7ac1457dfdf
I0804 00:08:14.205529    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:14.205529    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:14.205529    8704 round_trippers.go:447]     Content-Length: 286
I0804 00:08:14.205529    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:14 GMT
I0804 00:08:14.205529    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"virtualservices.networking.istio.io \"meshexpansion-vs-istiod\" not found","reason":"NotFound","details":{"name":"meshexpansion-vs-istiod","group":"networking.istio.io","kind":"virtualservices"},"code":404}
I0804 00:08:14.205529    8704 round_trippers.go:416] GET https://192.168.192.168/api/v1/namespaces/istio-system
I0804 00:08:14.206363    8704 round_trippers.go:423] Request Headers:
I0804 00:08:14.206363    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:14.206363    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:14.224364    8704 round_trippers.go:441] Response Status: 200 OK in 18 milliseconds
I0804 00:08:14.224364    8704 round_trippers.go:444] Response Headers:
I0804 00:08:14.225363    8704 round_trippers.go:447]     Audit-Id: 1bb84c52-1872-40d7-a88b-538891a77152
I0804 00:08:14.225363    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:14.225363    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:14.225363    8704 round_trippers.go:447]     Content-Length: 301
I0804 00:08:14.225363    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:14 GMT
I0804 00:08:14.225363    8704 request.go:947] Response Body: {"kind":"Namespace","apiVersion":"v1","metadata":{"name":"istio-system","selfLink":"/api/v1/namespaces/istio-system","uid":"e9222517-8c9c-4cea-8c68-094645a81cd3","resourceVersion":"25205892","creationTimestamp":"2020-08-03T13:48:35Z"},"spec":{"finalizers":["kubernetes"]},"status":{"phase":"Active"}}
I0804 00:08:14.226364    8704 request.go:947] Request Body: {"apiVersion":"networking.istio.io/v1beta1","kind":"VirtualService","metadata":{"annotations":{"kubectl.kubernetes.io/last-applied-configuration":"{\"apiVersion\":\"networking.istio.io/v1beta1\",\"kind\":\"VirtualService\",\"metadata\":{\"annotations\":{},\"labels\":{\"release\":\"istio\"},\"name\":\"meshexpansion-vs-istiod\",\"namespace\":\"istio-system\"},\"spec\":{\"gateways\":[\"meshexpansion-gateway\"],\"hosts\":[\"istiod.istio-system.svc.cluster.local\"],\"tcp\":[{\"match\":[{\"port\":15012}],\"route\":[{\"destination\":{\"host\":\"istiod.istio-system.svc.cluster.local\",\"port\":{\"number\":15012}}}]},{\"match\":[{\"port\":15017}],\"route\":[{\"destination\":{\"host\":\"istiod.istio-system.svc.cluster.local\",\"port\":{\"number\":443}}}]}]}}\n"},"labels":{"release":"istio"},"name":"meshexpansion-vs-istiod","namespace":"istio-system"},"spec":{"gateways":["meshexpansion-gateway"],"hosts":["istiod.istio-system.svc.cluster.local"],"tcp":[{"match":[{"port":15012}],"route":[{"destination":{"host":"istiod.ist [truncated 184 chars]
I0804 00:08:14.226364    8704 round_trippers.go:416] POST https://192.168.192.168/apis/networking.istio.io/v1beta1/namespaces/istio-system/virtualservices
I0804 00:08:14.227367    8704 round_trippers.go:423] Request Headers:
I0804 00:08:14.261367    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:14.261367    8704 round_trippers.go:426]     Content-Type: application/json
I0804 00:08:14.261367    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:44.397956    8704 round_trippers.go:441] Response Status: 500 Internal Server Error in 30136 milliseconds
I0804 00:08:44.398956    8704 round_trippers.go:444] Response Headers:
I0804 00:08:44.398956    8704 round_trippers.go:447]     Audit-Id: c14b06d9-c681-4d81-b8e7-c41c025fc306
I0804 00:08:44.398956    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:44.399955    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:44.399955    8704 round_trippers.go:447]     Content-Length: 118
I0804 00:08:44.399955    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:44 GMT
I0804 00:08:44.399955    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"context deadline exceeded","code":500}
I0804 00:08:44.399955    8704 round_trippers.go:416] GET https://192.168.192.168/apis/networking.istio.io/v1beta1/namespaces/istio-system/destinationrules/meshexpansion-dr-istiod
I0804 00:08:44.400955    8704 round_trippers.go:423] Request Headers:
I0804 00:08:44.400955    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:44.400955    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:44.626547    8704 round_trippers.go:441] Response Status: 404 Not Found in 225 milliseconds
I0804 00:08:44.627542    8704 round_trippers.go:444] Response Headers:
I0804 00:08:44.627542    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:44.627542    8704 round_trippers.go:447]     Content-Length: 288
I0804 00:08:44.627542    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:44 GMT
I0804 00:08:44.627542    8704 round_trippers.go:447]     Audit-Id: d0f6b85d-bd2a-4dcb-bbaf-4e93ca6cc8f2
I0804 00:08:44.628541    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:44.628541    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"destinationrules.networking.istio.io \"meshexpansion-dr-istiod\" not found","reason":"NotFound","details":{"name":"meshexpansion-dr-istiod","group":"networking.istio.io","kind":"destinationrules"},"code":404}
I0804 00:08:44.628541    8704 round_trippers.go:416] GET https://192.168.192.168/api/v1/namespaces/istio-system
I0804 00:08:44.628541    8704 round_trippers.go:423] Request Headers:
I0804 00:08:44.628541    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:44.628541    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:08:44.648552    8704 round_trippers.go:441] Response Status: 200 OK in 20 milliseconds
I0804 00:08:44.649050    8704 round_trippers.go:444] Response Headers:
I0804 00:08:44.651050    8704 round_trippers.go:447]     Audit-Id: bd770b55-320f-4aab-8c5c-85c2b1689671
I0804 00:08:44.651050    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:08:44.651050    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:08:44.651551    8704 round_trippers.go:447]     Content-Length: 301
I0804 00:08:44.652551    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:08:44 GMT
I0804 00:08:44.652551    8704 request.go:947] Response Body: {"kind":"Namespace","apiVersion":"v1","metadata":{"name":"istio-system","selfLink":"/api/v1/namespaces/istio-system","uid":"e9222517-8c9c-4cea-8c68-094645a81cd3","resourceVersion":"25205892","creationTimestamp":"2020-08-03T13:48:35Z"},"spec":{"finalizers":["kubernetes"]},"status":{"phase":"Active"}}
I0804 00:08:44.653051    8704 request.go:947] Request Body: {"apiVersion":"networking.istio.io/v1beta1","kind":"DestinationRule","metadata":{"annotations":{"kubectl.kubernetes.io/last-applied-configuration":"{\"apiVersion\":\"networking.istio.io/v1beta1\",\"kind\":\"DestinationRule\",\"metadata\":{\"annotations\":{},\"labels\":{\"release\":\"istio\"},\"name\":\"meshexpansion-dr-istiod\",\"namespace\":\"istio-system\"},\"spec\":{\"host\":\"istiod.istio-system.svc.cluster.local\",\"trafficPolicy\":{\"portLevelSettings\":[{\"port\":{\"number\":15012},\"tls\":{\"mode\":\"DISABLE\"}},{\"port\":{\"number\":15017},\"tls\":{\"mode\":\"DISABLE\"}}]}}}\n"},"labels":{"release":"istio"},"name":"meshexpansion-dr-istiod","namespace":"istio-system"},"spec":{"host":"istiod.istio-system.svc.cluster.local","trafficPolicy":{"portLevelSettings":[{"port":{"number":15012},"tls":{"mode":"DISABLE"}},{"port":{"number":15017},"tls":{"mode":"DISABLE"}}]}}}
I0804 00:08:44.653051    8704 round_trippers.go:416] POST https://192.168.192.168/apis/networking.istio.io/v1beta1/namespaces/istio-system/destinationrules
I0804 00:08:44.653051    8704 round_trippers.go:423] Request Headers:
I0804 00:08:44.684562    8704 round_trippers.go:426]     Accept: application/json
I0804 00:08:44.688562    8704 round_trippers.go:426]     Content-Type: application/json
I0804 00:08:44.688562    8704 round_trippers.go:426]     User-Agent: kubectl.exe/v1.15.11 (windows/amd64) kubernetes/f2a77f6
I0804 00:09:14.819248    8704 round_trippers.go:441] Response Status: 504 Gateway Timeout in 30130 milliseconds
I0804 00:09:14.819248    8704 round_trippers.go:444] Response Headers:
I0804 00:09:14.820255    8704 round_trippers.go:447]     Cache-Control: no-cache, private
I0804 00:09:14.820255    8704 round_trippers.go:447]     Content-Type: application/json
I0804 00:09:14.820255    8704 round_trippers.go:447]     Content-Length: 187
I0804 00:09:14.820255    8704 round_trippers.go:447]     Date: Mon, 03 Aug 2020 14:09:15 GMT
I0804 00:09:14.820255    8704 round_trippers.go:447]     Audit-Id: a355360e-b94f-41f8-a892-2c2d2e94d4b9
I0804 00:09:14.820255    8704 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"Timeout: request did not complete within requested timeout 30s","reason":"Timeout","details":{},"code":504}
I0804 00:09:14.821318    8704 helpers.go:199] server response object: [{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {},
  "status": "Failure",
  "message": "error when creating \".\\\\meshexpansion-gateway.yaml\": context deadline exceeded",
  "code": 500
}]
I0804 00:09:14.821318    8704 helpers.go:199] server response object: [{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {},
  "status": "Failure",
  "message": "error when creating \".\\\\meshexpansion-gateway.yaml\": context deadline exceeded",
  "code": 500
}]
I0804 00:09:14.821318    8704 helpers.go:199] server response object: [{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {},
  "status": "Failure",
  "message": "error when creating \".\\\\meshexpansion-gateway.yaml\": Timeout: request did not complete within requested timeout 30s",
  "reason": "Timeout",
  "details": {},
  "code": 504
}]
F0804 00:09:14.821318    8704 helpers.go:114] Error from server: error when creating ".\\meshexpansion-gateway.yaml": context deadline exceeded
Error from server: error when creating ".\\meshexpansion-gateway.yaml": context deadline exceeded
Error from server (Timeout): error when creating ".\\meshexpansion-gateway.yaml": Timeout: request did not complete within requested timeout 30s```

[Rob_Kenefeck]

Thanks to John, I was able to get to the bottom of this. The error message “context deadline exceeded” was a symptom of the validatingwebhookconfigurations blocking the resources from being created. I was able to work around that by running:

kubectl delete validatingwebhookconfigurations which removed the istiod-istio-system hook and when I applied my extracted resources they added successfully.

Troubleshooting the webhook using https://github.com/istio/istio/wiki/Troubleshooting-Istio#diagnostics pointed me to the GKE firewall rule that had magically reverted back to not allowing 15017. Once that was updated again, the straight istioctl install -f mysettings.yaml worked again successfully.