Skip to content

DateTimeOffset.Now TimeZone data impacts Android startup #71004

Closed

Description

@jonathanpeppers

Description

Reviewing a customer issue, we noticed any accidental usage of DateTimeOffset.Now has a noticeable impact to startup:

image

277ms is a lot of time given that the total startup time is 182ms of a dotnet new android app in Release mode. (It's also possible that 277ms is somewhat inflated by tracing)

If I record a custom AOT profile (to avoid JIT-ting), the time is better, but still shows up:

image

In this case, it would be better to use UtcNow, but I could see a lot of developers might run into this on accident. Is there anything we could do to improve this? Thanks!

Reproduction Steps

  1. dotnet new android
  2. Open MainActivity.cs and put _ = DateTimeOffset.Now; in the OnCreate() method.
  3. Build/run with dotnet build -c Release -t:Run

Expected behavior

DateTimeOffset.Now doesn't significantly slow down an Android app.

Actual behavior

DateTimeOffset.Now does seem to significantly slow down an Android app.

Regression?

No

Known Workarounds

Use UtcNow?

Configuration

I tested this with the .NET 6.0.400-preview.22301.10 SDK, and the SR 1 version of .NET MAUI.

Other information

Here is dotnet trace output:

datetimeoffset.now.zip

One is default settings (code path is JIT), and the second is using an AOT profile (code path is AOT).

Activity

  1. ghost added
    untriagedNew issue has not been triaged by the area owner
    on Jun 20, 2022
  2. Clockwork-Muse commented on Jun 20, 2022

    @Clockwork-Muse
    Contributor

    DateTimeOffset.Now doesn't significantly slow down an Android app.

    It's not DateTimeOffset.Now - it's everything under that to get the (local) offset that's the real culprit. The moment you need a localized value of some sort you're going to incur the cost to get the necessary info.

  3. steveisok commented on Jun 23, 2022

    @steveisok
    Member
  4. added this to the 6.0.x milestone on Jun 30, 2022
  5. steveisok commented on Jun 30, 2022

    @steveisok
    Member

    I suspect most of the cost is due to parsing the timezone xml file on device.

  6. modified the milestones: 6.0.x, 7.0.0 on Jun 30, 2022
  7. mdh1418 commented on Jul 1, 2022

    @mdh1418
    Member

    DateTimeOffset.Now should not be equal to DateTimeOffset.UtcNow unless the device/emulator's system settings are set to be in UTC.

    I took a look at the previous behavior (also the existing behavior for non Android Unix platforms) prior to #54845 (≈which overhauled the previous behavior and followed the mono/mono implementation that had performance in mind) and it returns Utc because it fails to find the timezone data, and by consequence, it doesn't find the correct current timezone that would represent DateTimeOffset.Now. Here is a speedscope of a sample where I ported over the previous behavior https://gist.github.com/mdh1418/6f4671548bcadb4c8ec7563f99e26abe. It would make sense that DateTimeOffset.Now is quick 67.89ms! if it fails fast and returns a default.

    I made modifications to have the previous behavior look for the tzdata file in the correct locations (noted in #54845 description), and the time for DateTimeOffset.Now is 690.38ms https://gist.github.com/mdh1418/6df6e249bb66f1caca3f10cf01865fdb. However, even with the right directories (and therefore a tzdata file), it fails to find the proper timezone and defaults to returning Utc.

    Running the current behavior, it took 555.76ms. https://gist.github.com/mdh1418/e037763acd0cfa4ece6d046f34186223

    Both the current and previous behavior end up calling GetTimeZoneFromTzData, which is measured to be relatively similar at 209ms and 208ms.

    The current behavior instantiates an AndroidTzData instance (loading all of the tzdata into relevant arrays for faster lookup) and takes 221ms, a significant portion of which is due to filtering out Backward TimeZone IDs #64028, which fixes an issue where duplicate IDs show up. Removing the filtering, DateTimeOffset.Now takes 386.58ms https://gist.github.com/mdh1418/bc5ddcd343375dab598d9f4f464aac49.

    I ran these in Debug configuration, so the times are worse than in release, but relatively speaking, the new behavior performs better and actually returns the correct DateTimeOffset.Now.

    I'll look more into the logic to see if theres some more time savings to be made, but I agree that if the actual local time is to be obtained, the data needs to be loaded, and as stated before, the previous mono/mono implementation had performance in mind. Not sure if @grendello has any other ideas of ways to speed this up or if its taking longer than expected.

    Its worth investigating if GetTimeZoneFromTzData is optimal as that takes a significant portion of the time.

  8. grendello commented on Jul 1, 2022

    @grendello
    Contributor

    @mdh1418 I have one idea in two variants which might make startup less affected by this, however it would likely require some changes in both XA and MonoVM. Namely, XA startup code is Java and the JavaVM already has all the tz data loaded and the current tz selected when it calls into our code. We could grab the current local time and pass it to the runtime as the default value for DateTimeOffset.Now (as well as DateTime.Now). In addition to the current time in Java, we also obtain the value of the kernel monotonic clock (by calling clock_gettime (CLOCK_MONOTONIC, ...)) and pass that to the runtime as well. With these values, when *.Now is first called, we can call clock_gettime again, add it to the stored default *.Now value and return current time with reasonable accuracy (the difference between the actual time and the calculated one should be more than a millisecond, usually less than that most probably). At the same time, MonoVM kicks off the process of finding and retrieving the current tz data in a background thread, so that the next time *.Now is called we get the actual time.

    The other variant would be to use *.UtcNow and obtain, in Java, the current zone offset from UTC and make the first call to *.Now use that to calculate the time. The rest would remain the same. The previous idea, even though more complicated, might be faster (depending on what Java does when requesting the offset vs the current local time - it would have to be measured).

  9. 9 remaining items

  10. jonpryor commented on Jul 1, 2022

    @jonpryor
    Contributor

    Perhaps I am mis-reading @mdh1418 's comment, but why can't we just use the mono/mono implementation? I don't see an explicit statement for why the mono/mono code -- which was working on Android -- cannot be used anymore.

  11. jonpryor commented on Jul 1, 2022

    @jonpryor
    Contributor

    Looks like #54845 was in fact a "port" of the mono/mono implementation. My bad.

  12. steveisok commented on Jul 1, 2022

    @steveisok
    Member

    @rgroenewoudt TimeZoneInfo.GetLocalUtcOffset() could use the value we'd store after obtaining it from the API in the previous comment. Ideally, we should avoid doing any JNI during startup, if possible. Local timezone offset could become a parameter to monovm_initialize_preparsed (possibly a member of the MonoCoreRuntimeProperties struct?)

    If that doesn't cost too much, I would prefer this option.

  13. grendello commented on Jul 1, 2022

    @grendello
    Contributor

    @rgroenewoudt TimeZoneInfo.GetLocalUtcOffset() could use the value we'd store after obtaining it from the API in the previous comment. Ideally, we should avoid doing any JNI during startup, if possible. Local timezone offset could become a parameter to monovm_initialize_preparsed (possibly a member of the MonoCoreRuntimeProperties struct?)

    If that doesn't cost too much, I would prefer this option.

    I'm counting on Java being able to access the tz data quicker than us, which should be the case.

    Also, this isn't much, but this code may be kicking off ICU loading. It might be worth doing something similar to what @jonathanpeppers did in this PR. Another good suggestion from @jonathanpeppers that came up in a discussion about this issue on Discord was that tz code could use ArrayPool to not only save memory but also probably speed up the code a bit.

  14. moved this from Todo: Performance to Future: Performance in .NET 7 MAUI Performanceon Aug 18, 2022
  15. ghost added
    in-prThere is an active PR which will close this issue when it is merged
    on Aug 23, 2022
  16. Repository owner moved this from Future: Performance to Done: Performance in .NET 7 MAUI Performanceon Sep 1, 2022
  17. ghost removed
    in-prThere is an active PR which will close this issue when it is merged
    on Sep 1, 2022
  18. ghost locked as resolved and limited conversation to collaborators on Oct 2, 2022
  19. moved this from Done: Performance to Done & Blogged in .NET 7 MAUI Performanceon Oct 11, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Type

No type

Projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions