payara / Payara

Payara Server is an open source middleware platform that supports reliable and secure deployments of Java EE (Jakarta EE) and MicroProfile applications in any environment: on premise, in the cloud or hybrid.
http://www.payara.fish
Other
879 stars 300 forks source link

Bug Report: Application deployment takes 1,5x as long and uses 1,5x the ram after deployment #6731

Closed RInverid closed 2 months ago

RInverid commented 3 months ago

Brief Summary

Starting since the 2023.11 release, application deployment has taken 1,5x as long and used 1,5x as much memory. This has been the case for all later releases as well. I see it is very similar to the issue #6554 .

Expected Outcome

Normal deployment times and memory use (2 minutes and 2 gigabytes, respectively).

Current Outcome

Significant increase in deployment time and memory use. deployment time is up to 3 minutes, and memory usage up to 3 gigabytes. This is up in both the heap (up from +- 750MB to 1G) and general allocation (up from +-1,25 G to 2G+).

Reproducer

I spent a lot of time on this, but was not able to make a simple reproducer. Using that time I did do a git bisect, which resulted in finding the offending commit: https://github.com/payara/Payara/commit/34153c8741382e051df38717b92b07905837bf4b. I further narrowed it down to this change in Jar entry loading:

- JarEntry entry = zip.getJarEntry(entryName);
+ JarFile jar = new JarFile(res.file, false, JarFile.OPEN_READ,
+                           Runtime.Version.parse(System.getProperty("java.version")));
+ JarEntry entry = jar.getJarEntry(entryName);

adding this change to the 2023.10 release reproduces my issue perfectly.

I tried a lot with this change, including using the new way of loading but changing the verify variable to true and the version hardcoded to 8:

JarFile jar = new JarFile(res.file, true, JarFile.OPEN_READ, Runtime.Version.parse("8"));
JarEntry entry = jar.getJarEntry(entryName);

Before this change, for some libraries such as BouncyCastle which are multirelease and signed libraries, the resulting classData byte[] would be different with the new way of loading. After this change, the resuting classData would be exactly the same, but the issue would still be present.

I could find no other differences in the code so I looked at the differences when doing a JFR recording for the application. The main difference in class calls was a significant increase in the amount of com.sun.enterprise.loader.ASURLClassLoader.loadClassData0(ASURLClassLoader$URLEntry, String) samples (29 in 2023.10, 1026 in 2023.10 with the offending Jar loading change) on the threadadmin-thread-pool::admin-listener.

The back trace of this call (in two screenshots, due to diverging paths): Screenshot 2024-05-22 at 09 03 15

Screenshot 2024-05-22 at 09 03 37

I am not able to investigate further due to the intimate knowledge of Payara required to continue the investigation. I would appreciate some assistance.

Operating System

Debian Bookworm

JDK Version

OpenJDK 17

Payara Distribution

Payara Server Full Profile

lprimak commented 3 months ago

Duplicate of #6554 - that issue should be reopened and this one closed.