Bug 24084

Summary: sgen assert in sgen_obj_get_descriptor () when frequently allocating with FormatterServices.GetUninitializedObject()
Product: [Mono] Runtime Reporter: Matt Z <matt.zinkevicius>
Component: GCAssignee: Bugzilla <bugzilla>
Status: RESOLVED FIXED    
Severity: normal CC: mark, mono-bugs+mono, mono-bugs+runtime, vargaz
Priority: ---    
Version: 3.8.0   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Tags: Is this bug a regression?: ---
Last known good build:
Attachments: Repro test program

Description Matt Z 2014-10-27 18:27:47 UTC
Created attachment 8521 [details]
Repro test program

Environment:
Ubuntu 14.04 LTS x64
Mono 3.10 (Xamarin official build)

We have a program that is getting a SIGSEGV signal when under load. We guessed that maybe Mono is out of heap space (we limited it via MONO_GC_PARAMS=max-heap-size=400m) but not failing gracefully with a OOM exception . It uses a custom serializer which allocates objects very frequently using FormatterServices.GetUninitializedObject().

To test our hypothesis, we wrote the attached test program. If you run it with an argument of 1, then it will allocate new byte arrays until a OOM exception is thrown. If you run it with an argument of 2, then it will SIGSEGV from allocating with GetUnitializedObject().

On Windows .NET, we correctly get an OOM exception in both cases.
Comment 1 Zoltan Varga 2014-10-27 22:51:03 UTC
I get:

Object can't be tagged
Stacktrace:

  at <unknown> <0xffffffff>
  at (wrapper managed-to-native) System.Runtime.Remoting.Activation.ActivationServices.AllocateUninitializedClassInstance (System.Type) <0xffffffff>
  at System.Runtime.Serialization.FormatterServices.GetUninitializedObject (System.Type) <0x00013>
  at mono_oom.Program.AllocateViaGetUninitializedObject () <0x0001a>
  at mono_oom.Program.Main (string[]) <0x001c6>
  at (wrapper runtime-invoke) <Module>.runtime_invoke_void_object (object,intptr,intptr,intptr) <0xffffffff>

Native stacktrace:

	0   mono                                0x000000010d999a43 mono_handle_native_sigsegv + 339
	1   mono                                0x000000010da8eef2 sigabrt_signal_handler + 146
	2   libsystem_platform.dylib            0x00007fff968545aa _sigtramp + 26
	3   ???                                 0x0000000000000016 0x0 + 22
	4   mono                                0x000000010ef4db0b raise + 27
	5   mono                                0x000000010ef4dbc2 abort + 18
	6   mono                                0x000000010dc81a6b monoeg_log_default_handler + 219
	7   mono                                0x000000010dc81972 monoeg_g_logv + 114
	8   mono                                0x000000010dc81be9 monoeg_g_log + 361
	9   mono                                0x000000010dbe33a6 sgen_obj_get_descriptor + 118
	10  mono                                0x000000010dbe3270 sgen_pin_object + 256
	11  mono                                0x000000010dc29e0c copy_object_no_checks + 188
	12  mono                                0x000000010dc26227 simple_nursery_serial_scan_object + 727
	13  mono                                0x000000010dbe313c sgen_drain_gray_stack + 332
	14  mono                                0x000000010dbe471e collect_nursery + 1358
	15  mono                                0x000000010dbe24e5 sgen_perform_collection + 581
	16  mono                                0x000000010dbe3fb3 sgen_ensure_free_space + 323
	17  mono                                0x000000010dc17384 mono_gc_alloc_obj_nolock + 1412
	18  mono                                0x000000010dc168c5 mono_gc_alloc_obj + 485
	19  mono                                0x000000010dbb036d mono_object_allocate_spec + 29
	20  mono                                0x000000010dbb02ac mono_object_new_alloc_specific + 92
	21  mono                                0x000000010dae1bea ves_icall_System_Runtime_Activation_ActivationServices_AllocateUninitializedClassInstance + 378
Comment 2 Matt Z 2014-10-28 17:19:09 UTC
@zoltan Were you using Mono 3.10 in you run? Here is the SIGSEGV we get 100% of the time:

$ MONO_GC_PARAMS=max-heap-size=400m mono oom.exe 2
Stacktrace:

  at <unknown> <0xffffffff>
  at (wrapper managed-to-native) object.__icall_wrapper_mono_gc_alloc_obj (intptr,intptr) <0xffffffff>
  at (wrapper alloc) object.Alloc (intptr) <0xffffffff>
  at System.Collections.Generic.LinkedList`1.AddLast (T) <0x000cf>
  at mono_oom.Program.Main (string[]) <0x0015f>
  at (wrapper runtime-invoke) <Module>.runtime_invoke_void_object (object,intptr,intptr,intptr) <0xffffffff>

Native stacktrace:

        mono() [0x4b3f7c]
        mono() [0x50c30f]
        mono() [0x423637]
        /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7fd4cd6d8340]
        mono() [0x5ebf91]
        mono() [0x5cff15]
        mono() [0x5d0483]
        mono() [0x5d3957]
        mono() [0x5f0101]
        mono() [0x5f03eb]
        [0x410ece08]

Debug info from gdb:


=================================================================
Got a SIGSEGV while executing native code. This usually indicates
a fatal error in the mono runtime or one of the native libraries
used by your application.
=================================================================
Comment 3 Zoltan Varga 2014-10-28 17:25:55 UTC
The assert is with mono master.
Comment 4 Mark Probst 2014-10-30 16:39:31 UTC
This branch should fix it: https://github.com/schani/mono/tree/fix-23401
Comment 5 Mark Probst 2014-10-30 19:29:07 UTC
Should be fixed in master now.
Comment 6 Matt Z 2014-10-31 00:42:42 UTC
Created a build from master, I now get a different error:

[mono-20141030175631][root@cist-build-centos6 test]# MONO_GC_PARAMS=max-heap-size=400m mono oom.exe 1
Caught exception: Out of memory
[mono-20141030175631][root@cist-build-centos6 test]# MONO_GC_PARAMS=max-heap-size=400m mono oom.exe 2

Unhandled Exception:
Nested exception detected.
Original Exception: at mono_oom.Program.Main (string[]) <0x001bb>

Nested exception:at (wrapper managed-to-native) System.Runtime.Remoting.Activation.ActivationServices.AllocateUninitializedClassInstance (System.Type) <0x00051>
at System.Runtime.Serialization.FormatterServices.GetUninitializedObject (System.Type) <0x00041>
at mono_oom.Program.AllocateViaGetUninitializedObject () <0x0001a>
at mono_oom.Program.Main (string[]) <0x00175>


[ERROR] FATAL UNHANDLED EXCEPTION: Nested exception detected.
Original Exception: at mono_oom.Program.Main (string[]) <0x001bb>

Nested exception:at (wrapper managed-to-native) System.Runtime.Remoting.Activation.ActivationServices.AllocateUninitializedClassInstance (System.Type) <0x00051>
at System.Runtime.Serialization.FormatterServices.GetUninitializedObject (System.Type) <0x00041>
at mono_oom.Program.AllocateViaGetUninitializedObject () <0x0001a>
at mono_oom.Program.Main (string[]) <0x00175>
Comment 7 Matt Z 2014-10-31 01:38:08 UTC
In case it's helpful, here are the last 50 lines of the above run with --trace enabled:

[0x7fb92562c760: 243.34632 5] ENTER: (wrapper managed-to-native) System.Text.Encoding:InternalCodePage (int&)([BYREF:0x7fffb8ed4838], )
[0x7fb92562c760: 243.34638 5] LEAVE: (wrapper managed-to-native) System.Text.Encoding:InternalCodePage (int&)[STRING:null],
[0x7fb92562c760: 243.34684 5] ENTER: (wrapper unknown) System.Threading.Monitor:FastMonitorEnterV4 (object,bool&)([System.Object:0x7fb91c268020], [BYREF:0x7fffb8ed47e0], )
[0x7fb92562c760: 243.34699 6] ENTER: (wrapper managed-to-native) System.Threading.Monitor:try_enter_with_atomic_var (object,int,bool&)([System.Object:0x7fb91c268020], -1, [BYREF:0x7fffb8ed47e0], )
[0x7fb92562c760: 243.34702 6] LEAVE: (wrapper managed-to-native) System.Threading.Monitor:try_enter_with_atomic_var (object,int,bool&)
[0x7fb92562c760: 243.34705 5] LEAVE: (wrapper unknown) System.Threading.Monitor:FastMonitorEnterV4 (object,bool&)
[0x7fb92562c760: 243.34706 5] ENTER: (wrapper alloc) object:AllocSmall (intptr)(0x1067e78, )
[0x7fb92562c760: 243.34707 6] ENTER: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)(0x1067e78, 0x58, )
[0x7fb92562c760: 243.67821 6] LEAVE: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)[System.Text.UTF8Encoding:0x7fb9255b00c0]
[0x7fb92562c760: 243.67825 5] LEAVE: (wrapper alloc) object:AllocSmall (intptr)[System.Text.UTF8Encoding:0x7fb9255b00c0]
[0x7fb92562c760: 244.00594 5] ENTER: (wrapper runtime-invoke) object:runtime_invoke_void (object,intptr,intptr,intptr)((nil), (nil), 0x7fffb8ed4368, 0x7fb91c986a00, )
[0x7fb92562c760: 244.00601 6] ENTER: (wrapper alloc) object:AllocSmall (intptr)(0x1068190, )
[0x7fb92562c760: 244.00602 7] ENTER: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)(0x1068190, 0x10, )
[0x7fb92562c760: 244.33217 7] LEAVE: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)[System.Text.EncoderExceptionFallback:0x7fb91c268030]
[0x7fb92562c760: 244.33221 6] LEAVE: (wrapper alloc) object:AllocSmall (intptr)[System.Text.EncoderExceptionFallback:0x7fb91c268030]
[0x7fb92562c760: 244.33222 6] ENTER: (wrapper alloc) object:AllocSmall (intptr)(0x10681f8, )
[0x7fb92562c760: 244.33224 7] ENTER: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)(0x10681f8, 0x18, )
[0x7fb92562c760:] EXCEPTION handling: System.OutOfMemoryException: (No exception message for: OutOfMemoryException)

EXCEPTION: catch found at clause 0 of (wrapper runtime-invoke) object:runtime_invoke_void (object,intptr,intptr,intptr)
[0x7fb92562c760: 244.66231 7] LEAVE: (wrapper runtime-invoke) object:runtime_invoke_void (object,intptr,intptr,intptr)[OBJECT:(nil)]
[0x7fb92562c760: 245.97942 7] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_object (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c2781f0], 0x7fffb8ed4200, (nil), 0x7fb91c7d8b40, )
[0x7fb92562c760: 245.97951 7] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_object (object,intptr,intptr,intptr)[OBJECT:(nil)]
[0x7fb92562c760: 245.97970 7] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c2781f0], (nil), 0x7fffb8ed4090, 0x7fb91c7951a0, )
[0x7fb92562c760: 245.97976 7] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)[System.String:0x7fb9255a0068]
[0x7fb92562c760:] EXCEPTION handling: System.TypeInitializationException: System.Text.EncoderFallback
EXCEPTION: finally clause 0 of System.Text.Encoding:get_UTF8Unmarked ()
EXCEPTION: catch found at clause 0 of (wrapper runtime-invoke) object:runtime_invoke_void (object,intptr,intptr,intptr)
[0x7fb92562c760: 246.30893 6] LEAVE: (wrapper runtime-invoke) object:runtime_invoke_void (object,intptr,intptr,intptr)[OBJECT:(nil)]
[0x7fb92562c760: 246.96737 6] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_object (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c278268], 0x7fffb8ed4a30, (nil), 0x7fb91c7d8b40, )
[0x7fb92562c760: 246.96744 6] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_object (object,intptr,intptr,intptr)[OBJECT:(nil)]
[0x7fb92562c760: 246.96747 6] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c278268], (nil), 0x7fffb8ed48c0, 0x7fb91c7951a0, )
[0x7fb92562c760: 246.96749 6] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)[System.String:0x7fb91c274048]
[0x7fb92562c760:] EXCEPTION handling: System.TypeInitializationException: System.Console
[0x7fb92562c760: 248.61953 6] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c278268], (nil), 0x7fffb8ed4588, 0x7fb91c795aa0, )
[0x7fb92562c760: 248.61983 7] ENTER: (wrapper managed-to-native) System.MonoType:getFullName (System.MonoType,bool,bool)([TYPE:System.TypeInitializationException], 0, 0, )
[0x7fb92562c760: 248.94892 7] LEAVE: (wrapper managed-to-native) System.MonoType:getFullName (System.MonoType,bool,bool)[STRING:0x7fb91c26c268:System.TypeInitializationException]
[0x7fb92562c760: 248.94897 7] ENTER: (wrapper alloc) object:AllocSmall (intptr)(0x1068680, )
[0x7fb92562c760: 248.94898 8] ENTER: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)(0x1068680, 0x30, )
[0x7fb92562c760:] EXCEPTION handling: System.OutOfMemoryException: (No exception message for: OutOfMemoryException)

EXCEPTION: catch found at clause 0 of (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)
[0x7fb92562c760: 249.27240 8] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)[OBJECT:(nil)]
[0x7fb92562c760: 249.27253 8] ENTER: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)([System.TypeInitializationException:0x7fb91c278268], (nil), 0x7fffb8ed4588, 0x7fb91c795aa0, )
[0x7fb92562c760: 249.27255 9] ENTER: (wrapper alloc) object:AllocSmall (intptr)(0x1068680, )
[0x7fb92562c760: 249.27256 10] ENTER: (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_obj (intptr,intptr)(0x1068680, 0x30, )
[0x7fb92562c760:] EXCEPTION handling: System.OutOfMemoryException: (No exception message for: OutOfMemoryException)

EXCEPTION: catch found at clause 0 of (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)
[0x7fb92562c760: 249.59602 10] LEAVE: (wrapper runtime-invoke) <Module>:runtime_invoke_object__this__ (object,intptr,intptr,intptr)[OBJECT:(nil)]
Comment 8 Matt Z 2014-11-03 16:04:49 UTC
Well it looks like the behavior is a little inconsistent. I am now _sometimes_ getting the appropriate OOM exception, so I think things are just a little weird in OOM situations, therefore I think marking this as closed is correct.