File I/O Instrumentation with OkHttp Cache enabled

[ssputay]

Problem Statement

When I enabled caching in the OkHttp client and activated File I/O Sentry instrumentation, I observed that the file.write span always ends with a deadline_exceeded status. This occurs due to the way OkHttp's DiskLruCache manages the journal file internally - it keeps the journalWriter open until explicitly closed.

Sentry SDK: 8.13.2 Sentry Gradle Plugin: 5.8.0

Solution Brainstorm

Ideally, we want the span to be properly closed each time cached data is flushed (written). Perhaps the Sentry SDK could handle this differently if the File I/O operation originates from the OkHttp cache. Alternatively, it would be beneficial if we could filter this span out, preventing its duration from contributing to the total ui.load time.

[linear[bot]]

JAVA-122 File I/O Instrumentation with OkHttp Cache enabled

[kahest]

Thanks for reporting, just posting here to acknowledge we're looking into this and currently discussing solutions

[kahest]

from internal discussion: we should probably change our instrumentation to create spans from first write  to either flush or close something like that. Probably will come up as a surprise for some people, but we could have an option controlling the behavior to easily switch it to the old one (current) (fyi @romtsn)

[markushi]

Adding on to this, a .flush() could trigger a span.finish(), and any consecutive write() will cause a new span creation again.

[markushi]

Alternatively, it would be beneficial if we could filter this span out, preventing its duration from contributing to the total ui.load time.

@ssputay As of now you could use our beforeSendTransaction() hook to remove those spans. See our docs for an example on how to get started with this.

[ssputay]

Alternatively, it would be beneficial if we could filter this span out, preventing its duration from contributing to the total ui.load time.

@ssputay As of now you could use our beforeSendTransaction() hook to remove those spans. See our docs for an example on how to get started with this.

Thanks for follow up. I've tried the filtering approach as below:

SentryAndroid.init(context) { options ->
            ...
            options.beforeSendTransaction = SentryOptions.BeforeSendTransactionCallback { transaction, _ ->
                if (transaction.transaction == "MyMainActivity") {
                    transaction.spans.removeAll { it.op == "file.write" && it.status == SpanStatus.DEADLINE_EXCEEDED }
                }
                transaction
            }
        }

in this case, the file.write span isn't sent, but the total ui.load time is still around ~32 seconds, meaning the write operation still contributes to the overall time. Is there a way to prevent it from contributing to the total duration?

[markushi]

@ssputay Oh I see, yes at this point the timestamps of the ui.load transaction won't be trimmed anymore to it's child spans. Unfortunately there's no way around this right now, as there's no public API to modify those timestamps. Let me discuss this internally, as this seems to be a common use case.

Would it be an option to rely on the ui.load.initial_display child span durations instead? Here are some more docs around this topic.