Infinite loop after malloc fails

iximeow commented 6 years ago

Steps to Reproduce

I'm stumped. I haven't been able to reproduce in controlled environments or minimized test cases. The code seems clear enough, though.

Current Behavior

If g_malloc (typedef'd to monoeg_malloc, in a compiled binary) makes a call to G_MALLOC_INTERNAL (which is just malloc()), and malloc fails, returning null, control proceeds to g_error().

g_error is a macro that calls g_log and infinitely loops. On the prior line, there is a comment indicating that this function should not return, hence the for(;;);.

g_log returns, reaching the infinite loop, and hanging forever.

Expected Behavior

If malloc fails, and the runtime is unable to reclaim memory, I would expect any of:

The typical "faulted in native code, runtime will log and exit now"
OutOfMemoryException, if that's even a reasonable thing to expect in this context (which, since I can't reproduce, I don't really expect)
Anything other than an infinite loop

On which platforms did you notice this

[ ] macOS [x] Linux [ ] Windows

Version Used:

Witnessed on 5.10.0.140, haven't tried to figure out how long this code has existed.

iximeow commented 6 years ago

Over in glib itself, the logging internals eventually calls abort() under FATAL conditions: https://github.com/GNOME/glib/blob/32cc60dbffedc537ee2d37b9de695693e7795aae/glib/gmessages.c#L1974 -- maybe that behavior should be reproduced here?

iximeow commented 6 years ago

Wasn't satisfied with what I'd written initially, looked further:

g_log() calls g_logv() which initializes and eventually calls default_log_func
default_log_func is initialized to g_log_default_handler which does call abort() if the log level was fatal
before default_log_func would have been called, if g_logv's vasprintf fails we return rather than reaching what would eventually abort

This seems more satisfying an explanation - I've seen other similar errors to the tune of "Could not allocate %i bytes for garbage collection" which I thought went through the same code path and aborted normally.

I'll follow up if I can figure out a reproducible test case.

[edit: fixed links to reference current source from mono/mono rather than mono/eglib]

kumpera commented 6 years ago

This probably affects all targets.

jvgutierrez commented 6 years ago

At Wikimedia Foundation we've seen the same issue on Mono 5.12.0.226 running on Ubuntu Trusty, more details available in our ticket https://phabricator.wikimedia.org/T195834

zhuyifei1999 commented 6 years ago

A minimal test case:

10:48:59 0 ✓ zhuyifei1999@tools-bastion-05: ~/T195834$ cat memoryhog.cs; csc memoryhog.cs; ulimit -v 1048576; mono memoryhog.exe & PID=$!; sleep 5; gdb -batch -ex 'thread apply all bt' -p $PID
using System;
using System.Threading;
using System.Threading.Tasks;

namespace MemoryHog {
    class Program {
        static void Main(string[] args) {
            while (true) {
                var thread = new Thread(new ThreadStart(delegate {
                    Console.WriteLine("Worker running");
                    Thread.Sleep(1000);
                }));
                thread.Start();
                Thread.Sleep(1);
            }
        }
    }
}
Microsoft (R) Visual C# Compiler version 2.6.0.62309 (d3f6b8e7)
Copyright (C) Microsoft Corporation. All rights reserved.

[3] 17091
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
Worker running
[New LWP 17110]
[New LWP 17094]
[New LWP 17093]
[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: No such file or directory.

Thread 4 (Thread 0x7f2959bff700 (LWP 17093)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00000000006bfef3 in mono_os_cond_wait (mutex=0xa2bba0 <lock>, cond=0xa2bb60 <work_cond>) at ../../mono/utils/mono-os-mutex.h:173
#2  get_work (job=<synthetic pointer>, do_idle=<synthetic pointer>, work_context=<synthetic pointer>, worker_index=0) at sgen-thread-pool.c:165
#3  thread_func (data=<optimized out>) at sgen-thread-pool.c:196
#4  0x00007f295c57f184 in start_thread (arg=0x7f2959bff700) at pthread_create.c:312
#5  0x00007f295c09603d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 3 (Thread 0x7f295a305700 (LWP 17094)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x000000000065bf3c in mono_os_sem_wait (flags=MONO_SEM_FLAGS_ALERTABLE, sem=0xa1cc40 <finalizer_sem>) at ../../mono/utils/mono-os-semaphore.h:209
#2  mono_coop_sem_wait (flags=MONO_SEM_FLAGS_ALERTABLE, sem=0xa1cc40 <finalizer_sem>) at ../../mono/utils/mono-coop-semaphore.h:43
#3  finalizer_thread (unused=unused@entry=0x0) at gc.c:893
#4  0x0000000000615a33 in start_wrapper_internal (stack_ptr=<optimized out>, start_info=0x0) at threads.c:1071
#5  start_wrapper (data=0x240cf80) at threads.c:1131
#6  0x00007f295c57f184 in start_thread (arg=0x7f295a305700) at pthread_create.c:312
#7  0x00007f295c09603d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 2 (Thread 0x7f2955e97700 (LWP 17110)):
#0  0x00000000006de5e0 in monoeg_g_calloc (n=n@entry=1, x=1656) at gmem.c:117
#1  0x00000000006de5fd in monoeg_malloc0 (x=<optimized out>) at gmem.c:121
#2  0x00000000006d54b4 in mono_thread_info_attach () at mono-threads.c:649
#3  0x0000000000615942 in start_wrapper (data=0x2424dc0) at threads.c:1127
#4  0x00007f295c57f184 in start_thread (arg=0x7f2955e97700) at pthread_create.c:312
#5  0x00007f295c09603d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7f295d0ac780 (LWP 17091)):
#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
#1  0x0000000000613a2c in mono_os_sem_wait (flags=MONO_SEM_FLAGS_NONE, sem=0x2424df8) at ../../mono/utils/mono-os-semaphore.h:209
#2  mono_coop_sem_wait (flags=MONO_SEM_FLAGS_NONE, sem=0x2424df8) at ../../mono/utils/mono-coop-semaphore.h:43
#3  create_thread (thread=thread@entry=0x7f2959c141d8, internal=internal@entry=0x7f295d009468, start_delegate=start_delegate@entry=0x7f2959c14250, start_func=start_func@entry=0x0, start_func_arg=start_func_arg@entry=0x0, flags=flags@entry=MONO_THREAD_CREATE_FLAGS_NONE, error=error@entry=0x7ffc1016da10) at threads.c:1231
#4  0x000000000061416b in ves_icall_System_Threading_Thread_Thread_internal (this_obj=0x7f2959c141d8, start=0x7f2959c14250) at threads.c:1472
#5  0x0000000040322600 in ?? ()
#6  0x0000000000000000 in ?? ()
10:51:21 0 ✓ zhuyifei1999@tools-bastion-05: ~/T195834$ mono --version
Mono JIT compiler version 5.12.0.226 (tarball Thu May  3 09:52:39 UTC 2018)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
    TLS:           __thread
    SIGSEGV:       altstack
    Notifications: epoll
    Architecture:  amd64
    Disabled:      none
    Misc:          softdebug 
    Interpreter:   yes
    LLVM:          supported, not enabled.
    GC:            sgen (concurrent by default)

Thread 2 (Thread 0x7f2955e97700 (LWP 17110)) is stuck in the infinite loop. No g_error log is visible

mono / mono