Watch cache regression: changes behavior of "resource version too old" error

[smarterclayton]

When attempting to fetch a resource version that is too old, the behavior of watch (for both HTTP and web sockets) changed when watch cache was enabled. The watch cache returns a 410 - without the watch cache, we return 200 and then write an "error" entry to the watch stream. This broke a client that dependent on the watch behavior, and moreover is inconsistent with other errors we set in the registry. Also, for watch over web sockets, most javascript clients will be unable to get at a 410 error from the connection, because browsers don't get access to the data.

We should restore the watch cache behavior to be consistent with the previous behavior as this is a regression in API semantics.

Resource without watch cache, watching too old:

$ curl ... "https:///oapi/v1/namespaces/clayton-dev/builds?watch=1&resourceVersion=1"
> GET /oapi/v1/namespaces/clayton-dev/builds?watch=1&resourceVersion=1 HTTP/1.1
> Accept: application/json, */*
> User-Agent: oc/v1.3.0 (darwin/amd64) kubernetes/2787678
> 
< HTTP/1.1 200 OK
< Cache-Control: no-store
< Transfer-Encoding: chunked
< Date: Wed, 04 May 2016 18:10:26 GMT
< Content-Type: text/plain; charset=utf-8
< Transfer-Encoding: chunked
< 
{"type":"ERROR","object":{"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"401: The event in requested index is outdated and cleared (the requested history has been cleared [4046756/2]) [4047755]","reason":"Expired","code":410}}

Resource with watch cache, watching too old:

$ curl ... "https:///apis/extensions/v1beta1/namespaces/clayton-dev/horizontalpodautoscalers?watch=1&resourceVersion=1"
> GET /apis/extensions/v1beta1/namespaces/clayton-dev/horizontalpodautoscalers?watch=1&resourceVersion=1 HTTP/1.1
> Accept: application/json, */*
> User-Agent: oc/v1.3.0 (darwin/amd64) kubernetes/2787678
> 
< HTTP/1.1 410 Gone
< Cache-Control: no-store
< Content-Type: application/json
< Date: Wed, 04 May 2016 18:08:25 GMT
< Content-Length: 146
< 
{"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"too old resource version: 1 (4034675)","reason":"Gone","code":410}

[smarterclayton]

@kubernetes/sig-api-machinery I think this is candidate for back port to 1.2 to restore the previous behavior.

[smarterclayton]

@jwforres since this broke your javascript client, @liggitt FYI because of watch cache

[ncdc]

+1 for backport

[wojtek-t]

hmm - we enabled watch cache in 1.1 - so this should also be broken in 1.1

[lavalamp]

It's possible that it was always nondeterministic and just depends on how fast the call to the storage layer executes. I think all of our in-tree clients will handle it either way.

[smarterclayton]

I'm fairly certain this never used to behave this way, because OpenShift
hasn't enabled the watch catch and we have never had a report of this until
we enabled the watch cache for Kube resources just recently.

On Wed, May 4, 2016 at 6:08 PM, Daniel Smith [email protected]
wrote:

It's possible that it was always nondeterministic and just depends on how
fast the call to the storage layer executes. I think all of our in-tree
clients will handle it either way.

—
You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub
#25151 (comment)

[smarterclayton]

I see what you mean about ordering - etcd remote call would almost never be
fast enough to beat the watch event. In practice, I suspect no one ever
saw this without the watch error.

Either way, for web sockets if we don't fix this clients can't get this
error (the browser eats the 410 during the websocket negotiation and client
code can't get access). So it's at least broken for web sockets.

On Wed, May 4, 2016 at 6:52 PM, Clayton Coleman [email protected] wrote:

I'm fairly certain this never used to behave this way, because OpenShift
hasn't enabled the watch catch and we have never had a report of this until
we enabled the watch cache for Kube resources just recently.

On Wed, May 4, 2016 at 6:08 PM, Daniel Smith [email protected]
wrote:

It's possible that it was always nondeterministic and just depends on how
fast the call to the storage layer executes. I think all of our in-tree
clients will handle it either way.

—
You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub
#25151 (comment)

[lavalamp]

Well, it should be easy to just not wait at all, maybe? I'm OK with changing this behavior.

[lavalamp]

Although, are web clients XSS hardened? I'm not sure that we're optimizing for them currently.

[liggitt]

If you mean CSRF, it isn't an issue with bearer token auth. Basic auth should already have a big warning around it saying "not safe with browsers"

[liggitt]

It's possible that it was always nondeterministic and just depends on how fast the call to the storage layer executes.

Maybe I'm missing something, but it seems deterministic to me. This is the uncached watch impl:

// Implements storage.Interface.
func (h *etcdHelper) WatchList(ctx context.Context, key string, resourceVersion string, filter storage.FilterFunc) (watch.Interface, error) {
    if ctx == nil {
        glog.Errorf("Context is nil")
    }
    watchRV, err := storage.ParseWatchResourceVersion(resourceVersion)
    if err != nil {
        return nil, err
    }
    key = h.prefixEtcdKey(key)
    w := newEtcdWatcher(true, h.quorum, exceptKey(key), filter, h.codec, h.versioner, nil, h)
    go w.etcdWatch(ctx, h.etcdKeysAPI, key, watchRV)
    return w, nil
}

once the resourceVersion parses, there is no path that returns a direct error, so all errors would have to be returned as an event via the ResultChan().

I don't see us reading from that until after we've already written a 200 and flushed: https://github.com/kubernetes/kubernetes/blob/master/pkg/apiserver/watch.go#L177

[cben]

Having read the docs, I was very surprised that "type": "ERROR" notices are sent as 200 (even over plain http), with the semantic code e.g. 410 only represented under object.code inside.
I see there was good motivation here to stick to 200, but it should be called out in the documentation.

https://kubernetes.io/docs/reference/using-api/api-concepts/#efficient-detection-of-changes doesn't show at all how watch returns errors, and it even says "clients must handle the case by recognizing the status code 410 Gone" which really makes one expect an actual HTTP 410.

[lavalamp]

@cben I agree this should be called out in the docs. Can you file a bug there and/or send a PR? I don't think this ~4 year old issue is the best place to track that. (Good detective work finding this, though!)