<div dir="auto">I guess I don't know which JDK it picks for the tests, but I guess OpenJDK</div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">Johannes Lichtenberger <<a href="mailto:lichtenberger.johannes@gmail.com">lichtenberger.johannes@gmail.com</a>> schrieb am Do., 15. Feb. 2024, 17:58:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">However, it's the same with: ./gradlew -Dorg.gradle.java.home=/home/johannes/.jdks/openjdk-21.0.2 :sirix-core:test --tests io.sirix.service.json.shredder.JsonShredderTest.testChicagoDescendantAxis using OpenJDK hopefully</div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">Am Do., 15. Feb. 2024 um 17:54 Uhr schrieb Johannes Lichtenberger <<a href="mailto:lichtenberger.johannes@gmail.com" target="_blank" rel="noreferrer">lichtenberger.johannes@gmail.com</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr">I've attached two logs, the first one without -XX:+Generational, the second one with the option set, even though I also saw, that generational ZGC is going to be supported in GraalVM 24.1 in September... so not sure what this does :)</div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">Am Do., 15. Feb. 2024 um 17:52 Uhr schrieb Johannes Lichtenberger <<a href="mailto:lichtenberger.johannes@gmail.com" target="_blank" rel="noreferrer">lichtenberger.johannes@gmail.com</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr">Strange, so does it simply ignore the option? The following is the beginning of the output from _non_ generational ZGC:<div><br></div><div>johannes@luna:~/IdeaProjects/sirix$ ./gradlew -Dorg.gradle.java.home=/home/johannes/.sdkman/candidates/java/21.0.2-graal :sirix-core:test --tests io.sirix.service.json.shredder.JsonShredderTest.testChicagoDescendantAxis<br><br>> Configure project :<br>The 'sonarqube' task depends on compile tasks. This behavior is now deprecated and will be removed in version 5.x. To avoid implicit compilation, set property 'sonar.gradle.skipCompile' to 'true' and make sure your project is compiled, before analysis has started.<br>The 'sonar' task depends on compile tasks. This behavior is now deprecated and will be removed in version 5.x. To avoid implicit compilation, set property 'sonar.gradle.skipCompile' to 'true' and make sure your project is compiled, before analysis has started.<br>[1,627s][info ][gc ] GC(0) Garbage Collection (Metadata GC Threshold) 84M(1%)->56M(0%)<br><br>> Task :sirix-core:test<br>[0.001s][warning][pagesize] UseLargePages disabled, no large pages configured and available on the system.<br>[1.253s][info ][gc ] Using The Z Garbage Collector<br><br>[2,930s][info ][gc ] GC(1) Garbage Collection (Warmup) 1616M(11%)->746M(5%)<br>[4,445s][info ][gc ] GC(2) Garbage Collection (Warmup) 3232M(21%)->750M(5%)<br>[5,751s][info ][gc ] GC(3) Garbage Collection (Warmup) 4644M(30%)->1356M(9%)<br>[9,886s][info ][gc ] GC(4) Garbage Collection (Allocation Rate) 10668M(69%)->612M(4%)<br>[10,406s][info ][gc ] GC(5) Garbage Collection (Allocation Rate) 2648M(17%)->216M(1%)<br>[13,931s][info ][gc ] GC(6) Garbage Collection (Allocation Rate) 11164M(73%)->1562M(10%)<br>[16,908s][info ][gc ] GC(7) Garbage Collection (Allocation Rate) 11750M(76%)->460M(3%)<br>[20,690s][info ][gc ] GC(8) Garbage Collection (Allocation Rate) 12670M(82%)->726M(5%)<br>[24,376s][info ][gc ] GC(9) Garbage Collection (Allocation Rate) 13422M(87%)->224M(1%)<br>[28,152s][info ][gc ] GC(10) Garbage Collection (Proactive) 13474M(88%)->650M(4%)<br>[31,526s][info ][gc ] GC(11) Garbage Collection (Allocation Rate) 12072M(79%)->1472M(10%)<br>[34,754s][info ][gc ] GC(12) Garbage Collection (Allocation Rate) 13050M(85%)->330M(2%)<br>[38,478s][info ][gc ] GC(13) Garbage Collection (Allocation Rate) 13288M(87%)->762M(5%)<br>[41,936s][info ][gc ] GC(14) Garbage Collection (Proactive) 13294M(87%)->504M(3%)<br>[45,353s][info ][gc ] GC(15) Garbage Collection (Allocation Rate) 12984M(85%)->268M(2%)<br>[48,861s][info ][gc ] GC(16) Garbage Collection (Allocation Rate) 13008M(85%)->306M(2%)<br>[52,133s][info ][gc ] GC(17) Garbage Collection (Proactive) 12042M(78%)->538M(4%)<br>[55,705s][info ][gc ] GC(18) Garbage Collection (Allocation Rate) 12420M(81%)->1842M(12%)<br>[59,000s][info ][gc ] GC(19) Garbage Collection (Allocation Rate) 12458M(81%)->1422M(9%)<br>[64,501s][info ][gc ] Allocation Stall (Test worker) 59,673ms<br>[64,742s][info ][gc ] Allocation Stall (Test worker) 240,077ms<br>[65,806s][info ][gc ] GC(20) Garbage Collection (Allocation Rate) 13808M(90%)->6936M(45%)<br>[66,476s][info ][gc ] GC(21) Garbage Collection (Allocation Stall) 7100M(46%)->4478M(29%)<br>[69,471s][info ][gc ] GC(22) Garbage Collection (Allocation Rate) 10098M(66%)->5888M(38%)<br>[72,252s][info ][gc ] GC(23) Garbage Collection (Allocation Rate) 11226M(73%)->5816M(38%)<br><br>...<br><br>So even here I can see some allocation stalls.<br><br>Running the Same with -XX:+ZGenerational in build.gradle probably using GraalVM does something differnt, but I don't know what... at least off-heap memory is exhausted at some point due to direct byte buffer usage!?<br><br>So, I'm not sure what's the difference, though.<br><br>With this:<br><br><div style="background-color:rgb(43,43,43);color:rgb(169,183,198)"><pre style="font-family:"JetBrains Mono",monospace;font-size:9.8pt"><span style="color:rgb(106,135,89)">"-XX:+UseZGC"</span>,<br><span style="color:rgb(106,135,89)">"-Xlog:gc*=debug:file=zgc-generational-detailed.log"</span>,<br><span style="color:rgb(106,135,89)">"-XX:+ZGenerational"</span>,<br><span style="color:rgb(106,135,89)">"-verbose:gc"</span>,<br><span style="color:rgb(106,135,89)">"-XX:+HeapDumpOnOutOfMemoryError"</span>,<br><span style="color:rgb(106,135,89)">"-XX:HeapDumpPath=heapdump.hprof"</span>,<br><span style="color:rgb(106,135,89)">"-XX:MaxDirectMemorySize=2g"</span>,</pre></div></div><div><br></div><div><pre style="font-size:11pt;padding:10px;margin-top:0px;margin-bottom:0px;background-color:rgb(247,247,247);border:1px solid rgb(208,208,208);min-width:700px;color:rgb(48,48,48);width:auto">Caused by: java.lang.OutOfMemoryError: Cannot reserve 60000 bytes of direct buffer memory (allocated: 2147446560, limit: 2147483648)
at java.base/java.nio.Bits.reserveMemory(Bits.java:178)
at java.base/java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:111)
at java.base/java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:360)
at net.openhft.chronicle.bytes.internal.NativeBytesStore.elasticByteBuffer(NativeBytesStore.java:191)
at net.openhft.chronicle.bytes.BytesStore.elasticByteBuffer(BytesStore.java:192)
at net.openhft.chronicle.bytes.Bytes.elasticByteBuffer(Bytes.java:176)
at net.openhft.chronicle.bytes.Bytes.elasticByteBuffer(Bytes.java:148)
at io.sirix.access.trx.page.NodePageTrx.lambda$parallelSerializationOfKeyValuePages$1(NodePageTrx.java:443)
</pre></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">Am Do., 15. Feb. 2024 um 12:05 Uhr schrieb Stefan Karlsson <<a href="mailto:stefan.karlsson@oracle.com" target="_blank" rel="noreferrer">stefan.karlsson@oracle.com</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hi Johannes,<br>
<br>
We tried to look at the log files and the jfr files, but couldn't find <br>
an OotOfMemoryError in any of them. Do you think you could try to rerun <br>
and capture the entire GC log from the OutOfMemoryError run?<br>
<br>
A few things to note:<br>
<br>
1) You seem to be running the Graal compiler. Graal doesn't support <br>
Generational ZGC, so you are going to run different compilers when you <br>
compare Singlegen ZGC with Generational ZGC.<br>
<br>
2) It's not clear to me that the provided JFR files matches the provided <br>
log files.<br>
<br>
3) The JFR files show that -XX:+UseLargePages are used, but the gc+init <br>
logs shows 'Large Page Support: Disabled', you might want to look into <br>
why that is the case.<br>
<br>
4) The singlegen JFR file has a -Xlog:gc:g1-chicago.log line. It should <br>
probably be named zgc-chicago.log.<br>
<br>
Cheers,<br>
StefanK<br>
<br>
On 2024-02-14 17:36, Johannes Lichtenberger wrote:<br>
> Hello,<br>
><br>
> a test of my little DB project fails using generational ZGC, but not <br>
> with ZGC and G1 (out of memory error).<br>
><br>
> To be honest, I guess the allocation rate and thus GC pressure, when <br>
> traversing a resource in SirixDB is unacceptable. The strategy is to <br>
> create fine-grained nodes from JSON input and store these in a trie. <br>
> First, a 3,8Gb JSON file is shredded and imported. Next, a preorder <br>
> traversal of the generated trie traverses a trie (with leaf pages <br>
> storing 1024 nodes each and in total ~300_000_000 (and these are going <br>
> to be deserialized one by one). The pages are furthermore referenced <br>
> in memory through PageReference::setPage. Furthermore, a Caffeine page <br>
> cache caches the PageReferences (keys) and the pages (values) and sets <br>
> the reference back to null once entries are going to be evicted <br>
> (PageReference.setPage(null)).<br>
><br>
> However, I think the whole strategy of having to have in-memory nodes <br>
> might not be best. Maybe it's better to use off-heap memory for the <br>
> pages itself with MemorySegments, but the pages are not of a fixed <br>
> size, thus it may get tricky.<br>
><br>
> The test mentioned is this: <br>
> <a href="https://github.com/sirixdb/sirix/blob/248ab141632c94c6484a3069a056550516afb1d2/bundles/sirix-core/src/test/java/io/sirix/service/json/shredder/JsonShredderTest.java#L69" rel="noreferrer noreferrer" target="_blank">https://github.com/sirixdb/sirix/blob/248ab141632c94c6484a3069a056550516afb1d2/bundles/sirix-core/src/test/java/io/sirix/service/json/shredder/JsonShredderTest.java#L69</a><br>
><br>
> I can upload the JSON file somewhere for a couple of days if needed.<br>
><br>
> Caused by: java.lang.OutOfMemoryError<br>
> at <br>
> java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:62)<br>
> at <br>
> java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)<br>
> at <br>
> java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)<br>
> at <br>
> java.base/java.util.concurrent.ForkJoinTask.getThrowableException(ForkJoinTask.java:542)<br>
> at <br>
> java.base/java.util.concurrent.ForkJoinTask.reportException(ForkJoinTask.java:567)<br>
> at <br>
> java.base/java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:670)<br>
> at <br>
> java.base/java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:160)<br>
> at <br>
> java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:174)<br>
> at <br>
> java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233)<br>
> at <br>
> java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)<br>
> at <br>
> <a href="http://io.sirix.access.trx.page" target="_blank" rel="noreferrer">io.sirix.access.trx.page</a>.NodePageTrx.parallelSerializationOfKeyValuePages(NodePageTrx.java:442)<br>
><br>
> I've uploaded several JFR recordings and logs over here (maybe besides <br>
> the async profiler JFR files the zgc-detailed log is most interesting):<br>
><br>
> <a href="https://github.com/sirixdb/sirix/tree/main/bundles/sirix-core" rel="noreferrer noreferrer" target="_blank">https://github.com/sirixdb/sirix/tree/main/bundles/sirix-core</a><br>
><br>
> kind regards<br>
> Johannes<br>
<br>
</blockquote></div>
</blockquote></div>
</blockquote></div>
</blockquote></div>