Segmentation faults and other native errors running helm-java with async-profiler

Hi,
Thanks for putting this library together! We've been looking for something like this for a while.

I was doing some performance evaluation with async-profiler and came across a very unusual issue. Esentially, attempting to install helm releases while async-profiler is running causes various errors from the native calls. The most common seems to be a segmentation violation but there seem to be others seemingly from Go, null pointer dereferences, etc.
When the same program is run without async-profiler, or if the profiler was started before the JNI library has been loaded then it works normally, no errors of any kind and the expected releases get created.

I've put together a minimal example repo that reproduces the problem and I'll include a few of the error logs we've gotten from it below.

Given the nature of this issue we've found it super hard to track down which project this would relate to or what kind of solutions/workarounds we might be able to put in place. Any advice would be much appreciated!

error.log
error2.log
error3.log
error4.log

(Corresponding async-profiler issue)

It seems like an issue with concurrency. However, you mention that it only happens while the profiler is running.

i.e. helm-java can run concurrently at stress if no profiling is involved (right?).

I'm not really sure there's an easy way to figure this out.
In case helm-java is the root-cause, I can only think of this section as conflicting:

helm-java/helm-java/src/main/java/com/marcnuri/helm/HelmCommand.java

Lines 46 to 47 in f44a88e

    
           final Result result = function.apply(helmLib); 
        
           helmLib.Free(result);

Basically, the helmLib.Free calls the following Go code that frees the allocated memory:

helm-java/native/main.go

Lines 624 to 629 in dae3cd8

    
           func Free(result C.Result) { 
        
           	C.free(unsafe.Pointer(result.out)) 
        
           	C.free(unsafe.Pointer(result.err)) 
        
           	C.free(unsafe.Pointer(result.stdOut)) 
        
           	C.free(unsafe.Pointer(result.stdErr)) 
        
           }

Thanks for the response!
So interestingly, the issue doesn't seem limited to concurrent installations, though it does fail faster that way (more chances to fail per second I suppose?). If I modify the code in my example to a simpler single-threaded approach:

object Application extends App {
  require(args.length == 1, "Exactly one argument should be provided: <true/false> to enable/disable profiling")
  val shouldProfile = args(0).toBoolean
  val releases = 100

  println(s"Starting")
  Helm.version().call() // JNI loading is lazy, this forces native libraries to be loaded before profiling starts

  val profiler = AsyncProfiler.getInstance()
  if (shouldProfile) profiler.execute(s"start,jfr,event=wall,event=alloc,file=profile_%t.jfr")

  (1 to releases).map { i =>
    val name = s"release$i-${Random.alphanumeric.take(5).mkString.toLowerCase}"
    println(s"Installing: $name")
    val installCommand = Helm.install("example-chart.tgz")
    installCommand.set("configmapName", s"$name-configmap")
    installCommand.withName(name).call()
  }
  println("complete")
  if (shouldProfile) profiler.execute("stop")
}

And run it in the same way as before, I get a similar failure after a few successful releases:

fatal error: found pointer to free object

goroutine 17 gp=0xc000006700 m=1 mp=0xc000082008 [running, locked to thread]:
runtime.throw({0x7f5b1e070a1d?, 0xc0000142f0?})
	/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.2.linux-amd64/src/runtime/panic.go:1023 +0x5e fp=0xc0000621a0 sp=0xc000062170 pc=0x7f5b1c3d083e
runtime.(*mspan).reportZombies(0x7f5bd3c36248)
	/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.2.linux-amd64/src/runtime/mgcsweep.go:872 +0x2ea fp=0xc000062220 sp=0xc0000621a0 pc=0x7f5b1c3be22a
runtime.(*sweepLocked).sweep(0x7f5b1ff94fc0?, 0x0)
	/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.2.linux-amd64/src/runtime/mgcsweep.go:643 +0xb88 fp=0xc000062338 sp=0xc000062220 pc=0x7f5b1c3bd9c8
runtime.sweepone()
...

full error

I've pushed barrett122/helm-java-issue-demo:0.1.1 with this code in case you want to try it yourself.

I don't suppose there could be some race condition here where Free might be called before the install is actually completed, and the profiling overhead is increasing the likelihood we hit it? To be totally honest I don't have a great understanding of how the JNI/Go calls work here but it wouldn't be possible to have something like helm handing the installation off to another thread/goroutine and returning, only for us to call Free while that thread is still running would it?

i.e. helm-java can run concurrently at stress if no profiling is involved (right?).

As far as I can tell yes, I've yet to see a single failure like this without the profiler running. With the profiler enabled it fails very consistently, generally within a few releases (for example, in the single-threaded execution above there were 13 successful releases before we hit that error)

I don't suppose there could be some race condition here where Free might be called before the install is actually completed, and the profiling overhead is increasing the likelihood we hit it? To be totally honest I don't have a great understanding of how the JNI/Go calls work here but it wouldn't be possible to have something like helm handing the installation off to another thread/goroutine and returning, only for us to call Free while that thread is still running would it?

So I tested this to the best of my ability by adding some delay between the install command and the call to free but unfortunately even with a full 1 second gap I see the same issue

To be totally honest I don't have a great understanding of how the JNI/Go calls work here but it wouldn't be possible to have something like helm handing the installation off to another thread/goroutine and returning, only for us to call Free while that thread is still running would it?

I think this is a good lead.
The regular helm install cmd actually does this in a very extensive way (AFAIR).

For the install command, have you tried the waitReady() option? This isn't advertised for the purpose at hand, but it should have the side-effect of fixing the issue if is cause by what you mention.

So I tested this to the best of my ability by adding some delay between the install command and the call to free but unfortunately even with a full 1 second gap I see the same issue

If the issue is caused by the goroutine still running, this should have no effect, since the goroutine might be running for much longer than a second. And even in that case, the Free operation shouldn't affect it. It would be caused by the Java app terminating the thread that holds the Go binding call.

Could you also please check if the changes in #113 make any difference (besides the waitReady).

After carefully inspecting the logs (especially error4.log), and seeing failures also when calling

helm-java/native/internal/helm/install.go

Line 82 in ad02f0c

client := action.NewInstall(NewCfg(cfgOptions))

it doesn't seem that this might have to do with gosubroutines running beyond the original call.

However, it's worth a try.

So I tested this with waitReady and with the changes on that branch both with and without waitReady and unfortunately didn't observe much difference.
I did get one more unusual error in that it somehow triggered a Java thread dump but I lost some of the go error due to the line limit on my terminal and haven't seen it happen again 😞 Attached anyway in case it happens to tell you anything useful.

error7.log

Unfortunately, I can't think of anything else that might be causing this trouble.
It might be caused by incompatibilities with async-profiler and this project setup or the JNA library.

AFAIU the error is only reproducible in case async-profiler is enabled, so there isn't a 100% real production issue. So at least, this is not terrible.

I committed #113 anyway since I guess that might solve some issues in case an underlying Java thread or process is aborted.

Navigation Menu

Repository navigation

Segmentation faults and other native errors running helm-java with async-profiler #112

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

	final Result result = function.apply(helmLib);
	helmLib.Free(result);

	func Free(result C.Result) {
	C.free(unsafe.Pointer(result.out))
	C.free(unsafe.Pointer(result.err))
	C.free(unsafe.Pointer(result.stdOut))
	C.free(unsafe.Pointer(result.stdErr))
	}

Segmentation faults and other native errors running helm-java with async-profiler #112

Description

Activity

manusa commented on May 19, 2024

barrett122 commented on May 20, 2024

barrett122 commented on May 21, 2024

manusa commented on May 22, 2024

manusa commented on May 22, 2024

barrett122 commented on May 23, 2024

manusa commented on May 28, 2024

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions