Skip to content

Issue #4572 - Implementing old logging TAG_PAD as Message Alignment.#4997

Merged
joakime merged 5 commits intojetty-10.0.xfrom
jetty-10.0.x-4572-message-indent
Aug 20, 2020
Merged

Issue #4572 - Implementing old logging TAG_PAD as Message Alignment.#4997
joakime merged 5 commits intojetty-10.0.xfrom
jetty-10.0.x-4572-message-indent

Conversation

@joakime
Copy link
Copy Markdown
Contributor

@joakime joakime commented Jun 24, 2020

Alternate approach from PR #4994

Signed-off-by: Joakim Erdfelt joakim.erdfelt@gmail.com

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
@joakime joakime requested a review from gregw June 24, 2020 15:55
@joakime joakime added this to the 10.0.x milestone Jun 24, 2020
@joakime joakime mentioned this pull request Jun 24, 2020
@joakime joakime linked an issue Jun 24, 2020 that may be closed by this pull request
@gregw gregw closed this Jun 25, 2020
@gregw
Copy link
Copy Markdown
Contributor

gregw commented Jun 25, 2020

Ooops wrong one

@gregw gregw reopened this Jun 25, 2020
Copy link
Copy Markdown
Contributor

@gregw gregw left a comment

Choose a reason for hiding this comment

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

LGTM. But perhaps check if substring of a string previously created by repeat is faster than repeat each time. Probably down in the noise!

builder.append(' ');
int padAmount = messageAlignColumn - builder.length();
if (padAmount > 0)
builder.append(" ".repeat(padAmount));
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I'm just a little cautious that repeat might be less efficient than taking a substring of a longer string.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Fair enough, i'll see what the numbers show.

I did look at the implementation of both in java.lang.String.

  • String.substring() results in a new String object, based on "this.value" byte[] array, with an array copy to a new array for the new String object.
  • String.repeat() results in a new String object, based on "this.value" byte[] array, with an array copy to a new array for the new String object.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

@gregw here's the results of the IndentBenchmark (jmh) test.

https://github.com/eclipse/jetty.project/blob/jetty-10.0.x-4572-message-indent/tests/jetty-jmh/src/main/java/org/eclipse/jetty/logging/jmh/IndentBenchmark.java

Benchmark                                                               Mode  Cnt          Score           Error   Units
IndentBenchmark.testStringRepeatLarge                                  thrpt    7  186589212.883 ±  14318698.518   ops/s
IndentBenchmark.testStringRepeatLarge:·gc.alloc.rate                   thrpt    7       7822.988 ±       601.504  MB/sec
IndentBenchmark.testStringRepeatLarge:·gc.alloc.rate.norm              thrpt    7         88.000 ±         0.001    B/op
IndentBenchmark.testStringRepeatLarge:·gc.churn.G1_Eden_Space          thrpt    7       7854.853 ±      3677.899  MB/sec
IndentBenchmark.testStringRepeatLarge:·gc.churn.G1_Eden_Space.norm     thrpt    7         88.310 ±        40.367    B/op
IndentBenchmark.testStringRepeatLarge:·gc.count                        thrpt    7         18.000                  counts
IndentBenchmark.testStringRepeatLarge:·gc.time                         thrpt    7         64.000                      ms
IndentBenchmark.testStringRepeatSmall                                  thrpt    7  343002605.870 ±  25715711.800   ops/s
IndentBenchmark.testStringRepeatSmall:·gc.alloc.rate                   thrpt    7       9150.062 ±       688.673  MB/sec
IndentBenchmark.testStringRepeatSmall:·gc.alloc.rate.norm              thrpt    7         56.000 ±         0.001    B/op
IndentBenchmark.testStringRepeatSmall:·gc.churn.G1_Eden_Space          thrpt    7       9078.653 ±      4249.875  MB/sec
IndentBenchmark.testStringRepeatSmall:·gc.churn.G1_Eden_Space.norm     thrpt    7         55.546 ±        25.642    B/op
IndentBenchmark.testStringRepeatSmall:·gc.count                        thrpt    7         18.000                  counts
IndentBenchmark.testStringRepeatSmall:·gc.time                         thrpt    7         73.000                      ms
IndentBenchmark.testStringSubStringLarge                               thrpt    7  179315393.232 ± 109455137.398   ops/s
IndentBenchmark.testStringSubStringLarge:·gc.alloc.rate                thrpt    7       7518.461 ±      4593.109  MB/sec
IndentBenchmark.testStringSubStringLarge:·gc.alloc.rate.norm           thrpt    7         88.000 ±         0.001    B/op
IndentBenchmark.testStringSubStringLarge:·gc.churn.G1_Eden_Space       thrpt    7       7535.104 ±      6436.079  MB/sec
IndentBenchmark.testStringSubStringLarge:·gc.churn.G1_Eden_Space.norm  thrpt    7         87.144 ±        46.695    B/op
IndentBenchmark.testStringSubStringLarge:·gc.count                     thrpt    7         18.000                  counts
IndentBenchmark.testStringSubStringLarge:·gc.time                      thrpt    7         51.000                      ms
IndentBenchmark.testStringSubStringSmall                               thrpt    7  303492551.318 ±  41265934.036   ops/s
IndentBenchmark.testStringSubStringSmall:·gc.alloc.rate                thrpt    7       8096.412 ±      1102.379  MB/sec
IndentBenchmark.testStringSubStringSmall:·gc.alloc.rate.norm           thrpt    7         56.000 ±         0.001    B/op
IndentBenchmark.testStringSubStringSmall:·gc.churn.G1_Eden_Space       thrpt    7       8215.101 ±      3847.187  MB/sec
IndentBenchmark.testStringSubStringSmall:·gc.churn.G1_Eden_Space.norm  thrpt    7         56.618 ±        22.595    B/op
IndentBenchmark.testStringSubStringSmall:·gc.count                     thrpt    7         18.000                  counts
IndentBenchmark.testStringSubStringSmall:·gc.time                      thrpt    7         43.000                      ms

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

When I look at the results, I see that String.repeat() is slightly faster (in terms of ops/s. 4% faster in large cases, 12% faster in the small cases).
And the GC is about the same.
But with a higher error-bars on the substring version.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

@gregw bump. could use a review of the benchmark results here.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

repeat LGTM. I think there may be other places we can do the same.... but another PR.

joakime added 4 commits July 16, 2020 13:21
Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
@joakime joakime merged commit c0dc907 into jetty-10.0.x Aug 20, 2020
@joakime joakime deleted the jetty-10.0.x-4572-message-indent branch August 20, 2020 19:14
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.

Replace Jetty Logging

2 participants