[Mono-list] CPU hang after mod-mono-server shutdown

Chris Swiedler cswiedler at trionworlds.com
Thu Sep 22 23:04:01 UTC 2016


I’ve run into a similar problem with mono server apps using Mono 4.2. My solution was to #ifdef out this code in icall.c in ves_icall_System_Environment_Exit:

#if 0
                /* Suspend all managed threads since the runtime is going away */
                mono_thread_suspend_all_other_threads ();
                 mono_runtime_quit ();
#endif

If anyone has a reason why doing this is a horribly bad thing, I’d love to hear it, but my attitude is “the process is going away so I don’t care much about cleanup”. There may be bad behavior with code running on other threads, but we make sure to stop all of that before calling Application.Exit.

chris

From: Mono-list [mailto:mono-list-bounces at lists.dot.net] On Behalf Of Felix Berlakovich
Sent: Thursday, September 22, 2016 3:55 PM
To: mono-list at lists.dot.net
Subject: Re: [Mono-list] CPU hang after mod-mono-server shutdown

Hi!

I Installed all the debug symbols I could find and made repeated the gdb procedure:

Thread 5 (Thread 0x7f6077fff700 (LWP 29595)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000000623af7 in mono_os_cond_wait (cond=0x98b420 <work_cond>, mutex=<optimized out>) at ../../mono/utils/mono-os-mutex.h:107
#2  thread_func (thread_data=0x0) at sgen-thread-pool.c:110
#3  0x00007f607950d0a4 in start_thread (arg=0x7f6077fff700) at pthread_create.c:309
#4  0x00007f607902c62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 4 (Thread 0x7f6075b10700 (LWP 29650)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x00000000005bb9c9 in mono_os_sem_wait (flags=MONO_SEM_FLAGS_ALERTABLE, sem=0x97c100 <finalizer_sem>) at ../../mono/utils/mono-os-semaphore.h:166
#2  mono_coop_sem_wait (sem=<optimized out>, flags=<optimized out>) at ../../mono/utils/mono-coop-semaphore.h:40
#3  finalizer_thread (unused=unused at entry=0x0) at gc.c:761
#4  0x000000000059c75c in start_wrapper_internal (data=<optimized out>) at threads.c:740
#5  start_wrapper (data=<optimized out>) at threads.c:788
#6  0x0000000000653c1c in inner_start_thread (arg=<optimized out>) at mono-threads-posix.c:92
#7  0x00007f607950d0a4 in start_thread (arg=0x7f6075b10700) at pthread_create.c:309
#8  0x00007f607902c62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 3 (Thread 0x7f6074533700 (LWP 29663)):
#0  sem_timedwait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_timedwait.S:101
#1  0x0000000000651598 in mono_os_sem_timedwait (sem=<optimized out>, timeout_ms=<optimized out>, flags=<optimized out>) at ../../mono/utils/mono-os-semaphore.h:208
#2  mono_threads_wait_pending_operations () at mono-threads.c:238
#3  0x000000000065275a in suspend_sync (interrupt_kernel=1, tid=140051565508352) at mono-threads.c:918
#4  suspend_sync_nolock (interrupt_kernel=1, id=140051565508352) at mono-threads.c:935
#5  mono_thread_info_safe_suspend_and_run (id=140051565508352, interrupt_kernel=1, callback=callback at entry=0x598870 <async_suspend_critical>, user_data=user_data at entry=0x7f6074532020) at mono-threads.c:978
#6  0x0000000000598e8c in async_suspend_internal (thread=0x7f604bf6f730, interrupt=<optimized out>) at threads.c:4899
#7  0x000000000059b81e in mono_thread_suspend_all_other_threads () at threads.c:3408
#8  0x0000000000546026 in ves_icall_System_Environment_Exit (result=0) at icall.c:7128
#9  0x00000000421019e1 in ?? ()
#10 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7f604bcff700 (LWP 29677)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000000000062a011 in mono_os_cond_wait (mutex=0x27aa0a0, cond=0x27aa0c8) at ../../mono/utils/mono-os-mutex.h:107
#2  mono_os_cond_timedwait (timeout_ms=4294967295, mutex=0x27aa0a0, cond=0x27aa0c8) at ../../mono/utils/mono-os-mutex.h:122
#3  _wapi_handle_timedwait_signal_handle (handle=handle at entry=0x204b, timeout=timeout at entry=4294967295, alertable=alertable at entry=0, poll=poll at entry=0, alerted=alerted at entry=0x7f604bcfed6c) at handles.c:1555
#4  0x000000000063fd74 in wapi_WaitForSingleObjectEx (handle=handle at entry=0x204b, timeout=4294967295, alertable=alertable at entry=0) at wait.c:181
#5  0x000000000063fee7 in wapi_WaitForSingleObject (handle=handle at entry=0x204b, timeout=<optimized out>) at wait.c:227
#6  0x00000000005a1e1b in mono_threadpool_ms_remove_domain_jobs (domain=domain at entry=0x2b6adf0, timeout=timeout at entry=-1) at threadpool-ms.c:1472
#7  0x00000000005b588f in unload_thread_main (arg=0x7f606402b460) at appdomain.c:2378
#8  0x0000000000653c1c in inner_start_thread (arg=<optimized out>) at mono-threads-posix.c:92
#9  0x00007f607950d0a4 in start_thread (arg=0x7f604bcff700) at pthread_create.c:309
#10 0x00007f607902c62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7f607a03e740 (LWP 29587)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x0000000000650b80 in mono_os_sem_wait (sem=0x27b2020, flags=<optimized out>) at ../../mono/utils/mono-os-semaphore.h:166
#2  mono_thread_info_wait_for_resume (info=0x27b1fc0) at mono-threads.c:153
#3  0x0000000000599cfd in mono_thread_suspend (thread=0x7f6079f54130) at threads.c:2393
#4  mono_thread_suspend (thread=0x7f6079f54130) at threads.c:2369
#5  0x000000000059e943 in mono_thread_manage () at threads.c:3266
#6  0x000000000047eb52 in mono_main (argc=9, argv=<optimized out>) at driver.c:2140
---Type <return> to continue, or q <return> to quit---
#7  0x0000000000422258 in mono_main_with_options (argv=0x7ffe0acd5198, argc=9) at main.c:28
#8  main (argc=9, argv=0x7ffe0acd5198) at main.c:177

Let me know if you need anything further.

Regards

Felix

Von: Rodrigo Kumpera [mailto:kumpera at gmail.com]
Gesendet: Freitag, 23. September 2016 00:13
An: Felix Berlakovich
Cc: mono-list at lists.dot.net<mailto:mono-list at lists.dot.net>
Betreff: Re: [Mono-list] CPU hang after mod-mono-server shutdown

Hey Felix,

You should install the debug symbols from your distro as there's nothing we can say from an incomplete backtrace.

--
Rodrigo

On Thu, Sep 22, 2016 at 2:18 AM, Felix Berlakovich <felix at berlakovich.at<mailto:felix at berlakovich.at>> wrote:
Hi!

I have a problem with a ASP.NET<http://ASP.NET> ServiceStack (3.9.72) application and mod-mono-server. I am running the application on Debian 8.5 with Apache 2.4.10 and mono 4.6 with Debian packages from mono-project.com<http://mono-project.com>. Everything works as expected except for a shutdown of the mod-mono-server. The shutdown occurs either on apache restart, apache stop or mod-mono-server –terminate. My application is shutdown properly (Application_End is executed), but then the mono process goes into a CPU loop. In case of apache restart a new process is spawned afterwards, but the hanging process remains. The hanging process can only be killed with kill -9.

My observations so far:

•         The hang does not occur with nginx + hyperfastcgi, so it cannot be a general problem with my application. I would strongly prefer apache though.

•         The hang does not occur with the mono ASP.NET<http://ASP.NET> example application

•         The hang occurs only after my application was loaded by mod-mono-server, i.e. at least one request to the application is needed before the shutdown

•         mod-mono-server logs a “mod-mono-server received a shutdown message” message before the hang

I have traced a shutdown of mod-mono-server and attached the tail of the log at [1]. Furthermore I attached to the hanging process with gdb and issued a thread apply all bt. The output is attached at [2]. I am completely out of ideas on how to further troubleshoot this problem.

Regards

Felix

[1] tail of a traced mod-mono-server shutdown:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
85      ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S: Datei oder Verzeichnis nicht gefunden.
  Id   Target Id         Frame
  10   Thread 0x7f76d6fff700 (LWP 17622) "SGen worker" pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  9    Thread 0x7f76d4fd2700 (LWP 17623) "Finalizer" sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
  8    Thread 0x7f76cffff700 (LWP 17625) "Main" 0x00007f76d83bdaed in poll () at ../sysdeps/unix/syscall-template.S:81
  7    Thread 0x7f76cffbe700 (LWP 17626) "Main" pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
  6    Thread 0x7f76cff7d700 (LWP 17627) "Threadpool work" 0x00007f76d83afbb7 in sched_yield () at ../sysdeps/unix/syscall-template.S:81
  5    Thread 0x7f76cfd7c700 (LWP 17628) "Threadpool work" 0x00007f76d88ae4c9 in __libc_waitpid (pid=17645, stat_loc=0x7f76d91f411c, options=0) at ../sysdeps/unix/sysv/linux/waitpid.c:40
  4    Thread 0x7f76cfb7b700 (LWP 17629) "Threadpool work" 0x00007f76d83b9bbd in read () at ../sysdeps/unix/syscall-template.S:81
  3    Thread 0x7f76ce6fb700 (LWP 17633) "Timer-Scheduler" pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
  2    Thread 0x7f76d423f700 (LWP 17644) "Threadpool work" 0x00007f76d83afbb7 in sched_yield () at ../sysdeps/unix/syscall-template.S:81
* 1    Thread 0x7f76d93d8740 (LWP 17621) "Main" sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85

Thread 10 (Thread 0x7f76d6fff700 (LWP 17622)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000000623dc7 in ?? ()
#2  0x00007f76d88a70a4 in start_thread (arg=0x7f76d6fff700) at pthread_create.c:309
#3  0x00007f76d83c662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 9 (Thread 0x7f76d4fd2700 (LWP 17623)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x00000000005bbc99 in ?? ()
#2  0x000000000059c87c in ?? ()
#3  0x0000000000653eec in ?? ()
#4  0x00007f76d88a70a4 in start_thread (arg=0x7f76d4fd2700) at pthread_create.c:309
#5  0x00007f76d83c662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 8 (Thread 0x7f76cffff700 (LWP 17625)):
#0  0x00007f76d83bdaed in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00000000005a2d8f in ?? ()
#2  0x00000000005a3da3 in ?? ()
#3  0x000000000059c87c in ?? ()
#4  0x0000000000653eec in ?? ()
#5  0x00007f76d88a70a4 in start_thread (arg=0x7f76cffff700) at pthread_create.c:309
#6  0x00007f76d83c662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 7 (Thread 0x7f76cffbe700 (LWP 17626)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x0000000000652375 in ?? ()
#2  0x00000000005a12e8 in ?? ()
#3  0x000000000059c87c in ?? ()
#4  0x0000000000653eec in ?? ()
#5  0x00007f76d88a70a4 in start_thread (arg=0x7f76cffbe700) at pthread_create.c:309
#6  0x00007f76d83c662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 6 (Thread 0x7f76cff7d700 (LWP 17627)):
#0  0x00007f76d83afbb7 in sched_yield () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000000000653dd9 in ?? ()
#2  0x0000000000479f05 in ?? ()
#3  0x000000004067e4ac in ?? ()
#4  0x00007f76ce7abe98 in ?? ()
#5  0x00007f76cff7c6e8 in ?? ()
#6  0x0000000000000031 in ?? ()
#7  0x00007f76cff7c6e0 in ?? ()
#8  0x0000000000000031 in ?? ()
#9  0x00007f76cff7c6c0 in ?? ()
#10 0x0000000000000000 in ?? ()

Thread 5 (Thread 0x7f76cfd7c700 (LWP 17628)):
#0  0x00007f76d88ae4c9 in __libc_waitpid (pid=17645, stat_loc=0x7f76d91f411c, options=0) at ../sysdeps/unix/sysv/linux/waitpid.c:40
#1  0x00000000004acd59 in ?? ()
#2  0x00000000005040fe in ?? ()
#3  0x00000000004275d7 in ?? ()
#4  <signal handler called>
#5  0x000000000047a2b8 in ?? ()
#6  0x0000000040cb8984 in ?? ()
#7  0x00007f76cdce92b0 in ?? ()
#8  0x0000000002c294a0 in ?? ()
#9  0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7f76cfb7b700 (LWP 17629)):
#0  0x00007f76d83b9bbd in read () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000000040692807 in ?? ()
#2  0x00007f76d73246f8 in ?? ()
#3  0x00007f76b8001950 in ?? ()
#4  0x00007f76d7324688 in ?? ()
#5  0x00007f76cfb7a780 in ?? ()
#6  0x00007f76cfb7a730 in ?? ()
#7  0x00007f76d73246f8 in ?? ()
#8  0x00007f76d7324688 in ?? ()
#9  0x00007f76d7325a48 in ?? ()
#10 0x0000000000000020 in ?? ()
#11 0x00007f76d7324610 in ?? ()
#12 0x00007f76cfb7a820 in ?? ()
#13 0x000000004069259c in ?? ()
#14 0x00000000000000ff in ?? ()
#15 0xffffffffffffffff in ?? ()
#16 0xe000fa03dd00fa03 in ?? ()
#17 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7f76ce6fb700 (LWP 17633)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x000000000062a1c8 in ?? ()
#2  0x000000000063fedd in ?? ()
#3  0x000000000059c5b7 in ?? ()
#4  0x000000000059d876 in ?? ()
#5  0x000000004070d1ec in ?? ()
#6  0x00007f76d70eafa8 in ?? ()
#7  0x00007f76ac001950 in ?? ()
#8  0x00007f76d70eafa8 in ?? ()
#9  0x00007f76ce6fa540 in ?? ()
#10 0x00007f76ce6fa4f0 in ?? ()
#11 0x0000000000000001 in ?? ()
#12 0x00007f76d70eafa8 in ?? ()
#13 0x00007f76d70eaf70 in ?? ()
#14 0x00000000000003e6 in ?? ()
#15 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7f76d423f700 (LWP 17644)):
#0  0x00007f76d83afbb7 in sched_yield () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000000000653dd9 in ?? ()
#2  0x0000000000479f05 in ?? ()
#3  0x000000004058ef64 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7f76d93d8740 (LWP 17621)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x0000000000650e50 in ?? ()
#2  0x0000000000599e1d in ?? ()
#3  0x000000000059ea63 in mono_thread_manage ()
#4  0x000000000047eb52 in mono_main ()
#5  0x0000000000422258 in ?? ()
#6  0x00007f76d82ffb45 in __libc_start_main (main=0x422160, argc=9, argv=0x7ffd524d96c8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd524d96b8) at libc-start.c:287
#7  0x0000000000422651 in _start ()

=================================================================
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.
=================================================================

[0x7f76cfd7c700: 9,79980 14] ENTER: (wrapper delegate-invoke) <Module>:invoke_void_object_EventArgs (object,System.EventArgs)(this:0x7f76cdce92b0[System.EventHandler a005241e],


[2] gdb thread apply all bt in the hanging mono process

Thread 5 (Thread 0x7fa95d7ff700 (LWP 17716)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000000623dc7 in ?? ()
#2  0x00007fa95ecfa0a4 in start_thread (arg=0x7fa95d7ff700) at pthread_create.c:309
#3  0x00007fa95e81962d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 4 (Thread 0x7fa95b434700 (LWP 17771)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x00000000005bbc99 in ?? ()
#2  0x000000000059c87c in ?? ()
#3  0x0000000000653eec in ?? ()
#4  0x00007fa95ecfa0a4 in start_thread (arg=0x7fa95b434700) at pthread_create.c:309
#5  0x00007fa95e81962d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 3 (Thread 0x7fa95a1f3700 (LWP 17783)):
#0  sem_timedwait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_timedwait.S:101
#1  0x0000000000651868 in ?? ()
#2  0x0000000000652b14 in ?? ()
#3  0x0000000000598fac in ?? ()
#4  0x000000000059b93e in ?? ()
#5  0x0000000000546146 in ?? ()
#6  0x0000000042501901 in ?? ()
#7  0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fa931cff700 (LWP 17795)):
#0  0x00007fa95e7663e2 in do_sigsuspend (set=0x98c340) at ../sysdeps/unix/sysv/linux/sigsuspend.c:31
#1  __GI___sigsuspend (set=0x98c340) at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
#2  0x00000000006543de in ?? ()
#3  <signal handler called>
#4  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#5  0x000000000062a2e1 in ?? ()
#6  0x0000000000640044 in ?? ()
#7  0x00000000005a1f3b in ?? ()
#8  0x00000000005b597f in ?? ()
#9  0x0000000000653eec in ?? ()
#10 0x00007fa95ecfa0a4 in start_thread (arg=0x7fa931cff700) at pthread_create.c:309
#11 0x00007fa95e81962d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7fa95f82b740 (LWP 17711)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x0000000000650e50 in ?? ()
#2  0x0000000000599e1d in ?? ()
#3  0x000000000059ea63 in mono_thread_manage ()
#4  0x000000000047eb52 in mono_main ()
#5  0x0000000000422258 in ?? ()
#6  0x00007fa95e752b45 in __libc_start_main (main=0x422160, argc=9, argv=0x7ffccf689c28, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffccf689c18) at libc-start.c:287
#7  0x0000000000422651 in _start ()

_______________________________________________
Mono-list maillist  -  Mono-list at lists.dot.net<mailto:Mono-list at lists.dot.net>
http://lists.dot.net/mailman/listinfo/mono-list

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.dot.net/pipermail/mono-list/attachments/20160922/62756302/attachment-0001.html>


More information about the Mono-list mailing list