Bandwidth meter reporting wrong speeds when used with HttpLoggingInterceptor

[limdale]

Hi, we have observed an issue where ABR doesn't work for our app's debug builds.

It seems this is caused by the bandwidth meter reporting insanely fast speeds when an OkHttp HttpLoggingInterceptor is present - up to 100x than normal. As a result ABR will always choose the highest quality regardless of network connection.

I've tested it on the demo app by adding the OkHttp data source and interceptor, then observing a Bitrate Estimate field that I added on the debug text. The branch on my changes can be found here. See the difference between the "Bitrate Estimate" on the two screenshots below:

No interceptor	With interceptor

I'm not 100% sure why it happens - but my guess is the bandwidth meter doesn't factor in the time it takes interceptor to read the response. By the time transferStarted is called, the subsequent read is significantly faster since it's stored in some buffer?

[tianyif]

Hi @limdale,

Thanks for the reporting and repro branch! I could reproduce this scenario from my end.

Not being an expert of the OkHttp HttpLoggingInteceptor though, I did some searching around it, and I think your assumption makes sense to me. According to https://square.github.io/okhttp/features/interceptors/, the Inteceptor sits in between the OkHttp Core and us until we got the response, and it can buffer the full body, thus it appears to us the elasped time from the time we got the response (onTransferStart) to the time we finished reading (onTransferEnd) will be much shorter. One observation from the BandwidthMeter to validate this is that the samples of the similar size:

• Without Interceptor:

androidx.media3.demo.main            W  sampleBytesTransferred: 28978040 sampleElapsedTime: 5000

• With Interceptor:

androidx.media3.demo.main            W  sampleBytesTransferred: 29140284 sampleElapsedTime: 75

It looks like the BODY level logging is only expected to be used for development only (square/okhttp#4273 (comment)), but I understand that you want to validate the network transfer as well as ensure the the player works normally at the debugging stage. I'm wondering if you could get the the desired insights from a our TransferListener, which is not intrusive to the transfer process. You can add the TransferListener to the OkHttpDataSource.Factory. If that doesn't work, writing a custom Interceptor is an alternative that is suggested from Okhttp team (from the above linked comment).

[limdale]

Thank you for looking into it @tianyif

I'm not sure if adding another TransferListener to the OkhttpDataSource will make any difference, since the problem is the way OkhttpDataSource notifies its transfer listeners in the first place. By the time the OkhttpDataSource calls onTransferStart on all it's listeners, the data has already been buffered.

Also this doesn't address the main issue I have with ABR not working. I believe this is because DefaultBandwidthMeter itself is a TransferListener too, and is attached to the same OkhttpDataSource. DefaultBandwidthMeter reporting the wrong speeds causes ABR to fail.

It seems like the only option now is to have a custom interceptor. Another potential fix I'm eyeing is having the bandwidth meter also count onTransferInitializing when sampling - just out of curiosity is there a reason why DefaultBandwidthMeter doesn't do this?