CircleCI Linux segfaults for 64-bit shared Phobos testrunners during parallel GC marking

[kinke]

See #3093 (comment) and following posts, some weird and so far irreproducible segfaults in some other .so in GC worker threads. Worked around for now by a9a15c9.

[marcioapm]

This crash is not CircleCI specific - we are seeing it in one of our micro-services running in a Docker container, with Ubuntu 18.04 LTS (minimal) as base image.

The only different from this micro-service to others we run that are working fine, is that this one has very limited CPU and memory. (0.25 CPU and 256MB RAM)

It's unclear if this has been fixed on 1.18 or just worked around by disabling it for the test runner. Could you clarify? Thanks!

[kinke]

Okay thx for reporting, pinging @rainers - it's still worked around in current master, though I haven't checked whether Circle would pass now.

[rainers]

Are you using fork in your applications? This could be related to this then: dlang/druntime#2805

[ikod]

Maybe this is related:

import std.stdio;
import core.sys.posix.signal;
import core.thread;
import core.sys.posix.unistd;
import core.sys.posix.sys.wait;
import core.memory;
import std.algorithm;
import std.range;

void block(int signum) {
    sigset_t m;
    sigemptyset(&m);
    sigaddset(&m, signum);
    sigprocmask(SIG_BLOCK, &m, null);
}

void main()
{
    auto x = new int[](10000);
    iota(10000).each!(i => x ~= i); 
    GC.collect();  // ldc create thread here
    block(SIGHUP); // block works only for current thread, not for thread created by GC.collect
    auto parent_pid = getpid();
    auto child_pid = fork();
    if ( child_pid == 0 ) { 
        //child
        kill(parent_pid, SIGHUP); // send signal to parent
        _exit(0);
    }   
    if ( child_pid == -1 ) { 
        _exit(0);
    }   
    Thread.sleep(1.seconds);
    writeln("This should be printed");
}

do not print what expected with ldc 1.17.0 on ubuntu (works ok with dmd).
The problem is that gc worker will not inherit sigmask and receive signal.

UPD: forgot to mention that --DRT-gcopt=parallel:0 fix problem.

[marcioapm]

Are you using fork in your applications? This could be related to this then: dlang/druntime#2805

No forking, it's just a simple vibe.d HTTP service.

[marcioapm]

I suppose the threads are only created when the GC collection actually runs, right?
If so, could it be that in very limited environments, like containers, at that moment there might not be enough memory to create the new threads? Perhaps pre-creating the threads could be optional for these cases?

[kinke]

The CircleCI failures still persist after Rainer's latest druntime fixes, which are in LDC v1.18.0-beta2.

works ok with dmd

@ikod: That's strange, I don't think LDC's druntime diverges greatly in this regard. Did you test with the corresponding DMD version, 2.087? Otherwise please test with the latest LDC beta, which is based on 2.088. Also, do you link against shared libphobos.so with DMD? The problem here has only shown up with shared druntime AFAIK. LDC has separate shared druntime/Phobos libs, while DMD merges druntime into libphobos.so...

[ikod]

Hello @kinke

No, I tried with dmd 2.083 and it was OK. now installed dmd 2.087.1 and it fails with dmd the same way as with ldc.

$ sudo dpkg -i dmd_2.087.1-0_amd64.deb 
[sudo] password for igor: 
(Reading database ... 291627 files and directories currently installed.)
Preparing to unpack dmd_2.087.1-0_amd64.deb ...
Unpacking dmd (2.087.1-0) over (2.083.0-0) ...
...
$ dub run
Performing "debug" build using /usr/bin/dmd for x86_64.
test ~master: building configuration "application"...
Linking...
Running ./test 
Program exited with code -1
$ ./test --DRT-gcopt=parallel:0
This should be printed
$ ldd test
	linux-vdso.so.1 =>  (0x00007ffdc7d5e000)
	libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007fd1b1294000)
	libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007fd1b0f8b000)
	librt.so.1 => /lib/x86_64-linux-gnu/librt.so.1 (0x00007fd1b0d83000)
	libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007fd1b0b7f000)
	libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007fd1b0969000)
	libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fd1b059f000)
	/lib64/ld-linux-x86-64.so.2 (0x00007fd1b14b1000)

So --DRT-gcopt=parallel:0 fix problem in both dmd and ldc case.
Do you think I can place bugreport for druntime?

UPD. same problem with dmd 2.088

[kinke]

Do you think I can place bugreport for druntime?

Yep, please do; parallel GC marking was introduced with druntime 2.087.

[ikod]

Do you think I can place bugreport for druntime?

Yep, please do; parallel GC marking was introduced with druntime 2.087.

Done
https://issues.dlang.org/show_bug.cgi?id=20256
Thanks!

[kinke]

@rainers: The situation has apparently worsened/become more visible/? with dlang/druntime#2816 - the shared libs CircleCI job newly failed dmd-testsuite's runnable/test8.d 2 out of 2 times. From https://circleci.com/gh/ldc-developers/ldc/9888:

1700: [New Thread 0x7fa1b919f700 (LWP 34339)]
1700: [New Thread 0x7fa1b0e0e700 (LWP 34340)]
1700: [New Thread 0x7fa1b8e0e700 (LWP 34341)]
1700: 
1700: Thread 2 "test8_0" received signal SIGSEGV, Segmentation fault.
1700: [Switching to Thread 0x7fa1b919f700 (LWP 34339)]
1700: 0x00007fa1b9329c25 in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #0  0x00007fa1b9329c25 in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #1  0x00007fa1b932a17a in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #2  0x00007fa1b932aa71 in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #3  0x00007fa1b932f7b7 in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #4  0x00007fa1b9336a9e in ?? () from /lib64/ld-linux-x86-64.so.2
1700: #5  0x00007fa1b926971f in _D4core4sync5event5Event4waitMFNbNiSQBi4time8DurationZb (this=0x2, tmout=...) at event.d:247
1700: #6  0x00007fa1b9269692 in core.sync.event.Event.wait() (this=0x2) at event.d:203
1700: #7  0x00007fa1b9281c6f in _D2gc4impl12conservativeQw3Gcx14scanBackgroundMFNbZv (this=0x0) at gc.d:2907
1700: #8  0x00007fa1b9270852 in _D4core6thread8osthread20createLowLevelThreadFNbNiDFNbZvkDFNbZvZ20thread_lowlevelEntryUNbPvZQd (ctx=0x55df0543fdd0 "") at osthread.d:4177
1700: #9  0x00007fa1b8e25669 in start_thread (arg=<optimized out>) at pthread_create.c:479
1700: #10 0x00007fa1b90b0323 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

[rainers]

Is it reproducible locally, now?

[kinke]

I haven't tried it, but as CircleCI is the only failing service, I bet it isn't.

[rainers]

I tried on Ubuntu 19, also with reduced memory, but all tests pass.

[kinke]

Thx for the effort.

[kinke]

With v2.090 (#3262), this issue now also surfaces with static druntime; again CircleCI only, dmd-testsuite's runnable/sieve.d apparently consistently fails. From the CI log:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7f758c5c6700 (LWP 8156)]
[New Thread 0x7f758c5b5700 (LWP 8157)]
[New Thread 0x7f758c5b0700 (LWP 8158)]
[New Thread 0x7f758c5ab700 (LWP 8159)]
[New Thread 0x7f758c5a6700 (LWP 8160)]
[New Thread 0x7f758c5a1700 (LWP 8161)]
[New Thread 0x7f758c59c700 (LWP 8162)]
[New Thread 0x7f758c597700 (LWP 8163)]
[New Thread 0x7f758c592700 (LWP 8164)]
[New Thread 0x7f758c58d700 (LWP 8165)]
[New Thread 0x7f758c588700 (LWP 8166)]
[New Thread 0x7f758c583700 (LWP 8167)]
[New Thread 0x7f758c57e700 (LWP 8169)]
[New Thread 0x7f758c579700 (LWP 8170)]
[New Thread 0x7f758c574700 (LWP 8171)]
[New Thread 0x7f758c56f700 (LWP 8172)]
[New Thread 0x7f758c56a700 (LWP 8173)]
[New Thread 0x7f758c565700 (LWP 8174)]
[New Thread 0x7f758c560700 (LWP 8175)]
[New Thread 0x7f758c55b700 (LWP 8176)]
[New Thread 0x7f758c556700 (LWP 8177)]
[New Thread 0x7f758c551700 (LWP 8178)]
[New Thread 0x7f758c54c700 (LWP 8179)]
[New Thread 0x7f758c547700 (LWP 8180)]
[New Thread 0x7f758c542700 (LWP 8181)]
[New Thread 0x7f758c53d700 (LWP 8182)]
[New Thread 0x7f758c538700 (LWP 8183)]
[New Thread 0x7f758c533700 (LWP 8184)]
[New Thread 0x7f758c52e700 (LWP 8185)]
[New Thread 0x7f758c529700 (LWP 8186)]
[New Thread 0x7f758c524700 (LWP 8187)]
[New Thread 0x7f758c51f700 (LWP 8188)]
[New Thread 0x7f758c51a700 (LWP 8189)]
[New Thread 0x7f758c515700 (LWP 8190)]
[New Thread 0x7f758c510700 (LWP 8191)]
[New Thread 0x7f758c50b700 (LWP 8192)]
[New Thread 0x7f758c506700 (LWP 8193)]
[New Thread 0x7f758c501700 (LWP 8194)]
[New Thread 0x7f758c4fc700 (LWP 8195)]
[New Thread 0x7f758c4f7700 (LWP 8196)]
[New Thread 0x7f758c4f2700 (LWP 8197)]
[New Thread 0x7f758c4ed700 (LWP 8198)]
[New Thread 0x7f758c4e8700 (LWP 8199)]
[New Thread 0x7f758c4e3700 (LWP 8200)]
[New Thread 0x7f758c4de700 (LWP 8201)]
[New Thread 0x7f758c4d9700 (LWP 8202)]
[New Thread 0x7f758c4d4700 (LWP 8205)]
[New Thread 0x7f758c4cf700 (LWP 8209)]
[New Thread 0x7f758c4ca700 (LWP 8269)]
[New Thread 0x7f758c4c5700 (LWP 8271)]
[New Thread 0x7f758c4c0700 (LWP 8272)]
[New Thread 0x7f758c4bb700 (LWP 8273)]
[New Thread 0x7f758c4b6700 (LWP 8274)]
[New Thread 0x7f758c4b1700 (LWP 8275)]
[New Thread 0x7f758c4ac700 (LWP 8276)]
[New Thread 0x7f758c4a7700 (LWP 8277)]
[New Thread 0x7f758c4a2700 (LWP 8278)]
[New Thread 0x7f758c49d700 (LWP 8279)]
[New Thread 0x7f758c498700 (LWP 8280)]
[New Thread 0x7f758c493700 (LWP 8281)]
[New Thread 0x7f758c48e700 (LWP 8282)]
[New Thread 0x7f758c489700 (LWP 8283)]
[New Thread 0x7f758c484700 (LWP 8284)]

Thread 63 "sieve_0" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f758c489700 (LWP 8283)]
do_lookup_x (undef_name=undef_name@entry=0x7f758bd78870 "__clock_gettime", new_hash=new_hash@entry=845041693, old_hash=old_hash@entry=0x7f758c4860c0, ref=0x7f758bd763e0, result=result@entry=0x7f758c4860d0, scope=0x7f758c5c9428, i=0, version=0x7f758c5bb570, flags=5, skip=0x0, type_class=1, undef_map=0x7f758c5bda00) at dl-lookup.c:338
338	dl-lookup.c: No such file or directory.
#0  do_lookup_x (undef_name=undef_name@entry=0x7f758bd78870 "__clock_gettime", new_hash=new_hash@entry=845041693, old_hash=old_hash@entry=0x7f758c4860c0, ref=0x7f758bd763e0, result=result@entry=0x7f758c4860d0, scope=0x7f758c5c9428, i=0, version=0x7f758c5bb570, flags=5, skip=0x0, type_class=1, undef_map=0x7f758c5bda00) at dl-lookup.c:338
#1  0x00007f758c3ab1ef in _dl_lookup_symbol_x (undef_name=0x7f758bd78870 "__clock_gettime", undef_map=0x7f758c5bda00, ref=ref@entry=0x7f758c486168, symbol_scope=0x7f758c5bdd58, version=0x7f758c5bb570, type_class=type_class@entry=1, flags=5, skip_map=<optimized out>) at dl-lookup.c:813
#2  0x00007f758c3afec3 in _dl_fixup (l=<optimized out>, reloc_arg=<optimized out>) at ../elf/dl-runtime.c:112
#3  0x00007f758c3b77ca in _dl_runtime_resolve_xsavec () at ../sysdeps/x86_64/dl-trampoline.h:125
#4  0x00007f758bd82e8a in __pthread_cond_wait_common (abstime=0x7f758c486cc0, mutex=0x564fd3ed74d0, cond=0x564fd3ed74f8) at pthread_cond_wait.c:517
#5  __pthread_cond_timedwait (cond=0x564fd3ed74f8, mutex=0x564fd3ed74d0, abstime=0x7f758c486cc0) at pthread_cond_wait.c:667
#6  0x0000564fd31d578e in _D4core4sync5event5Event4waitMFNbNiSQBi4time8DurationZb ()
#7  0x0000564fd31d1c85 in _D2gc4impl12conservativeQw3Gcx__T21pullFromScanStackImplVbi0ZQBcMFNbZv ()
#8  0x0000564fd31d1a08 in _D2gc4impl12conservativeQw3Gcx14scanBackgroundMFNbZv ()
#9  0x0000564fd31b4d76 in _D4core6thread8osthread20createLowLevelThreadFNbNiDFNbZvkDFNbZvZ20thread_lowlevelEntryUNbPvZQd ()
#10 0x00007f758bd7c6db in start_thread (arg=0x7f758c489700) at pthread_create.c:463
#11 0x00007f758b4ef88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Test runnable/sieve.d failed.  The logged output:
/root/build/bin/ldmd2 -conf= -m64 -Irunnable -cov -O  -od../../../../build/dmd-testsuite/runnable -of../../../../build/dmd-testsuite/runnable/sieve_0  runnable/sieve.d 
../../../../build/dmd-testsuite/runnable/sieve_0 ../../../../build/dmd-testsuite/runnable
Segmentation fault (core dumped)

[jondegenhardt]

fyi, dub issue 1812, seg faults in travis-ci builds. May be related. Has been worked around by turning parallel GC off in dub in the dmd-2.090.0 / dub-1.19.0 release. Presumably still an issue though.

[rainers]

Thanks, @jondegenhardt it looks very much related. A stack overflow could explain the strange failures.

[kinke]

Fixed upstream by above PR; now in LDC master.