JDK-8259710: Inlining trace leaks memory #2063

tstuefe · 2021-01-13T14:51:44Z

We see C-heap leaking, originating in C2:

1434777 [0x00007f58214af461] stringStream::stringStream(unsigned long)+0x55
1434778 [0x00007f5820c6db3e] Compile::PrintInliningBuffer::PrintInliningBuffer()+0x6c
1434779 [0x00007f5820c724f1] GrowableArrayWithAllocator<Compile::PrintInliningBuffer, GrowableArray<Compile::PrintInliningBuffer> >::grow(int)+0x163
1434780 [0x00007f5820c7160e] GrowableArrayWithAllocator<Compile::PrintInliningBuffer, GrowableArray<Compile::PrintInliningBuffer> >::insert_before(int, Compile::PrintInliningBuffer const&)+0x82
1434781 [0x00007f5820c6aaf2] Compile::print_inlining_push()+0x70

accumulating over the course of days to some hundred MB at a customer site where inline tracing was active.

Analysis:

To build up a comprehensive inlining trace, c2 keeps trace snippets in an internal list and assembles them at print time. These are stringStream's, contained in PrintInliningBuffer:

GrowableArray<PrintInliningBuffer>* _print_inlining_list;
...
  class PrintInliningBuffer : public ResourceObj {
   private:
    CallGenerator* _cg;
    stringStream* _ss;

   public:
    PrintInliningBuffer()
      : _cg(NULL) {
      _ss = new stringStream();
    }

    void freeStream() {
      _ss->~stringStream(); _ss = NULL; }
...
  };

With JDK-8224193, stringStream was changed to use C-heap instead of ResourceArea for its internal buffer. This means one cannot just omit stringStream destruction anymore - even where stringStream objects themselves live in RA, their internal buffers don't, they live in C-Heap. To clean up properly, ~stringStream() must be called.

Those PrintInliningBuffer objects are kept by value in a GrowableArray Compile::_print_inlining_list. Normally, if an object is kept by value, it needs to implement correct copy- and destruction-semantics. PrintInliningBuffer does not do that and instead relies on manual cleanup (PrintInliningBuffer::freeStream()) - I assume the authors did not want to deal with reference counting the contained stringStream on copying.

That however is a problem because GrowableArray creates internally temporary objects of the item type to pre-populate its array - its whole capacity - when it grows:

template <typename E, typename Derived>
void GrowableArrayWithAllocator<E, Derived>::grow(int j) {

...
  for (     ; i < this->_len; i++) ::new ((void*)&newData[i]) E(this->_data[i]);
  for (     ; i < this->_max; i++) ::new ((void*)&newData[i]) E(); <<<<<<< 
  for (i = 0; i < old_max; i++) this->_data[i].~E();
...
}

this it does for the whole new capacity, which means more objects get created than have been added; if the caller does not fill the GrowableArray up to its capacity, it never knows about the excess objects created. This is normally not a problem since all these objects are destructed by GrowableArray in void GrowableArrayWithAllocator<E, Derived>::clear_and_deallocate(). But since PrintInliningBuffer does not implement a destructor, this has no effect.

PrintInliningBuffer instead relies on manual cleanup of the stringStreams: at the end of the compile phase, it calls PrintInliningBuffer::freeStream() on all buffers it thinks are contained in the array:

    assert(_print_inlining_list != NULL, "process_print_inlining should be called only once.");
    for (int i = 0; i < _print_inlining_list->length(); i++) {
      ss.print("%s", _print_inlining_list->adr_at(i)->ss()->as_string());
      _print_inlining_list->at(i).freeStream();
    }

but this of course leaves the excess objects untouched (objects whose index is array length >= index >= array capacity).

There are several ways to fix this:

implement correct destructor- and copy semantics for PrintInliningBuffer. This would work but is not optimal since we would still pay for creation of unnecessary PrintInliningBuffer objects when the array is prepopulated on grow()
delay construction of PrintInliningBuffer::_ss until the stream is actually used for writing into. This would would mean we have to check the stringStream for NULL before using it.
Just let the PrintInliningBuffer live in C-heap instead of the RA. Its only a small shell anywhere now that the stringStream buffer lives in C-heap. Instead, let PrintInliningBuffer contain the stringStream as a member, allocate PrintInliningBuffer from C-heap, and change the list to contain pointers to PrintInliningBuffer, not the object itself. This removes all that unnecessary copying, removes creation of temporary objects, and simplifies the code. Having to free those objects is no big deal since we free the stringStream objects manually anyway.

I went with (3). I also decreased the default stringStream buffer size for this scenario since when testing I found out that many trace snippets are below 128 bytes.

Note that (3) is not only simpler, but also more efficient: many of the PrintInliningBuffer objects are inserted into the middle of the _print_inlining_list; GrowableArray does shift all higher items up to provide space for the new item. If those items are simple pointers instead of whole objects, less memory is moved around.

Tests:

github actions
Nightlies at SAP
I manually tested the patch and compared the NMT output of a tracing scenario to verify that the leak went away and no other numbers changed

Thanks, Thomas

Progress

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

Issue

JDK-8259710: Inlining trace leaks memory

Reviewers

Tobias Hartmann (@TobiHartmann - Reviewer)
Nils Eliasson (@neliasso - Reviewer)

Download

$ git fetch https://git.openjdk.java.net/jdk pull/2063/head:pull/2063
$ git checkout pull/2063

bridgekeeper · 2021-01-13T14:52:50Z

👋 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.

openjdk · 2021-01-13T14:53:47Z

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

hotspot-compiler

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 · 2021-01-14T07:39:09Z

Webrevs

TobiHartmann

Otherwise, looks good to me.

src/hotspot/share/opto/compile.cpp

openjdk · 2021-01-18T11:26:10Z

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

8259710: Inlining trace leaks memory

Reviewed-by: thartmann, neliasso

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

09489e2: 8260338: Some fields in HaltNode is not cloned
af155fc: 8258836: JNI local refs exceed capacity getDiagnosticCommandInfo
d825339: 8260263: Remove PtrQueue::_qset
5898ab6: 8259894: refactor parts of jvm.h into jvm_io.h and jvm_constants.h
764111f: 8260272: bash configure --prefix does not work after JDK-8257679
4ae39b1: 8260208: Improve dummy object filling condition in G1CollectedHeap::fill_archive_regions in cds
c52c6c6: 8260273: DataOutputStream writeChars optimization
535c292: 8260306: Do not include osThread.hpp in thread.hpp
06348df: 8259776: Remove ParallelGC non-CAS oldgen allocation
6c4c96f: 8258742: Move PtrQueue reset to PtrQueueSet subclasses
... and 170 more: https://git.openjdk.java.net/jdk/compare/ce9451208772534efd532a6bc44c226a419f570d...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.

tstuefe · 2021-01-19T06:01:29Z

Otherwise, looks good to me.

Thanks Tobias. I added your suggestion.

Cheers, Thoams

TobiHartmann

Thanks for updating. Looks good but you accidentally pushed make/hs_err_pid10680.log, make/replay_pid10680.log :)

Best regards,
Tobias

tstuefe · 2021-01-19T09:17:43Z

Thanks for updating. Looks good but you accidentally pushed make/hs_err_pid10680.log, make/replay_pid10680.log :)

Best regards,
Tobias

Oops. Corrected. Not my day today :)

neliasso

Looks good.

tstuefe · 2021-01-25T10:48:48Z

Looks good.

Thank you Nils!

tstuefe · 2021-01-25T10:50:15Z

GA errors seem unrelated, and this patch runs in our SAP internal tests since a week without problems.

/integrate

openjdk · 2021-01-25T10:51:05Z

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

09489e2: 8260338: Some fields in HaltNode is not cloned
af155fc: 8258836: JNI local refs exceed capacity getDiagnosticCommandInfo
d825339: 8260263: Remove PtrQueue::_qset
5898ab6: 8259894: refactor parts of jvm.h into jvm_io.h and jvm_constants.h
764111f: 8260272: bash configure --prefix does not work after JDK-8257679
4ae39b1: 8260208: Improve dummy object filling condition in G1CollectedHeap::fill_archive_regions in cds
c52c6c6: 8260273: DataOutputStream writeChars optimization
535c292: 8260306: Do not include osThread.hpp in thread.hpp
06348df: 8259776: Remove ParallelGC non-CAS oldgen allocation
6c4c96f: 8258742: Move PtrQueue reset to PtrQueueSet subclasses
... and 170 more: https://git.openjdk.java.net/jdk/compare/ce9451208772534efd532a6bc44c226a419f570d...master

Your commit was automatically rebased without conflicts.

Pushed as commit ca20c63.

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

Initial

95f9931

openjdk bot added the hotspot-compiler hotspot-compiler-dev@openjdk.org label Jan 13, 2021

Decrease default buffer size for ilt stringStream

4045f2f

tstuefe marked this pull request as ready for review January 14, 2021 07:36

openjdk bot added the rfr Pull request is ready for review label Jan 14, 2021

TobiHartmann approved these changes Jan 18, 2021

View reviewed changes

src/hotspot/share/opto/compile.cpp Outdated Show resolved Hide resolved

openjdk bot added the ready Pull request is ready to be integrated label Jan 18, 2021

change return parameter of Compile::print_inlining_current()

b52b140

openjdk bot added the build build-dev@openjdk.org label Jan 19, 2021

TobiHartmann suggested changes Jan 19, 2021

View reviewed changes

openjdk bot removed the ready Pull request is ready to be integrated label Jan 19, 2021

Remove accidental adds

faa1e63

openjdk bot removed the build build-dev@openjdk.org label Jan 19, 2021

TobiHartmann approved these changes Jan 20, 2021

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Jan 20, 2021

neliasso approved these changes Jan 25, 2021

View reviewed changes

openjdk bot closed this Jan 25, 2021

openjdk bot added integrated Pull request has been integrated and removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jan 25, 2021

tstuefe deleted the JDK-8259710-inlining-trace-leaks-memory branch February 1, 2021 07:55

JDK-8259710: Inlining trace leaks memory #2063

JDK-8259710: Inlining trace leaks memory #2063

tstuefe commented Jan 13, 2021 •

edited by openjdk bot

bridgekeeper bot commented Jan 13, 2021

openjdk bot commented Jan 13, 2021

mlbridge bot commented Jan 14, 2021 •

edited

TobiHartmann left a comment

openjdk bot commented Jan 18, 2021 •

edited

tstuefe commented Jan 19, 2021

TobiHartmann left a comment

tstuefe commented Jan 19, 2021

neliasso left a comment

tstuefe commented Jan 25, 2021

tstuefe commented Jan 25, 2021

openjdk bot commented Jan 25, 2021

JDK-8259710: Inlining trace leaks memory #2063

JDK-8259710: Inlining trace leaks memory #2063

Conversation

tstuefe commented Jan 13, 2021 • edited by openjdk bot

Progress

Issue

Reviewers

Download

bridgekeeper bot commented Jan 13, 2021

openjdk bot commented Jan 13, 2021

mlbridge bot commented Jan 14, 2021 • edited

Webrevs

TobiHartmann left a comment

Choose a reason for hiding this comment

openjdk bot commented Jan 18, 2021 • edited

tstuefe commented Jan 19, 2021

TobiHartmann left a comment

Choose a reason for hiding this comment

tstuefe commented Jan 19, 2021

neliasso left a comment

Choose a reason for hiding this comment

tstuefe commented Jan 25, 2021

tstuefe commented Jan 25, 2021

openjdk bot commented Jan 25, 2021

tstuefe commented Jan 13, 2021 •

edited by openjdk bot

mlbridge bot commented Jan 14, 2021 •

edited

openjdk bot commented Jan 18, 2021 •

edited