kube-proxy doesn't respond to updates

[lavalamp]

Reported by pixie79 in IRC. Changing the service didn't cause the proxy to change the ports it was directing traffic to, but restarting the proxy made it start working again.

[lavalamp]

@smarterclayton any way this could be due to your config changes?

[smarterclayton]

Possible, testing.

[smarterclayton]

I was able to get update to work, but it looks like delete of a service is not purging the service from the proxy map. Did you update the service via the REST API or kubecfg (because it looks like kubecfg is broken for update, or at least... doesn't work for me, which I'm fixing in a related pull)?

[smarterclayton]

Did a create on port 9999, then an update to 9998 (no endpoints in this case), and got this dump (which shows that the config is properly set, so probably not my change). The proxier may not be expecting a port change. Will look tomorrow. Also, proxy/config/etcd.go needs a deeper rewrite to match kubelet/config/etcd.go at some point. It's possible for the channels to race and cause out of order updates (delete delivered before add, for example).

I0723 00:03:34.063100 04224 logs.go:39] etcd DEBUG: [recv.success. http://127.0.0.1:4001/v2/keys/registry/services/endpoints/frontend?consistent=true&recursive=false&sorted=true]
I0723 00:03:34.063125 04224 etcd.go:140] Got service: frontend on localport 9998 mapping to: {frontend []}
I0723 00:03:34.063144 04224 config.go:233] Setting services {[{{ frontend   0} 9998 map[] map[name:frontend] false {0 0 }}] 0}
I0723 00:03:34.063164 04224 config.go:138] Setting endpoints {[{frontend []}] 0}
I0723 00:03:34.063170 04224 proxier.go:127] Received update notice: [{JSONBase:{Kind: ID:frontend CreationTimestamp: SelfLink: ResourceVersion:0} Port:9998 Labels:map[] Selector:map[name:frontend] CreateExternalLoadBalancer:false ContainerPort:{Kind:0 IntVal:0 StrVal:}}]
I0723 00:03:35.400360 04224 logs.go:39] etcd DEBUG: [recv.response.from http://127.0.0.1:4001/v2/keys/registry/services?consistent=true&recursive=true&wait=true&waitIndex=269]
I0723 00:03:35.400391 04224 logs.go:39] etcd DEBUG: [recv.success. http://127.0.0.1:4001/v2/keys/registry/services?consistent=true&recursive=true&wait=true&waitIndex=269]
I0723 00:03:35.400444 04224 logs.go:39] etcd DEBUG: get [/registry/services/ http://127.0.0.1:4001] [%!s(MISSING)]
I0723 00:03:35.400468 04224 logs.go:39] etcd DEBUG: [Connecting to etcd: attempt 1 for keys/registry/services?consistent=true&recursive=true&wait=true&waitIndex=270]
I0723 00:03:35.400478 04224 logs.go:39] etcd DEBUG: [send.request.to  http://127.0.0.1:4001/v2/keys/registry/services?consistent=true&recursive=true&wait=true&waitIndex=270  | method  GET]
I0723 00:03:35.400498 04224 etcd.go:190] Processing a change in service configuration... {set %!s(*etcd.Node=&{/registry/services/endpoints/frontend {"Name":"frontend","Endpoints":[]} false <nil> 0 [] 269 269}) %!s(*etcd.Node=&{/registry/services/endpoints/frontend {"Name":"frontend","Endpoints":[]} false <nil> 0 [] 268 268}) %!s(uint64=268) %!s(uint64=5423) %!s(uint64=0)}
I0723 00:03:35.400523 04224 etcd.go:221] Processing a change in endpoint configuration... {set %!s(*etcd.Node=&{/registry/services/endpoints/frontend {"Name":"frontend","Endpoints":[]} false <nil> 0 [] 269 269}) %!s(*etcd.Node=&{/registry/services/endpoints/frontend {"Name":"frontend","Endpoints":[]} false <nil> 0 [] 268 268}) %!s(uint64=268) %!s(uint64=5423) %!s(uint64=0)}
I0723 00:03:35.400616 04224 config.go:128] Adding new endpoint from source etcd : [{frontend []}]

[lavalamp]

Heh, #468 seems to be reporting the same thing.

[pixie79]

Hi,

I was using kubecfg.

Regards
Mark

[brendandburns]

I believe this is now fixed. Please re-open if it re-occurs.