Ethr_mutex.h:657: Fatal error in ethr_mutex_lock(): Invalid argument (22) Aborted (core dumped)

blackham · August 24, 2022, 3:47pm

What can I do to avoid seeing this error again? (Answer: Program in Pascal) What can I do to avoid seeing this error and still program in Elixir?

../include/internal/ethr_mutex.h:657: Fatal error in ethr_mutex_lock(): Invalid argument (22)
Aborted (core dumped)

I’m guessing it’s this Erlang file:https://fossies.org/linux/otp/erts/include/internal/ethr_mutex.h

  652 static ETHR_INLINE void
  653 ETHR_INLINE_MTX_FUNC_NAME_(ethr_mutex_lock)(ethr_mutex *mtx)
  654 {
  655     int res = pthread_mutex_lock(&mtx->pt_mtx);
  656     if (res != 0)
  657     ETHR_FATAL_ERROR__(res);
  658 }

And it also looks like error code 22 is EINVAL

   EINVAL The mutex was created with the protocol attribute having
          the value PTHREAD_PRIO_PROTECT and the calling thread's
          priority is higher than the mutex's current priority
          ceiling.

https://man7.org/linux/man-pages/man3/pthread_mutex_lock.3p.html

Elixir/Erlang/OS specs:

elixir --version
Erlang/OTP 25 [erts-13.0.3] [source] [64-bit] [smp:128:128] [ds:128:128:10] [async-threads:1] [jit:ns]
Elixir 1.13.2 (compiled with Erlang/OTP 24)

uname -rmo
Arch Linux: 5.15.61-1-lts

Did I run out of resources? Should I stop doing things like max_connections: (:erlang.system_info(:logical_processors_available) * 4) or running async_stream() when I have LOTS of cores?

al2o3cr · August 24, 2022, 5:16pm

I’m not sure if it’s related, but there’s this issue - also a segfault, also around pthreads, also new in OTP25

github.com/erlang/otp

Coredump during beam shutdown

opened 04:42PM - 07 Jun 22 UTC

itssundeep

team:VM in progress bug

**Describe the bug** We are seeing coredump during beam shutdown. We are hittin…g an assert in pthread_mutex_lock. **To Reproduce** I have not a right way to reproduce this issue consistently, but opening the bug to see if you have a theory from the corefile. **Expected behavior** No coredump during beam shutdown. **Affected versions** We are seeing this issue with OTP 25-Rc3 **Additional context** Here is the backtrace from the coredump. ``` (gdb) bt #0 __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:45 #1 __GI___pthread_kill (threadid=<optimized out>, signo=6) at pthread_kill.c:62 #2 0x00007fea8e55750d in __GI_raise (sig=6) at ../sysdeps/posix/raise.c:26 #3 0x00007fea8e53f433 in __GI_abort () at abort.c:79 #4 0x00007fea8e54ec48 in __assert_fail_base (fmt=0x7fea8e6f51d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7fea8e6f15ea "mutex->__data.__owner == 0", file=0x7fea8e6f15bf "pthread_mutex_lock.c", line=90, function=<optimized out>) at assert.c:92 #5 0x00007fea8e54ecb3 in __GI___assert_fail (assertion=0x7fea8e6f15ea "mutex->__data.__owner == 0", file=0x7fea8e6f15bf "pthread_mutex_lock.c", line=90, function=0x7fea8e6f9880 <__PRETTY_FUNCTION__.0> "___pthread_mutex_lock") at assert.c:101 #6 0x00007fea8e5b111c in ___pthread_mutex_lock (mutex=<optimized out>, mutex@entry=0x7fe027d18190) at pthread_mutex_lock.c:90 #7 0x000000000082ca61 in event_wait (mtxb=mtxb@entry=0x7fe027d18188, tse=tse@entry=0x7fe068310540, spincount=0, type=type@entry=1073741824, is_freq_read=is_freq_read@entry=0, is_rwmtx=1) at common/ethr_mutex.c:429 #8 0x000000000082e397 in write_lock_wait (is_rwmtx=1, is_freq_read=0, initial=<optimized out>, mtxb=0x7fe027d18188) at common/ethr_mutex.c:710 #9 rwmutex_normal_rwlock_wait (initial=<optimized out>, rwmtx=0x7fe027d18188) at common/ethr_mutex.c:2313 #10 ethr_rwmutex_rwlock (rwmtx=rwmtx@entry=0x7fe027d18188) at common/ethr_mutex.c:3033 #11 0x000000000061787e in erts_rwmtx_rwlock (rwmtx=0x7fe027d18188) at beam/erl_threads.h:2049 #12 erts_de_rwlock (dep=0x7fe027d18168) at beam/erl_node_tables.h:355 #13 abort_pending_connection (was_connected_p=0x0, conn_id=695150728, dep=0x7fe027d18168) at beam/dist.c:5307 #14 erts_do_net_exits (dep=<optimized out>, reason=<optimized out>) at beam/dist.c:940 #15 0x000000000046c4f7 in erts_continue_exit_process (p=0x17c36e8) at beam/erl_process.c:13975 #16 0x00007fe016cd9fe0 in ?? () #17 0x0000000000000000 in ?? () ``` and as the assert indicates owner is not 0. ``` (gdb) p *rwmtx $6 = {rwmtx = {mtxb = {flgs = {counter = 236638704}, aux_scnt = 32736, main_scnt = 0, qlck = {__data = {__lock = 1, __count = 0, __owner = 5, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x7fe027f9ff18, __next = 0x1fe55}}, __size = "\001\000\000\000\000\000\000\000\005", '\000' <repeats 15 times>, "\030\377\371'\340\177\000\000U\376\001\000\000\000\000", __align = 1}, q = 0x7fe027d18000}, type = ETHR_RWMUTEX_TYPE_NORMAL, rq_end = 0x0, tdata = {ra = 0x3, rs = 3}}} ``` Is this is the right owner thread. ``` Thread 5 (LWP 1033): #0 futex_wait (private=0, expected=2, futex_word=0x976760 <drv_ev_state+2176>) at ../sysdeps/nptl/futex-internal.h:146 #1 __GI___lll_lock_wait (futex=0x976760 <drv_ev_state+2176>, private=0) at lowlevellock.c:50 #2 0x00007fea8e5b1051 in lll_mutex_lock_optimized (mutex=0x976760 <drv_ev_state+2176>) at pthread_mutex_lock.c:49 #3 ___pthread_mutex_lock (mutex=mutex@entry=0x976760 <drv_ev_state+2176>) at pthread_mutex_lock.c:89 #4 0x00000000007a803b in ethr_mutex_lock (mtx=0x976760 <drv_ev_state+2176>) at ../include/internal/ethr_mutex.h:655 #5 erts_mtx_lock (mtx=0x976760 <drv_ev_state+2176>) at beam/erl_threads.h:1733 #6 driver_select (ix=0x7fe1395a50f0, e=82594, mode=mode@entry=4, on=on@entry=0) at sys/common/erl_check_io.c:840 #7 0x00000000007c0d53 in desc_close (desc=0x7fe13952dd20) at drivers/common/inet_drv.c:4764 #8 erl_inet_close (desc=desc@entry=0x7fe13952dd20) at drivers/common/inet_drv.c:4802 #9 0x00000000007c1884 in inet_stop (desc=0x7fe13952dd20) at drivers/common/inet_drv.c:10185 #10 tcp_inet_stop (e=0x7fe13952dd20) at drivers/common/inet_drv.c:10185 #11 0x00000000005b3be7 in terminate_port (prt=prt@entry=0x7fe1395a50f0) at beam/io.c:3736 #12 0x00000000005b90ac in flush_port (p=<optimized out>) at beam/io.c:3682 #13 erts_deliver_port_exit (prt=prt@entry=0x7fe1395a50f0, from=from@entry=659638744035303, reason=<optimized out>, send_closed=send_closed@entry=0, drop_normal=drop_normal@entry=0) at beam/io.c:3931 #14 0x00000000005b983e in call_deliver_port_exit (broken_link=<optimized out>, reason=<optimized out>, state=<optimized out>, prt=0x7fe1395a50f0, from=659638744035303, bang_op=0) at beam/io.c:2178 #15 port_sig_exit (prt=0x7fe1395a50f0, state=<optimized out>, op=<optimized out>, sigdp=0x7fe06f8b7dc0) at beam/io.c:2202 #16 0x00000000005e9364 in erts_port_task_execute (runq=runq@entry=0x7fe06838a180, curr_port_pp=curr_port_pp@entry=0x7fe069e6efe0) at beam/erl_port_task.c:1796 #17 0x0000000000467bc4 in erts_schedule (esdp=<optimized out>, p=<optimized out>, calls=<optimized out>) at beam/erl_process.c:9788 #18 0x00007fe016cd9848 in ?? () #19 0x0000000000000000 in ?? () ``` A lot of threads in the core are cleaning up dist connections. ``` Thread 11 (LWP 1020): #0 0x00007fea8e64049a in epoll_ctl () at ../sysdeps/unix/syscall-template.S:120 #1 0x00000000007a345b in concurrent_update_pollset (events=0, op=ERTS_POLL_OP_DEL, fd=25880, ps=0x7fe0275fddc0) at sys/common/erl_poll.c:803 #2 poll_control (do_wake=<optimized out>, events=<optimized out>, op=<optimized out>, fd=25880, ps=0x7fe0275fddc0) at sys/common/erl_poll.c:1395 #3 erts_poll_control (ps=0x7fe0275fddc0, fd=fd@entry=25880, op=op@entry=ERTS_POLL_OP_DEL, events=events@entry=0, do_wake=do_wake@entry=0x7fe0149891cc) at sys/common/erl_poll.c:1441 #4 0x00000000007a853b in erts_io_control_wakeup (wake_poller=0x7fe0149891cc, pe=<optimized out>, op=ERTS_POLL_OP_DEL, state=0x7fe229871ef8) at sys/common/erl_check_io.c:444 #5 driver_select (ix=<optimized out>, e=25880, mode=7, mode@entry=4, on=on@entry=0) at sys/common/erl_check_io.c:954 #6 0x00000000007c0d53 in desc_close (desc=0x7fe083113488) at drivers/common/inet_drv.c:4764 #7 erl_inet_close (desc=desc@entry=0x7fe083113488) at drivers/common/inet_drv.c:4802 #8 0x00000000007c1884 in inet_stop (desc=0x7fe083113488) at drivers/common/inet_drv.c:10185 #9 tcp_inet_stop (e=0x7fe083113488) at drivers/common/inet_drv.c:10185 #10 0x00000000005b3be7 in terminate_port (prt=prt@entry=0x7fe083064788) at beam/io.c:3736 #11 0x00000000005b90ac in flush_port (p=<optimized out>) at beam/io.c:3682 #12 erts_deliver_port_exit (prt=prt@entry=0x7fe083064788, from=from@entry=686100088938503, reason=<optimized out>, send_closed=send_closed@entry=0, drop_normal=drop_normal@entry=0) at beam/io.c:3931 #13 0x00000000005b983e in call_deliver_port_exit (broken_link=<optimized out>, reason=<optimized out>, state=<optimized out>, prt=0x7fe083064788, from=686100088938503, bang_op=0) at beam/io.c:2178 #14 port_sig_exit (prt=0x7fe083064788, state=<optimized out>, op=<optimized out>, sigdp=0x7fe06f8fcf88) at beam/io.c:2202 #15 0x00000000005e9364 in erts_port_task_execute (runq=runq@entry=0x7fe068388ac0, curr_port_pp=curr_port_pp@entry=0x7fe069dea8e0) at beam/erl_port_task.c:1796 #16 0x0000000000467bc4 in erts_schedule (esdp=<optimized out>, p=<optimized out>, calls=<optimized out>) at beam/erl_process.c:9788 #17 0x00007fe016cd9848 in ?? () #18 0x0000000000000000 in ?? () ``` Unfortunately I cannot share the core file, but can run any commands that are needed.

nhpip · August 24, 2022, 5:27pm

May want to cross post to Erlang forums too.

LostKobrakai · August 24, 2022, 5:35pm

Likely not the root cause, but OTP 25 is only officially supported with elixir >=1.13.4