Negative Request Timing from URLSession delegate for TransactionMetrics

Hello,

We recently had a surge in following issue, although this seems like something that always existed (With Apollo iOS 0.x too).

We implement urlSession(_:task:didFinishCollecting:) delegate method and collect request metrics, We saw URLSessionTaskTransactionMetrics object (transactionMetrics.first) sometimes reports a negative request duration. Here we calculate request timing as the interval between metrics.responseEndDate and metrics.fetchStartDate and for some requests, this value is negative.

This issue occurs randomly, across different query types and endpoints and Our URLRequest.cachePolicy for most of these requests is set to .reloadIgnoringLocalCacheData for most of these graphql requests.

Are we aware of this issue or what might cause request timings to be negative? This might be fixed in Apollo 2.0 with networking stack changes but I want to understand what is happening here.
Thanks!

Hey there @Reshu_Malik ,

I don’t believe we’ve ever had reports of anything like this before, but I don’t think I’ve spoken with anyone about using Apollo with URLSessionTaskTransactionMetrics. I’m not sure what could be causing this.

I’d like to see a reproduction case to figure out what is going on here. But it sounds like this isn’t happening consistently, and a reproduction might be difficult to create. I’m not really sure where to even start with this.

What we are doing is calculating time taken by request which we log for some metrics transactionMetrics.responseEndDate - transactionMetrics.fetchStartDate
This is coming out to be negative for some of the requests. From our logs we can see that its happening for multiple operations most of them with cachePolicy `.fetchIgnoringCacheCompletely`.

Yes, it’s not happening consistently, We are logging these in prod. I saw an earlier issue here which is not same but could these two be related?

It’s possible these are related. We never resolved that issue, but we are about to release Apollo iOS 2.0 which does not interact with the URLSessionDelegate at all, so this should be a non-issue in 2.0. Or if it is still an issue, it’s would almost certainly be an Apple bug, not an Apollo bug.

Thanks for making the community aware of this issue. I don’t think there is anything actionable that we can do to resolve this in 1.0 without a reproduction case though.