invenia / Memento.jl

A flexible logging library for Julia
https://invenia.github.io/Memento.jl/latest
Other
87 stars 14 forks source link

Make TimeZones.jl and Syslogs.jl optional dependencies #182

Closed rofinn closed 2 years ago

rofinn commented 2 years ago

AFAICT, this shouldn't be breaking because our formatting code still produces the same output. The only differences is that our records are only storing localzone datetimes which are converted to the appropriate timezone when necessary.

codecov[bot] commented 2 years ago

Codecov Report

Merging #182 (d4b2fbc) into master (b557fed) will increase coverage by 0.02%. The diff coverage is 100.00%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master     #182      +/-   ##
==========================================
+ Coverage   98.23%   98.25%   +0.02%     
==========================================
  Files          13       14       +1     
  Lines         396      401       +5     
==========================================
+ Hits          389      394       +5     
  Misses          7        7              
Impacted Files Coverage Δ
src/syslog.jl 100.00% <ø> (ø)
src/Memento.jl 100.00% <100.00%> (ø)
src/formatters.jl 98.03% <100.00%> (-0.11%) :arrow_down:
src/records.jl 94.11% <100.00%> (ø)
src/tz.jl 100.00% <100.00%> (ø)

Continue to review full report at Codecov.

Legend - Click here to learn more Δ = absolute <relative> (impact), ø = not affected, ? = missing data Powered by Codecov. Last update b557fed...d4b2fbc. Read the comment docs.

rofinn commented 2 years ago

NOTE: I haven't changed the tests at all, but we actually handle a case now that wasn't used before, when the record field is a DateTime and output_tz is set. I'll add an extra test for that use case if folks seem okay with this.

rofinn commented 2 years ago

Since one concern of using Requires.jl is that it can impact load times I've also run some adhoc tests.

Current:

julia> @time using Memento
[ Info: Precompiling Memento [f28f55f0-a522-5efc-85c2-fe41dfb9b2d9]
  3.666940 seconds (2.75 M allocations: 171.231 MiB, 1.06% gc time, 14.89% compilation time)
...
julia> @time using Memento
  0.845733 seconds (1.30 M allocations: 86.864 MiB, 3.01% gc time, 0.40% compilation time)
...
julia> @time using Memento
  0.850416 seconds (1.30 M allocations: 86.862 MiB, 2.98% gc time, 0.38% compilation time)

Proposed:

julia> @time using Memento
[ Info: Precompiling Memento [f28f55f0-a522-5efc-85c2-fe41dfb9b2d9]
  2.175065 seconds (2.55 M allocations: 151.316 MiB, 1.63% gc time, 25.91% compilation time)
...
julia> @time using Memento
  0.745858 seconds (1.10 M allocations: 66.871 MiB, 1.46% gc time, 0.50% compilation time)
...
julia> @time using Memento
  0.637695 seconds (1.10 M allocations: 66.871 MiB, 1.40% gc time, 0.69% compilation time)

Proposed w/ TimeZones:

julia> @time using TimeZones, Memento
  1.019449 seconds (1.79 M allocations: 109.391 MiB, 2.13% gc time, 0.41% compilation time)
...
julia> @time using TimeZones, Memento
  0.985635 seconds (1.79 M allocations: 109.460 MiB, 2.22% gc time, 0.31% compilation time)
...
julia> @time using TimeZones, Memento
  1.041589 seconds (1.79 M allocations: 109.430 MiB, 2.37% gc time, 0.38% compilation time)

Obviously, it's a little worse when using both Memento and TimeZones, but that seems similar to the relative improvement when you don't need TimeZones.jl.

One thing that's annoying is that Julia seems to give this warning when using the Requires.jl solution, which is annoying.

┌ Warning: Package Memento does not have TimeZones in its dependencies:
│ - If you have Memento checked out for development and have
│   added TimeZones as a dependency but haven't updated your primary
│   environment's manifest file, try `Pkg.resolve()`.
│ - Otherwise you may need to report an issue with Memento
└ Loading TimeZones into Memento from project dependency, future warnings for Memento are suppressed.
rofinn commented 2 years ago

Nevermind, If if fix the warning the load times are pretty close to the current release.

julia> @time using TimeZones, Memento
  0.822394 seconds (1.21 M allocations: 75.391 MiB, 1.57% gc time, 0.49% compilation time)
...
julia> @time using TimeZones, Memento
  0.804423 seconds (1.21 M allocations: 75.492 MiB, 1.40% gc time, 0.52% compilation time)
rofinn commented 2 years ago

I think @iamed2 added the initial code to store timestamps in UTC time. Do you see any issue with just storing a localzone datetime which can be converted to a specific timezone with the output_tz argument? I don't remember if there was a specific issue where you needed the actual record to store a UTC ZonedDateTime?

https://github.com/invenia/Memento.jl/pull/94

iamed2 commented 2 years ago

Nevermind, If if fix the warning the load times are pretty close to the current release.

julia> @time using TimeZones, Memento
  0.822394 seconds (1.21 M allocations: 75.391 MiB, 1.57% gc time, 0.49% compilation time)
...
julia> @time using TimeZones, Memento
  0.804423 seconds (1.21 M allocations: 75.492 MiB, 1.40% gc time, 0.52% compilation time)

What happens in the ...? This is what I'm seeing with TimeZones 1.6.2 and Memento 1.2.0:

julia> @time using TimeZones, Memento
  1.582060 seconds (2.43 M allocations: 147.404 MiB, 0.78% gc time, 89.17% compilation time)

julia> @time using TimeZones, Memento
  0.000474 seconds (306 allocations: 22.719 KiB)

Are those actually separate Julia sessions?

iamed2 commented 2 years ago

I think @iamed2 added the initial code to store timestamps in UTC time. Do you see any issue with just storing a localzone datetime which can be converted to a specific timezone with the output_tz argument? I don't remember if there was a specific issue where you needed the actual record to store a UTC ZonedDateTime?

94

I think e.g. CloudWatchLogs.jl will still work correctly, although this incorrect documentation says it won't...

EDIT: according to the TimeZones.jl documentation it will work correctly, but in practice it doesn't. The CloudWatchLogs.jl documentation is correct. EDIT2: PR made for TimeZones.jl documentation which might be technically not incorrect: https://github.com/JuliaTime/TimeZones.jl/pull/367

iamed2 commented 2 years ago

Alright, storing local time will break CloudWatchLogs.jl. Would you rather coordinate updates and manually change the registry to upper-bound Memento for existing versions of CloudWatchLogs.jl, or release a breaking Memento release?

rofinn commented 2 years ago

I think e.g. CloudWatchLogs.jl will still work correctly, although this incorrect documentation says it won't...

No, I'm pretty sure that'll result in inaccurate timestamps. I do think CloudWatchLogs.jl should assume localzone since that's what the rest of the Julia ecosystem assumes (e.g., now, today, ZonedDateTime). I'm fine with a conversion to ensure that the output is always a UTC unix timestamp, but that doesn't seems like a reasonable default for a generic logging library if we don't want to directly depend on the TimeZones.jl package.

rofinn commented 2 years ago

Yeah, this seems like a pretty specific edge case that I don't expect to impact most users and isn't very well documented yet. I'm inclined to make this a minor release for Memento and more clearly document what's stored in the default record and why. We can upper bound the Memento version in CWL.jl and then update it properly after this gets merged and tagged. Since neither package is that active I imagine most folks won't even notice.

rofinn commented 2 years ago

Are those actually separate Julia sessions?

Yes, cause I wanted to measure time to first load.

rofinn commented 2 years ago

Looks like I don't need to bump the minor release cause registrator was never triggered on https://github.com/invenia/Memento.jl/pull/177

rofinn commented 2 years ago

Alright, I think once the CWL.jl change is merged (to avoid breaking nightly CI) we should be good to merge and tag a 1.3 release.

rofinn commented 2 years ago

Bump. I think this should be good now that both the Registry change and CWL.jl have been updated.