BackendService Sync bug in 1.2

[freehan]

Somehow, the backend pool is not getting the correct service ports to sync.

The logs in question is below. See the highlighted log lines.

I0715 22:08:29.085212 1 controller.go:122] Ingress default/weather-frontend added, enqueuing
I0715 22:08:29.087433 1 controller.go:268] Syncing default/weather-frontend
I0715 22:08:29.088726 1 event.go:218] Event(v1.ObjectReference{Kind:"Ingress", Namespace:"default", Name:"weather-frontend", UID:"9a9766fb-887b-11e8-8139-42010a8000e2", APIVersion:"extensions", ResourceVersion:"338003", FieldPath:""}): type: 'Normal' reason: 'ADD' default/weather-frontend
I0715 22:08:29.089596 1 controller.go:322] Updating NEG visibility annotation "{"network_endpoint_groups":{"80":"k8s1-d5fe052f-default-weather-api-80-81f38065"},"zones":["us-central1-b"]}" on service default/weather-api.
I0715 22:08:29.101494 1 manager.go:83] EnsureSyncer default/weather-api: removing map[] ports, adding map[80:80] ports
I0715 22:08:29.101536 1 syncer.go:80] New syncer for service default/weather-api port 80 NEG "k8s1-d5fe052f-default-weather-api-80-81f38065"
I0715 22:08:29.101548 1 syncer.go:113] Starting NEG syncer for service port default/weather-api-80/80
I0715 22:08:29.101588 1 controller.go:246] Syncing service "default/weather-frontend"
I0715 22:08:29.101932 1 syncer.go:196] Sync NEG "k8s1-d5fe052f-default-weather-api-80-81f38065" for default/weather-api-80/80.
I0715 22:08:29.105143 1 controller.go:322] Updating NEG visibility annotation "{"network_endpoint_groups":{"80":"k8s1-d5fe052f-default-weather-frontend-80-89bd2927"},"zones":["us-central1-b"]}" on service default/weather-frontend.
I0715 22:08:29.111893 1 manager.go:83] EnsureSyncer default/weather-frontend: removing map[] ports, adding map[80:80] ports
I0715 22:08:29.111954 1 syncer.go:80] New syncer for service default/weather-frontend port 80 NEG "k8s1-d5fe052f-default-weather-frontend-80-89bd2927"
I0715 22:08:29.111968 1 syncer.go:113] Starting NEG syncer for service port default/weather-frontend-80/80
I0715 22:08:29.111997 1 controller.go:246] Syncing service "default/weather-api"
I0715 22:08:29.115084 1 syncer.go:196] Sync NEG "k8s1-d5fe052f-default-weather-frontend-80-89bd2927" for default/weather-frontend-80/80.
I0715 22:08:29.115884 1 manager.go:83] EnsureSyncer default/weather-api: removing map[] ports, adding map[] ports
I0715 22:08:29.116322 1 controller.go:246] Syncing service "default/weather-frontend"
I0715 22:08:29.118509 1 manager.go:83] EnsureSyncer default/weather-frontend: removing map[] ports, adding map[] ports
I0715 22:08:29.185277 1 instances.go:94] Creating instance group us-central1-b/k8s-ig--d5fe052f3ca01df6.
I0715 22:08:31.014116 1 instances.go:137] Instance group us-central1-b/k8s-ig--d5fe052f3ca01df6 does not have ports [30013], adding them now.
I0715 22:08:31.665468 1 instances.go:230] Adding nodes [gke-test-default-pool-643e9c7e-qdsz gke-test-default-pool-643e9c7e-rk8l gke-test-default-pool-643e9c7e-t0tt] to k8s-ig--d5fe052f3ca01df6 in zone us-central1-b
I0715 22:08:32.384980 1 backends.go:249] Sync: backends [{{kube-system/default-http-backend {1 0 http}} 30013 80 HTTP 8080 false } {{default/weather-frontend {0 80 }} 0 80 HTTP 80 true }]
I0715 22:08:32.580493 1 healthchecks.go:149] Creating health check for port 30013 with protocol HTTP
I0715 22:08:34.476449 1 backends.go:294] Creating backend service for port 30013 named k8s-be-30013--d5fe052f3ca01df6
I0715 22:08:34.486190 1 composite.go:56] Creating ga backend service k8s-be-30013--d5fe052f3ca01df6
I0715 22:08:37.384209 1 backends.go:487] Backend service "k8s-be-30013--d5fe052f3ca01df6" has instance groups [], want [projects/mixia-cube/zones/us-central1-b/instanceGroups/k8s-ig--d5fe052f3ca01df6]
I0715 22:08:37.384994 1 composite.go:82] Updating ga backend service k8s-be-30013--d5fe052f3ca01df6
I0715 22:08:40.277462 1 healthchecks.go:142] Creating beta health check with protocol HTTP
I0715 22:08:41.922219 1 backends.go:294] Creating backend service for port 0 named k8s1-d5fe052f-default-weather-frontend-80-89bd2927
I0715 22:08:41.922320 1 composite.go:49] Creating beta backend service k8s1-d5fe052f-default-weather-frontend-80-89bd2927
I0715 22:08:45.082228 1 l7s.go:116] Syncing load balancer default/weather-frontend
I0715 22:08:45.087210 1 l7s.go:67] Creating l7 default-weather-frontend--d5fe052f3ca01df6
I0715 22:08:45.242218 1 url_maps.go:51] Creating url map k8s-um-default-weather-frontend--d5fe052f3ca01df6 for backend k8s-be-30013--d5fe052f3ca01df6
I0715 22:08:47.476854 1 target_proxies.go:39] Creating new http proxy for urlmap k8s-um-default-weather-frontend--d5fe052f3ca01df6
I0715 22:08:50.093687 1 forwarding_rules.go:72] Creating forwarding rule for proxy "https://www.googleapis.com/compute/v1/projects/mixia-cube/global/targetHttpProxies/k8s-tp-default-weather-frontend--d5fe052f3ca01df6" and ip :80-80
I0715 22:08:56.799437 1 firewalls.go:89] Creating firewall rule "k8s-fw-l7--d5fe052f3ca01df6"
E0715 22:09:05.382941 1 taskqueue.go:85] Requeuing "default/weather-frontend" due to error: googleapi: Error 404: The resource 'projects/mixia-cube/global/backendServices/k8s1-d5fe052f-default-weather-api-80-81f38065' was not found, notFound (ingresses)
I0715 22:09:05.382999 1 controller.go:268] Syncing default/weather-frontend
I0715 22:09:05.385375 1 event.go:218] Event(v1.ObjectReference{Kind:"Ingress", Namespace:"default", Name:"weather-frontend", UID:"9a9766fb-887b-11e8-8139-42010a8000e2", APIVersion:
"extensions", ResourceVersion:"338003", FieldPath:""}): type: 'Warning' reason: 'Sync' Error during sync: googleapi: Error 404: The resource 'projects/mixia-cube/global/backendServices/k
8s1-d5fe052f-default-weather-api-80-81f38065' was not found, notFound
I0715 22:09:05.631611 1 backends.go:249] Sync: backends [{{kube-system/default-http-backend {1 0 http}} 30013 80 HTTP 8080 false } {{default/weather-api {0 80 }} 0 80 HTTP 80
true }]
I0715 22:09:05.806434 1 healthchecks.go:130] Health check k8s-be-30013--d5fe052f3ca01df6 already exists and has the expected path /healthz
I0715 22:09:05.985606 1 healthchecks.go:142] Creating beta health check with protocol HTTP
I0715 22:09:07.897490 1 backends.go:294] Creating backend service for port 0 named k8s1-d5fe052f-default-weather-api-80-81f38065
I0715 22:09:07.897596 1 composite.go:49] Creating beta backend service k8s1-d5fe052f-default-weather-api-80-81f38065
I0715 22:09:10.375592 1 l7s.go:116] Syncing load balancer default/weather-frontend
I0715 22:09:10.476402 1 url_maps.go:46] Url map k8s-um-default-weather-frontend--d5fe052f3ca01df6 already exists
I0715 22:09:17.191068 1 url_maps.go:167] Updating URLMap: "k8s-um-default-weather-frontend--d5fe052f3ca01df6"
I0715 22:09:18.896482 1 controller.go:419] Updating loadbalancer default/weather-frontend with IP 130.211.15.1
I0715 22:09:18.902523 1 event.go:218] Event(v1.ObjectReference{Kind:"Ingress", Namespace:"default", Name:"weather-frontend", UID:"9a9766fb-887b-11e8-8139-42010a8000e2", APIVersion:
"extensions", ResourceVersion:"338003", FieldPath:""}): type: 'Normal' reason: 'CREATE' ip: 130.211.15.1
I0715 22:09:18.905848 1 controller.go:246] Syncing service "default/weather-api"
I0715 22:09:18.907233 1 controller.go:144] Ingress default/weather-frontend changed, enqueuing

[freehan]

fixed by #402