Моно 100% вращения процессора в mono_conc_hashtable_lookup - PullRequest
0 голосов
/ 18 мая 2018

У меня есть приложение, которое является автономным процессором пакетных задач. По сути, исполнитель задач, который принимает входные данные в stdin, выполняет заданную командную задачу, сохраняет выходные данные через NHibernate для базы данных MySQL. Это не сложно и работает однопоточно (подумайте модель Apache Prefork).

При развертывании на более современной версии mono у меня были процессы зависали, используя 100% ядра процессора. Приложение обычно развертывается в Linux, но я смог воспроизвести его в отладчике Visual Studio Community для Mac на Mono 5.8.1 и 5.12.0.233. В Visual Studio Community, когда я ломаю приложение, я не получаю никакой информации о том, что выполняется оператор.

При переходе к gdb в Linux я получаю следующие следы:

трассировка:


    #0  0x00000000006fdff0 in mono_conc_hashtable_lookup (hash_table=0xf174e0, key=key@entry=0x963d4f0) at mono-conc-hashtable.c:175
    #1  0x000000000042fd29 in mono_jit_runtime_invoke (method="System.Object:lambda_method ()", obj=0x0, params=0x7fffb1067c10, exc=0x0, 
        error=0x7fffb1067d00) at mini-runtime.c:2668
    #2  0x0000000000605a8f in do_runtime_invoke (method="System.Object:lambda_method ()", obj=, params=, 
        exc=, error=0x7fffb1067d00) at object.c:2922
    #3  0x0000000000611911 in mono_runtime_try_invoke_array (method=method@entry="System.Object:lambda_method ()", obj=obj@entry=0x0, 
        params=params@entry=0x7fdb5d61fe68, exc=exc@entry=0x0, error=error@entry=0x7fffb1067d00) at object.c:5261
    #4  0x0000000000611bd0 in mono_runtime_invoke_array_checked (method=method@entry="System.Object:lambda_method ()", obj=obj@entry=0x0, 
        params=params@entry=0x7fdb5d61fe68, error=error@entry=0x7fffb1067d00) at object.c:5139
    #5  0x00000000005c17fb in ves_icall_InternalInvoke (method=0x7fdb5d61fe40, this_arg=0x0, params=0x7fdb5d61fe68, exc=0x7fffb1067e70) at icall.c:3392
    #6  0x0000000040c4081a in ?? ()
    #7  0x00007fdb5d5ab2a0 in ?? ()
    #8  0x00007fdb5d61e688 in ?? ()
    #9  0x00007fdb5d61e828 in ?? ()
    #10 0x0000000000000000 in ?? ()

mono_backtrace


    #0  0x00000000006fdff0 in mono_conc_hashtable_lookup (hash_table=0xf174e0, key=key@entry=0x963d4f0) at mono-conc-hashtable.c:175
    175             if (key == kvs [i].key) {
    [New Thread 0x7fdaf9b1d700 (LWP 11880)]
    #1  0x000000000042fd29 in mono_jit_runtime_invoke (method="System.Object:lambda_method ()", obj=0x0, params=0x7fffb1067c10, exc=0x0, 
        error=0x7fffb1067d00) at mini-runtime.c:2668
    2668        info = (RuntimeInvokeInfo *)mono_conc_hashtable_lookup (domain_info->runtime_invoke_hash, method);
    [New Thread 0x7fdb50baa700 (LWP 11881)]
    #2  0x0000000000605a8f in do_runtime_invoke (method="System.Object:lambda_method ()", obj=, params=, 
        exc=, error=0x7fffb1067d00) at object.c:2922
    2922        result = callbacks.runtime_invoke (method, obj, params, exc, error);
    #3  0x0000000000611911 in mono_runtime_try_invoke_array (method=method@entry="System.Object:lambda_method ()", obj=obj@entry=0x0, 
        params=params@entry=0x7fdb5d61fe68, exc=exc@entry=0x0, error=error@entry=0x7fffb1067d00) at object.c:5261
    5261                res = mono_runtime_invoke_checked (method, obj, pa, error);
    #4  0x0000000000611bd0 in mono_runtime_invoke_array_checked (method=method@entry="System.Object:lambda_method ()", obj=obj@entry=0x0, 
        params=params@entry=0x7fdb5d61fe68, error=error@entry=0x7fffb1067d00) at object.c:5139
    5139        return mono_runtime_try_invoke_array (method, obj, params, NULL, error);
    [New Thread 0x7fdaf8d27700 (LWP 11882)]
    #5  0x00000000005c17fb in ves_icall_InternalInvoke (method=0x7fdb5d61fe40, this_arg=0x0, params=0x7fdb5d61fe68, exc=0x7fffb1067e70) at icall.c:3392
    3392        MonoObject *result = mono_runtime_invoke_array_checked (m, obj, params, error);
    #6 0x40c4081a in  (wrapper managed-to-native) System.Reflection.MonoMethod:InternalInvoke (System.Reflection.MonoMethod,object,object[],System.Exception&) {0x12a4498} + 0x6a (0x40c407b0 0x40c4088c) [0xf125d0 - MOAB.Task.TaskRunner.exe]
    [New Thread 0x7fdb509a9700 (LWP 11884)]
    #7  0x00007fdb5d5ab2a0 in ?? ()
    #8  0x00007fdb5d61e688 in ?? ()
    #9  0x00007fdb5d61e828 in ?? ()
    #10 0x0000000000000000 in ?? ()

Когда это происходит, большинство потоков спит:


      Id   Target Id         Frame 
      15   Thread 0x7fdb5d3ff700 (LWP 11515) "SGen worker" pthread_cond_wait@@GLIBC_2.3.2 ()
        at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
      14   Thread 0x7fdb5aee5700 (LWP 11516) "Finalizer" 0x00007fdb6458da0b in futex_abstimed_wait (cancel=true, private=, abstime=0x0, 
        expected=0, futex=0xa45c00 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:43
      13   Thread 0x7fdb515df700 (LWP 11519) "Timer-Scheduler" pthread_cond_timedwait@@GLIBC_2.3.2 ()
        at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
      12   Thread 0x7fdb50dab700 (LWP 11520) "Thread Pool I/O" 0x00007fdb64094a3d in poll () at ../sysdeps/unix/syscall-template.S:81
      11   Thread 0x7fdaf991c700 (LWP 11572) "Datastore Capac" pthread_cond_timedwait@@GLIBC_2.3.2 ()
        at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
      10   Thread 0x7fdaebfff700 (LWP 11822) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaebffeda0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      9    Thread 0x7fdaeaed3700 (LWP 11879) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaeaed2da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      8    Thread 0x7fdb509a9700 (LWP 11884) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdb509a8da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      7    Thread 0x7fdaf9d1e700 (LWP 11944) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaf9d1dda0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      6    Thread 0x7fdaeacd2700 (LWP 11993) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaeacd1da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      5    Thread 0x7fdaf9b1d700 (LWP 12002) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaf9b1cda0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      4    Thread 0x7fdaf8d27700 (LWP 12201) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdaf8d26da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      3    Thread 0x7fdb507a8700 (LWP 12631) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdb507a7da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
      2    Thread 0x7fdae8899700 (LWP 12632) "Thread Pool Wor" 0x00007fdb6458dc21 in futex_abstimed_wait (cancel=true, private=0, abstime=0x7fdae8898da0, 
        expected=0, futex=0xa465c8 ) at ../nptl/sysdeps/unix/sysv/linux/sem_waitcommon.c:87
    * 1    Thread 0x7fdb650b3780 (LWP 11511) "TaskRunner" 0x00000000006fdff0 in mono_conc_hashtable_lookup (hash_table=0xf174e0, key=key@entry=0x963d4f0)
        at mono-conc-hashtable.c:175

Код для mono_conc_hashtable_lookup:

</p> <pre> 158 mono_conc_hashtable_lookup (MonoConcurrentHashTable *hash_table, gpointer key) 159 { 160 MonoThreadHazardPointers* hp; 161 conc_table *table; 162 int hash, i, table_mask; 163 key_value_pair *kvs; 164 hash = mix_hash (hash_table->hash_func (key)); 165 hp = mono_hazard_pointer_get (); 166 167 retry: 168 table = (conc_table *)mono_get_hazardous_pointer ((gpointer volatile*)&hash_table->table, hp, 0); 169 table_mask = table->table_size - 1; 170 kvs = table->kvs; 171 i = hash & table_mask; 172 173 if (G_LIKELY (!hash_table->equal_func)) { 174 while (kvs [i].key) { 175 if (key == kvs [i].key) { 176 gpointer value; 177 /* The read of keys must happen before the read of values */ 178 mono_memory_barrier (); 179 value = kvs [i].value; 180 /* FIXME check for NULL if we add suppport for removal */ 181 mono_hazard_pointer_clear (hp, 0); 182 return value; 183 } 184 i = (i + 1) & table_mask; 185 } 186 } else { 187 GEqualFunc equal = hash_table->equal_func; 188 189 while (kvs [i].key) { 190 if (kvs [i].key != TOMBSTONE && equal (key, kvs [i].key)) { 191 gpointer value; 192 /* The read of keys must happen before the read of values */ 193 mono_memory_barrier (); 194 value = kvs [i].value; 195 196 /* We just read a value been deleted, try again. */ 197 if (G_UNLIKELY (!value)) 198 goto retry; 199 200 mono_hazard_pointer_clear (hp, 0); 201 return value; 202 } 203 i = (i + 1) & table_mask; 204 } 205 } 206 207 /* The table might have expanded and the value is now on the newer table */ 208 mono_memory_barrier (); 209 if (hash_table->table != table) 210 goto retry; 211 212 mono_hazard_pointer_clear (hp, 0); 213 return NULL; 214 } </pre> <p>

Установка точек останова на возвратах, 182,201,213:


    (gdb) break 182 thread 1
    Breakpoint 4 at 0x6fdff5: file mono-conc-hashtable.c, line 182.
    (gdb) break 201 thread 1
    Breakpoint 5 at 0x6fe0e0: file mono-conc-hashtable.c, line 201.
    (gdb) break 213 thread 1
    Breakpoint 6 at 0x6fe024: file mono-conc-hashtable.c, line 213.

Эти точки останова никогда не попадают в бесконечный цикл? Давайте попробуем gotos:


    (gdb) break 198 thread 1
    Breakpoint 5 at 0x6fe0d5: file mono-conc-hashtable.c, line 198.
    (gdb) break 210 thread 1
    Breakpoint 6 at 0x6fe019: file mono-conc-hashtable.c, line 210.

Похоже, они тоже не пострадали.

Я сосредоточился на i = (i + 1) & table_mask; в строке 184:


    Breakpoint 12, mono_conc_hashtable_lookup (hash_table=0xf174e0, key=key@entry=0x963d4f0) at mono-conc-hashtable.c:184
    184             i = (i + 1) & table_mask;
    (gdb) p i
    $15 = 4095
    (gdb) p table_mask
    $16 = 4095
    (gdb) s
    174         while (kvs [i].key) {
    (gdb) p i
    $17 = 0

Похоже, что он сканирует ключи kvs, используя i в качестве индекса, но когда я достигаю значения table_mask, он сбрасывается в 0 из-за маски и возвращается к циклу.

На данный момент, я застрял и спрашиваю, как отладить это дальше? Я нахожусь на пределе в знании моно внутренностей. Это действительно входит в бесконечный цикл? Если да, то каков сценарий, при котором ввод mono_conc_hashtable_lookup вызовет его?

Другие примечания:

Эта проблема возникает в случайное время и не является последовательной по своей схеме.

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...