8256367: [windows] Better logging for some system calls

Reviewed-by: iklam
This commit is contained in:
Thomas Stuefe 2020-11-16 07:15:43 +00:00
parent 1e9a432d59
commit 298bce1d92

View File

@ -178,6 +178,91 @@ static inline double fileTimeAsDouble(FILETIME* time) {
// Implementation of os // Implementation of os
#define RANGE_FORMAT "[" PTR_FORMAT "-" PTR_FORMAT ")"
#define RANGE_FORMAT_ARGS(p, len) p2i(p), p2i((address)p + len)
// A number of wrappers for more frequently used system calls, to add standard logging.
struct PreserveLastError {
const DWORD v;
PreserveLastError() : v(::GetLastError()) {}
~PreserveLastError() { ::SetLastError(v); }
};
// Logging wrapper for VirtualAlloc
static LPVOID virtualAlloc(LPVOID lpAddress, SIZE_T dwSize, DWORD flAllocationType, DWORD flProtect) {
LPVOID result = ::VirtualAlloc(lpAddress, dwSize, flAllocationType, flProtect);
if (result != NULL) {
log_trace(os)("VirtualAlloc(" PTR_FORMAT ", " SIZE_FORMAT ", %x, %x) returned " PTR_FORMAT "%s.",
p2i(lpAddress), dwSize, flAllocationType, flProtect, p2i(result),
((lpAddress != NULL && result != lpAddress) ? " <different base!>" : ""));
} else {
PreserveLastError ple;
log_info(os)("VirtualAlloc(" PTR_FORMAT ", " SIZE_FORMAT ", %x, %x) failed (%u).",
p2i(lpAddress), dwSize, flAllocationType, flProtect, ple.v);
}
return result;
}
// Logging wrapper for VirtualFree
static BOOL virtualFree(LPVOID lpAddress, SIZE_T dwSize, DWORD dwFreeType) {
BOOL result = ::VirtualFree(lpAddress, dwSize, dwFreeType);
if (result != FALSE) {
log_trace(os)("VirtualFree(" PTR_FORMAT ", " SIZE_FORMAT ", %x) succeeded",
p2i(lpAddress), dwSize, dwFreeType);
} else {
PreserveLastError ple;
log_info(os)("VirtualFree(" PTR_FORMAT ", " SIZE_FORMAT ", %x) failed (%u).",
p2i(lpAddress), dwSize, dwFreeType, ple.v);
}
return result;
}
// Logging wrapper for VirtualAllocExNuma
static LPVOID virtualAllocExNuma(HANDLE hProcess, LPVOID lpAddress, SIZE_T dwSize, DWORD flAllocationType,
DWORD flProtect, DWORD nndPreferred) {
LPVOID result = ::VirtualAllocExNuma(hProcess, lpAddress, dwSize, flAllocationType, flProtect, nndPreferred);
if (result != NULL) {
log_trace(os)("VirtualAllocExNuma(" PTR_FORMAT ", " SIZE_FORMAT ", %x, %x, %x) returned " PTR_FORMAT "%s.",
p2i(lpAddress), dwSize, flAllocationType, flProtect, nndPreferred, p2i(result),
((lpAddress != NULL && result != lpAddress) ? " <different base!>" : ""));
} else {
PreserveLastError ple;
log_info(os)("VirtualAllocExNuma(" PTR_FORMAT ", " SIZE_FORMAT ", %x, %x, %x) failed (%u).",
p2i(lpAddress), dwSize, flAllocationType, flProtect, nndPreferred, ple.v);
}
return result;
}
// Logging wrapper for MapViewOfFileEx
static LPVOID mapViewOfFileEx(HANDLE hFileMappingObject, DWORD dwDesiredAccess, DWORD dwFileOffsetHigh,
DWORD dwFileOffsetLow, SIZE_T dwNumberOfBytesToMap, LPVOID lpBaseAddress) {
LPVOID result = ::MapViewOfFileEx(hFileMappingObject, dwDesiredAccess, dwFileOffsetHigh,
dwFileOffsetLow, dwNumberOfBytesToMap, lpBaseAddress);
if (result != NULL) {
log_trace(os)("MapViewOfFileEx(" PTR_FORMAT ", " SIZE_FORMAT ") returned " PTR_FORMAT "%s.",
p2i(lpBaseAddress), dwNumberOfBytesToMap, p2i(result),
((lpBaseAddress != NULL && result != lpBaseAddress) ? " <different base!>" : ""));
} else {
PreserveLastError ple;
log_info(os)("MapViewOfFileEx(" PTR_FORMAT ", " SIZE_FORMAT ") failed (%u).",
p2i(lpBaseAddress), dwNumberOfBytesToMap, ple.v);
}
return result;
}
// Logging wrapper for UnmapViewOfFile
static BOOL unmapViewOfFile(LPCVOID lpBaseAddress) {
BOOL result = ::UnmapViewOfFile(lpBaseAddress);
if (result != FALSE) {
log_trace(os)("UnmapViewOfFile(" PTR_FORMAT ") succeeded", p2i(lpBaseAddress));
} else {
PreserveLastError ple;
log_info(os)("UnmapViewOfFile(" PTR_FORMAT ") failed (%u).", p2i(lpBaseAddress), ple.v);
}
return result;
}
bool os::unsetenv(const char* name) { bool os::unsetenv(const char* name) {
assert(name != NULL, "Null pointer"); assert(name != NULL, "Null pointer");
return (SetEnvironmentVariable(name, NULL) == TRUE); return (SetEnvironmentVariable(name, NULL) == TRUE);
@ -340,7 +425,6 @@ int os::get_native_stack(address* stack, int frames, int toSkip) {
return captured; return captured;
} }
// os::current_stack_base() // os::current_stack_base()
// //
// Returns the base of the stack, which is the stack's // Returns the base of the stack, which is the stack's
@ -2900,7 +2984,7 @@ static char* allocate_pages_individually(size_t bytes, char* addr, DWORD flags,
// Overflowed. // Overflowed.
return NULL; return NULL;
} }
p_buf = (char *) VirtualAlloc(addr, p_buf = (char *) virtualAlloc(addr,
size_of_reserve, // size of Reserve size_of_reserve, // size of Reserve
MEM_RESERVE, MEM_RESERVE,
PAGE_READWRITE); PAGE_READWRITE);
@ -2946,7 +3030,7 @@ static char* allocate_pages_individually(size_t bytes, char* addr, DWORD flags,
p_new = NULL; p_new = NULL;
} else { } else {
if (!UseNUMAInterleaving) { if (!UseNUMAInterleaving) {
p_new = (char *) VirtualAlloc(next_alloc_addr, p_new = (char *) virtualAlloc(next_alloc_addr,
bytes_to_rq, bytes_to_rq,
flags, flags,
prot); prot);
@ -2954,7 +3038,7 @@ static char* allocate_pages_individually(size_t bytes, char* addr, DWORD flags,
// get the next node to use from the used_node_list // get the next node to use from the used_node_list
assert(numa_node_list_holder.get_count() > 0, "Multiple NUMA nodes expected"); assert(numa_node_list_holder.get_count() > 0, "Multiple NUMA nodes expected");
DWORD node = numa_node_list_holder.get_node_list_entry(count % numa_node_list_holder.get_count()); DWORD node = numa_node_list_holder.get_node_list_entry(count % numa_node_list_holder.get_count());
p_new = (char *)VirtualAllocExNuma(hProc, next_alloc_addr, bytes_to_rq, flags, prot, node); p_new = (char *)virtualAllocExNuma(hProc, next_alloc_addr, bytes_to_rq, flags, prot, node);
} }
} }
@ -3100,7 +3184,7 @@ char* os::map_memory_to_file(char* base, size_t size, int fd) {
return NULL; return NULL;
} }
LPVOID addr = MapViewOfFileEx(fileMapping, FILE_MAP_WRITE, 0, 0, size, base); LPVOID addr = mapViewOfFileEx(fileMapping, FILE_MAP_WRITE, 0, 0, size, base);
CloseHandle(fileMapping); CloseHandle(fileMapping);
@ -3127,14 +3211,19 @@ void os::split_reserved_memory(char *base, size_t size, size_t split) {
assert(is_aligned(base, os::vm_allocation_granularity()), "Sanity"); assert(is_aligned(base, os::vm_allocation_granularity()), "Sanity");
assert(is_aligned(split_address, os::vm_allocation_granularity()), "Sanity"); assert(is_aligned(split_address, os::vm_allocation_granularity()), "Sanity");
release_memory(base, size); const bool rc = release_memory(base, size) &&
attempt_reserve_memory_at(base, split); (attempt_reserve_memory_at(base, split) != NULL) &&
attempt_reserve_memory_at(split_address, size - split); (attempt_reserve_memory_at(split_address, size - split) != NULL);
if (!rc) {
log_warning(os)("os::split_reserved_memory failed for [" RANGE_FORMAT ")",
RANGE_FORMAT_ARGS(base, size));
assert(false, "os::split_reserved_memory failed for [" RANGE_FORMAT ")",
RANGE_FORMAT_ARGS(base, size));
}
// NMT: nothing to do here. Since Windows implements the split by // NMT: nothing to do here. Since Windows implements the split by
// releasing and re-reserving memory, the parts are already registered // releasing and re-reserving memory, the parts are already registered
// as individual mappings with NMT. // as individual mappings with NMT.
} }
// Multiple threads can race in this code but it's not possible to unmap small sections of // Multiple threads can race in this code but it's not possible to unmap small sections of
@ -3198,7 +3287,7 @@ char* os::pd_attempt_reserve_memory_at(char* addr, size_t bytes) {
// will go thru reserve_memory_special rather than thru here. // will go thru reserve_memory_special rather than thru here.
bool use_individual = (UseNUMAInterleaving && !UseLargePages); bool use_individual = (UseNUMAInterleaving && !UseLargePages);
if (!use_individual) { if (!use_individual) {
res = (char*)VirtualAlloc(addr, bytes, MEM_RESERVE, PAGE_READWRITE); res = (char*)virtualAlloc(addr, bytes, MEM_RESERVE, PAGE_READWRITE);
} else { } else {
elapsedTimer reserveTimer; elapsedTimer reserveTimer;
if (Verbose && PrintMiscellaneous) reserveTimer.start(); if (Verbose && PrintMiscellaneous) reserveTimer.start();
@ -3277,7 +3366,7 @@ char* os::pd_reserve_memory_special(size_t bytes, size_t alignment, char* addr,
// normal policy just allocate it all at once // normal policy just allocate it all at once
DWORD flag = MEM_RESERVE | MEM_COMMIT | MEM_LARGE_PAGES; DWORD flag = MEM_RESERVE | MEM_COMMIT | MEM_LARGE_PAGES;
char * res = (char *)VirtualAlloc(addr, bytes, flag, prot); char * res = (char *)virtualAlloc(addr, bytes, flag, prot);
return res; return res;
} }
@ -3314,7 +3403,7 @@ bool os::pd_commit_memory(char* addr, size_t bytes, bool exec) {
// is always within a reserve covered by a single VirtualAlloc // is always within a reserve covered by a single VirtualAlloc
// in that case we can just do a single commit for the requested size // in that case we can just do a single commit for the requested size
if (!UseNUMAInterleaving) { if (!UseNUMAInterleaving) {
if (VirtualAlloc(addr, bytes, MEM_COMMIT, PAGE_READWRITE) == NULL) { if (virtualAlloc(addr, bytes, MEM_COMMIT, PAGE_READWRITE) == NULL) {
NOT_PRODUCT(warn_fail_commit_memory(addr, bytes, exec);) NOT_PRODUCT(warn_fail_commit_memory(addr, bytes, exec);)
return false; return false;
} }
@ -3339,7 +3428,7 @@ bool os::pd_commit_memory(char* addr, size_t bytes, bool exec) {
MEMORY_BASIC_INFORMATION alloc_info; MEMORY_BASIC_INFORMATION alloc_info;
VirtualQuery(next_alloc_addr, &alloc_info, sizeof(alloc_info)); VirtualQuery(next_alloc_addr, &alloc_info, sizeof(alloc_info));
size_t bytes_to_rq = MIN2(bytes_remaining, (size_t)alloc_info.RegionSize); size_t bytes_to_rq = MIN2(bytes_remaining, (size_t)alloc_info.RegionSize);
if (VirtualAlloc(next_alloc_addr, bytes_to_rq, MEM_COMMIT, if (virtualAlloc(next_alloc_addr, bytes_to_rq, MEM_COMMIT,
PAGE_READWRITE) == NULL) { PAGE_READWRITE) == NULL) {
NOT_PRODUCT(warn_fail_commit_memory(next_alloc_addr, bytes_to_rq, NOT_PRODUCT(warn_fail_commit_memory(next_alloc_addr, bytes_to_rq,
exec);) exec);)
@ -3391,11 +3480,11 @@ bool os::pd_uncommit_memory(char* addr, size_t bytes) {
} }
assert((size_t) addr % os::vm_page_size() == 0, "uncommit on page boundaries"); assert((size_t) addr % os::vm_page_size() == 0, "uncommit on page boundaries");
assert(bytes % os::vm_page_size() == 0, "uncommit in page-sized chunks"); assert(bytes % os::vm_page_size() == 0, "uncommit in page-sized chunks");
return (VirtualFree(addr, bytes, MEM_DECOMMIT) != 0); return (virtualFree(addr, bytes, MEM_DECOMMIT) == TRUE);
} }
bool os::pd_release_memory(char* addr, size_t bytes) { bool os::pd_release_memory(char* addr, size_t bytes) {
return VirtualFree(addr, 0, MEM_RELEASE) != 0; return virtualFree(addr, 0, MEM_RELEASE) != 0;
} }
bool os::pd_create_stack_guard_pages(char* addr, size_t size) { bool os::pd_create_stack_guard_pages(char* addr, size_t size) {
@ -4941,10 +5030,9 @@ char* os::pd_map_memory(int fd, const char* file_name, size_t file_offset,
// we might consider DLLizing the shared archive with a proper PE // we might consider DLLizing the shared archive with a proper PE
// header so that mapping executable + sharing is possible. // header so that mapping executable + sharing is possible.
base = (char*) VirtualAlloc(addr, bytes, MEM_COMMIT | MEM_RESERVE, base = (char*) virtualAlloc(addr, bytes, MEM_COMMIT | MEM_RESERVE,
PAGE_READWRITE); PAGE_READWRITE);
if (base == NULL) { if (base == NULL) {
log_info(os)("VirtualAlloc() failed: GetLastError->%ld.", GetLastError());
CloseHandle(hFile); CloseHandle(hFile);
return NULL; return NULL;
} }
@ -4976,10 +5064,9 @@ char* os::pd_map_memory(int fd, const char* file_name, size_t file_offset,
} }
DWORD access = read_only ? FILE_MAP_READ : FILE_MAP_COPY; DWORD access = read_only ? FILE_MAP_READ : FILE_MAP_COPY;
base = (char*)MapViewOfFileEx(hMap, access, 0, (DWORD)file_offset, base = (char*)mapViewOfFileEx(hMap, access, 0, (DWORD)file_offset,
(DWORD)bytes, addr); (DWORD)bytes, addr);
if (base == NULL) { if (base == NULL) {
log_info(os)("MapViewOfFileEx() failed: GetLastError->%ld.", GetLastError());
CloseHandle(hMap); CloseHandle(hMap);
CloseHandle(hFile); CloseHandle(hFile);
return NULL; return NULL;
@ -5051,9 +5138,8 @@ bool os::pd_unmap_memory(char* addr, size_t bytes) {
return pd_release_memory(addr, bytes); return pd_release_memory(addr, bytes);
} }
BOOL result = UnmapViewOfFile(addr); BOOL result = unmapViewOfFile(addr);
if (result == 0) { if (result == 0) {
log_info(os)("UnmapViewOfFile() failed: GetLastError->%ld.", GetLastError());
return false; return false;
} }
return true; return true;