Hey guys, I recently activated Configuration Cache in my project. Everything works fine, except when executing

./gradlew :app:dependencies

I receive the following exception:

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-1-thread-1"

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "main"

I am using

org.gradle.jvmargs=-Xmx10240m

and also increasing it to 12 GB didn't help. All the other tasks just run fine, e.g. building, testing etc. - the activated configuration cache is on develop for a few days now already. Does anyone have an idea what could cause the OOM on the dependencies task and how to fix it? Deactivating the configuration cache fixes it but should not be an option here 😄

If I would have to debug this, I would create a Heapdump and analzye it. https://docs.gradle.org/current/userguide/config_gradle.html -> HeapDumpOnOutOfMemoryError Its a possibility that the outOfMemory error occurs in the gradle client rather in the daemon that would explain why setting jvmargs has no effect

As a first step you could also use the

jconsole

utility to check if your heap settings make their way to the correct JVM process and the difference in heap usage between the other tasks and

dependencies

. If the latter one eats several GiBs more there is definitely an issue to investigate.

As a first step, I would simply use

--stacktrace

to see where the OOM happens (cli, daemon, worker, ...). And if it is not the CLI process, the

gradle-profiler

might also help to investigate what is happening with the heap.

In

VM Summary

Tab in

jconsole

I can see my jvmargs values as expected. Unfortunately, HeapDumpOnOutOfMemorryError seems to have no effect. Same applies for

--stacktrace

option. Memory Usage in

jconsole

is around 4 GB für Heap, so low enough I think and

testDebugUnitTest

consumes even more than

dependencies

but doesn't throw OOM, that's strange. I will have a look on the

gradle-profiler

that would kind of indicate to me that you are looking at the gradle daemon, which is affected by the jvmargs, but the Error happens in the client/cli which is not affected by the jvmargs but needs to be adressed using the JAVA_OPTS

HeapDumpOnOutOfMemorryError seems to have no effect

Probably because wrong process, that's why I said, check first where the error happens

Same applies for

--stacktrace

option

Of course it still fails, but it shows you the full stacktrace where you can see where it happens, as I said.

I meant

--stacktrace

does not give any additional output

using the JAVA_OPTS

If so, better

GRADLE_OPTS

or you hit all start scripts that look at

JAVA_OPTS

I used the terminal in AS - default Mac terminal looks the same.

does adding --console plain help?

Nope, doesn't change anything unfortunately 😕

Hm, very strange. I don't know whether the

gradle-profiler

will help if it indeed is a CLI process problem. Does it fix it if you use

GRADLE_OPTS

to increase the CLI process max heap, respectively do you get a heap dump if you there add the dump option?

with

GRADLE_OPTS="-Xmx10240m -XX:+HeapDumpOnOutOfMemoryError" ./gradlew :app:dependencies --stacktrace

the task is running successfully 🤔

Yeah, then it is a CLI process problem

java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid10549.hprof ...

yup

I've never seen the CLI process going OOM actually 😄

also if you have a chance with

jconsole

on a process that fails take a look at the Memory tab and check the various charts for different memory pools including non-heap to find the one that gets close to the limit

Well, as increasing the max hep helps, I'd say non-heap is not the problem 😄

I don't want to rule out the possibility that it's our pretty complex project setup. I'm kinda new to the team and still in the process of unterstanding the dependency stuff. Maybe I need to dig more into that

But, well, the CLI process is basically just handling the commandline input and output. That's why the default max heap is very low (

64m

).

I'd say non-heap is not the problem

it didn't help above, and OP wrote usage stayed around 4GB so it's worth looking IMO, won't take long...

That might be a different problem, but the main topic here is the OOME and that is in the CLI process and increasing the max heap of the CLI process did help

I've never seen the CLI process going OOM actually 😄

same here, but weird things happen, and hopefully it will be easier to debug

Anyway, it would definitely be good if you could reproduce somehow getting this OOME and create an issue with it, or maybe with that heap dump, or right away find out yourself where the problem lies. Maybe there is some leak somewhere, or some unlucky handling in the CLI or something like that.

you could also try different settings of Xmx to find out how off you are from the default limit

Hm, no,

println(".".repeat(64 * 1024 * 1024))

works without problem

Or maybe you send one line that is longer than 64m and the CLI tries to read it, no idea 😄

Wait a second... This project has pretty heavy output stuff during configuration phase which I currently can't get rid of. Since the problem occurred after enabling configuration cache - might that output be the cause for it?

if you want to analyze the heap dump yourself you could try

visualvm

I just caught the

gradle-wrapper.jar :app:dependencies

Process in

jconsole

(got the daemon the other times) and that one actually doesn't have the arguments, Xmx is 64m for that

Yes, that's the default as I said 🙂

Got it 👍 Let me check where all the text output during configuration phase comes from in our project, maybe that's the real cause (since it's the same for every module it doesn't really provide a benefit)

Hm, no, that's from 8.14.3, that should be fine, I tested with 7.6.4

But could you test with 8.14.3? Maybe the missing output is a bug in newer versions?

Let me check where all the text output during configuration phase comes from in our project

Many output should not be a problem usually. I just thought maybe it is a very long line that busts the memory if the CLI reads it line by line from the daemon.

that kind of streaming bug can be sensitive to timing

Yeah, probably the 64m String is right on the edge and thus it might work or might not. It's just that now it consistenly fails, just worked the first time. 🤷‍♂️

that's where investigating a heap dump is interesting ... now you can have an interesting exercise submitting a non-flaky test case to the project along a bug report 😉

quite a challenge when you never used a heap dump 😄 will try my best 😉 might answer tomorrow since I leave soon

can you tell us how many lines ./gradlew appdependencies prints? (when its working, sth like ./gradlew appdependencies | wc -l

122.121

🙂 yup that will do it. gradle isnt exactly optimized for huge amounts of outputs without increasing memory. Pretty much the same thing will happen if your tests prints millions of lines

so it might just be a coincident that this happened after enabling configuration cache?

i would say yes. I could also be the case that something odd is going on and using configuration cache you suddenly have more dependencies

Our integ tests probably do output veeeery many lines and we never had that problem. Are you sure @TheGoesen? I would not expect the CLI to keep all lines in memory, that wouldn't make too much sense. That's why I thought it might be a very long line instead.

I just disabled it out of curiosity and got the line count again, pretty much the same with 122.119 but ran successfully without increasing the heap size of the CLI via GRADLE_OPTS (which I need to do with configuration cache enabled), kinda strange.

Hm, I tried with

(1..1_000_000_000).forEach {
    println("foo: $it")
}

After ~300_000 lines the daemon went OOM, the CLI was fine at 35 MiB

Didn't look at the issues you linked to yet, but I now increased the daemon max heap with my

(1..1_000_000_000).forEach {
    println("foo: $it")
}

snippet. You can hardly send output faster to the CLI process from the daemon. I'm at 4_500_000 messages right now and there is no problem on the CLI at all. The CLI process oscillates between 20 and 50 MiB. Only the daemon seems to have some leak, currently being at 12 GiB RAM. But that could also be because it does not do a bigger garbage collection as still enough heap is available.

I am aware that these issues are not specific about the gradle cli, but in general gradle is not throttling itself when it reads too much output, thats pretty much present in every component. Calling println in a loop is actually not a very fast way to send output to the cli, as it causes a full flush. so something like this will most likely still work:

val foo by tasks.registering {
    doLast {
        repeat(Int.MAX_VALUE) {
            println()
            repeat(5) {
                print("$it aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa")
            }
        }


    }
}

but if you bump 5 to 50 or something its too fast

Talking about that speed, would you agree that

repeat(Int.MAX_VALUE) {
    println()
    repeat(50) {
        print("$it aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa")
    }
}

is the same regarding how fast the output is given to the CLI as

repeat(Int.MAX_VALUE) {
    println()
    print((1..50).joinToString("") { "$it aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa" })
}

if not even faster, because the whole string is given in one call?

good question, I would not be confident saying they have or do not have the same performance characteristics.

Pff, running the CLI with profiler results in a result file wihtout content, running through debugger with debugger in OOM constructor still does not cause the breakpoint to be hit. This seems to be a very stubborn OOM somewhere.

Looking around in the sourcecode: GroupingProgressLogEventGenerator$OperationGroup is the culprit here. The log output goes into the bufferedLogs (not sure if thats "correct", if the "focus" is not on the operationgroup where is it ?) bufferedLogs is just a ArrayList which can grow until OOME. And then there is this beauty of sourcedecode

maybeFlushOutput

, which only flushes the output after 2 seconds(maybe) or after 30 s (unconditionally) Not sure what happens when the OOME doesnt happen, I would guess either it gets so slow that the 2 s timeout hits or its supposed to always forward its output directly

I also got the stacktrace-less non-debuggable OOMEs with

--conole=plain

. I think with that there should be no grouping tried.

It can be excruciatingly difficult to nail down these kind of streaming/timing issues and craft a reliable reproducer (and then, non-flaky test cases for them). Typically it will crash or not depending on CPU load, i/o load, RAM availability and some randomness thrown in. Testing reliably usually require introducing artificial pauses in processing threads. My hypothesis here is that the configuration cache makes the daemon faster and/or make it group output beyond buffering capacity of the launcher. The issues quoted above are certainly close to the root cause.

If I can assist any further, let me know. Sharing the repo is not possible unfortunately 😕

Well, ultimately you should probably open an issue if there is none. The ones posted here were not about the CLI going OOM

Alright, will do that tomorrow 👍