Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use garbage-free formatter for s and S patterns #3338

Merged
merged 15 commits into from
Dec 31, 2024

Conversation

ppkarwasz
Copy link
Contributor

This PR improves #3139, by introducing a new InstantPatternFormatter for patterns of the form "ss.S{n}". Unlike the previous formatter based on DateTimeFormatter, the formatter is garbage-free.

We also simplify the merging algorithm for pattern formatter factories, by moving the merging logic to the pattern formatter factories themselves.

This PR does not contain a separate change log entry, since #3139 has not been published yet.

Fixes #3337.

This PR improves #3139, by introducing a new `InstantPatternFormatter` for patterns of the form "ss\.S{n}". Unlike the previous formatter based on `DateTimeFormatter`, the formatter is garbage-free.

We also simplify the merging algorithm for pattern formatter factories, by moving the merging logic to the pattern formatter factories themselves.

This PR does not contain a separate change log entry, since #3139 has not been published yet.

Fixes #3337.
@ppkarwasz ppkarwasz requested a review from vy December 27, 2024 19:04
Copy link
Member

@vy vy left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like the changes, they are to-the-point and restores the old garbage-free date & time formatting without involving [too much] manual computation. 💯 I would really really appreciate 🥺 if we can restore the old

  • PatternSequence name (IMHO, it greatly lowers the cognitive barrier compared to overloading the overloaded formatter concept.)
  • Method (i.e., tryMerge()) documentation with examples

Additionally,

  • Mind sharing the before-after results for InstantPatternFormatterBenchmark and InstantPatternFormatterBenchmark, please?
  • Manual needs to be updated on parts where subminute precision is stated to be not garbage-free

Allow me to remind that the long-term maintainability (readability & simplicity) of this particular piece of code is of uttermost importance. We implemented several date & time formatters each having its own quirks because we could not dare to fix/extend the old one.

Copy link
Member

@vy vy left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Left some minor comments, overall code changes LGTM. 💯 IMHO, we should still

  1. Share benchmark results
  2. Update pattern-layout.adoc (on garbage-free aspects of %d)

@ppkarwasz
Copy link
Contributor Author

Here are the results of the InstantPatternFormatterBenchmark using:

  • Temurin 22.0.2
  • 32 threads of an AMD EPYC 7351P 16-Core processor (with hyperthreading)

Each operation formats 1000 timestamps that differ less than a second between each other.

Reference

Formatter type Format Score Error Units
FastDatePrinter yyyy-MM-dd'T'HH:mm:ss.SSS 76.0 ±0.87 kops/ms
FastDatePrinter HH:mm:ss.SSS 119.1 ±2.3 kops/ms
FixedDateFormat yyyy-MM-dd'T'HH:mm:ss.SSS 632.6 ±.35 kops/ms
FixedDateFormat HH:mm:ss.SSS 632.8 ±.32 kops/ms
DateTimeFormatter yyyy-MM-dd'T'HH:mm:ss.SSS 16.0 ±6.4 kops/ms
DateTimeFormatter HH:mm:ss.SSS 43.9 ±16.8 kops/ms

Where FastDatePrinter and FixedDateFormat are legacy Log4j Core 2 formatters.

Before

Formatter type Format Score Error Units
InstantPatternFormatter yyyy-MM-dd'T'HH:mm:ss.SSS 23.3 ±6.3 kops/ms
InstantPatternFormatter HH:mm:ss.SSS 28.0 ±3.5 kops/ms

After

Formatter type Format Score Error Units
InstantPatternFormatter yyyy-MM-dd'T'HH:mm:ss.SSS 246.0 ±6.0 kops/ms
InstantPatternFormatter HH:mm:ss.SSS 248.9 ±5.5 kops/ms

I wouldn't attach too much importance to the precise numbers, since DateTimeFormatter seems to suffer from some multi-threading issues, but the performance has clearly improved.

Running the benchmark on a single thread for the two best performing implementations gives:

  • Around 34.5 kops/ms for FixedDateFormat.
  • Around 12.7 kops/ms for InstantPatternFormatter.

Note that FixedDateFormat only supports specific date formats, while InstantPatternFormatter supports all the date formats. 20 µs per operation seems a fair price to pay for flexibility.

@ppkarwasz
Copy link
Contributor Author

In 0b198fc, I optimized performance a little bit, by:

  • replacing iterations over an ArrayList to iteration over an array.
  • unrolling the common case of two pattern sequences.
  • rewriting formatFractionalDigits to only use StringBuilder.append() and output the digits in order.
  • unrolling formatFractionalDigits for the common case of millisecond precision.

Overall this gives a performance around 60% higher on the ISO8601 format:

Formatter type Format Score Error Units
InstantPatternFormatter yyyy-MM-dd'T'HH:mm:ss.SSS 393.8 ±18.1 kops/ms
InstantPatternFormatter HH:mm:ss.SSS 375.0 ±14.4 kops/ms

It also doubles the single-thread performance (around 23.1 kops/ms).

@ppkarwasz ppkarwasz merged commit 81b0aed into 2.x Dec 31, 2024
9 checks passed
@ppkarwasz ppkarwasz deleted the feature/2.x/instant-formatter branch December 31, 2024 09:54
@vy
Copy link
Member

vy commented Jan 14, 2025

@ppkarwasz, a734365 invalidated log4j-perf-test/README.adoc, am I mistaken? If not, would you mind fixing it, please?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[MS27] Unified Date and Time Format #3
2 participants