Eventing: Broker doesn't retry on "unexpected EOF" reading replies

[maschmid]

Describe the bug
Having a broker (mtbroker backed by InMemoryChannel, or KafkaChannel) with retries configured

  delivery:
    backoffDelay: PT1S
    backoffPolicy: linear
    retry: 20

and triggers subscribing knative services.

One of the ksvcs, written in golang, returns new events as replies.

The applications sporadically loses events when stream is unexpectedly terminated becase of a golang bug affecting the knative serving service

(see https://github.com/golang/go/issues/40747 , https://github.com/knative/serving/issues/6146 )

with the following error in mt-broker-filter logs:

{"level":"error","ts":"2021-01-28T17:13:15.221Z","logger":"mt_broker_filter","caller":"filter/filter_handler.go:220","msg":"failed to write response","error":"unexpected EOF","stacktrace":"knative.dev/eventing/pkg/mtbroker/filter.(*Handler).send\n\t/home/maschmid/go/src/knative.dev/eventing/pkg/mtbroker/filter/filter_handler.go:220\nknative.dev/eventing/pkg/mtbroker/filter.(*Handler).ServeHTTP\n\t/home/maschmid/go/src/knative.dev/eventing/pkg/mtbroker/filter/filter_handler.go:202\ngo.opencensus.io/plugin/ochttp.(*Handler).ServeHTTP\n\t/home/maschmid/go/src/knative.dev/eventing/vendor/go.opencensus.io/plugin/ochttp/server.go:92\nknative.dev/pkg/network/handlers.(*Drainer).ServeHTTP\n\t/home/maschmid/go/src/knative.dev/eventing/vendor/knative.dev/pkg/network/handlers/drain.go:88\nnet/http.serverHandler.ServeHTTP\n\t/usr/lib/golang/src/net/http/server.go:2843\nnet/http.(*conn).serve\n\t/usr/lib/golang/src/net/http/server.go:1925"}

The broker doesn't seem to attempt a retry in this case and the event the ksvc tried to reply is effectively lost.

Expected behavior
The broker with configured retries should attempt to retry when "unexpected EOF" error happens reading a reply.

To Reproduce
Hard to reproduce, the EOF event is very sporadic. In this case larger events (~30kB) are send by multiple producers. I believe this problem only occurs when using a ksvc that responds with events in an HTTP reply.

Knative release version
eventing 0.19.2

Additional context

[slinkydeveloper]

My opinion is that I consider the unexpected EOF on response a user error (sometimes it's even caused by a svc bug) and we shouldn't retry user errors, because they may cause unexpected behaviours from the user side.

IMO If a user needs to push back messages to the broker delivery in an "affordable" way, we should just tell him "send a request to the broker ingress"

[maschmid]

Note that flows ( https://knative.dev/docs/eventing/flows/sequence/ ) also depend on using replies...

Also, if the user specifies non-zero delivery.retry, they already must be prepared for the possibility of having the service invoked more than once with the same event.

Another point is that if you'd front the service by a proxy that would verify the responses are complete and a valid cloudevent and returned a 502 if not, we would retry it, right?

[vaikas]

Just making sure I understand what's happening first :)

We send an event, function responds but something goes wrong and we get EOF and the event is not retried?
My knee jerk reaction is that we should retry that, just like at the protocol level failure we'd retry, why not retry at the network level?

[slinkydeveloper]

Discussed during the Event Delivery WG February 9, 2021: We should retry this error. We also expressed interest in letting the user configure retry policies

[slinkydeveloper]

/assign

[slinkydeveloper]

/unassign

Now that I'm looking at it, for this particular issue, the problem is that the filter_handler doesn't execute retries at all, it's related to https://github.com/knative/eventing/issues/4821

[slinkydeveloper]

Depends on https://github.com/knative/eventing/issues/4873

[pierDipi]

Isn't the downstream dispatcher (channel dispatcher) responsible for retrying?

[slinkydeveloper]

Please let's move this discussion in #4873

[slinkydeveloper]

This doesn't depend on #4873 and it should be an easy fix. The filter http handler must return a retryable status code in case unexpected eof happens and then the caller "channel" will take care of retrying

[matzew]

@slinkydeveloper Isn't that just a matter of handling it here properly ?

https://github.com/knative/eventing/blob/master/pkg/mtbroker/filter/filter_handler.go#L213-L217

[matzew]

@maschmid do yoyu have some test-case yaml for this to share?

[slinkydeveloper]

@matzew yes, in case of err at this line https://github.com/knative/eventing/blob/master/pkg/mtbroker/filter/filter_handler.go#L214 it should reply back with a non 200 status code

[maschmid]

@matzew writeResponse should already be setting proper response error status correctly if the event was not read, so IMHO it may be that it is not an issue in the broker after all. In our original discussion with @slinkydeveloper we've thought we are sure that broker doesn't retry on EOF (which is kind of true, but irrelevant, as now we've realized it is actually channel's responsibilty to do the retry...) So as long as the broker returns an error status, it is working as intended.

I think we can close this then, and I'll try reproducing the problem again, this time seeing if it really was the channel dispatcher that missed the retry for some other reason.

[matzew]

@slinkydeveloper I can do that tomorrow or so, adding the check

[maschmid]

@matzew Any EOF during reply parsing should be handled by https://github.com/knative/eventing/blob/bb87cb13f77a7df783a632f05698050d9186d0da/pkg/mtbroker/filter/filter_handler.go#L277-L284 already (or potentially before that... ), so I think this case is already covered...

[slinkydeveloper]

/assign

[matzew]

@maschmid yes - and it does return currently a 502 ... so should be good?

But see the PR that changes it to 500 status code :thinking:

[maschmid]

502 should work as well, In https://github.com/knative/eventing/blob/master/pkg/kncloudevents/message_sender.go#L164 we retry anything >=300 , so I don't think any change is necessary now...

[slinkydeveloper]

@maschmid Are we 100% sure the error is at line 277 and not here?

    if err := cehttp.WriteResponseWriter(ctx, eventResponse, resp.StatusCode, writer); err != nil {
        return http.StatusInternalServerError, fmt.Errorf("failed to write response event: %w", err)
    }

[maschmid]

@slinkydeveloper I am not sure... The error in the logs was "msg":"failed to write response","error":"unexpected EOF"

But anyway, as I said above, I now tend to believe the "unexpected EOF" error in the broker logs was a red herring, and, without further evidence, we should just close this. (at this point we don't have any evidence that broker-filter doesn't return a 5xx error in this case)
```

[slinkydeveloper]

Ok I'm going to close it, if it pops up again and you have a repro for that, reopen it