Performance issues with batch decompilation

[sad-dev]

Is your feature request related to a problem? Please describe.
Some of my scripts and plugins rely on decompiling large numbers of functions. I noticed that in particular, decompiling multiple functions at once does not scale past roughly 10 concurrent threads, even when not limited by the processor/memory. To test this, I repurposed the FindPotentialDecompilerProblems.java script to just decompile all functions in a medium sized binary (25k functions), and adjusted the core.override. Decompilation speed basically hits a peak at about 10-12 threads and is noticeably worse with core.override=16 and beyond (although the machine I was testing on has a lot more than 16 cores available)

My best guess is that the decompiler I/O is being the bottleneck here, but any help diagnosing/increasing performance would be most welcome.

Additional context
Ghidra 9.2.2

[dragonmacher]

Assuming you are using the decompilation to markup a program, then the program database lock will become the bottleneck. If you are using the decompilation without reading/writing the program, then you are likely bumping into the natural limitations of the JVM running on your particular machine. If you have access, you could try running your scripts on a server-grade machine to separate hardware from Ghidra software limitations.

[sad-dev]

My machine isn't quite server grade, but it is close.

My scripts do not write to the program while analysis is ongoing (decompiling all functions accounts for > 95% of runtime), so this script (shamelessly ripped off FindPotentialDecompilerProblems) has very similar runtime, and is what I use to benchmark batch decompilation speed with varying numbers of threads (core.override). Do you think the program database lock would be the bottleneck here, or simply the JVM?

import java.util.*;

import ghidra.app.decompiler.*;
import ghidra.app.decompiler.parallel.*;
import ghidra.app.script.GhidraScript;
import ghidra.app.tablechooser.*;
import ghidra.program.model.address.Address;
import ghidra.program.model.listing.*;
import ghidra.program.model.pcode.*;
import ghidra.program.model.symbol.Reference;
import ghidra.program.model.symbol.ReferenceIterator;
import ghidra.util.task.TaskMonitor;
import util.CollectionUtils;

public class ModifiedFindPotentialDecompilerProblems extends GhidraScript {

	@Override
	public void run() throws Exception {

		if (isRunningHeadless()) {
			printf("This script cannot be run in headless mode.\n");
			return;
		}

		DecompilerCallback<Void> callback =
			new DecompilerCallback<Void>(currentProgram, new BasicConfigurer(currentProgram)) {
				@Override
				public Void process(DecompileResults results, TaskMonitor tMonitor)
						throws Exception {
                                         // Put Analysis Code here
					return null;
				}
			};

		Set<Function> funcsToDecompile = new HashSet<>();
		FunctionIterator fIter = currentProgram.getFunctionManager().getFunctionsNoStubs(true);
		fIter.forEach(e -> funcsToDecompile.add(e));

		ParallelDecompiler.decompileFunctions(callback, funcsToDecompile, monitor);
		monitor.checkCanceled();
	}

	static class BasicConfigurer implements DecompileConfigurer {
		private Program p;

		public BasicConfigurer(Program prog) {
			p = prog;
		}

		@Override
		public void configure(DecompInterface decompiler) {
			decompiler.toggleCCode(true);
			decompiler.toggleSyntaxTree(true);
			decompiler.setSimplificationStyle("decompile");
			DecompileOptions opts = new DecompileOptions();
			opts.grabFromProgram(p);
			decompiler.setOptions(opts);
		}
	}
}

[dragonmacher]

Based on this code, I'd say you are not running into program lock limitations. You would have to profile the app to find the bottleneck, as it could be any part of your machine.

So, this may have something to do with your observations:

		if (numProcessors > 10) {
			// TODO: This bound is fairly arbitrary, probably could be made even lower
			numProcessors = 10;
		}

ghidra/Ghidra/Framework/Utility/src/main/java/ghidra/util/SystemUtilities.java

Line 455 in 45927bb

if (numProcessors > 10) {

[sad-dev]

I have barely touched the decompiler internals, but my first guess would be ArchitectureGhidra, with the Ghidra client getting overloaded by multiple decompiler processes. Looks like I'll have to compile it after all ...

Setting core.override in support/launch.properties overrides numProcessors via getCPUOverride (so each trial involves me changing that value and reopening Ghidra)

[dragonmacher]

(See my updated comment above.)

We have a hard-coded limit of 10 for the option you are using). There is no way to override this without changing the source code, whether the SystemUtilities class that parses the property you are updating or the ParallelDecopmiler, which is what your script ends up calling into.

[sad-dev]

The simple

println("CpuCoreOverride + "System.getProperty("cpu.core.override"));

returns whatever I set VMARGS=-Dcpu.core.override= to.

ghidra/Ghidra/Framework/Utility/src/main/java/ghidra/util/SystemUtilities.java

Line 433 in 45927bb

Integer cpuOverride = getCPUOverride();

and

ghidra/Ghidra/Framework/Utility/src/main/java/ghidra/util/SystemUtilities.java

Lines 470 to 478 in 45927bb

	private static Integer getCPUOverride() {
	String cpuOverrideString = System.getProperty("cpu.core.override");
	if (cpuOverrideString == null || cpuOverrideString.trim().isEmpty()) {
	return null;
	}
	try {
	return Integer.parseInt(cpuOverrideString);
	}

seem to imply my option will be respected

[dragonmacher]

Ghidra does not change the value of the system property. Rather, it calls the method getCPUOverride() and then will cap the value returned to a limit of 10. This is the code that I linked above.

[sad-dev]

ghidra/Ghidra/Framework/Utility/src/main/java/ghidra/util/SystemUtilities.java

Lines 431 to 436 in 45927bb

	public static int getDefaultThreadPoolSize() {
	Integer cpuOverride = getCPUOverride();
	if (cpuOverride != null) {
	return cpuOverride;
	}

Doesn't it get returned right away without being capped here?

[dragonmacher]

Haha. I knew one of us was mistaken. Clearly I am still suffering from brain fog today.

Yes, you are correct.

This leaves me back at my original line of thinking. At this point you would have to experiment and profile Ghidra, the JVM and your machine to find the bottleneck(s).

[sad-dev]

Yeah, that's what I was dreading - hopefully my solution won't involve some nonsense with multiple clients/programs

[dragonmacher]

Please keep us updated with what you find. We would like to fix any clear algorithmic mistakes. It will obviously be more difficult to make architecture-level changes.

[sad-dev]

I replaced the decompilation with executing an expensive mathematical calculation a random number of times, choosing a logarithmic distribution to (hopefully) roughly mirror the distribution of function sizes. The resulting speed (1/runtime) scales almost linearly with number of threads in the pool up to 32 (31.5x faster), with a slight dip to about 56x faster at 64 threads, so it appears that the concurrency mechanism eg. DecompilerConcurrentQ isn't to blame (as expected, since it is based on ThreadPoolExecutor).

I should also remark that the parallel decompile only takes up 4GB or so of ram on the 25k function binary at peak, nowhere near being a bottleneck.

My suspicion is that some (instance?) component of the Ghidra (Java) client is getting bottlenecked, either:

1.) Reading the database
2.) Sending data to the decompilers
3.) Receiving and parsing data from the decompilers

VisualVM is proving super finicky but hopefully it'll eventually shed more light here.

[sad-dev]

Based on a dump when running 64 parallel decompilers, I am pretty sure the bottlenecks are in program.database; a snapshot shows 35 of them waiting at various locks on the database records @dragonmacher

(based on commit cfaf865567f69194c24405660d7bdf4354e4dc38)

      2 	at ghidra.program.database.code.CodeManager.getDefinedDataAt(CodeManager.java:1319)
      4 	at ghidra.program.database.code.CodeManager.getInstructionAt(CodeManager.java:1283)
      9 	at ghidra.program.database.code.CodeUnitDB.getBytes(CodeUnitDB.java:648)
      5 	at ghidra.program.database.code.InstructionDB.getDefaultFallThrough(InstructionDB.java:718)
     10 	at ghidra.program.database.function.FunctionDB.getEntryPoint(FunctionDB.java:314)
      2 	at ghidra.program.database.function.FunctionDB.isFunctionFlagSet(FunctionDB.java:2396)
      1 	at ghidra.program.database.references.ReferenceDBManager.getReferencesFrom(ReferenceDBManager.java:796)
      1 	at ghidra.program.database.symbol.NamespaceManager.getAddressSet(NamespaceManager.java:265)
      1 	at ghidra.program.database.symbol.SymbolDB.getSymbolData1(SymbolDB.java:804)

the callstacks all resemble the following:

"Batch Test-pool-11-thread-34" #202 daemon prio=5 os_prio=0 cpu=313.53ms elapsed=6.95s tid=0x00007fc1c0008000 nid=0xe382 in Object.wait()  [0x00007fc2b1cf0000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.lang.Object.wait(java.base@11.0.9/Native Method)
	- waiting on <no object reference available>
	at java.lang.Object.wait(java.base@11.0.9/Object.java:328)
	at ghidra.util.Lock.acquire(Lock.java:56)
	- waiting to re-lock in wait() <0x000000008645c730> (a ghidra.util.Lock)
	at ghidra.program.database.code.CodeUnitDB.getBytes(CodeUnitDB.java:648)
	at ghidra.program.database.code.InstructionDB.getBytes(InstructionDB.java:38)
	at ghidra.app.plugin.processors.sleigh.SleighParserContext.getInstructionBytes(SleighParserContext.java:198)
	at ghidra.app.plugin.processors.sleigh.ParserWalker.getInstructionBytes(ParserWalker.java:230)
	at ghidra.app.plugin.processors.sleigh.expression.TokenField.getInstructionBytes(TokenField.java:170)
	at ghidra.app.plugin.processors.sleigh.expression.TokenField.getValue(TokenField.java:102)
	at ghidra.app.plugin.processors.sleigh.SleighInstructionPrototype.resolveHandles(SleighInstructionPrototype.java:1405)
	at ghidra.app.plugin.processors.sleigh.SleighInstructionPrototype.getParserContext(SleighInstructionPrototype.java:1536)
	at ghidra.app.plugin.processors.sleigh.SleighInstructionPrototype.getParserContext(SleighInstructionPrototype.java:48)
	at ghidra.program.database.code.InstructionDB.getParserContext(InstructionDB.java:785)
	at ghidra.app.plugin.processors.sleigh.SleighInstructionPrototype.getPcodePacked(SleighInstructionPrototype.java:993)
	at ghidra.app.decompiler.DecompileCallback.getPcodePacked(DecompileCallback.java:296)
	at ghidra.app.decompiler.DecompileProcess.getPcodePacked(DecompileProcess.java:669)
	at ghidra.app.decompiler.DecompileProcess.readResponse(DecompileProcess.java:323)
	at ghidra.app.decompiler.DecompileProcess.sendCommand1ParamTimeout(DecompileProcess.java:541)
	- locked <0x00000000beb5d420> (a ghidra.app.decompiler.DecompileProcess)
	at ghidra.app.decompiler.DecompInterface.decompileFunction(DecompInterface.java:712)
	- locked <0x00000000bf018a70> (a ghidra.app.decompiler.DecompInterface)
	at BatchDecompiler$MyDecompilerCallback.process(BatchDecompiler.java:115)
	at BatchDecompiler$MyDecompilerCallback.process(BatchDecompiler.java:107)
	at generic.concurrent.ConcurrentQ$CallbackCallable.call(ConcurrentQ.java:658)
	at java.util.concurrent.FutureTask.run(java.base@11.0.9/FutureTask.java:264)
	at generic.concurrent.FutureTaskMonitor.run(FutureTaskMonitor.java:76)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.9/ThreadPoolExecutor.java:1128)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.9/ThreadPoolExecutor.java:628)
	at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)

   Locked ownable synchronizers:
	- <0x00000000bdba1168> (a java.util.concurrent.ThreadPoolExecutor$Worker)