Application freezes on futex() call

user_1980863 0
Viewed 192

I have microservice written in Haskell. It uses Scotty. LTS is 13.20. OS: Linux 3.10.0-957.el7.x86_64, it works under Kubernetes. The service worked about 0.5 year without problems but now I hit several times some mysterious freezing. I think it is not a result of a regression, because the code was not modified, but the loading on service was increased.

The symptoms are:

  • CPU consumption - OK
  • Memory consumption - OK
  • strace reports freezing on futex(...) call: futex(0x349c9c4, FUTEX_WAIT_PRIVATE, 83, NULL
  • a lot of threads which look like:
F S   UID   PID  SPID  PPID  C PRI  NI ADDR SZ WCHAN  TTY          TIME CMD
4 S     0     1     1     0  0  80   0 -   274 do_sig ?        00:00:00 myinit
4 S     0     6     6     1  0  80   0 -  2922 do_wai ?        00:00:00 rc.init
4 S     0    32    32     0  0  80   0 -  2955 do_wai pts/0    00:00:00 bash
4 S     0  4464  4464     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service
1 S     0  4464  4465     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4466     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4467     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4468     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4469     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4470     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4471     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4472     6  0  80   0 - 268854048 timerf ?    00:00:00 ghc_ticker
1 S     0  4464  4473     6  0  80   0 - 268854048 ep_pol ?    00:00:00 my-service:w
1 S     0  4464  4474     6  0  80   0 - 268854048 poll_s ?    00:00:00 my-service:w
1 S     0  4464  4475     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4476     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4477     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4478     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4479     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4480     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4481     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4482     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4483     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4484     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service
1 S     0  4464  4485     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service
1 S     0  4464  4486     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
1 S     0  4464  4487     6  0  80   0 - 268854048 futex_ ?    00:00:00 my-service:w
0 R     0  4511  4511    32  0  80   0 - 12405 -      pts/0    00:00:00 ps

After attachment to the PID with gdb:

[New LWP 4487]
[New LWP 4486]
[New LWP 4485]
[New LWP 4484]
[New LWP 4483]
[New LWP 4482]
[New LWP 4481]
[New LWP 4480]
[New LWP 4479]
[New LWP 4478]
[New LWP 4477]
[New LWP 4476]
[New LWP 4475]
[New LWP 4474]
[New LWP 4473]
[New LWP 4472]
[New LWP 4471]
[New LWP 4470]
[New LWP 4469]
[New LWP 4468]
[New LWP 4467]
[New LWP 4466]
[New LWP 4465]
....
(gdb) bt full
#0  0x00007fc03ec23965 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
No symbol table info available.
#1  0x00000000015185e9 in waitCondition (pCond=pCond@entry=0x2f029c0, pMut=pMut@entry=0x2f029f0) at rts/posix/OSThreads.c:117
No locals.
#2  0x000000000150713b in waitForWorkerCapability (task=<optimized out>) at rts/Capability.c:651
        cap = <optimized out>
#3  yieldCapability (pCap=pCap@entry=0x7fffc6ae0a78, task=task@entry=0x2f029b0, gcAllowed=gcAllowed@entry=true) at rts/Capability.c:888
        cap = <optimized out>
#4  0x0000000001504d85 in scheduleYield (task=0x2f029b0, pcap=0x7fffc6ae0a70) at rts/Schedule.c:672
        cap = 0x2e7cff0
        didGcLast = <optimized out>
#5  schedule (initialCapability=initialCapability@entry=0x2edf1b0, task=task@entry=0x2f029b0) at rts/Schedule.c:292
        t = <optimized out>
        cap = 0x2e7cff0
        ret = <optimized out>
        prev_what_next = <optimized out>
        ready_to_gc = <optimized out>
#6  0x0000000001505bee in scheduleWaitThread (tso=0x4200823388, ret=ret@entry=0x0, pcap=pcap@entry=0x7fffc6ae0b08) at rts/Schedule.c:2533
        task = 0x2f029b0
        cap = 0x2edf1b0
#7  0x0000000001500584 in rts_evalLazyIO (cap=cap@entry=0x7fffc6ae0b08, p=p@entry=0x15a00d0, ret=ret@entry=0x0) at rts/RtsAPI.c:530
        tso = <optimized out>
#8  0x00000000015102be in hs_main (argc=2, argv=0x7fffc6ae0cf8, main_closure=0x15a00d0, rts_config=...) at rts/RtsMain.c:72
        cap = 0x2edf1b0
        exit_status = <optimized out>
        status = <optimized out>
#9  0x00000000004311b0 in main ()
No symbol table info available.

So, my questions are: how to fix it, investigate, what would be good to try, to check? I had idea to switch to new LTS, but I am not sure that it's the reason of the problem (I found similar problems with old LTS/GHC versions in Web forums)... IMHO it looks like a bug in RTS.

freeze haskell
1 Answers

Usually workers wait on the condition in waitForWorkerCapability when there is no work to do. E.g. all haskell threads are blocked on IO, so we don't have anything to run. The condition is signaled in giveCapabilityToTask, it's called in few places in the same file.

If you are sure there should be work to do, then you probably found a bug in RTS. Try to come with a minimal example that reproduces the issue. (I know, it's often not possible at all.)

But there could be a bug in your code or dependencies. You can try to inspect capabilities in gdb. (There is a global array on them). You might be interested in running_task, run_queue_hd, suspended_ccalls, spare_workers, returning_tasks_hd fields. I think you should have no running task and empty ran queue on all capabilities, and all workers should be in the spare_workers list of some capability.

(That's just my understanding of the issue. I'm not an expert in GHC RTS, and probably saying nonsense.)

user_4928650
Related