Setting log level to BODY deactivates EventHandler

[automatictester]

Configuring EventSource with OkHttpClient using HttpLoggingInterceptor with log level set to BODY deactivates EventHandler. Method onMessage will not execute any more.

No other log levels cause this problem. Reproducible on Java 8 and 11.

Complete project with fully reproducible scenario: here.

This is either a very unusual defect, or there must be something that I missed.

[eli-darkly]

At first glance, it looks to me like the implementation of HttpLoggingInterceptor, when body logging is turned on, attempts to buffer the entire response body so it can log it— and then play it back from the buffer for the application code that wants to read the body. That's pretty much the only way such a thing can work.

But that assumes that the response is finite. A streaming response, as long as the connection is still alive, doesn't end... so the interceptor never stops buffering, and the client code never gets to see the response data. That would be my guess.

My recommendation would be basically "don't do that"; what is it exactly that you're hoping to accomplish in this case by turning on the BODY level?

[automatictester]

I set the log level to BODY as this is considered to be the most verbose log level available. Then things stopped working and it took me a while to figure out that's the culprit. I can use other log level, e.g. HEADERS.
It is a bit scary when changing log level can break your code, isn't it? :) Is there anything you can do to prevent, or at least help people avoid such problems?
What about e.g. throwing IllegalArgumentException in EventSource.Builder if the provided instance of OkHttpClient has interceptor with such a log level configured?

[eli-darkly]

It is a bit scary when changing log level can break your code, isn't it?

I take your point, but... the existence of the interceptor mechanism in OkHttp makes it impossible for any client code that accepts a pre-configured OkHttp client to guarantee that an interceptor won't interfere with responses somehow. And the way HttpLoggingInterceptor is written, it is not really just a logging component; it transforms the response, and it blocks all further processing until the response is complete, which is totally inappropriate for use with any streaming API. I wish they had documented that a bit better (or at all, really) since indeed most people wouldn't expect logging to have side effects like that.

I think at a minimum we should add some documentation of our own—probably in the doc comments for EventSource.Builder.client and EventSource.Builder.clientBuilderActions—to warn people about this issue with HttpLoggingInterceptor.

I'm less sure about your suggestion of having EventSource.Builder inspect the interceptors. That's clever, but it makes our code reliant on details of the OkHttp API (like, both the name of that interceptor class and the fact that it has a public getter for the level property) that are pretty unrelated to what the EventSource library is for—and, more to the point, it doesn't fully protect against this problem, because it is always possible for the application to add more interceptors to the client at a later time, or to use some other interceptor that has the same kind of problem but that we don't happen to have noticed yet. So, rather than trying to block the application from using someone else's library in this one particular potentially harmful way, I feel like it'd be better to give people the information they need to be aware of this potential problem or troubleshoot it if it's happened.

[eli-darkly]

In fact, it looks like this is a known issue which they've decided not to address:

square/okhttp#4298

[eli-darkly]

(Another reason not to do the "inspect the interceptors" thing is that if the OkHttp maintainers changed their mind and actually fixed HttpLoggingInterceptor to get rid of this problem—for instance, using any of the three approaches that were suggested on that GitHub issue—our code would still be preventing you from using that class, so you wouldn't be able to take advantage of the fix until we noticed it and released a patch of our own. I realize that they've made it pretty clear they're not going to fix it, but it's still a good principle not to bake knowledge of a current bug in the current version of someone else's code into one's own code.)