Skip to content

Conversation

@iklam
Copy link
Member

@iklam iklam commented Oct 1, 2020

For analyzing the contents of a CDS archive, we need a "map file" that describes the archive in different levels of detail. This can be done using unified logging. E.g.,

java -Xshare:dump -Xlog:cds+map=trace:file=cds.map:none:filesize=0

For example, we can use the map file for troubleshooting JDK-8253495
(runtime/cds/DeterministicDump.java broken). We can diff two different cds.map files to see where the non-deterministic contents come from.

See attachments in JDK-8253909 for example map files at the info/debug/trace levels.


Progress

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

Testing

Linux x64 Windows x64 macOS x64
Build ✔️ (3/3 passed) ✔️ (2/2 passed) ✔️ (2/2 passed)
Test (tier1) ✔️ (0/0 passed) ✔️ (9/9 passed) ✔️ (9/9 passed)

Issue

Reviewers

Download

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

@bridgekeeper
Copy link

bridgekeeper bot commented Oct 1, 2020

👋 Welcome back iklam! 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
Copy link

openjdk bot commented Oct 1, 2020

@iklam 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.

@openjdk openjdk bot added the hotspot-runtime hotspot-runtime-dev@openjdk.org label Oct 1, 2020
@iklam iklam marked this pull request as ready for review October 1, 2020 20:11
@openjdk openjdk bot added the rfr Pull request is ready for review label Oct 1, 2020
@mlbridge
Copy link

mlbridge bot commented Oct 1, 2020

Webrevs

Copy link
Member

@tstuefe tstuefe left a comment

Choose a reason for hiding this comment

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

Not a full review, just some drive-by comments.


// Dump all the data [base...top). Pretend that the base address
// will be mapped to runtime_base at run-time.
static void write_data(address base, address top, address runtime_base) {
Copy link
Member

Choose a reason for hiding this comment

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

Consider printing the data with os::print_hex_dump() instead. Would slim down this coding.

} else {
log_info(cds, map)("Log level = info");
log_info(cds, map)("Run with -Xlog:cds+map=debug for more detailed information");
log_info(cds, map)("Run with -Xlog:cds+map=trace for even more detailed information");
Copy link
Member

Choose a reason for hiding this comment

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

Matter of taste, but I do not think usage information belongs into a log.

void write(ArchiveBuilder* builder, FileMapInfo* mapinfo,
GrowableArray<MemRegion> *closed_heap_regions,
GrowableArray<MemRegion> *open_heap_regions,
char* bitmap, size_t bitmap_size_in_bytes) {
Copy link
Member

Choose a reason for hiding this comment

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

Consider, instead of directly writing to UL, writing to an outputStream*. That would make the code more versatile and reusable. You can then use LogStream to print to UL with the same result.

// a different location at runtime. At dump time, the buffers may be at arbitrary locations
// picked by the OS. At runtime, we try to map at a fixed location (SharedBaseAddress). For
// consistency, we log everything using runtime addresses.
class ArchiveBuilder::CDSMapLogger {
Copy link
Member

Choose a reason for hiding this comment

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

AllStatic?

address header = address(mapinfo->header());
address header_end = header + mapinfo->header()->header_size();
write_region("header", header, header_end, 0);
write_data(header, header_end, 0);
Copy link
Member

Choose a reason for hiding this comment

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

Consider writing out the header members human-readable, that would be more useful than a hexdump. I'd also print them already at Info level, since often the header info is the only thing interesting.

void write_region(int region, char* base, size_t size,
bool read_only, bool allow_exec);
void write_bitmap_region(const CHeapBitMap* ptrmap,
char* write_bitmap_region(const CHeapBitMap* ptrmap,
Copy link
Member

Choose a reason for hiding this comment

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

Can you add a comment here and in MetaspaceShared::write_core_archive_regions() that the returned bitmap is c-heap allocated and needs to be freed?

@mlbridge
Copy link

mlbridge bot commented Oct 5, 2020

Mailing list message from Ioi Lam on hotspot-runtime-dev:

Hi Thomas,

Thanks for the review!

On 10/1/20 11:26 PM, Thomas Stuefe wrote:

Not a full review, just some drive-by comments.

src/hotspot/share/memory/archiveBuilder.cpp line 723:

721: // Dump all the data [base...top). Pretend that the base address
722: // will be mapped to runtime_base at run-time.
723: static void write_data(address base, address top, address runtime_base) {
Consider printing the data with os::print_hex_dump() instead. Would slim down this coding.

Fixed. I had to modify os::print_hex_dump() to optionally print a
"logical" address.

src/hotspot/share/memory/archiveBuilder.cpp line 769:

767: log_info(cds, map)("Log level = info");
768: log_info(cds, map)("Run with -Xlog:cds+map=debug for more detailed information");
769: log_info(cds, map)("Run with -Xlog:cds+map=trace for even more detailed information");
Matter of taste, but I do not think usage information belongs into a log.

Removed

src/hotspot/share/memory/archiveBuilder.cpp line 759:

757: GrowableArray<MemRegion> *closed_heap_regions,
758: GrowableArray<MemRegion> *open_heap_regions,
759: char* bitmap, size_t bitmap_size_in_bytes) {
Consider, instead of directly writing to UL, writing to an outputStream*. That would make the code more versatile and
reusable. You can then use LogStream to print to UL with the same result.

UL allows several logging levels. I don't know how to do that with
outputStream (without passing 3 different outputStreams).

src/hotspot/share/memory/archiveBuilder.cpp line 609:

607: // picked by the OS. At runtime, we try to map at a fixed location (SharedBaseAddress). For
608: // consistency, we log everything using runtime addresses.
609: class ArchiveBuilder::CDSMapLogger {
AllStatic?

Fixed

src/hotspot/share/memory/archiveBuilder.cpp line 775:

773: address header_end = header + mapinfo->header()->header_size();
774: write_region("header", header, header_end, 0);
775: write_data(header, header_end, 0);
Consider writing out the header members human-readable, that would be more useful than a hexdump. I'd also print them
already at Info level, since often the header info is the only thing interesting.

Done. I attached the updated example logs to the bug report.

src/hotspot/share/memory/filemap.hpp line 461:

459: void write_region(int region, char* base, size_t size,
460: bool read_only, bool allow_exec);
461: char* write_bitmap_region(const CHeapBitMap* ptrmap,
Can you add a comment here and in MetaspaceShared::write_core_archive_regions() that the returned bitmap is c-heap
allocated and needs to be freed?

Fixed.

Thanks
- Ioi

st->print_cr("- use_full_module_graph %d", _use_full_module_graph);
st->print_cr("- ptrmap_size_in_bits: " SIZE_FORMAT, _ptrmap_size_in_bits);
}

Copy link
Member

Choose a reason for hiding this comment

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

Great, thank you!

Comment on lines +689 to +693
static void print_hex_dump(outputStream* st, address start, address end, int unitsize,
int bytes_per_line, address logical_start);
static void print_hex_dump(outputStream* st, address start, address end, int unitsize) {
print_hex_dump(st, start, end, unitsize, /*bytes_per_line=*/16, /*logical_start=*/start);
}
Copy link
Member

Choose a reason for hiding this comment

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

This is a bit unclear. Could we do it like this instead:

// Print a hex dump from [start .. end). Output lines are prefixed with addresses.
static void print_hex_dump(outputStream* st, address start, address end, int unitsize)

// Print a hex dump from [base+start .. base+end). Output lines are prefixed with offset in relation to base.
static void print_hex_dump(outputStream* st, address base, intx start, intx end, int unitsize)

Copy link
Member Author

Choose a reason for hiding this comment

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

But this is not what I want. I am calling with parameters like:

print_hex_dump(st, /*start=*/0x7ffff0000, end, unitsize, bytes_per_line,  /*logical_start=*/0x800000000);

So my buffer is at some random address, but I want the print out to pretend that it started at 0x800000000.

Copy link
Member

Choose a reason for hiding this comment

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

Okay. A bit special, usually one would base it at 0 (e.g. printing network packets or similar). I think its okay then. We can revisit this later if needed.

CDSMapLogger logger;
logger.write(this, mapinfo, closed_heap_regions,open_heap_regions,
bitmap, bitmap_size_in_bytes);
CDSMapLogger::write(this, mapinfo, closed_heap_regions,open_heap_regions,
Copy link
Member

Choose a reason for hiding this comment

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

Needs a space before open_heap_regions.

Copy link
Member

@calvinccheung calvinccheung left a comment

Choose a reason for hiding this comment

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

One nit in archiveBuilder.cpp.

@openjdk
Copy link

openjdk bot commented Oct 6, 2020

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

8253909: Implement detailed map file for CDS

Reviewed-by: stuefe, ccheung

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

  • abe2593: 8232092: (fs) Files::isWritable returns false on a writeable root directory (win)
  • 5a9bd41: 8254102: use ProcessHandle::pid instead of ManagementFactory::getRuntimeMXBean to get pid in tests
  • 38159d5: 8253876: jdk/test/lib/hexdump/ASN1FormatterTest.java fails with "AssertionError: Lines expected [126] but found [202]"

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.

@openjdk openjdk bot added the ready Pull request is ready to be integrated label Oct 6, 2020
}

write_region(MetaspaceShared::bm, (char*)buffer, size_in_bytes, /*read_only=*/true, /*allow_exec=*/false);
return (char*)buffer;
Copy link
Member

Choose a reason for hiding this comment

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

buffer is declared as char*, no need to typecast.

Copy link
Member

@tstuefe tstuefe left a comment

Choose a reason for hiding this comment

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

LGTM

@iklam
Copy link
Member Author

iklam commented Oct 7, 2020

/integrate

1 similar comment
@iklam
Copy link
Member Author

iklam commented Oct 7, 2020

/integrate

@openjdk openjdk bot closed this Oct 8, 2020
@openjdk 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 Oct 8, 2020
@openjdk
Copy link

openjdk bot commented Oct 8, 2020

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

  • 7733a0e: 8254182: remove Utils.tryFindJvmPid/waitForJvmPid
  • 4e5ef30: 8254104: MethodCounters must exist before nmethod is installed
  • fd0cb98: 8253901: ARM32: SIGSEGV during monitorexit due to incorrect register use (after JDK-8253540)
  • abe2593: 8232092: (fs) Files::isWritable returns false on a writeable root directory (win)
  • 5a9bd41: 8254102: use ProcessHandle::pid instead of ManagementFactory::getRuntimeMXBean to get pid in tests
  • 38159d5: 8253876: jdk/test/lib/hexdump/ASN1FormatterTest.java fails with "AssertionError: Lines expected [126] but found [202]"

Your commit was automatically rebased without conflicts.

Pushed as commit d1e94ee.

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

hotspot-runtime hotspot-runtime-dev@openjdk.org integrated Pull request has been integrated

Development

Successfully merging this pull request may close these issues.

3 participants