chore(android-sqlite): Repair start times of spans generated by SentrySQLiteDriver

[0xadam-brown]

📜 Description

Repairs the nanoTimetamp of the SentryNanotimeDates used as start times for the spans generated by SentrySQLiteDriver.

For more details, see the discussion here. This PR implements approach [1] ("Offset SQLite spans based nano duration between parent and child start times").

💡 Motivation and Context

Without those repairs, all spans within a given wall clock millisecond are displayed by Sentry UI as starting at that same millisecond and are re-ordered arbitrarily. Often that's quite confusing as actual BEGIN -> EXECUTE STATEMENT -> END sequences can appear as EXECUTE STATEMENT -> END -> BEGIN (etc.).

JAVA-275

Screenshots

Before

(Link)

After

(Link)

Before

(Link)

After

(Link)

💚 How did you test it?

• Unit tests
• Via the sample app + verifying span appearance in Sentry UI (see screenshots above)

📝 Checklist

• I added GH Issue ID & Linear ID
• I added tests to verify the changes.
• No new PII added or SDK only sends newly added PII if sendDefaultPII is enabled.
• I updated the docs if needed.
• I updated the wizard if needed.
• Review from the native team if needed.
• No breaking change or entry added to the changelog.
• No breaking change for hybrid SDKs or communicated to hybrid SDKs.

🔮 Next steps

Consider implementing nesting of spans as mentioned here.

[sentry]

📲 Install Builds

Android

🔗 App Name	App ID	Version	Configuration
SDK Size	io.sentry.tests.size	8.43.2 (1)	release

⚙️ sentry-android Build Distribution Settings

[github-actions]

Performance metrics 🚀

	Plain	With Sentry	Diff
Startup time	333.56 ms	363.85 ms	30.29 ms
Size	0 B	0 B	0 B

Baseline results on branch: main

Startup times

Revision	Plain	With Sentry	Diff
a416a65	333.78 ms	410.37 ms	76.59 ms
d15471f	304.55 ms	408.43 ms	103.87 ms
ca6b6d8	380.45 ms	460.38 ms	79.93 ms
c8125f3	397.65 ms	485.14 ms	87.49 ms
b936425	302.69 ms	372.86 ms	70.17 ms
ed33deb	334.19 ms	362.30 ms	28.11 ms
cf708bd	408.35 ms	458.98 ms	50.63 ms
eb95ded	317.51 ms	369.08 ms	51.57 ms
a5ab36f	320.47 ms	389.77 ms	69.30 ms
80fd6ad	321.06 ms	375.79 ms	54.73 ms

App size

Revision	Plain	With Sentry	Diff
a416a65	1.58 MiB	2.12 MiB	555.26 KiB
d15471f	1.58 MiB	2.13 MiB	559.54 KiB
ca6b6d8	0 B	0 B	0 B
c8125f3	1.58 MiB	2.10 MiB	532.32 KiB
b936425	0 B	0 B	0 B
ed33deb	1.58 MiB	2.13 MiB	559.52 KiB
cf708bd	1.58 MiB	2.11 MiB	539.71 KiB
eb95ded	0 B	0 B	0 B
a5ab36f	1.58 MiB	2.12 MiB	555.26 KiB
80fd6ad	0 B	0 B	0 B

Previous results on branch: chore/offset-sqlite-start-timestamps

Startup times

Revision	Plain	With Sentry	Diff
eb8ae87	323.80 ms	377.66 ms	53.86 ms
455bc3a	473.69 ms	605.96 ms	132.27 ms
3cacd74	342.60 ms	409.53 ms	66.93 ms
48f43f7	333.27 ms	443.52 ms	110.25 ms

App size

Revision	Plain	With Sentry	Diff
eb8ae87	0 B	0 B	0 B
455bc3a	0 B	0 B	0 B
3cacd74	0 B	0 B	0 B
48f43f7	0 B	0 B	0 B

[runningcode]

Thanks for looking at this tricky problem. I might be missing some context and I realize that the dates in our codebase are a mess.

Is it possible to pass around timestamp offsets as long everywhere? This would keep maximum precision and improve performance.

I realize that we lose type safety here, but creating two date objects in recordSpan in order to do arithmetic seems quite heavy when these transactions require nanosecond precision.

Otherwise if using a long isn't possible, what stops us from using a more precise date object like SentryNanotimeDate instead of SentryDate?

[0xadam-brown]

@runningcode – thanks much for your comments. I'll reply presently.

Fyi, looks like you reviewed this in the few minutes between my merging the underlying branch + retargeting this PR. Apologies! Fyi, I've re-pushed. What you saw that was relevant to this PR is in the first commit (unchanged). What little is new (just making the key repair method internal so I can write better tests against it) is in the second commit. No need to look again until I've replied to your comments.

[0xadam-brown]

@runningcode – great questions! Answers below

Is it possible to pass around timestamp offsets as long everywhere? This would keep maximum precision and improve performance.

Yes! but there are few extra pieces we need to account for. In particular, three constraints show up if we want to record a span start time with ns-precision:

1. we need a wall clock instant in order to peg the timestamp to the epoch;
2. we need a nanosecond to compute the offset from the wall clock instant (the instant + offset is our timestamp's ns-precise value); and
3. we have to pass a SentryDate to the span creation API b/c it requires as much.

At present we're getting (1) and half of (2) from the parent span (which is created by other code we don't control, so we can ignore its cost). We get the other half of (2) from a SentryDate we request from the globally available SentryDateProvider...

...and it's the creation of that provided date that's wasteful, not the creation of the SentryLongDate in the repair method. (Requirement (3) means the creation of a SentryDate has to happen somewhere, and we know we need a SentryLongDate b/c it's the only way on Android to capture a ns-precise timestamp. So the best we can do is to create a single SentryLongDate and skip the SentryNanotimeDate from the provider.)

The nub, then, becomes extracting the nanos value from the parent without the (otherwise superfluous) SentryNanotimeDate. That's tricky b/c SentryNanotimeDate doesn't expose its nanos field directly and the relevant diff API expects another SentryDate instance.

But @markushi has shown the way in SpanFrameMetricsCollector 🎉. We can copy the approach there and allocate a single SentryNanotimeDate when SQLiteSpanInstrumentation is initiated (cf. here and here).

...and that should do it!

Thanks for challenging this point. I didn't think past the expectations of the diff API in my original approach, and so I didn't question the idea of getting the SentryDate from the provider. Good stuff 💯

Otherwise if using a long isn't possible, what stops us from using a more precise date object like SentryNanotimeDate instead of SentryDate?

Fyi, we're already using SentryNanotimeDate everywhere on Android. Part of what makes that class confusing is that its nanoTimestamp() method is misnamed. The 'timestamp' part is correct; the 'nano' part is sometimes wrong on the JVM and always wrong an Android. IMO, it'd be better if it were called instant() or epochalTimestamp(), b/c its return value represents the wall clock instant ticked off from the Unix epoch at whatever resolution the platform allows.

Note: on Java 9+ Instant.now() actually provides sub-ms precision (sometimes microsecond, sometimes nanosecond, depending on the JVM, IIRC). (See the SentryInstantDate implementation, which relies on Instant.) So if the world consisted solely of SentryInstantDate running on JVMs targeting Java 9+, we'd see a microsecond- or ns-precise epochal timestamp returned by nanoTimestamp() and the name would make sense. The problem is pre-Java 9 environments still see ms-precision, as does anything before Android 33, as that was the first Android API to introduce sub-ms precision with Instant.now(). (Ten years from now when our minSdk is 33 😅 , we can get rid of SentryNanotimeDate and use SentryInstanceDate everywhere.)

[runningcode]

If we are already using SentryNanodateTime everywhere on Android as you say, can we enforce that using types if it would simplify the code?

[runningcode]

I'll approve this since it is an improvement. We should probably have another reviewer take a look given the complexity.

[0xadam-brown]

If we are already using SentryNanodateTime everywhere on Android as you say, can we enforce that using types if it would simplify the code?

That's a great question. The short answer is no b/c, when I said we're using SentryNanotimeDate everywhere on Android, I was being hand-wavy. We occasionally use SentryLongDate too.

SentryNanotimeDate is used "everywhere" in the sense that the universally-available SentryDateProvider (scopes.options.dateProvider) on Android always exposes a SentryAndroidDateProvider, and that in turn always vends a SentryNanotimeDate. But nothing stops Android code (or a user) from hand-rolling SentryLongDate's. And sometimes we do just that (eg, ActivityLifecycleIntegration does so for some app start transactions).

That's^^ the global reason. W/r/t local declarations, analyzing whether SentryNanotimeDate is safe or SentryDate is needed one method at a time is probably too burdensome in most scenarios (esp when the source of those dates originates from a SentryDate declaration we can't change, eg, scopes.span). But folks could always do so if it ever makes sense.

[markushi]

Looks great, thanks for following this rabbit hole down to the root cause.