We have been seeing intermittent segfaults and process hangs in our C# mono project, running on Ubuntu. I’ve spent quite a bit of time trying to debug the issue, including following these instructions: http://www.mono-project.com/docs/debug+profile/debug/
Data points:
The frequency with which this happens varies significantly across different environments. In our UAT environment, it happens very rarely. In production, it's every few hours, and on our dev machine, the process is lucky to run for 20 minutes without failing.
We upgraded our mono version to 4.03, with no improvement.
Symptoms:
Either the process hangs, and does not respond to SIGQUIT or SIGTERM, or it fails with either SIGSEGV, or SIGABRT
Here's an example dump, although they vary a bit, and mostly don't contain the below assertion failure.
* Assertion: should not be reached at sgen-scan-object.h:101
Native stacktrace:
/usr/bin/mono() [0x4b23ac]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7fbaa5e50340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7fbaa5ab1cc9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7fbaa5ab50d8]
/usr/bin/mono() [0x629839]
/usr/bin/mono() [0x629a47]
/usr/bin/mono() [0x629b96]
/usr/bin/mono() [0x5d85a8]
/usr/bin/mono() [0x5cbd56]
/usr/bin/mono() [0x5cd458]
/usr/bin/mono() [0x5cdaab]
/usr/bin/mono() [0x5d0d32]
/usr/bin/mono(mono_gc_collect+0x28) [0x5d1458]
/usr/bin/mono() [0x59c18a]
/usr/bin/mono() [0x623a06]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7fbaa5e48182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7fbaa5b7547d]
Debug info from gdb:
Could not attach to process. If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user. For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Operation not permitted.
No threads.
=================================================================
Got a SIGABRT while executing native code. This usually indicates
a fatal error in the mono runtime or one of the native libraries
used by your application.
=================================================================
I'm not 100% sure that the hangs, segfaults, and sigabrt's are all caused by the same issue, but I suspect they are. The hangs don't feel like an ordinary deadlock, since the process doesn't respond to SIGQUIT or SIGTERM.
I've tried attaching gdb, following the instructions in http://www.mono-project.com/docs/debug+profile/debug/, but the results were less than spectacular.
Here's my .gdbinit:
less ~/.gdbinit
handle SIGXCPU SIG33 SIG35 SIGPWR nostop noprint
define mono_stack
set $mono_thread = mono_thread_current ()
if ($mono_thread == 0x00)
printf "No mono thread associated with this thread\n"
else
set $ucp = malloc (sizeof (ucontext_t))
call (void) getcontext ($ucp)
call (void) mono_print_thread_dump ($ucp)
call (void) free ($ucp)
end
end
Here's the output from one of my gdb debugging sessions (of the hung process):
(gdb) where
#0 0x00007f2bbba05062 in do_sigsuspend (set=0x945300) at ../sysdeps/unix/sysv/linux/sigsuspend.c:31
#1 __GI___sigsuspend (set=0x945300) at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
#2 0x00000000005c8ccc in ?? ()
#3 <signal handler called>
#4 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#5 0x00000000005fdda7 in ?? ()
#6 0x0000000000610aac in ?? ()
#7 0x0000000000585f6e in ?? ()
#8 0x0000000000586ee9 in ?? ()
#9 0x00000000403eb416 in ?? ()
#10 0x000000000290e8b0 in ?? ()
#11 0x00007fff29bfacb0 in ?? ()
#12 0x0000000000000000 in ?? ()
(gdb) p mono_pmip (0x00000000005fdda7)
$1 = 0
(doesn’t seem to print anything either to gdb console or process stdout)
(gdb) call mono_locks_dump (0)
$2 = 0
Total locks (in 10 array(s)): 16368, used: 399, on freelist: 213, to recycle: 15752
(gdb) mono_stack()
"<unnamed thread>" tid=0x0x7f2bbc8d47c0 this=0x0x7f2bbc858140 thread handle 0x403 state : waiting on 0x41a : Event owns ()
at <unknown> <0xffffffff>
at (wrapper managed-to-native) System.Threading.WaitHandle.WaitOne_internal (System.Threading.WaitHandle,intptr,int,bool) <IL 0x0001c, 0xffffffff>
at System.Threading.WaitHandle.WaitOne (System.TimeSpan,bool) <0x0009b>
at System.Threading.WaitHandle.WaitOne (System.TimeSpan) <0x0001d>
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.RunUntilSignaled () [0x00073] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:184
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.Run (string[]) [0x00019] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:35
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.Main (string[]) [0x00000] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:24
at (wrapper runtime-invoke) <Module>.runtime_invoke_int_object (object,intptr,intptr,intptr) <IL 0x0006c, 0xffffffff>
"<unnamed thread>" tid=0x0x7f2bbc8d47c0 this=0x0x7f2bbc858140 thread handle 0x403 state : waiting on 0x41a : Event owns ()
at <unknown> <0xffffffff>
at (wrapper managed-to-native) System.Threading.WaitHandle.WaitOne_internal (System.Threading.WaitHandle,intptr,int,bool) <IL 0x0001c, 0xffffffff>
at System.Threading.WaitHandle.WaitOne (System.TimeSpan,bool) <0x0009b>
at System.Threading.WaitHandle.WaitOne (System.TimeSpan) <0x0001d>
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.RunUntilSignaled () [0x00073] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:184
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.Run (string[]) [0x00019] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:35
at COG.PonteDeiSospiri.PdSDaemon.CuratorDaemon.Main (string[]) [0x00000] in /home/ubuntu/jenkins/sharedspace/bridge-shared-workspace/app/PdS-Daemon/CuratorDaemon.cs:24
at (wrapper runtime-invoke) <Module>.runtime_invoke_int_object (object,intptr,intptr,intptr) <IL 0x0006c, 0xffffffff>
call mono_locks_dump (0)
$1 = 51700864
(gdb) call mono_locks_dump (1)
$2 = 56715296
Total locks (in 10 array(s)): 16368, used: 399, on freelist: 213, to recycle: 15752
Lock 0x29d68d0 in object 0x7f2ba8d13590 untaken
Lock 0x29d68f8 in object 0x7f2b7482c2c0 untaken
Lock 0x29d6920 in object 0x7f2b7482cd00 untaken
Lock 0x29d6948 in object 0x7f2b7482cb70 untaken
Lock 0x29d6970 in object 0x7f2b7482c760 untaken
Lock 0x29d6998 in object 0x7f2b7482d380 untaken
Lock 0x29d69c0 in object 0x7f2b7482c540 untaken
Lock 0x29d69e8 in object 0x7f2b7482c240 untaken
…...
times lots
(gdb) call mono_object_describe (0x41a)
The following is printed to the gdb console.
Program received signal SIGSEGV, Segmentation fault.
0x000000000052c1a2 in mono_object_describe ()
The program being debugged was signaled while in a function called from GDB.
GDB remains in the frame where the signal was received.
To change this behavior use "set unwindonsignal on".
Evaluation of the expression containing the function
(mono_object_describe) will be abandoned.
When the function is done executing, GDB will silently stop.
(gdb) quit
A debugging session is active.
Inferior 1 [process 7763] will be detached.
Quit anyway? (y or n) y
Detaching from program: /usr/bin/mono-sgen, process 7763
As soon as gdb finishes, the process writes remaining log messages to gdb console and then restarts (possibly by upstart)
ubuntu@shim-megastore-prod:/var/log/upstart$ 2015-08-20 01:48:20,124 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: Service check complete.
2015-08-20 01:48:22,641 INFO ( 5) iri.PdSDaemon.Services.CloudWatchService :: 936 metrics averaged...
2015-08-20 01:48:22,716 INFO ( 5) iri.PdSDaemon.Services.CloudWatchService :: 4 metrics posted to CloudWatch.
2015-08-20 01:48:29,568 INFO (ker) piri.PdSDaemon.Services.PriceSyncService :: 98.8% synchronised (15.1/sec)
2015-08-20 01:48:39,820 DEBUG ( 4) ri.PdSDaemon.Services.ProductSyncService :: Zzzz
Process restarts, or is restarted by Upstart
2015-08-20 06:51:20,163 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: Ponte dei Sospiri Daemon Version 1.0.5695.31695
2015-08-20 06:51:20,172 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: Process ID: 12625
2015-08-20 06:51:20,172 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon ::
2015-08-20 06:51:20,182 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: ProductSyncService is not running, firing it up...
2015-08-20 06:51:20,183 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: CloudWatchService is not running, firing it up...
2015-08-20 06:51:20,185 INFO ( 1) .PonteDeiSospiri.PdSDaemon.CuratorDaemon :: OrderProcessingService is not running, firing it up...
The above is all written to the gdb console window. From then on, the output goes to the upstart console log.
Here is a list of the dependencies of the project:
<package id="AWSSDK" version="2.3.20.0" targetFramework="net40" />
<package id="CsvHelper" version="2.10.0" targetFramework="net40" />
<package id="FluentMigrator" version="1.4.0.0" targetFramework="net40" />
<package id="Mono.Options" version="1.1" targetFramework="net40" />
<package id="Npgsql" version="2.2.5" targetFramework="net40" />
<package id="ServiceStack.Common" version="3.9.71" targetFramework="net40" />
<package id="ServiceStack.OrmLite.PostgreSQL" version="3.9.71" targetFramework="net40" />
<package id="ServiceStack.OrmLite.Sqlite.Mono" version="3.9.71" targetFramework="net40" />
<package id="ServiceStack.Text" version="3.9.71" targetFramework="net40" />
targetFramework="net40" />
<package id="log4net" version="2.0.3" targetFramework="net40" />
Any ideas / suggestions on how I can get more specific information on what is causing this to happen? It seems likely that it's either a bug in mono, or in one of the native libraries (since we have no unsafe code), but I can't seem to work out where the issue is coming from.
Any assistance greatly appreciated!
