ZGC: Failed to truncate backing file (Permission denied) at startup after 14.0.2 to 15.0.1 upgrade

Mon Nov 23 14:35:49 UTC 2020

Hi Per,

Thank you for your quick reply.

> The fact that ftruncate returns EACCESS suggests that there's some kind  
> of environment problem that is blocking the file from growing.
> In the production system, is this process running in some constrained  
> environment/container/cgroup?
Yes, it is running inside a pod in an OpenShift environment.

> To test this, run with JDK 14 and use "-Xms270g -Xmx270g"
I tried with "-Xms100g -Xmx100g", I hope that it is fine for this test.

$ /opt/3rd_party/jdk_installed/jdk-14.0.2/bin/java -Xms100g -Xmx100g  
-XX:+UnlockExperimentalVMOptions -XX:+UseZGC -Xlog:gc*=debug -version
[0.006s][debug][gc,heap] Minimum heap 107374182400  Initial heap  
107374182400  Maximum heap 107374182400
[0.006s][info ][gc,init] Initializing The Z Garbage Collector
[0.006s][info ][gc,init] Version: 14.0.2+12-46 (release)
[0.006s][info ][gc,init] NUMA Support: Disabled
[0.006s][info ][gc,init] CPUs: 70 total, 40 available
[0.006s][info ][gc,init] Memory: 419840M
[0.006s][info ][gc,init] Large Page Support: Disabled
[0.006s][info ][gc,init] Medium Page Size: 32M
[0.006s][info ][gc,init] Workers: 24 parallel, 5 concurrent
[0.009s][debug][gc,task] Executing Task: ZWorkersInitializeTask, Active  
Workers: 24
[0.009s][info ][gc,init] Address Space Type:  
Contiguous/Unrestricted/Complete
[0.009s][info ][gc,init] Address Space Size: 1638400M x 3 = 4915200M
[0.010s][info ][gc,init] Heap backed by file: /memfd:java_heap
[0.010s][info ][gc,init] Min Capacity: 102400M
[0.010s][info ][gc,init] Initial Capacity: 102400M
[0.010s][info ][gc,init] Max Capacity: 102400M
[0.010s][info ][gc,init] Max Reserve: 80M
[0.010s][info ][gc,init] Pre-touch: Disabled
[0.010s][info ][gc,init] Available space on backing filesystem: N/A
[25.372s][info ][gc,init] Uncommit: Disabled
[25.372s][debug][gc,marking] Expanding mark stack space: 0M->32M
[25.888s][info ][gc,init   ] Runtime Workers: 24 parallel
[25.960s][info ][gc        ] Using The Z Garbage Collector
[26.179s][debug][gc,nmethod] Rebuilding NMethod Table: 0->1024 entries,  
0(0%->0%) registered, 0(0%->0%) unregistered
openjdk version "14.0.2" 2020-07-14
OpenJDK Runtime Environment (build 14.0.2+12-46)
OpenJDK 64-Bit Server VM (build 14.0.2+12-46, mixed mode)

$ /opt/3rd_party/jdk_installed/jdk-15.0.1/bin/java -Xms100g -Xmx100g  
-XX:+UnlockExperimentalVMOptions -XX:+UseZGC -Xlog:gc*=debug -version
[0.006s][debug][gc,heap] Minimum heap 107374182400  Initial heap  
107374182400  Maximum heap 107374182400
[0.006s][info ][gc,init] Initializing The Z Garbage Collector
[0.006s][info ][gc,init] Version: 15.0.1+9-18 (release)
[0.006s][info ][gc,init] NUMA Support: Disabled
[0.006s][info ][gc,init] CPUs: 70 total, 40 available
[0.006s][info ][gc,init] Memory: 419840M
[0.006s][info ][gc,init] Large Page Support: Disabled
[0.007s][info ][gc,init] Workers: 24 parallel, 5 concurrent
[0.010s][debug][gc,task] Executing Task: ZWorkersInitializeTask, Active  
Workers: 24
[0.011s][info ][gc,init] Address Space Type:  
Contiguous/Unrestricted/Complete
[0.011s][info ][gc,init] Address Space Size: 1638400M x 3 = 4915200M
[0.012s][info ][gc,init] Heap Backing File: /memfd:java_heap
[0.012s][error][gc     ] Failed to truncate backing file (Permission  
denied)
[0.012s][debug][gc,marking] Expanding mark stack space: 0M->32M
[0.081s][info ][gc,init   ] Runtime Workers: 24 parallel
[0.084s][info ][gc        ] Using The Z Garbage Collector
Error: Could not create the Java Virtual Machine.
Error: A fatal exception has occurred. Program will exit.

> The fact that ftruncate returns EACCESS suggests that there's some kind  
> of environment problem
Is there a workaround or a way to fix the environment problem ?

Best Regards
David

On Mon, 23 Nov 2020 15:11:30 +0100, Per Liden <per.liden at oracle.com> wrote:

> Hi David,
>
> On 11/20/20 4:21 PM, David Tavoularis wrote:
>> Hi,
>>  I found a possible regression in customer production environment  
>> linked to JDK-8245203 "ZGC: Don't track size in ZPhysicalMemoryBacking"  
>> or JDK15 "Fixed support for transparent huge pages".
>> After upgrade from jdk-14.0.2 to jdk-15.0.1, the JVM (using ZGC) is  
>> crashing at startup with the error message "Failed to truncate backing  
>> file (Permission denied)"
>>  This error message was introduced in changelist  
>> http://hg.openjdk.java.net/jdk-updates/jdk15u/rev/556d5070c458
>> Cf source code :  
>> http://hg.openjdk.java.net/jdk-updates/jdk15u/file/556d5070c458/src/hotspot/os/linux/gc/z/zPhysicalMemoryBacking_linux.cpp  
>>   The issue was seen in Prod, not in Test, nor in labs, I suspect that   
>> Heap Backing Filesystem  is not correctly set to tmpfs in Prod or a  
>> permission issue on a directory/file owned by root.
>>  $ /opt/3rd_party/jdk_installed/jdk-15.0.1/bin/java -version
>> openjdk version "15.0.1" 2020-10-20
>> OpenJDK Runtime Environment (build 15.0.1+9-18)
>> OpenJDK 64-Bit Server VM (build 15.0.1+9-18, mixed mode, sharing)
>>  $ /opt/3rd_party/jdk_installed/jdk-15.0.1/bin/java -XX:+UseZGC -version
>> [0.009s][error][gc] Failed to truncate backing file (Permission denied)
>> Error: Could not create the Java Virtual Machine.
>> Error: A fatal exception has occurred. Program will exit.
>>  $ /opt/mycom/3rd_party/jdk_installed/jdk-14.0.2/bin/java  
>> -XX:+UnlockExperimentalVMOptions -XX:+UseZGC -version
>> openjdk version "14.0.2" 2020-07-14
>> OpenJDK Runtime Environment (build 14.0.2+12-46)
>> OpenJDK 64-Bit Server VM (build 14.0.2+12-46, mixed mode)
>>  Should I fill a bug at https://bugreport.java.com/bugreport/ ?
>> What additional information should I provide ?
>> Any workaround ?
>
> It's hard to tell exactly why this fails. One difference between JDK 14  
> and 15 is that the backing file will be truncated to the max heap size  
> up-front when the JVM starts (but it will not be backed by any memory  
> until we actually start to expand the heap), instead of gradually grown  
> as the heap expands. So, one theory is that you could have had this  
> problem even with 14, but the heap might not have grown large enough for  
> the problem to be exposed. To test this, run with JDK 14 and use  
> "-Xms270g -Xmx270g". This will force the backing file to be truncated  
> up-front, similar to what happens in JDK 15.
>
> Also running with "-Xlog:gc*=debug" will print a few more things that  
> might be interesting.
>
> The fact that ftruncate returns EACCESS suggests that there's some kind  
> of environment problem that is blocking the file from growing. In the  
> production system, is this process running in some constrained  
> environment/container/cgroup?
>
> cheers,
> Per