jdk icon indicating copy to clipboard operation
jdk copied to clipboard

8317453: NMT: Performance benchmarks are needed to measure speed and memory

Open gerard-ziemski opened this issue 2 years ago • 14 comments
trafficstars

This is a work in progress...

Please review a new mechanism and benchmark for testing NMT performance, which includes both speed and space.

For measuring the speed:

The major insight here was to try and record a real world use case, generating a microbenchmark, that we can later "playback" using any proposed changes and observe whether there was an expected improvement or unexpected regression.

The process separates the recording of the memory allocations phase from the actual benchmark phase, allowing us to time the actual memory allocations later.

For measuring the memory space used:

Run the target process using the diagnostic runtime flag NMTRecordMemoryAllocations. The flag default value is 0, which turns the recording OFF. If it's set to the max value of 2147483647, it will keep recording until the process exits. Any other value will stop recording and exit the process once the specified numbers of allocation recordings has been reached. For example this command will record allocations of HelloWorld java example until it exits: "java -XX:+UnlockDiagnosticVMOptions -XX:NativeMemoryTracking=detail -XX:NMTRecordMemoryAllocations=2147483647 HelloWorld" This will produce the following 3 recording files:

  • hs_nmt_pid1758_info_record.log, which records session info such as the NMT mode (off, summary or detail) and memory header size used

  • hs_nmt_pid1758_memory_record.log, which records each memory allocation parameters such as type (malloc, realloc or free), requested size, actual size (as provided by the OS), NMT flag, time stamp and pointer values (used to consolidate the memory allocations released by the corresponding "free" operation)

  • hs_nmt_pid1758_threads_record.log, which records the thread id and thread name used by the recorded allocation operation

At this point we can use these 3 files to analyze the memory overhead of NMT. We can do this by using an external java based tool, which I wrote as a reference implementation. Others might choose to povide their own, more specialized tools that suit their specific needs. For example, the following command will analyze the memory overhead and print out NMT overhead analysis: java nmt.Main MemoryOverhead ./build/jdk/bin/java . 1758

-----------------------------------------------------------------------------------------------------------------------------
                                     NMT_LogInfo: NMT_detail


                            Requested (with NMT):  27,087,308 bytes
                            Allocated (with NMT):  28,183,984 bytes
   Overhead due to malloc rounding up (with NMT):   1,096,676 bytes [4.049%]

                         Requested (est. no NMT):  26,602,070 bytes
                         Allocated (est. no NMT):  26,712,192 bytes
Overhead due to malloc rounding up (est. no NMT):     110,122 bytes [0.414%]

         Overhead due to NMT headers (requested):     320,454 bytes [1.197%] [#17803]
         Overhead due to NMT objects (requested):     164,784 bytes [0.612%] [#1882]
                 Overhead due to NMT (requested):     485,238 bytes [1.824%]

               NMT overhead (requested) increase:       1.824 %
               NMT overhead (allocated) increase:       5.510 %

Other memory related choices are:

  • MemoryHistograms, which calculates and displays histograms of NMT memory overhead grouped by NMT category type (Java Heap, Class, Thread, etc.)

  • MemorySummary, which calculates and displays tables sorted by thread id and NMT component of total allocations and overheads

In order to obtain the speed numbers, we now actually have to run java process, which will play back the recorder operations and measure their individual times into yet another (fourth) recording file using a command such as: java -XX:+UnlockDiagnosticVMOptions -XX:NativeMemoryTracking=detail -XX:NMTBenchmarkRecordedDir=. -XX:NMTBenchmarkRecordedPID=1758

  • hs_nmt_pid1758_benchmark.log, which records timing information of each memory request, their requested size as well as the acttual size as allocated by the OS

At this time, we can look at the timing results (in nanoseconds). For example, the following command will display timing histograms grouped by the operation type (malloc, realloc, free) and sorted by their sizes: java nmt.Main PerformanceHistograms ./build/jdk/bin/java . 1758

Comparing the results of two or more benchmark timing results, thus answering whether a measured change is a performance improvmemnt or a regression (or noise), does not require further changes to the hotspot itself and can be provided by anyone. We are committed, however, to providing a reference implementation as part of our external java based tool, which requires some statistical comparisons of normal distributions and is under active development.

/cc hotspot


Progress

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

Errors

 ⚠️ Executable files are not allowed (file: src/hotspot/share/nmt/memoryLogRecorder.cpp)  ⚠️ Executable files are not allowed (file: src/hotspot/share/nmt/memoryLogRecorder.hpp)

Issue

  • JDK-8317453: NMT: Performance benchmarks are needed to measure speed and memory (Enhancement - P4)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 16034

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

Using diff file

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

gerard-ziemski avatar Oct 03 '23 22:10 gerard-ziemski

:wave: Welcome back gziemski! 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.

bridgekeeper[bot] avatar Oct 03 '23 22:10 bridgekeeper[bot]

@gerard-ziemski The hotspot label was successfully added.

openjdk[bot] avatar Oct 03 '23 22:10 openjdk[bot]

@gerard-ziemski this pull request can not be integrated into master due to one or more merge conflicts. To resolve these merge conflicts and update this pull request you can run the following commands in the local repository for your personal fork:

git checkout JDK-8317453
git fetch https://git.openjdk.org/jdk.git master
git merge FETCH_HEAD
# resolve conflicts and follow the instructions given by git merge
git commit -m "Merge master"
git push

openjdk[bot] avatar Oct 25 '23 20:10 openjdk[bot]

@gerard-ziemski This pull request has been inactive for more than 8 weeks and will be automatically closed if another 8 weeks passes without any activity. To avoid this, simply add a new comment to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

bridgekeeper[bot] avatar Jan 16 '24 00:01 bridgekeeper[bot]

@afshin-zafari @jdksjolen ping

gerard-ziemski avatar Jan 16 '24 17:01 gerard-ziemski

I found that the comments are not located to the exact places in code. Scroll up a few lines in the code, the places can be found. Sorry.

afshin-zafari avatar Jan 19 '24 11:01 afshin-zafari

❗ This change is not yet ready to be integrated. See the Progress checklist in the description for automated requirements.

openjdk[bot] avatar Mar 13 '24 20:03 openjdk[bot]

@gerard-ziemski This pull request has been inactive for more than 8 weeks and will be automatically closed if another 8 weeks passes without any activity. To avoid this, simply add a new comment to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

bridgekeeper[bot] avatar May 08 '24 22:05 bridgekeeper[bot]

Making progress...

gerard-ziemski avatar May 28 '24 19:05 gerard-ziemski

Getting ready for reviews. Should I close this one and open a new one?

gerard-ziemski avatar Jul 02 '24 15:07 gerard-ziemski

@gerard-ziemski This pull request has been inactive for more than 8 weeks and will be automatically closed if another 8 weeks passes without any activity. To avoid this, simply add a new comment to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

bridgekeeper[bot] avatar Aug 27 '24 20:08 bridgekeeper[bot]