8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections #18626

MBaesken · 2024-04-04T12:34:19Z

Currently the 'generic' hs_errfile Events message log (filled by Events::log) is sometimes rather full by messages for memory protection operations and nmethod flushes. Those seem to occur quite often and potentially move out other less frequent events, because the number of entries in the log is limited.
It might be better to separate the events into separate sections.

The mentioned memory protection operations related entries look like this :
Event: 0.178 Protecting memory [0x000000016ebf0000,0x000000016ebfc000] with protection modes 0

Progress

Change must be properly reviewed (1 review required, with at least 1 Reviewer)
Change must not contain extraneous whitespace
Commit message must refer to an issue

Issue

JDK-8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections (Enhancement - P4)

Reviewers

Lutz Schmidt (@RealLucy - Reviewer) ⚠️ Review applies to 7de2f9e5
Stefan Karlsson (@stefank - Reviewer) ⚠️ Review applies to 912afc31
Thomas Stuefe (@tstuefe - Reviewer)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk.git pull/18626/head:pull/18626
$ git checkout pull/18626

Update a local copy of the PR:
$ git checkout pull/18626
$ git pull https://git.openjdk.org/jdk.git pull/18626/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 18626

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

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk/pull/18626.diff

Webrev

Link to Webrev Comment

bridgekeeper · 2024-04-04T12:34:56Z

👋 Welcome back mbaesken! 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.

openjdk · 2024-04-04T12:35:42Z

@MBaesken 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:

8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections

Reviewed-by: lucy, stefank, stuefe

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 141 new commits pushed to the master branch:

77a217d: 8330095: RISC-V: Remove obsolete vandn_vi instruction
717a07b: 8322140: javax/swing/JTable/JTableScrollPrintTest.java does not print the rows and columns of the table in Nimbus and Aqua LookAndFeel
aebfd53: 8329660: G1: Improve TestGCLogMessages to be more precise
006a516: 8329962: Remove CardTable::invalidate
c7fcd62: 8330006: Serial: Extract out ContiguousSpace::block_start_const
2c8b432: 8330003: Serial: Move the logic of FastEvacuateFollowersClosure to SerialHeap
2c45eca: 8328879: G1: Some gtests modify global state crashing the JVM during GC after JDK-8289822
bde3fc0: 8330106: C2: VectorInsertNode::make() shouldn't call ConINode::make() directly
e45fea5: 8329757: Crash with fatal error: DEBUG MESSAGE: Fast Unlock lock on stack
ece7d43: 8329416: Split relocation pointer map into read-write and read-only maps
... and 131 more: https://git.openjdk.org/jdk/compare/bea493bcb86370dc3fb00d86c545f01fc614e000...master

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.

openjdk · 2024-04-04T12:36:03Z

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

hotspot

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.

mlbridge · 2024-04-04T12:39:15Z

Webrevs

stefank · 2024-04-04T13:02:43Z

We still have flooding in the frequent events. Instead of creating a common section for these vent, did you consider creating two new separate, specific sections for memory protection and nmethod flushing?

MBaesken · 2024-04-04T13:14:39Z

We still have flooding in the frequent events. Instead of creating a common section for these vent, did you consider creating two new separate, specific sections for memory protection and nmethod flushing?

I thought about creating new specific sections. Regarding those 2, maybe they are a bit too specific ? But on the other hand, if others like this idea, I am fine with it (creating sections for memory protection operations and for nmethod flushing).

MBaesken · 2024-04-08T13:45:37Z

But on the other hand, if others like this idea, I am fine with it (creating sections for memory protection operations and for nmethod flushing).

I asked around in my team and added a separate section for the nmethod flush operations.

TheRealMDoerr · 2024-04-08T19:27:41Z

src/hotspot/share/utilities/events.cpp

@@ -97,6 +99,8 @@ void Events::print() {
 void Events::init() {
  if (LogEvents) {
    _messages = new StringEventLog("Events", "events");
+    _nmethod_flush_messages = new StringEventLog("Nmethod flushs", "nmethodflushs");


Should be "flushes" or "flushing events".

RealLucy

LGTM - given the scope of this PR.
In general, I don't like the event log to be split into multiple streams being printed separately. Yes, separate sections prevent displacement of events by other, too verbose, events. On the other hand, time coherence is lost or has to be manually re-established by the support engineer. Often enough, an issue can only be understood when seeing multiple/all events in timely order.

Merging the event sections at print time by timestamp would be a helpful enhancement.

stefank · 2024-04-10T05:31:38Z

LGTM - given the scope of this PR. In general, I don't like the event log to be split into multiple streams being printed separately. Yes, separate sections prevent displacement of events by other, too verbose, events. On the other hand, time coherence is lost or has to be manually re-established by the support engineer. Often enough, an issue can only be understood when seeing multiple/all events in timely order.

Merging the event sections at print time by timestamp would be a helpful enhancement.

FWIW, I think I am of the opposite opinion. I find it very helpful to have the events separated into distinct sections and wouldn't want them all combined into one big section.

MBaesken · 2024-04-10T07:10:55Z

Hi Lucy, thanks for the review ! May I have a second one please ?

FWIW, I think I am of the opposite opinion. I find it very helpful to have the events separated into distinct sections and wouldn't
want them all combined into one big section.

Yeah, both approaches (one single big log, or multiple ones) have pros and cons.
But having multiple logs is a long established HS approach so I do not think that it is in scope of this PR to change the established approach.

RealLucy · 2024-04-10T09:23:43Z

... I do not think that it is in scope of this PR ...
Oh no, I didn't want to suggest to do such a change in the scope of this PR. And yes, I agree, there are reasons why you would want separate streams. As always, a solution that suits all needs is hard to find.

TheRealMDoerr

I think it's ok if @stefank also likes it.

tstuefe · 2024-04-11T16:00:05Z

Hmm, I think the separation makes sense, but I don't like the "frequent" moniker. All other event logs are separated by thematic area. "frequent" is orthogonal to that. I can have frequent/non-frequent class loading messages, or exceptions.

My proposal would be either to drop these memory protection events (do we need them? or are they remnants of some old support issues?) or to put them into a 'memprot' section or similar.

stefank · 2024-04-11T16:09:00Z

I agree with @tstuefe

MBaesken · 2024-04-12T06:47:39Z

My proposal would be either to drop these memory protection events (do we need them? or are they remnants of some old >support issues?) or to put them into a 'memprot' section or similar.

A separate memprotect section would be good I can add this.
I think usually these protection events appear around/after threads are added. I think we had some issues with these mem protections in the past so I would be cautious to completely remove them.

MBaesken · 2024-04-12T11:16:09Z

I added a memprotect section.

MBaesken · 2024-04-12T11:16:20Z

Hi Stefan, thanks for the review !

tstuefe

Good, thank you

MBaesken · 2024-04-12T14:08:59Z

/integrate

openjdk · 2024-04-12T14:09:24Z

Going to push as commit 397d948.
Since your change was applied there have been 145 commits pushed to the master branch:

f706949: 8329781: Serial: Remove serialFullGC.inline.hpp
0f78d01: 8329658: Serial: Refactor ContiguousSpace::_next_compaction_space
b8f675f: 8329771: G1: Refactor G1BlockOffsetTable::verify
3e9c381: 8329488: Move OopStorage code from safepoint cleanup and remove safepoint cleanup code
77a217d: 8330095: RISC-V: Remove obsolete vandn_vi instruction
717a07b: 8322140: javax/swing/JTable/JTableScrollPrintTest.java does not print the rows and columns of the table in Nimbus and Aqua LookAndFeel
aebfd53: 8329660: G1: Improve TestGCLogMessages to be more precise
006a516: 8329962: Remove CardTable::invalidate
c7fcd62: 8330006: Serial: Extract out ContiguousSpace::block_start_const
2c8b432: 8330003: Serial: Move the logic of FastEvacuateFollowersClosure to SerialHeap
... and 135 more: https://git.openjdk.org/jdk/compare/bea493bcb86370dc3fb00d86c545f01fc614e000...master

Your commit was automatically rebased without conflicts.

openjdk · 2024-04-12T14:09:31Z

@MBaesken Pushed as commit 397d948.

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

JDK-8329605

27a319b

openjdk bot added the rfr Pull request is ready for review label Apr 4, 2024

openjdk bot added the hotspot hotspot-dev@openjdk.org label Apr 4, 2024

Introduce separate nmethod flush log

63ccaff

TheRealMDoerr reviewed Apr 8, 2024

View reviewed changes

adjust typo

7de2f9e

RealLucy approved these changes Apr 9, 2024

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Apr 9, 2024

openjdk bot changed the title ~~JDK-8329605: hs errfile generic events - introduce sections for Frequent/NotFrequent Events~~ 8329605: hs errfile generic events - introduce sections for Frequent/NotFrequent Events Apr 10, 2024

TheRealMDoerr reviewed Apr 11, 2024

View reviewed changes

add memprotect section

912afc3

MBaesken changed the title ~~8329605: hs errfile generic events - introduce sections for Frequent/NotFrequent Events~~ 8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections Apr 12, 2024

stefank approved these changes Apr 12, 2024

View reviewed changes

use nmethodflushes not nmethodflushs

77f64c8

tstuefe approved these changes Apr 12, 2024

View reviewed changes

openjdk bot added the integrated Pull request has been integrated label Apr 12, 2024

openjdk bot closed this Apr 12, 2024

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Apr 12, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections #18626

8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections #18626

MBaesken commented Apr 4, 2024 •

edited by openjdk bot

Loading

bridgekeeper bot commented Apr 4, 2024

openjdk bot commented Apr 4, 2024 •

edited

Loading

openjdk bot commented Apr 4, 2024

mlbridge bot commented Apr 4, 2024 •

edited

Loading

stefank commented Apr 4, 2024

MBaesken commented Apr 4, 2024

MBaesken commented Apr 8, 2024

TheRealMDoerr Apr 8, 2024

RealLucy left a comment

stefank commented Apr 10, 2024

MBaesken commented Apr 10, 2024

RealLucy commented Apr 10, 2024

TheRealMDoerr left a comment

tstuefe commented Apr 11, 2024

stefank commented Apr 11, 2024

MBaesken commented Apr 12, 2024 •

edited

Loading

MBaesken commented Apr 12, 2024

MBaesken commented Apr 12, 2024

tstuefe left a comment

MBaesken commented Apr 12, 2024

openjdk bot commented Apr 12, 2024

openjdk bot commented Apr 12, 2024

8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections #18626

8329605: hs errfile generic events - move memory protections and nmethod flushes to separate sections #18626

Conversation

MBaesken commented Apr 4, 2024 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

Webrev

bridgekeeper bot commented Apr 4, 2024

openjdk bot commented Apr 4, 2024 • edited Loading

openjdk bot commented Apr 4, 2024

mlbridge bot commented Apr 4, 2024 • edited Loading

Webrevs

stefank commented Apr 4, 2024

MBaesken commented Apr 4, 2024

MBaesken commented Apr 8, 2024

TheRealMDoerr Apr 8, 2024

Choose a reason for hiding this comment

RealLucy left a comment

Choose a reason for hiding this comment

stefank commented Apr 10, 2024

MBaesken commented Apr 10, 2024

RealLucy commented Apr 10, 2024

TheRealMDoerr left a comment

Choose a reason for hiding this comment

tstuefe commented Apr 11, 2024

stefank commented Apr 11, 2024

MBaesken commented Apr 12, 2024 • edited Loading

MBaesken commented Apr 12, 2024

MBaesken commented Apr 12, 2024

tstuefe left a comment

Choose a reason for hiding this comment

MBaesken commented Apr 12, 2024

openjdk bot commented Apr 12, 2024

openjdk bot commented Apr 12, 2024

MBaesken commented Apr 4, 2024 •

edited by openjdk bot

Loading

openjdk bot commented Apr 4, 2024 •

edited

Loading

mlbridge bot commented Apr 4, 2024 •

edited

Loading

MBaesken commented Apr 12, 2024 •

edited

Loading