ponyc
ponyc copied to clipboard
Published
20 hours ago •
ponylang
ponylang
Backend null in epoll during CI run
trafficstars
So here is the log output:
2023-10-04T02:18:21.1675656Z 365 tests started, 365 complete: time/PosixDate complete
2023-10-04T02:18:21.1677854Z /__w/ponyc/ponyc/src/libponyrt/asio/epoll.c:364: pony_asio_event_subscribe: Assertion `b != NULL` failed.
2023-10-04T02:18:21.1678496Z
2023-10-04T02:18:21.1930993Z Backtrace:
2023-10-04T02:18:21.1931759Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(ponyint_assert_fail+0x96) [0x555555b42676]
2023-10-04T02:18:21.1932382Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(pony_asio_event_subscribe+0x94) [0x555555b33a54]
2023-10-04T02:18:21.1933015Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(pony_asio_event_create+0x113) [0x555555b34213]
2023-10-04T02:18:21.1933643Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(signals_SignalHandler_Dispatch+0x120) [0x55555582eed0]
2023-10-04T02:18:21.1934225Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(+0x5dda0a) [0x555555b31a0a]
2023-10-04T02:18:21.1934777Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(ponyint_actor_run+0xda) [0x555555b310da]
2023-10-04T02:18:21.1935333Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(+0x5efe73) [0x555555b43e73]
2023-10-04T02:18:21.1935854Z /__w/ponyc/ponyc/build/debug-pool_memalign/stdlib-release(+0x5ef3d0) [0x555555b433d0]
2023-10-04T02:18:21.1936327Z /lib/x86_64-linux-gnu/libc.so.6(+0x94b43) [0x7ffff7d13b43]
2023-10-04T02:18:21.1936739Z /lib/x86_64-linux-gnu/libc.so.6(+0x126a00) [0x7ffff7da5a00]
2023-10-04T02:18:21.1966455Z Resuming thread 0x1805 in process 6149
2023-10-04T02:18:21.1966791Z Process 6149 resuming
2023-10-04T02:18:21.1967476Z Process 6149 stopped and restarted: thread 3 received signal: SIGCHLD
2023-10-04T02:18:21.1967901Z Process 6149 stopped and restarted: thread 3 received signal: SIGCHLD
2023-10-04T02:18:21.1968312Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1968713Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1969113Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1969507Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1969888Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1970303Z Process 6149 stopped and restarted: thread 3 received signal: SIGCHLD
2023-10-04T02:18:21.1970700Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1971093Z Process 6149 stopped and restarted: thread 2 received signal: SIGCHLD
2023-10-04T02:18:21.1972442Z Process 6149 stopped
2023-10-04T02:18:21.1973259Z * thread #4, name = 'stdlib-release', stop reason = signal SIGABRT
2023-10-04T02:18:21.1973656Z frame #0: 0x00007ffff7d15a7c libc.so.6`pthread_kill + 300
2023-10-04T02:18:21.1973960Z libc.so.6`pthread_kill:
2023-10-04T02:18:21.1974306Z -> 0x7ffff7d15a7c <+300>: movl %eax, %r13d
2023-10-04T02:18:21.1974597Z 0x7ffff7d15a7f <+303>: negl %r13d
2023-10-04T02:18:21.1974939Z 0x7ffff7d15a82 <+306>: cmpl $0xfffff000, %eax ; imm = 0xFFFFF000
2023-10-04T02:18:21.1976333Z 0x7ffff7d15a87 <+311>: movl $0x0, %eax
2023-10-04T02:18:21.1976800Z (lldb) frame variable
2023-10-04T02:18:21.1977043Z (lldb) register read
2023-10-04T02:18:21.1990057Z General Purpose Registers:
2023-10-04T02:18:21.1990670Z rax = 0x0000000000000000
2023-10-04T02:18:21.1991248Z rbx = 0x00007ffff6c79640
2023-10-04T02:18:21.1991608Z rcx = 0x00007ffff7d15a7c libc.so.6`pthread_kill + 300
2023-10-04T02:18:21.1991908Z rdx = 0x0000000000000006
2023-10-04T02:18:21.1992176Z rdi = 0x0000000000001805
2023-10-04T02:18:21.1992419Z rsi = 0x000000000000180a
2023-10-04T02:18:21.1992657Z rbp = 0x000000000000180a
2023-10-04T02:18:21.1992900Z rsp = 0x00007ffff6c780a0
2023-10-04T02:18:21.1993148Z r8 = 0x00007ffff6c78170
2023-10-04T02:18:21.1993375Z r9 = 0x000000007fffffff
2023-10-04T02:18:21.1993604Z r10 = 0x0000000000000008
2023-10-04T02:18:21.1993835Z r11 = 0x0000000000000246
2023-10-04T02:18:21.1994065Z r12 = 0x0000000000000006
2023-10-04T02:18:21.1994295Z r13 = 0x0000000000000016
2023-10-04T02:18:21.1994517Z r14 = 0x00007fffdd603010
2023-10-04T02:18:21.1995035Z r15 = 0x0000000000000002
2023-10-04T02:18:21.1995339Z rip = 0x00007ffff7d15a7c libc.so.6`pthread_kill + 300
2023-10-04T02:18:21.1995637Z rflags = 0x0000000000000246
2023-10-04T02:18:21.1995877Z cs = 0x0000000000000033
2023-10-04T02:18:21.1996095Z fs = 0x0000000000000000
2023-10-04T02:18:21.1996334Z gs = 0x0000000000000000
2023-10-04T02:18:21.1996565Z ss = 0x000000000000002b
2023-10-04T02:18:21.1996809Z fs_base = 0x00007ffff6c79640
2023-10-04T02:18:21.1997053Z gs_base = 0x0000000000000000
2023-10-04T02:18:21.1997275Z ds = 0x0000000000000000
2023-10-04T02:18:21.1997506Z es = 0x0000000000000000
2023-10-04T02:18:21.1997650Z
2023-10-04T02:18:21.1997736Z (lldb) bt all
2023-10-04T02:18:21.2365835Z thread #1, name = 'stdlib-release'
2023-10-04T02:18:21.2366270Z frame #0: 0x00007ffff7d10197 libc.so.6`___lldb_unnamed_symbol3457 + 231
2023-10-04T02:18:21.2366660Z frame #1: 0x00007ffff7d156a4 libc.so.6`___lldb_unnamed_symbol3483 + 308
2023-10-04T02:18:21.2367242Z frame #2: 0x0000555555b494c9 stdlib-release`ponyint_thread_join(thread=140737333663296) at threads.c:226:6
2023-10-04T02:18:21.2367792Z frame #3: 0x0000555555b44d30 stdlib-release`ponyint_sched_shutdown at scheduler.c:1138:5
2023-10-04T02:18:21.2368702Z frame #4: 0x0000555555b4332f stdlib-release`ponyint_sched_start(library=false) at scheduler.c:1328:5
2023-10-04T02:18:21.2369424Z frame #5: 0x0000555555b45580 stdlib-release`pony_start(library=false, exit_code=0x0000000000000000, language_features=0x00007fffffffe2c0) at start.c:342:7
2023-10-04T02:18:21.2369955Z frame #6: 0x0000555555b30f47 stdlib-release`main + 231
2023-10-04T02:18:21.2370320Z frame #7: 0x00007ffff7ca8d90 libc.so.6`___lldb_unnamed_symbol3139 + 128
2023-10-04T02:18:21.2370694Z frame #8: 0x00007ffff7ca8e40 libc.so.6`__libc_start_main + 128
2023-10-04T02:18:21.2371118Z frame #9: 0x000055555581fca5 stdlib-release`_start + 37
2023-10-04T02:18:21.2371548Z * thread #4, name = 'stdlib-release', stop reason = signal SIGABRT
2023-10-04T02:18:21.2371940Z * frame #0: 0x00007ffff7d15a7c libc.so.6`pthread_kill + 300
2023-10-04T02:18:21.2372283Z frame #1: 0x00007ffff7cc1476 libc.so.6`raise + 22
2023-10-04T02:18:21.2372605Z frame #2: 0x00007ffff7ca77f3 libc.so.6`abort + 211
2023-10-04T02:18:21.2373345Z frame #3: 0x0000555555b4271b stdlib-release`ponyint_assert_fail(expr="b != NULL", file="/__w/ponyc/ponyc/src/libponyrt/asio/epoll.c", line=364, func="pony_asio_event_subscribe") at ponyassert.c:65:3
2023-10-04T02:18:21.2374067Z frame #4: 0x0000555555b33a54 stdlib-release`pony_asio_event_subscribe(ev=0x00007fffe3f88590) at epoll.c:364:3
2023-10-04T02:18:21.2374735Z frame #5: 0x0000555555b34213 stdlib-release`pony_asio_event_create(owner=0x00007fffdd603010, fd=0, flags=8, nsec=2, noisy=false) at event.c:39:3
2023-10-04T02:18:21.2375322Z frame #6: 0x000055555582eed0 stdlib-release`signals_SignalHandler_Dispatch + 288
2023-10-04T02:18:21.2375980Z frame #7: 0x0000555555b31a0a stdlib-release`handle_message(ctx=0x000055555607fa08, actor=0x00007fffdd603010, msg=0x00007fffd862f8a0) at actor.c:507:7
2023-10-04T02:18:21.2376691Z frame #8: 0x0000555555b310da stdlib-release`ponyint_actor_run(ctx=0x000055555607fa08, actor=0x00007fffdd603010, polling=false) at actor.c:592:20
2023-10-04T02:18:21.2377296Z frame #9: 0x0000555555b43e73 stdlib-release`run(sched=0x000055555607f9c0) at scheduler.c:1075:23
2023-10-04T02:18:21.2377854Z frame #10: 0x0000555555b433d0 stdlib-release`run_thread(arg=0x000055555607f9c0) at scheduler.c:1127:3
2023-10-04T02:18:21.2378267Z frame #11: 0x00007ffff7d13b43 libc.so.6`___lldb_unnamed_symbol3481 + 755
2023-10-04T02:18:21.2378636Z frame #12: 0x00007ffff7da5a00 libc.so.6`___lldb_unnamed_symbol3865 + 11
2023-10-04T02:18:21.2378934Z (lldb) quit 1
2023-10-04T02:18:21.3160875Z make: *** [Makefile:239: test-stdlib-release] Error 1
Note that are running code from signals/SignalHandler that leads to an asio event create which wou;ld mean we are creating a SignalHandler. But as far as I can see there's nothing in our tests that does that. I'm kind of confused.
Like #4438, this is happening at/hear shutdown of the program.
Our handler could be coming from a successful signal test run where we didn't dispose of the handler after the test completed successfully.
The signal handler test in question is _TestSignalINT, which currently only disposes the handler in the case of a timeout.
We should try running the tests and sending a SIGCHLD while they are running and see what happens... We believe the signal handling being triggered is related to SIGCHLD arriving but we arent certain.
We need to run multiple times as WHEN the signal arrives in relation to our signal unit tests might be important.