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

JDK-8266503: [UL] Make Decorations safely copy-able and reduce their size #3874

Closed

Conversation

@tstuefe
Copy link
Member

@tstuefe tstuefe commented May 5, 2021

This patch reduces the size of UL LogDecorations by about 85% (from 368 -> 56 bytes on Linux x64). This matters in the context of asynchronous logging in UL where we plan to keep a buffer containing log messages, including decorations, for asynchronous printing.

As a side effect, it makes the LogDecorations object safe to copy with trivial assignment constructors and operators (which it had not been before).

As another side effect, the 256-char-for-all-decorators limit has been removed with this patch.

What the patch does:

In LogDecorations, we resolve the values of the given decorators ("uptime", "tid" etc) and print them in human-readable format. Before this patch, the class LogDecorations stored the printed decorators in an internal (limited, fixed-sized) buffer. This is inefficient since this takes much more memory than storing the binary data before printing them.

So this patch separates the decorator value resolving from the printing. It stores the resolved values in binary form and only prints them when needed. Since a decorations object is only printed once this is fine. No need to cache the formatted text.

Please Note that this patch includes the fix for JDK-8266536: "Provide a variant of os::iso8601_time which works with arbitrary timestamps" which is in a separate PR (#3869) - so please ignore all the iso6801 stuff. It also contains a fix for the broken harfbuzz build.

Testing:

  • gtests, manually
  • jtreg runtime/logging, manually
  • SAP nightlies ran fine, but since then the tests changed, will run them again tonight

Progress

  • Change must not contain extraneous whitespace
  • Commit message must refer to an issue
  • Change must be properly reviewed

Issue

  • JDK-8266503: [UL] Make Decorations safely copy-able and reduce their size

Reviewers

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/3874/head:pull/3874
$ git checkout pull/3874

Update a local copy of the PR:
$ git checkout pull/3874
$ git pull https://git.openjdk.java.net/jdk pull/3874/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 3874

View PR using the GUI difftool:
$ git pr show -t 3874

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/3874.diff

@bridgekeeper
Copy link

@bridgekeeper bridgekeeper bot commented May 5, 2021

👋 Welcome back stuefe! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

Loading

@openjdk
Copy link

@openjdk openjdk bot commented May 5, 2021

@tstuefe The following label will be automatically applied to this pull request:

  • hotspot-runtime

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

Loading

@tstuefe tstuefe force-pushed the JDK-8266503-make-UL-decorators-cheaper branch from c199e5b to 74b08d8 May 5, 2021
@tstuefe tstuefe force-pushed the JDK-8266503-make-UL-decorators-cheaper branch from 1983347 to 1c845a9 May 6, 2021
@tstuefe tstuefe changed the title JDK-8266503: [ul] Make Decorations safely copy-able and reduce their size (second attempt) JDK-8266503: [UL] Make Decorations safely copy-able and reduce their size May 6, 2021
@tstuefe tstuefe force-pushed the JDK-8266503-make-UL-decorators-cheaper branch 2 times, most recently from 0ba500d to 3c22ac9 May 6, 2021
@tstuefe tstuefe force-pushed the JDK-8266503-make-UL-decorators-cheaper branch from 3c22ac9 to 9df5a1f May 6, 2021
@tstuefe tstuefe marked this pull request as ready for review May 6, 2021
@openjdk openjdk bot added the rfr label May 6, 2021
@mlbridge
Copy link

@mlbridge mlbridge bot commented May 6, 2021

Loading

Copy link
Member

@simonis simonis left a comment

Hi Thomas,

your change looks good and I like it :)

Am I right that you've changed the 256-char-for-all-decorators limit to a 255-char limit for a single decorator (which is obviously much better)?

Find my other comments inline.

Thank you and best regards,
Volker

Loading

src/hotspot/share/logging/logDecorations.hpp Outdated Show resolved Hide resolved
Loading
test/hotspot/gtest/logging/test_logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/runtime/os.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/runtime/os.hpp Outdated Show resolved Hide resolved
Loading
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
src/hotspot/share/logging/logDecorations.hpp Outdated Show resolved Hide resolved
Loading
@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 6, 2021

Hi Thomas,

your change looks good and I like it :)

:-)

Am I right that you've changed the 256-char-for-all-decorators limit to a 255-char limit for a single decorator (which is obviously much better)?

yes - and even that can be improved by using a fileStream directly, not raw jio_fprintf.

Find my other comments inline.

Thank you and best regards,
Volker

Thanks!

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 6, 2021

Hi @simonis , @YaSuenag , thanks for your Reviews!

New version - mostly driven by Volkers feedback:

  • I now cache the pid, which further reduces the size of this object to 48. As mentioned in #3874 (comment), one could further reduce it but I think this is already fine.
  • I added LogDecorations::max_decoration_size and used it for temp buffers. Note that this limit would be easy to remove by using fileStream in LogFileStreamOutput::write_decorations() - however, fileStream misses some functionality and I wanted to limit the patch size.
  • I fixed the error handling for os::iso8601_time()
  • I added a overload to LogTagSet which takes an outputStream - this is more elegant and prevents the copy. I also added a gtest for this function
  • I removed the harfbuzz build fix

Thanks for reviewing!

..Thomas

Loading

Copy link
Member

@YaSuenag YaSuenag left a comment

Looks good!

Loading

src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
@openjdk
Copy link

@openjdk openjdk bot commented May 6, 2021

@tstuefe This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8266503: [UL] Make Decorations safely copy-able and reduce their size

Reviewed-by: simonis, ysuenaga

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 6 new commits pushed to the master branch:

  • 3fcdc50: 8266646: Add more diagnostic to java/lang/System/LoggerFinder/modules
  • 9a19a0c: 8264760: JVM crashes when two threads encounter the same resolution error
  • 14f0afe: 8214237: Join parallel phases post evacuation
  • 2798b0d: 8266349: Pass down requested page size to reserve_memory_special
  • e0c8688: 8262992: Improve @see output
  • d2b5350: 8263507: Improve structure of package summary pages

Please see this link for an up-to-date comparison between the source branch of this pull request and the master branch.
As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

Loading

@openjdk openjdk bot added the ready label May 6, 2021
src/hotspot/share/logging/logDecorations.cpp Outdated Show resolved Hide resolved
Loading
@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

@navyxliu @simonis @YaSuenag
Thanks for your feedbacks!

Latest iteration:

  • changed help text printing to use the new LogTagSet::label(outputStream) interface
  • added Xin's proposal of a debug check testing if someone prints an uninitialized decorator value.

Thanks, Thomas

Loading

@YaSuenag
Copy link
Member

@YaSuenag YaSuenag commented May 7, 2021

I just approved #3869, so I hope to use os::iso8601_timestamp_size in this PR.

Loading

@navyxliu
Copy link
Contributor

@navyxliu navyxliu commented May 7, 2021

I guess you will revert code change of JDK-8266536.
For other parts in this patch, LGTM.

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

I guess you will revert code change of JDK-8266536.
Sure

For other parts in this patch, LGTM.
Thanks!

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

@simonis : if you approve, I will push.

All nightlies at SAP ran through fine.

..thomas

Loading

Copy link
Member

@simonis simonis left a comment

Hi Thomas,

everything looks fine now except the comments below (i.e. didn't you wanted to use the new iso8601_timestamp_size?).

If that 's clarified I'll approve this PR.

Thanks,
Volker

Loading

int written = buf == NULL ? -1 : 29;
ASSERT_AND_RETURN(written, pos)
void LogDecorations::print_time_decoration(outputStream* st) const {
char buf[29];
Copy link
Member

@simonis simonis May 7, 2021

Choose a reason for hiding this comment

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

Didn't you wanted to use the new iso8601_timestamp_size constant here?

Loading

int written = jio_snprintf(pos, DecorationsBufferSize - (pos - _decorations_buffer), "%.3fs", os::elapsedTime());
ASSERT_AND_RETURN(written, pos)
void LogDecorations::print_utctime_decoration(outputStream* st) const {
char buf[29];
Copy link
Member

@simonis simonis May 7, 2021

Choose a reason for hiding this comment

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

Didn't you wanted to use the new iso8601_timestamp_size constant here?

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

Hi Thomas,

everything looks fine now except the comments below (i.e. didn't you wanted to use the new iso8601_timestamp_size?).

If that 's clarified I'll approve this PR.

Thanks,
Volker

Hi Volker,

thanks! Yes, I missed that, will change it before pushing.

Cheers, Thomas

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

Hi Thomas,

everything looks fine now except the comments below (i.e. didn't you wanted to use the new iso8601_timestamp_size?).

If that 's clarified I'll approve this PR.

Thanks,
Volker

@simonis done. You can approve.

Has been nice to have you as a Reviewer again ;-)

Loading

simonis
simonis approved these changes May 7, 2021
Copy link
Member

@simonis simonis left a comment

It has been a pleasure :)

Approved.

Loading

@tstuefe
Copy link
Member Author

@tstuefe tstuefe commented May 7, 2021

/integrate

Loading

@openjdk openjdk bot closed this May 7, 2021
@openjdk openjdk bot added integrated and removed ready rfr labels May 7, 2021
@openjdk
Copy link

@openjdk openjdk bot commented May 7, 2021

@tstuefe Since your change was applied there have been 7 commits pushed to the master branch:

  • 86b8dc9: 8265426: Update java.security to use instanceof pattern variable
  • 3fcdc50: 8266646: Add more diagnostic to java/lang/System/LoggerFinder/modules
  • 9a19a0c: 8264760: JVM crashes when two threads encounter the same resolution error
  • 14f0afe: 8214237: Join parallel phases post evacuation
  • 2798b0d: 8266349: Pass down requested page size to reserve_memory_special
  • e0c8688: 8262992: Improve @see output
  • d2b5350: 8263507: Improve structure of package summary pages

Your commit was automatically rebased without conflicts.

Pushed as commit 74fecc0.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

Loading

@tstuefe tstuefe deleted the JDK-8266503-make-UL-decorators-cheaper branch Jun 29, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
4 participants