Has anybody seen this one before?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/home/opam/.opam/4.03.0/bin/coclobas-ketrew start-server -C /tmp/cocloketrew/co'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00000000007b5321 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:196
196 src/core/lwt.ml: No such file or directory.
[Current thread is 1 (Thread 0x7f1d11448740 (LWP 3780))]
(gdb) bt
#0 0x00000000007b5321 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:196
#1 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#2 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#3 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#4 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#5 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#6 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#7 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#8 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#9 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#10 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#11 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#12 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#13 0x00000000007b5357 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:201
#14 0x00000000007b567c in camlLwt__safe_run_waiters_1433 () at src/core/lwt.ml:305
#15 0x00000000007e110c in camlArray__iter_1247 () at array.ml:80
#16 0x0000000000863a0e in caml_start_program ()
#17 0x000000000085f089 in caml_callback ()
#18 0x00007f1d10b84d73 in ev_invoke_pending () from /usr/lib/x86_64-linux-gnu/libev.so.4
#19 0x000000000083ec34 in lwt_libev_loop (val_loop=<optimized out>, val_block=<optimized out>) at src/unix/lwt_libev_stubs.c:100
#20 0x000000000072d5d9 in camlLwt_engine__fun_2546 () at src/unix/lwt_engine.ml:151
#21 0x000000000072f998 in camlLwt_main__run_1327 () at src/unix/lwt_main.ml:41
#22 0x00000000005dd90d in camlKetrew__Command_line__run_main_17268 () at command_line.ml:818
#23 0x000000000054d86e in camlCocloketrew__entry () at src/test/cocloketrew.ml:4
#24 0x0000000000548339 in caml_program ()
#25 0x0000000000863a0e in caml_start_program ()
#26 0x000000000084af0d in caml_main ()
#27 0x0000000000546f4c in main ()
It's in a pretty big program that does a lot of things, so not sure whethe the backtrace means anything at all.
On Wed, Feb 08, 2017 at 01:29:15PM -0800, Sebastien Mondet wrote:
Has anybody seen this one before?
(gdb) bt #0 0x00000000007b5321 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:196 [...] #27 0x0000000000546f4c in main ()It's in a pretty big program that does a lot of things, so not sure whethe the backtrace means anything at all.
I was going to suggest a stack overflow, but the backtrace is short enough.
Do you use any stubs?
--
Mauricio Fernández
@mfp yes, too many :)
Many are linked-in but should not be actually in use though (sqlite3, openssl, gnutls → this instance is using —heavily— Postgresql, and no SSL/TLS on the ocaml side):
linux-vdso.so.1 => (0x00007ffdc9cec000)
libpq.so.5 => /usr/lib/x86_64-linux-gnu/libpq.so.5 (0x00007f4f25d15000)
libgmp.so.10 => /usr/lib/x86_64-linux-gnu/libgmp.so.10 (0x00007f4f25a95000)
libev.so.4 => /usr/lib/x86_64-linux-gnu/libev.so.4 (0x00007f4f25886000)
libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f4f25669000)
libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f4f25360000)
libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f4f2515b000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f4f24d92000)
libssl.so.1.0.0 => /lib/x86_64-linux-gnu/libssl.so.1.0.0 (0x00007f4f24b29000)
libcrypto.so.1.0.0 => /lib/x86_64-linux-gnu/libcrypto.so.1.0.0 (0x00007f4f246e4000)
libgssapi_krb5.so.2 => /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2 (0x00007f4f2449a000)
libldap_r-2.4.so.2 => /usr/lib/x86_64-linux-gnu/libldap_r-2.4.so.2 (0x00007f4f24249000)
/lib64/ld-linux-x86-64.so.2 (0x0000562558dc2000)
libkrb5.so.3 => /usr/lib/x86_64-linux-gnu/libkrb5.so.3 (0x00007f4f23f76000)
libk5crypto.so.3 => /usr/lib/x86_64-linux-gnu/libk5crypto.so.3 (0x00007f4f23d47000)
libcom_err.so.2 => /lib/x86_64-linux-gnu/libcom_err.so.2 (0x00007f4f23b43000)
libkrb5support.so.0 => /usr/lib/x86_64-linux-gnu/libkrb5support.so.0 (0x00007f4f23937000)
liblber-2.4.so.2 => /usr/lib/x86_64-linux-gnu/liblber-2.4.so.2 (0x00007f4f23728000)
libresolv.so.2 => /lib/x86_64-linux-gnu/libresolv.so.2 (0x00007f4f2350d000)
libsasl2.so.2 => /usr/lib/x86_64-linux-gnu/libsasl2.so.2 (0x00007f4f232f1000)
libgssapi.so.3 => /usr/lib/x86_64-linux-gnu/libgssapi.so.3 (0x00007f4f230b0000)
libgnutls.so.30 => /usr/lib/x86_64-linux-gnu/libgnutls.so.30 (0x00007f4f22d80000)
libkeyutils.so.1 => /lib/x86_64-linux-gnu/libkeyutils.so.1 (0x00007f4f22b7b000)
libheimntlm.so.0 => /usr/lib/x86_64-linux-gnu/libheimntlm.so.0 (0x00007f4f22972000)
libkrb5.so.26 => /usr/lib/x86_64-linux-gnu/libkrb5.so.26 (0x00007f4f226e7000)
libasn1.so.8 => /usr/lib/x86_64-linux-gnu/libasn1.so.8 (0x00007f4f22445000)
libhcrypto.so.4 => /usr/lib/x86_64-linux-gnu/libhcrypto.so.4 (0x00007f4f22212000)
libroken.so.18 => /usr/lib/x86_64-linux-gnu/libroken.so.18 (0x00007f4f21ffb000)
libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007f4f21de1000)
libp11-kit.so.0 => /usr/lib/x86_64-linux-gnu/libp11-kit.so.0 (0x00007f4f21b7d000)
libidn.so.11 => /usr/lib/x86_64-linux-gnu/libidn.so.11 (0x00007f4f21949000)
libtasn1.so.6 => /usr/lib/x86_64-linux-gnu/libtasn1.so.6 (0x00007f4f21736000)
libnettle.so.6 => /usr/lib/x86_64-linux-gnu/libnettle.so.6 (0x00007f4f21500000)
libhogweed.so.4 => /usr/lib/x86_64-linux-gnu/libhogweed.so.4 (0x00007f4f212cc000)
libwind.so.0 => /usr/lib/x86_64-linux-gnu/libwind.so.0 (0x00007f4f210a3000)
libheimbase.so.1 => /usr/lib/x86_64-linux-gnu/libheimbase.so.1 (0x00007f4f20e94000)
libhx509.so.5 => /usr/lib/x86_64-linux-gnu/libhx509.so.5 (0x00007f4f20c48000)
libsqlite3.so.0 => /usr/lib/x86_64-linux-gnu/libsqlite3.so.0 (0x00007f4f20973000)
libcrypt.so.1 => /lib/x86_64-linux-gnu/libcrypt.so.1 (0x00007f4f2073b000)
libffi.so.6 => /usr/lib/x86_64-linux-gnu/libffi.so.6 (0x00007f4f20532000)
On Wed, Feb 08, 2017 at 01:48:16PM -0800, Sebastien Mondet wrote:
@mfp yes, too much :)
Many are linked-in but should not be actually in use though (sqlite3, openssl, gnutls → this instance is using —heavily— Postgresql, and no SSL/TLS on the ocaml side):
[...]
It's hard to tell what's going on; the segfault is happening in a fairly
"uninteresting" area (presumably when waking up a promise).
You could try to stress the GC by sprinkling some dummy allocations (e.g.
creating dummy strings) to see if you can get the segfault to happen at some
other point -- that would indicate there's likely a bug in some C stubs
relative to root registration or some other C interfacing GC rules.
--
Mauricio Fernández
@mfp of course, cannot reproduce when running with more logging :)
Will update if I get more info.
Thanks though!
I'm also running into this (or a very similar issue) and I hope I can provide some useful infos:
Fatal error: exception "Assert_failure src/core/lwt.ml:500:9"
Raised at file "src/core/lwt.ml", line 500, characters 9-21
Called from file "src/core/lwt.ml", line 202, characters 8-15
Called from file "src/core/lwt.ml", line 202, characters 8-15
Called from file "src/core/lwt.ml", line 202, characters 8-15
Called from file "src/core/lwt.ml", line 202, characters 8-15
Called from file "src/core/lwt.ml", line 202, characters 8-15
Called from file "src/core/lwt.ml", line 207, characters 8-15
Called from file "src/core/lwt.ml", line 306, characters 2-34
Called from file "src/core/lwt_sequence.ml", line 149, characters 31-47
Called from file "src/unix/lwt_engine.ml", line 188, characters 6-24
Called from file "src/unix/lwt_engine.ml", line 188, characters 6-24
Re-raised at file "src/unix/lwt_engine.ml", line 191, characters 6-15
Called from file "src/unix/lwt_main.ml", line 41, characters 8-82
Called from file "src/server.ml" (inlined), line 210, characters 14-37
Called from file "main.ml", line 1, characters 9-23
"websocket";
"websocket-lwt";
"lwt";
"conduit";
"conduit.lwt-unix";
"nocrypto";
"nocrypto.unix";
"yojson";
"gen";
"sequence";
"cmdliner";
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000000000050ffd4 in camlLwt__repr_rec_1360 () at src/core/lwt.ml:173
173 let rec repr_rec t =
[Current thread is 1 (Thread 0x7f256227f5c0 (LWP 2589))]
(gdb) bt
#0 0x000000000050ffd4 in camlLwt__repr_rec_1360 () at src/core/lwt.ml:173
#1 0x000000000050fff3 in camlLwt__repr_rec_1360 () at src/core/lwt.ml:175
#2 0x000000000050fff3 in camlLwt__repr_rec_1360 () at src/core/lwt.ml:175
#3 0x0000000000510c4d in camlLwt__connect_1537 () at src/core/lwt.ml:178
#4 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#5 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#6 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#7 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#8 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#9 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#10 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#11 0x00000000005101b7 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:202
#12 0x0000000000510189 in camlLwt__run_waiters_rec_1372 () at src/core/lwt.ml:207
#13 0x00000000005104fc in camlLwt__safe_run_waiters_1434 () at src/core/lwt.ml:306
#14 0x000000000050f65d in camlLwt_sequence__loop_1257 () at src/core/lwt_sequence.ml:149
#15 0x000000000061526a in caml_start_program ()
#16 0x0000000000610909 in caml_callback (closure=<optimized out>, arg=<optimized out>) at callback.c:173
#17 0x00007f2561c014e3 in ev_invoke_pending () from /usr/lib/libev.so.4
#18 0x00000000005f2b85 in lwt_libev_loop (val_loop=<optimized out>, val_block=<optimized out>) at src/unix/lwt_libev_stubs.c:130
#19 0x00000000004f38a9 in camlLwt_engine__fun_2802 () at src/unix/lwt_engine.ml:188
#20 0x00000000004f6818 in camlLwt_main__run_1327 () at src/unix/lwt_main.ml:41
#21 0x0000000000409775 in camlMain__entry () at src/server.ml:210
#22 0x0000000000406779 in caml_program ()
#23 0x000000000061526a in caml_start_program ()
#24 0x00000000006155b5 in caml_main (argv=0x7ffe55027c98) at startup.c:145
#25 0x000000000040586c in main (argc=<optimized out>, argv=<optimized out>) at main.c:37
Oof. Looking for it...
@copy, in your case, can you reproduce this reliably or somewhat reliably? It would help me to be able to investigate it locally.
That Assert_failure is similar to #349. Just noting the connection at this point (accidental pun not averted), because we never really determined the reason.
Yes, both of these are due to a promise actually being resolved, when lwt.ml expects it to still be pending. If that's a fault in lwt.ml (and not some kind of preemptive threading race condition), it represents a pretty serious logical error, and I'd love to fix it/for us to fix it.
And 🤣
edit: cc @domsj
edit2: I guess there is one more way to trigger these assertion failures besides the promise being resolved, but it's also another kind of error involving internal logical assumptions lwt.ml makes about promise state.
in your case, can you reproduce this reliably or somewhat reliably
Somewhat, it happens when stress-testing my program, so it does indeed seem to be similar to #349. My program doesn't do a lot of different lwt-related operations, mostly logging and receiving/sending a lot of websocket frames.
Since we're a bit shooting in the dark, might as well try this: could you disassemble the region around the segfault, so that we can pinpoint the exact instruction?
I'd add that even though the stacktrace is very short and directly negates it, the way the segfaults happen is reminiscent of those you sometimes get when the stack overflows (and indeed, it was said in #349 that switching to tail-recursive functions elsewhere did help).
Now, there are only 2 "direct" memory accesses in repr_rec (and then those implicit to allocate, plus stack handling for the non-tail-recursive call and the write barrier when updating t.state). Knowing which one is failing might shed some light upon this.
(gdb) disass 0x000000000050ffd4
Dump of assembler code for function camlLwt__repr_rec_1360:
0x000000000050ffd0 <+0>: sub rsp,0x18
=> 0x000000000050ffd4 <+4>: mov rbx,QWORD PTR [rax]
0x000000000050ffd7 <+7>: movzx rdi,BYTE PTR [rbx-0x8]
0x000000000050ffdc <+12>: cmp rdi,0x3
0x000000000050ffe0 <+16>: jl 0x510030 <camlLwt__repr_rec_1360+96>
0x000000000050ffe2 <+18>: mov QWORD PTR [rsp+0x8],rax
0x000000000050ffe7 <+23>: mov rax,QWORD PTR [rbx]
0x000000000050ffea <+26>: mov QWORD PTR [rsp],rax
0x000000000050ffee <+30>: call 0x50ffd0 <camlLwt__repr_rec_1360>
0x000000000050fff3 <+35>: mov rbx,rax
0x000000000050fff6 <+38>: mov rax,QWORD PTR [rsp]
0x000000000050fffa <+42>: cmp rbx,rax
0x000000000050fffd <+45>: je 0x510028 <camlLwt__repr_rec_1360+88>
0x000000000050ffff <+47>: sub r15,0x10
0x0000000000510003 <+51>: mov rax,0xa30be0
0x000000000051000a <+58>: cmp r15,QWORD PTR [rax]
0x000000000051000d <+61>: jb 0x510035 <camlLwt__repr_rec_1360+101>
0x000000000051000f <+63>: lea rsi,[r15+0x8]
0x0000000000510013 <+67>: mov QWORD PTR [rsi-0x8],0x403
0x000000000051001b <+75>: mov QWORD PTR [rsi],rbx
0x000000000051001e <+78>: mov rdi,QWORD PTR [rsp+0x8]
0x0000000000510023 <+83>: call 0x6028a0 <caml_modify>
0x0000000000510028 <+88>: mov rax,rbx
0x000000000051002b <+91>: add rsp,0x18
0x000000000051002f <+95>: ret
0x0000000000510030 <+96>: add rsp,0x18
0x0000000000510034 <+100>: ret
0x0000000000510035 <+101>: call 0x614fc4 <caml_call_gc>
0x000000000051003a <+106>: jmp 0x50ffff <camlLwt__repr_rec_1360+47>
rax is 0x2001 at this point.
I'd add that even though the stacktrace is very short and directly negates it, the way the segfaults happen is reminiscent of those you sometimes get when the stack overflows
Could it be a bug in my program then? I do call Websocket_lwt.Connected_client.recv recursively like this:
let rec client_loop game client =
Lwt_unix.with_timeout (fun () -> Connected_client.recv client) >>= fun frame ->
match handle_client_frame game client frame with
| `Stop_closed -> Lwt.return (Ok `Stop_closed)
| `Continue -> client_loop game client
(gdb) disass 0x000000000050ffd4
Dump of assembler code for function camlLwt__repr_rec_1360:
0x000000000050ffd0 <+0>: sub rsp,0x18
=> 0x000000000050ffd4 <+4>: mov rbx,QWORD PTR [rax]
so we can forget about the stack, it really is bombing when reading t.state to pattern match in
let rec repr_rec t =
match t.state with
Are you using flambda? Maybe (wild guess) the internal use of %identity violates one of its assumptions wrt. (im)mutable values and so on (RAX = t is the OCaml integer 0x1000 and not a pointer to the OCaml heap).
Are you using flambda?
No, this is without flambda.
Reran with #354.
Fatal error: exception (Invalid_argument "compare: functional value")
Raised at file "src/core/lwt.ml", line 2677, characters 18-25
Called from file "src/unix/lwt_main.ml", line 34, characters 8-18
Called from file "src/server.ml" (inlined), line 210, characters 14-37
Called from file "main.ml", line 1, characters 9-23
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00000000005119a8 in camlLwt__cancel_and_collect_callbacks_6600 () at src/core/lwt.ml:1350
1350 (Packed callbacks)::callbacks_accumulator
[Current thread is 1 (Thread 0x7f66476645c0 (LWP 19534))]
(gdb) bt
#0 0x00000000005119a8 in camlLwt__cancel_and_collect_callbacks_6600 () at src/core/lwt.ml:1350
#1 0x0000000000511856 in camlLwt__cancel_6595 () at src/core/lwt.ml:1360
#2 0x00000000005148cb in camlLwt__nth_completed_and_cancel_pending_59049 () at src/core/lwt.ml:2315
#3 0x000000000050158e in camlLwt_io__perform_io_1622 () at src/unix/lwt_io.ml:216
#4 0x0000000000501813 in camlLwt_io__flush_total_1843 () at src/unix/lwt_io.ml:270
#5 0x0000000000512e1c in camlLwt__catch_24828 () at src/core/lwt.ml:1842
#6 0x0000000000501a40 in camlLwt_io__fun_6940 () at src/unix/lwt_io.ml:307
#7 0x00000000005123fa in camlLwt__callback_14791 () at src/core/lwt.ml:1740
#8 0x000000000051109f in camlLwt__iter_callback_list_4505 () at src/core/lwt.ml:1135
#9 0x0000000000511299 in camlLwt__run_in_completion_loop_4556 () at src/core/lwt.ml:1233
#10 0x000000000050f91d in camlLwt_sequence__loop_1257 () at src/core/lwt_sequence.ml:149
#11 0x00000000004f6af6 in camlLwt_main__run_1327 () at src/unix/lwt_main.ml:43
#12 0x0000000000409775 in camlMain__entry () at src/server.ml:210
#13 0x0000000000406779 in caml_program ()
#14 0x000000000061616a in caml_start_program ()
#15 0x00000000006164b5 in caml_main (argv=0x7ffdd9dcb4c8) at startup.c:145
#16 0x000000000040586c in main (argc=<optimized out>, argv=<optimized out>) at main.c:37
Whoa, thanks!
Good news! I've been able to reproduce this issue with a minimal test case. This is based on an echo server for ocaml-websocket and a stress test written in c++ from uWebSockets.
For the server:
websocket and websocket-lwt from this repositoryjbuilder build test/bench_server.exe && ./_build/default/test/bench_server.exeFor the stress test:
g++ -std=c++11 -O3 throughput.cpp -s -o throughput -luv./throughput 1000 20 10 3000Mostly the segmentation fault appears within 3 minutes. Sometimes I don't get it and need to rerun the server and the test.
This is on OCaml 4.04.1 with lwt 3.0.0.
Great! I still didn't get a chance to look at the VM, due primarily to other work in my queue – so this is very nice to have. I'll follow these instructions later today to see if I can reproduce the problem locally.
cc @AlexOnWork
EDIT also cc @domsj
Another update: Reading about [1] this morning, I immediately thought about this issue, as my CPU was also affected. I reproduced the fault after 5 minutes of running the stress test, then applied the microcode upgrade. I haven't been able to reproduce the issue after several hours of stress testing now.
If you're affected by this fault, try the mitigations described in [1]. You can check if your CPU is affected by this bug using this perl script.
[1] https://lists.debian.org/debian-devel/2017/06/msg00308.html
cc @AlexOnWork, @domsj, @smondet about the hyperthreading bug:
[WARNING] Intel Skylake/Kaby Lake processors: broken hyper-threading
any chance you have one of the processors listed in the link from @copy above?
I just started setting up to reproduce this on Linux in DO a few hours ago, using the latest instructions (after failing to reproduce on my MacBook). I'm going to pause that. The perl script says the DO droplet is likely not affected.
Please let me know if you observe the bug again.
Also, @copy, could you test with the new lwt.ml on your machine, now that it has the microcode upgrade?
@aantron sorry I don't know the architecture this happened in a docker image on a cloud node (hence the /home/opam/ paths ;) ).
Hi, my processor is indeed affected.
So combined with the fact that my colleagues did not have this problem, I think we can conclude that this probably causes/caused the problems I was seeing.
I'll wait a bit more for ubuntu to include the updated microcodes package and then I'll test again
Updated my laptop with the instructions from https://launchpad.net/~nschloe/+archive/ubuntu/intel-microcode-backports
Started the stress test that could previously reproduce my issue & left it running for a few hours and it ran without problems (usually it takes less than 30 minutes), so quite confident my issue was caused by the cpu bug
Ok, I think we can close this issue as resolved. Thanks to all involved for debugging, running stress tests, and paying attention to mailing lists. I guess this also includes the compiler team for their work towards finding the bug :)
We also have this blog/report. Found the link on Reddit:
...also How I found a bug in Intel Skylake processors from Xavier Leroy.
Most helpful comment
Good news! I've been able to reproduce this issue with a minimal test case. This is based on an echo server for ocaml-websocket and a stress test written in c++ from uWebSockets.
For the server:
websocketandwebsocket-lwtfrom this repositoryjbuilder build test/bench_server.exe && ./_build/default/test/bench_server.exeFor the stress test:
g++ -std=c++11 -O3 throughput.cpp -s -o throughput -luv./throughput 1000 20 10 3000Mostly the segmentation fault appears within 3 minutes. Sometimes I don't get it and need to rerun the server and the test.
This is on OCaml 4.04.1 with lwt 3.0.0.