Segmentation Fault: 11 from inside hxcpp GC when launching a large OpenFL app on a Mac

[Leo Lännenmäki]

Hello,

I told about my problem a couple of days ago on #haxe IRC and deltaluca helped me to debug the problem, but I wasn't able to reduce the problem enough to report it anywhere. Hopefully you guys can give me more tips in trying to track down the root cause.

Environment(s):
At least three different Macs running Maverics

Haxe 3.1.1 and Haxe 3.1.3
hxcpp 3.1.39 and the latest from Github

openfl-native 1.4.0
openfl 2.0.1
lime 1.0.1
and some other libs that I think are unrelated to the problem. Our binary size is around 60MB and we don't use any embedded assets.

Problem:
Segmentation Fault: 11 when launching the app. Sometimes it happens randomly like two times a day, and the app requires 40 tries before it starts. The error happens before the app gets to run my main classes

Output when running the game with lldb:

Process stopped

    frame #0: 0x0000000101cc82e6 The Masterplan`hx::MarkContext::Process(this=0x0000000103c03e90) + 150 at GCInternal.cpp:954
   951 	          if (obj)
   952 	          {
   953 	             block = (char *)(((size_t)obj) & IMMIX_BLOCK_BASE_MASK);
-> 954 	             obj->__Mark(this);
   955 	          }

(lldb) bt all
  thread #1: tid = 0xac94, 0x00007fff9114a716 libsystem_kernel.dylib`__psynch_cvwait + 10, queue = 'com.apple.main-thread'
    frame #0: 0x00007fff9114a716 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff9473dc3b libsystem_pthread.dylib`_pthread_cond_wait + 727
    frame #2: 0x0000000101cb7787 The Masterplan`MySemaphore::Wait(this=0x0000000103a0cec0) + 87 at Thread.h:326
    frame #3: 0x0000000101cb5bf7 The Masterplan`GlobalAllocator::MarkAll(this=0x0000000103a0c580, inDoClear=true) + 695 at GCInternal.cpp:2061
    frame #4: 0x0000000101caf8e5 The Masterplan`GlobalAllocator::Collect(this=0x0000000103a0c580, inMajor=false, inForceCompact=false) + 565 at GCInternal.cpp:2143
    frame #5: 0x0000000101cb8f45 The Masterplan`GlobalAllocator::GetEmptyBlock(this=0x0000000103a0c580, inTryCollect=true) + 101 at GCInternal.cpp:1537
    frame #6: 0x0000000101cb8d52 The Masterplan`GlobalAllocator::GetRecycledBlock(this=0x0000000103a0c580, inRequiredRows=1) + 482 at GCInternal.cpp:1519
    frame #7: 0x0000000101caf47b The Masterplan`LocalAllocator::Alloc(this=0x0000000103a0c980, inSize=8, inIsObject=false) + 811 at GCInternal.cpp:2684
    frame #8: 0x0000000101cace2d The Masterplan`hx::InternalNew(inSize=8, inIsObject=false) + 253 at GCInternal.cpp:2945
    frame #9: 0x0000000101cab3f7 The Masterplan`hx::NewString(inLen=7) + 39 at GC.cpp:62
    frame #10: 0x0000000101cef7a3 The Masterplan`String::operator+(this=0x00007fff5fbfdf80, inRHS=<unavailable>) const + 275 at String.cpp:896
    frame #11: 0x0000000101cbf504 The Masterplan`__loadprim(inLib=<unavailable>, inPrim=<unavailable>, inArgCount=2) + 708 at Lib.cpp:592
    frame #12: 0x0000000101c955a1 The Masterplan`cpp::Lib_obj::load(lib=<unavailable>, prim=<unavailable>, nargs=2) + 193 at Lib.cpp:32
    frame #13: 0x0000000101c7f072 The Masterplan`openfl::Lib_obj::load(library=<unavailable>, method=<unavailable>, __o_args=<unavailable>) + 610 at Lib.cpp:435
    frame #14: 0x0000000100e4c851 The Masterplan`openfl::gl::GL_obj::load(inName=<unavailable>, inArgCount=2) + 209 at GL.cpp:1981
    frame #15: 0x0000000100e60142 The Masterplan`openfl::gl::GL_obj::__boot() + 3458 at GL.cpp:5447
    frame #16: 0x0000000101ca13f3 The Masterplan`__boot_all() + 9667 at __boot__.cpp:3139
    frame #17: 0x0000000101ca1e02 The Masterplan`main(argc=1, argv=0x00007fff5fbff898) + 50 at __main__.cpp:10
    frame #18: 0x0000000100000a54 The Masterplan`start + 52
 
* thread #2: tid = 0xaca4, 0x0000000101cae066 The Masterplan`hx::MarkContext::Process(this=0x00000001039e6e90) + 150 at GCInternal.cpp:954, stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
  * frame #0: 0x0000000101cae066 The Masterplan`hx::MarkContext::Process(this=0x00000001039e6e90) + 150 at GCInternal.cpp:954
    frame #1: 0x0000000101cb7d05 The Masterplan`GlobalAllocator::MarkerLoop(this=0x0000000103a0c580, inId=0) + 69 at GCInternal.cpp:2080
    frame #2: 0x0000000101cb7cb0 The Masterplan`GlobalAllocator::SMarkerFunc(inInfo=0x0000000000000000) + 32 at GCInternal.cpp:2087
    frame #3: 0x00007fff9473b899 libsystem_pthread.dylib`_pthread_body + 138
    frame #4: 0x00007fff9473b72a libsystem_pthread.dylib`_pthread_start + 137
 
  thread #3: tid = 0xaca5, 0x0000000101cab8a6 The Masterplan`hx::MarkObjectAlloc(inPtr=0x0000000103d479d0, __inCtx=0x0000000103b80e90) + 38 at GCInternal.cpp:1018
    frame #0: 0x0000000101cab8a6 The Masterplan`hx::MarkObjectAlloc(inPtr=0x0000000103d479d0, __inCtx=0x0000000103b80e90) + 38 at GCInternal.cpp:1018
    frame #1: 0x000000010076e564 The Masterplan`void hx::MarkMember<String>(outT=0x0000000103d47730, __inCtx=0x0000000103b80e90) + 52 at GCTemplates.h:22
    frame #2: 0x0000000101ce0831 The Masterplan`Class_obj::__Mark(this=0x0000000103d476d0, __inCtx=0x0000000103b80e90) + 161 at Class.cpp:116
    frame #3: 0x0000000101cae068 The Masterplan`hx::MarkContext::Process(this=0x0000000103b80e90) + 152 at GCInternal.cpp:954
    frame #4: 0x0000000101cb7d05 The Masterplan`GlobalAllocator::MarkerLoop(this=0x0000000103a0c580, inId=1) + 69 at GCInternal.cpp:2080
    frame #5: 0x0000000101cb7cb0 The Masterplan`GlobalAllocator::SMarkerFunc(inInfo=0x0000000000000001) + 32 at GCInternal.cpp:2087
    frame #6: 0x00007fff9473b899 libsystem_pthread.dylib`_pthread_body + 138
    frame #7: 0x00007fff9473b72a libsystem_pthread.dylib`_pthread_start + 137
 
  thread #4: tid = 0xaca6, 0x000000010076e841 The Masterplan`void hx::MarkMember<String>(outT=0x0000000103d39af4, __inCtx=0x0000000103c03e90) + 49 at GCTemplates.h:30
    frame #0: 0x000000010076e841 The Masterplan`void hx::MarkMember<String>(outT=0x0000000103d39af4, __inCtx=0x0000000103c03e90) + 49 at GCTemplates.h:30
    frame #1: 0x000000010076cb68 The Masterplan`Array_obj<String>::__Mark(this=0x0000000103d39820, __inCtx=0x0000000103c03e90) + 120 at Array.h:311
    frame #2: 0x0000000101caba9a The Masterplan`hx::MarkObjectAlloc(inPtr=0x0000000103d39820, __inCtx=0x0000000103c03e90) + 538 at GCInternal.cpp:1042
    frame #3: 0x000000010076e564 The Masterplan`void hx::MarkMember<String>(outT=0x0000000103d39744, __inCtx=0x0000000103c03e90) + 52 at GCTemplates.h:22
    frame #4: 0x0000000101ce0831 The Masterplan`Class_obj::__Mark(this=0x0000000103d396e4, __inCtx=0x0000000103c03e90) + 161 at Class.cpp:116
    frame #5: 0x0000000101cae068 The Masterplan`hx::MarkContext::Process(this=0x0000000103c03e90) + 152 at GCInternal.cpp:954
    frame #6: 0x0000000101cb7d05 The Masterplan`GlobalAllocator::MarkerLoop(this=0x0000000103a0c580, inId=2) + 69 at GCInternal.cpp:2080
    frame #7: 0x0000000101cb7cb0 The Masterplan`GlobalAllocator::SMarkerFunc(inInfo=0x0000000000000002) + 32 at GCInternal.cpp:2087
    frame #8: 0x00007fff9473b899 libsystem_pthread.dylib`_pthread_body + 138
    frame #9: 0x00007fff9473b72a libsystem_pthread.dylib`_pthread_start + 137
 
  thread #5: tid = 0xaca7, 0x000000010076cb3d The Masterplan`Array_obj<String>::__Mark(this=0x0000000103d45124, __inCtx=0x0000000103c86e90) + 77 at Array.h:310
    frame #0: 0x000000010076cb3d The Masterplan`Array_obj<String>::__Mark(this=0x0000000103d45124, __inCtx=0x0000000103c86e90) + 77 at Array.h:310
    frame #1: 0x0000000101caba9a The Masterplan`hx::MarkObjectAlloc(inPtr=0x0000000103d45124, __inCtx=0x0000000103c86e90) + 538 at GCInternal.cpp:1042
    frame #2: 0x000000010076e564 The Masterplan`void hx::MarkMember<String>(outT=0x0000000103d45110, __inCtx=0x0000000103c86e90) + 52 at GCTemplates.h:22
    frame #3: 0x0000000101ce0808 The Masterplan`Class_obj::__Mark(this=0x0000000103d450b8, __inCtx=0x0000000103c86e90) + 120 at Class.cpp:115
    frame #4: 0x0000000101cae068 The Masterplan`hx::MarkContext::Process(this=0x0000000103c86e90) + 152 at GCInternal.cpp:954
    frame #5: 0x0000000101cb7d05 The Masterplan`GlobalAllocator::MarkerLoop(this=0x0000000103a0c580, inId=3) + 69 at GCInternal.cpp:2080
    frame #6: 0x0000000101cb7cb0 The Masterplan`GlobalAllocator::SMarkerFunc(inInfo=0x0000000000000003) + 32 at GCInternal.cpp:2087
    frame #7: 0x00007fff9473b899 libsystem_pthread.dylib`_pthread_body + 138
    frame #8: 0x00007fff9473b72a libsystem_pthread.dylib`_pthread_start + 137

Part of the issue when debugging this problem is that I cannot reproduce it 100% of the time. It comes and goes. What I managed to do is get the problem to happen somewhat more often by reducing the stack size on my Mac. If type "ulimit -s 128" on a single terminal session I get the crash to happen pretty frequently. Anything lower than that, then SDL fails on creating the game window. The weird thing is that normally the stack size limit is 8196, which is much larger than 128 and it happens with that as well. Unfortunately, I haven't found a way to increase the stack size to work around the problem (and I don't even know if that would help).

Other threads seem to be running something related to GC and the first thread is inside loading OpenGL stuff inside "void GL_obj::__boot()". In any case, it seems to be allocating a string at the moment of the crash:

lime_gl_stencil_mask= ::openfl::gl::GL_obj::load(HX_CSTRING("lime_gl_stencil_mask"),(int)1);

So when the crash happens, it seems to happen during processing of import declarations? In any case, I'm pretty much at loss on how to move forward. I'm not sure if this is a problem in OpenFL or hxcpp, or what might be most likely, in our app. Threads might make the problem come and go randomly, maybe :)

Any help would be greatly appreciated.

Thanks,

Leo

[David Elahee]

It looks like a "you are not on the gl owner thread" type of issue, are you aware of this one ?

--
To post to this group haxe...@googlegroups.com
http://groups.google.com/group/haxelang?hl=en
---
You received this message because you are subscribed to the Google Groups "Haxe" group.
For more options, visit https://groups.google.com/d/optout.

--
David Elahee

[Leo Lännenmäki]

No, I'm not aware of that one. Could you elaborate a bit? :)

[David Elahee]

It would take a long time to explain everything so i'll sum up.

If you happen to use threads, you have to be careful about which part of your application is doing in which thread.

For example gl calls MUST allways happen on the main thread, some os calls too...

In extenso on our java lib whenever doing android call, since you don't know who called you, we always do this :

```
act().runOnUiThread(new Runnable() {
            public void run() {
              ....
            }
        });
```

And that sort of applies to any system native calls.

In you cas it seems to me that something was bounced to one thread to another without being either properlly marked for thread usage or calling gl from an invalid thread.

If it sounds like your scenario, i'll have to ask you to dig in throught the mailing list, Hugh often explains this in informal responses.

If you are still stuck, please ping him :)

bye !

[Leo Lännenmäki]

Thanks for the explanation! Unfortunately that doesn't really apply to our problem. Or at least I think so.

I managed to debug the problem a bit more. The crash happens during during the execution of some "::ClassNameFoo::boot();" calls in __boot__.cpp. It seems to be pretty random in which class triggers the crash. In this example https://gist.github.com/leolannenmaki/70492889e303b5bdc0a9#file-backtrace, it crashes when allocating a string inside "::openfl::text::TextField_obj::__boot();".

In this project the __boot__.cpp file is over 3500 lines long with quite a lot of classes.

I managed to work around the problem by disabling GC during boot. I did this by adding 

static function __init__() {

enable(false);

}

to cpp.vm.Gc. I re-enable GC after the bootup process calls my main class. So now my __boot__.cpp file looks like:

#include <hxcpp.h>

#include <zpp_nape/util/ZPP_Set_ZPP_CbSet.h>

// snipped rest of includes..

void __files__boot();

void __boot_all()

{

__files__boot();

hx::RegisterResources( hx::GetResources() );

::zpp_nape::util::ZPP_Set_ZPP_CbSet_obj::__register();

// snipped rest of register() calls...

::cpp::vm::Gc_obj::__init__(); // THIS NOW DISABLES GC
// snipped rest of init() calls...

::cpp::Lib_obj::__boot();

// snipped rest of __boot() calls...

Adding that enable(false) call to GC.__init__() is really not ideal, but that was the first thing I could think of :) I think I'll report this problem to hxcpp's issue tracker, as it seems to be just related to the size of our project and not to any particular library.

[Hugh]

This was a bit of a doozie - but easy to reproduce if you force a collect in String operator +.

The problem was to do with the inline constructor in the CFFI code - usually the haxe code does not have inline constructors.  This allowed a GC collection to slip in between the "new" call and the body of the constructor, where things are partially constructed.  So your fix of disabling gc while loading the prims in the boot call was pretty good, but it should be fixed properly now on the hxcpp git version.

Hugh

[Leo Lännenmäki]

We've been running all day on the latest hxcpp from Github. No segfaults. Thank you!