JDK-8207139 : NMT is not enabled on Windows 2016/10
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 11
  • Priority: P2
  • Status: Closed
  • Resolution: Fixed
  • OS: windows_10
  • CPU: x86
  • Submitted: 2018-07-11
  • Updated: 2018-08-16
  • Resolved: 2018-08-02
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 12
11 b26Fixed 12Fixed
Related Reports
Relates :  
JDK-8074895 - os::getenv is inadequate
Description
For JDK11 b20 NMT doesn't work on Windows 2016
java -XX:NativeMemoryTracking=detail fails to enable NMT with 
"Java HotSpot(TM) 64-Bit Server VM warning: Native Memory Tracking did not setup properly, using wrong launcher?"


The bug is Windows-2016/10 specific only!
Comments
Fix Request Reason: Reinstate NMT functionality on Windows 10 Webrev: http://cr.openjdk.java.net/~mgronlun/8207139/webrev00/ Review thread: http://mail.openjdk.java.net/pipermail/hotspot-runtime-dev/2018-August/029373.html Reviewed-by: dcubed, zgu, dholmes Testing: hotspot_nmt Risk: low
01-08-2018
Fix request approved.
01-08-2018
[~mgronlun] My thanks also for the extensive investigation, analysis and writeup.
29-07-2018
Thanks Zhengyu, I have considered two alternatives to solve this situation proper: 1. Revisit CRT linkages 2. Re-introduce the os::getenv() abstraction that was taken out as of https://bugs.openjdk.java.net/browse/JDK-8074895 . These alternatives will increase the risk for 11, so we might need to consider yet another, safer, alternative: 3. Do a local fix that will read the NMT env variable using GetEnvironmentVariable() (as you say, to use Win API at this location). This will solve this specific case for NMT. See attached patch: 8207139_local_fix_Windows_API.patch for a suggestion on how this could be done. We could attempt to better understand and address alternatives 1 and/or 2 in 12.
26-07-2018
Markus, Thanks for the fantastic writings and great job to get to the root of the causes. However, I think the right solution is to use WIN API instead of playing around CRT linkage.
26-07-2018
Attached a potential fix / workaround which will change the linkage for the CRT. Unknown impact of changing the CRT linkage from static to dynamic. Unsure of the original rationale for the static linkage for launcher and jli (outside of having a "self-contained" launcher).
24-07-2018
Visual Studio 2013 Platform Toolset -> CRT v120 _putenv() has an explict call to SetEnvironmentVariableA 1912 305127 [ 2] java!__crtsetenv 1 0 [ 3] KERNEL32!SetEnvironmentVariableAStub <<-- thunks to A 8 0 [ 3] KERNELBASE!SetEnvironmentVariableA getenv() using [msvcr120!_environ (00007ffc`462c0408)] msvcr120!_environ 0x0000028d`2b483aa0 -> 0x0000028d`2b483d90 "ADD_EXPORTS1=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED" ... 0000028d`2b483ba0 0000028d`2b4a5de0 0000028d`2b483ba8 0000028d`2b4a5ed0 0000028d`2b483bb0 0000028d`2b4a5f40 0000028d`2b483bb8 0000028d`2b4a5fd0 0000028d`2b483bc0 0000028d`2b4a6090 0000028d`2b483bc8 0000028d`2b4a61c0 0000028d`2b483bd0 0000028d`2b4a6250 0000028d`2b483bd8 0000028d`2b4a62b0 0000028d`2b483be0 0000028d`2b4a6310 0000028d`2b483be8 0000028d`2b4a63a0 0000028d`2b483bf0 0000028d`2b4a6400 0000028d`2b483bf8 0000028d`2b4a6470 0000028d`2b483c00 0000028d`2b4a64c0 0000028d`2b483c08 0000028d`2b4a6520 0000028d`2b483c10 0000028d`2b4a6580 <<--- the NMT entry set via _putenv() makes it into the environment table for msvcr120!_environ 0000028d`2b483c18 0000028d`2b4a65d0 0000028d`2b4a6580 "NMT_LEVEL_14156=detail" Visual Studio 2017 Platform Toolset -> v141 CRT _putenv() also has an explict call to SetEnvironmentVariableA but here it thunks to SetEnvironmentVariableW: 62 1915 [ 4] java!__acrt_convert_wcs_mbs<char,wchar_t,unsigned __int64 __cdecl(wchar_t * __ptr64,char const * __ptr64,unsigned __int64,__crt_locale_pointers * __ptr64),__crt_win32_buffer_internal_dynamic_resizing> 45 4100 [ 3] java!__acrt_SetEnvironmentVariableA 1 0 [ 4] KERNEL32!SetEnvironmentVariableWStub <<--- thunks to W 81 0 [ 4] KERNELBASE!SetEnvironmentVariableW 208 0 [ 5] ntdll!RtlSetEnvironmentVar getenv() using [ucrtbase!environ_table] does not contain an NMT entry set via _putenv() ucrtbase!environ_table dps 00000221`94697570 00000221`94697570 00000221`9468c3e0 00000221`94697578 00000221`9468a6a0 00000221`94697580 00000221`9468a710 00000221`94697588 00000221`9468c180 00000221`94697590 00000221`9468c1e0 00000221`94697598 00000221`9468c230 00000221`946975a0 00000221`946978c0 00000221`946975a8 00000221`94697930 00000221`946975b0 00000221`946979a0 00000221`946975b8 00000221`94697a10 00000221`946975c0 00000221`94697a60 00000221`946975c8 00000221`94697ab0 00000221`946975d0 00000221`94686400 00000221`946975d8 00000221`94697b10 00000221`946975e0 00000221`94697b80 00000221`946975e8 00000221`94697c10 <<-- there is no entry in this table corresponding to what was set via _putenv() ... Summary: This is a change in behavior (regression) in the Windows CRT from v120 -> v141.
20-07-2018
// _putenv() java!_environ_table +0x000 _value : [1] 0x00000264`d07a6cf0 -> 0x00000264`d079a150 "ADD_EXPORTS1=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED" java!create_environment_string<char>+0x13f [minkernel\crts\ucrt\src\desktopcrt\env\putenv.cpp @ 100] java!common_putenv_nolock<char>+0x4f [minkernel\crts\ucrt\src\desktopcrt\env\putenv.cpp @ 178] java!common_putenv<char>+0x26 [minkernel\crts\ucrt\src\desktopcrt\env\putenv.cpp @ 209] java!SetJvmEnvironment+0x161 [d:\dev\jdk\jdk\open\src\java.base\share\native\libjli\java.c @ 854] java!JLI_Launch+0x1e5 [d:\dev\jdk\jdk\open\src\java.base\share\native\libjli\java.c @ 285] java!main+0x3ce [d:\dev\jdk\jdk\open\src\java.base\share\native\launcher\main.c @ 215] java!invoke_main+0x22 java!__scrt_common_main_seh+0x10c [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 283] KERNEL32!BaseThreadInitThunk+0x14 ntdll!RtlUserThreadStart+0x21 ��� 00007ff6`38080c61 7512 jne java!common_set_variable_in_environment_nolock<char>+0x85 (00007ff6`38080c75) 00007ff6`38080c63 498bce mov rcx,r14 00007ff6`38080c66 e8c9050000 call java!copy_environment<char> (00007ff6`38081234) <<-- new env table 00007ff6`38080c6b 4c8bf0 mov r14,rax 00007ff6`38080c6e 48890563e00100 mov qword ptr [java!_environ_table (00007ff6`3809ecd8)],rax <<-- set new env table java!_environ_table +0x000 _value : [1] 0x00000264`d07ad480 -> 0x00000264`d07ad7d0 "ADD_EXPORTS1=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED" ... 00000264`d07ad788 00000264`d07b2980 00000264`d07ad790 00000264`d07aca20 <<-- new entry added 00000264`d07ad798 00000000`00000000 00000264`d07aca20 "NMT_LEVEL_82504=detail" The above list is the environment table for the CRT instance associated with java.exe / jli. Note: Although the added environment variable entry is CRT "local", it also seems Windows performs a write-through for the added entry by also adding an additional internal entry (UNICODE) to the Process Environment Block (PEB): ... Environment: 00000264d07b2ae0 <<-- UNICODE ... NMT_LEVEL_82504=detail <<--------------------- NUMBER_OF_PROCESSORS=4 00000264`d07b45b4 "MSMPI_BIN=C:\Program Files\Microsoft MPI\Bin\" 00000264`d07b4658 "NMT_LEVEL_82504=detail" <<---------------------------- UNICODE 00000264`d07b4658 4e 00 4d 00 54 00 5f 00-4c 00 45 00 56 00 45 00 N.M.T._.L.E.V.E. 00000264`d07b4668 4c 00 5f 00 38 00 32 00-35 00 30 00 34 00 3d 00 L._.8.2.5.0.4.=. 00000264`d07b4678 64 00 65 00 74 00 61 00-69 00 6c 00 00 00 4e 00 d.e.t.a.i.l...N. ... // getenv() getenv() does not perform a "read-though" to the PEB; it only looks in the dynamically loaded CRT instance (here ucrtbase!environ_table): ��� lea rcx,[ucrtbase!environ_table+0x1d8 (00007fff`7a776e38)] It is possible to read the environment variable set via the CRT _putenv() routine by going over the PEB. Easiest way to do this is to use GetEnvironmentVariable(): For example: diff -r c96c7d08ae49 src/hotspot/share/services/memTracker.cpp --- a/src/hotspot/share/services/memTracker.cpp Thu Jul 19 16:22:19 2018 +0800 +++ b/src/hotspot/share/services/memTracker.cpp Fri Jul 20 01:08:02 2018 +0200 @@ -52,8 +52,10 @@ NMT_TrackingLevel MemTracker::init_tracking_level() { NMT_TrackingLevel level = NMT_off; char buf[64]; + char result[64]; jio_snprintf(buf, sizeof(buf), "NMT_LEVEL_%d", os::current_process_id()); - const char *nmt_option = ::getenv(buf); + GetEnvironmentVariable(buf, result, 64); + const char *nmt_option = result; if (nmt_option != NULL) { if (strcmp(nmt_option, "summary") == 0) { level = NMT_summary; result: Local var @ 0xb61212f000 Type char[] [64] "detail" nmt_option: Local var @ 0xb61212efb8 Type char* 0x000000b6`1212f000 "detail" Interestingly, there once existed platform specific code here as part of os::getenv(), and on Windows that would have used GetEnvironmentVariable() here. See: https://bugs.openjdk.java.net/browse/JDK-8074895 // there seems to be some leftovers here: // Remove the environment variable to avoid leaking to child processes os::unsetenv(buf); <<--- removes the PEB entry (but not the CRT instance entry in java!_environ_table) } java!_environ_table +0x000 _value : [1] 0x0000029f`f8d4d3e0 -> 0x0000029f`f8d4d730 "ADD_EXPORTS1=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED" da 0000029f`f8d4c980 0000029f`f8d4c980 "NMT_LEVEL_41316=detail" <<-- still available The overall problem should probably be framed in terms of the asymmetry between _putenv() and getenv(), and we need to figure out what is the expected behavior here. Is control using linking (/MD vs /MT) a supported option? What about backwards compatibility?
19-07-2018
Every CRT object, for example an environment variable or a file handle, is associated with "its" CRT instance. java.exe + jli_static.lib is statically linked to a CRT by means of -MT [this unit will now have its own, local, CRT instance] jvm.dll is dynamically linked to a CRT instance, to be discovered during runtime by means of -MD [this will use the runtime loaded CRT instance, via ucrtbase.dll] The _putenv() of "NMT_LEVEL_<pid>" in java!SetJVMEnvironment() is local to the java / jli CRT instance. The getenv() at MemTracker::init_tracking_level() in jvm.dll attempts to reads from the runtime loaded, shared, CRT instance associated with ucrtbase.dll. But it will fail because there is no such entry. Microsoft have done refactoring associated with breaking out ucrtbase.dll into a Windows component (from the CRT, starting with Visual Studio 2015). It looks like CRT instance boundaries are now enforced much more strict that was done previously (java!__dcrt_initial_narrow_environment is a new structure for the environment) The environment variable passing example in this document describes the NMT situation well: https://docs.microsoft.com/en-us/cpp/c-runtime-library/potential-errors-passing-crt-objects-across-dll-boundaries Additional information about CRT refactoring (from Visual Studio 2015): https://docs.microsoft.com/en-us/cpp/c-runtime-library/crt-library-features. I did an experiment to validate some of this, by removing some static link code (attached), and this does indeed get the NMT environment variable passing back on track. It does this by only using a single shared runtime linked CRT instance for passing CRT objects between JLI and the jvm.dll. Attaching only for inspiration, not a solution.
19-07-2018
Here is the explanation why getenv works in jli.dll, but not jvm.dll: jli.dll is static linked and jvm.dll is not, and they are two completely different c function entries. Print getenv function pointers from jli.dll and jvm.dll: C:\Users\zgu\workspace\jdk11\build\windows-x86_64-normal-server-fastdebug\jdk\bin>java -XX:NativeMemoryTracking=detail -version Launcher getenv : 0x19c30ca8 JVM getenv: 0x36611390 However, it is strange that getenv can read environment variables set from command line, e.g. JAVA_TOOL_OPTIONS, but not the one set by jli vs putenv(). https://docs.microsoft.com/en-us/cpp/c-runtime-library/reference/getenv-wgetenv has following statement: "getenv operates only on the data structures accessible to the run-time library and not on the environment "segment" created for the process by the operating system." that might be the problem?
17-07-2018
The only obvious difference between libjli and libjvm that I can see is that the former is C while the latter is C++. I'm not able to find what flags would be indicative of activating "UWP" and compile or link time so don't know what to look for.
16-07-2018
Erik, Could you confirm that JVM should not and is not built as a UWP application, as David stated.
16-07-2018
Looks like a code fix in hotspot is needed.
16-07-2018
I did not think we were building the JVM as a UWP application. Further as I stated I would not expect an unavailable API to just do nothing rather than generate an error. Plus getenv works in jli.dll just not in jvm,.dll. So there's more to this I think. IIRC it's not that long since we got rid of os::getenv! But to get a fix for 11 we may have to just change the code - and then try to find out exactly what's going on. FYI I'm now away for two weeks so this is my last word.
14-07-2018
Universal Windows Platform (UWP) was introduced in Windows 10. getenv CRT function is *not* supported and has *no* workaround* under UWP according to https://docs.microsoft.com/en-us/cpp/cppcx/crt-functions-not-supported-in-universal-windows-platform-apps. While GetEnvironmentVariable() is one of UWP core APIs (https://docs.microsoft.com/en-us/uwp/win32-and-com/win32-and-com-for-uwp-apps), is supported by all Windows 10 devices. Looks like it is the time to introduce os::getenv()/os::putenv(), alongside with existing os::unsetenv().
13-07-2018
Of course we also need to explain how getenv works fine inside libjli but not libjvm. Different link flags?
13-07-2018
Possible hint here as to what may be going wrong: https://docs.microsoft.com/en-us/cpp/c-runtime-library/crt-library-features "Starting in Visual Studio 2015, the CRT has been refactored into new binaries. The Universal CRT (UCRT) contains the functions and globals exported by the standard C99 CRT library. The UCRT is now a Windows component, and ships as part of Windows 10." Then from: https://docs.microsoft.com/en-us/cpp/c-runtime-library/reference/getenv-wgetenv Important! This API cannot be used in applications that execute in the Windows Runtime. For more information, see CRT functions not supported in Universal Windows Platform apps. --- Is there a connection here between "Universal Windows Platform apps" and use of the "Universal CRT"? One would expect a runtime error if a function were not available, rather than just not working.
13-07-2018
This problem has been introduced by the change to Visual Studio 2017 - or more likely the change to the vcruntime140.dll version of the runtime that came with it - though only for Windows 10
13-07-2018
No problem with JDK 10.0.1
13-07-2018
Thanks [~zgu]! I was trying to do my own tests. This is very interesting. I can't find anything that would suggest either that this is an intended change or a known bug! Need to try and verify if this is a new issue or not by testing older builds. If it is a new issue then I can only assume it is build related.
13-07-2018
I did following test: java -XX:NativeMemoryTracking=detail -version jio_snprintf(buf, sizeof(buf), "NMT_LEVEL_%d", os::current_process_id()); // const char *nmt_option = ::getenv(buf); //printf("nmt_options = %s\n", nmt_option); <=== nmt_option == NULL char nmt_option[128]; GetEnvironmentVariable(buf, nmt_option, 128); printf("nmt_options = %s\n", nmt_option); <=== nmt_option = detail Seems that getenv() no longer works on Windows 10
13-07-2018
Yes but that is only in a code example. Nothing in the documentation states it is deprecated (in contrast putenv is clearly marked as such). From google it seems the MSC compiler will flag it with a deprecation warning but mainly that seems to be due to the potential safety issues. Anyway I find nothing to suggest the behaviour should have changed at all in Windows 10, and the getenv in the launcher code works correctly.
13-07-2018
https://msdn.microsoft.com/en-us/library/tehxacec.aspx // Get the value of the LIB environment variable. libvar = getenv( "LIB" ); // C4996 // Note: getenv is deprecated; consider using getenv_s instead
13-07-2018
I don't see getenv being deprecated: https://docs.microsoft.com/en-us/cpp/c-runtime-library/reference/getenv-wgetenv
13-07-2018
Could be ::getenv() call from MemTracker::init_tracking_level(), looks like it was depreciated on Windows.
13-07-2018
Interesting this is Windows 10 specific. Can't repo on Windows 7. Can't fix by running in "compatibility mode".
13-07-2018
Enabling launcher debug output shows the env var being set and read back correctly.
13-07-2018
Likely launcher (java.exe) does not properly setup internal env variable NMT _LEVEL_${pid}. I will take a look tomorrow.
13-07-2018
[~zgu] Do you have any idea what may be happening here?
13-07-2018
I confirmed the problem on my personal Windows 10 laptop. Need to check if b20 had any compiler changes ... there was a later change to NMT static initialization logic.
12-07-2018
Moving to hotspot/runtime for initial triage. The ""Native Memory Tracking did not setup properly, using wrong launcher?"" warning seems to be emitted when -XX:NativeMemoryTracking is used without a value to indicate the tracking mode.
12-07-2018
The warning will be generated if the nmt level is not initialized to the level expected.
12-07-2018