Crash in vibe.d

Permalink: HTTP NNTP

Posted Fri, 26 Sep 2014 19:27:58 GMT

Hello,

I have been trying to use vibe.d for a simple project where items (arrays of bytes) are inserted and popped, kind of like a stack. Under heavy load it always crashes and after days of struggling I was able to see where it crashes - I am new to Linux in general;

Program terminated with signal 11, Segmentation fault.
#0 0x00000000007d0c98 in rt.dehwin64posix.terminate() ()

I have no idea what that means and google doesn't point me to anything useful.

The only clue I have so far is the number of users/sessions, that is when I run a load test using concurrent pushes and pops from my computer it's super fast and stable (about 5k req/sec), but using a load agent (in the cloud) scaling up to 1300 users, each with multiple sessions reliably crashes my service.

If that's too vague I might be able to simplify and post my code here, though reproducing the issue may not be easy unless you can use a load agent.

Thanks!

Re: Crash in vibe.d

Permalink: HTTP NNTP

flamencofantasy

Posted Fri, 26 Sep 2014 19:33:29 GMT in reply to flamencofantasy

On Fri, 26 Sep 2014 19:27:58 GMT, flamencofantasy wrote:

Hello,

I have been trying to use vibe.d for a simple project where items (arrays of bytes) are inserted and popped, kind of like a stack. Under heavy load it always crashes and after days of struggling I was able to see where it crashes - I am new to Linux in general;

Program terminated with signal 11, Segmentation fault.
#0 0x00000000007d0c98 in rt.dehwin64posix.terminate() ()

I have no idea what that means and google doesn't point me to anything useful.

The only clue I have so far is the number of users/sessions, that is when I run a load test using concurrent pushes and pops from my computer it's super fast and stable (about 5k req/sec), but using a load agent (in the cloud) scaling up to 1300 users, each with multiple sessions reliably crashes my service.

If that's too vague I might be able to simplify and post my code here, though reproducing the issue may not be easy unless you can use a load agent.

Thanks!

The OS is CentOS 5.

Re: Crash in vibe.d

Permalink: HTTP NNTP

David Monagle

Posted Tue, 30 Sep 2014 03:06:13 GMT in reply to flamencofantasy

You will have more luck with finding the exact point in your code that's causing issues if you run your program within gdb (GNU Debugger)

Try executing your code like this:

gdb <name-of-your-compiled-application>

This will open a little shell. In the shell type "run" and hit enter (don't type the quotes). This will start the application and run through until you hit your segfault. At this point running "bt" and enter will give you a backtrace showing where in your app the segfault occurred.

Re: Crash in vibe.d

Permalink: HTTP NNTP

flamencofantasy

Posted Mon, 06 Oct 2014 20:05:00 GMT in reply to David Monagle

Thanks a lot!

Here is what I see;

GNU gdb (GDB) Red Hat Enterprise Linux (7.2-64.el65.2)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x8664-redhat-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /home/centos/mq/mq...done.

warning: exec file is newer than core file.
[New Thread 31660]
[New Thread 31659]
[New Thread 31661]
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Core was generated by `./mq'.
Program terminated with signal 11, Segmentation fault.
#0 0x00000000007d0c98 in vibe.data.bson.BsonSerializer.endWriteDictionary!(CMD).endWriteDictionary (this=0x6852bf)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/data/bson.d:1375

1375 mdst.data[sh .. sh + 4] = toBsonData(cast(uint)(mdst.data.length - sh))[];
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.132.el65.4.x8664

Thanks again for your help!

Re: Crash in vibe.d

Permalink: HTTP NNTP

flamencofantasy

Posted Mon, 06 Oct 2014 21:09:10 GMT in reply to flamencofantasy

Hello again,

The previous post was from a core dump.

I was able to follow your instructions and here is the stack trace;

Program received signal SIGUSR1, User defined signal 1.
[Switching to Thread 0x7fff96ebf700 (LWP 29303)]
vibe.core.drivers.libevent2.levlockmutex (mode=0, lock=0x0)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2.d:1287

1287 int levlockmutex(uint mode, void* lock)
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.132.el65.4.x8664 keyutils-libs-1.4-4.el6.x8664 krb5-libs-1.10.3-15.el65.1.x8664 libcomerr-1.41.12-18.el65.1.x8664 libselinux-2.0.94-5.3.el64.1.x8664 openssl-1.0.1e-16.el65.15.x8664 zlib-1.2.3-29.el6.x8664
(gdb) bt
#0 vibe.core.drivers.libevent2.levlock_mutex (mode=0, lock=0x0)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2.d:1287

#1 0x00007ffff7dbe86d in eventadd (ev=0x7fff9001dab8, tv=0x0) at event.c:1964
#2 0x00007ffff7dc9060 in besocketenable (bufev=0x7fff9001daa8, event=2) at buffereventsock.c:554
#3 0x00007ffff7dc72af in buffereventunsuspendread (bufev=0x7fff9001daa8, what=<value optimized out>)

at bufferevent.c:85

#4 0x00007ffff7dc3415 in evbufferruncallbacks (buffer=0x7fff8803b8d8, running_deferred=<value optimized out>)

at buffer.c:486

#5 0x00007ffff7dc6801 in evbufferdrain (buf=0x7fff8803b8d8, len=28) at buffer.c:1012
#6 0x00007ffff7dc6baf in evbufferremove (buf=0x7fff8803b8d8, data_out=<value optimized out>,

datlen=<value optimized out>) at buffer.c:1027

#7 0x00007ffff7dc8260 in bufferevent_read (bufev=<value optimized out>, data=<value optimized out>,

size=<value optimized out>) at bufferevent.c:397

#8 0x00000000006b660d in vibe.core.drivers.libevent2_tcp.Libevent2TCPConnection.read (this=0x7fff88056420,

dst=...) at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2_tcp.d:242

#9 0x00000000006f4d13 in vibe.stream.counting.LimitedInputStream.read (this=0x7fff9002aa50, dst=...)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/counting.d:62

#10 0x00000000006f6355 in vibe.stream.operations.readUntil!(StreamOutputRange).readUntil.skip (

this=0x7fff9566cf80, nbytes=28)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/operations.d:138

#11 0x00000000006f6180 in vibe.stream.operations.readUntil!(StreamOutputRange).readUntil (max_bytes=4096,

end_marker=..., dst=0x7fff9566cfc0, stream=0x7fff9002aa78)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/operations.d:179

#12 0x00000000006f5bd9 in vibe.stream.operations.readUntil!().readUntil (maxbytes=4096, endmarker=...,

dst=0x7fff9566d1a8, stream=0x7fff9002aa78)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/operations.d:101

#13 0x00000000006f5afa in vibe.stream.operations.readUntil!().readUntil (alloc=0x7fff9566d538, max_bytes=4096,

end_marker=..., stream=0x7fff9002aa78)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/operations.d:92

#14 0x00000000006f5a40 in vibe.stream.operations.readLine!().readLine (alloc=0x7fff9566d538, linesep=...,

max_bytes=4096, stream=0x7fff9002aa78)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/stream/operations.d:37

#15 0x0000000000751dfb in vibe.http.server.parseRequestHeader (maxheadersize=8192, alloc=0x7fff9566d538,

http_stream=0x7fff88056518, req=0x7fff88017a90)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/http/server.d:1506

#16 0x000000000074ffda in vibe.http.server.handleRequest (keep_alive=0x7fff9566dbe0, settings=0x7fff9566dbd8,

listen_info=..., tcp_connection=0x7fff88056518, http_stream=0x7fff88056518)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/http/server.d:1325

#17 0x000000000074f922 in vibe.http.server.handleHTTPConnection (listen_info=..., connection=0x7fff88056518)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/http/server.d:1229

#18 0x000000000074f634 in vibe.http.server.listenHTTPPlain.doListen.__lambda4 (this=0x7ffff7aa7940,

conn=0x7fff88056518) at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/http/server.d:120

#19 0x00000000006b84e4 in vibe.core.drivers.libevent2_tcp.onConnect.ClientTask.execute (this=0x7fff900695d0)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2_tcp.d:522

#20 0x00000000006a2693 in vibe.core.core.makeTaskFuncInfo!(void delegate(), ).makeTaskFuncInfo.callDelegate (

tfi=0x7fff9566de50) at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/core.d:468

#21 0x000000000069e98b in vibe.core.core.CoreTask.run (this=0x7ffff7b98600)

at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/core.d:958

#22 0x0000000000844c8e in core.thread.Fiber.run() ()
#23 0x00007ffff7b98600 in ?? ()
#24 0x00007fff9566dff0 in ?? ()
#25 0x0000000000844ba1 in fiber_entryPoint ()
#26 0x0000000000000000 in ?? ()
(gdb)

My service is basically a queue where messages (arrays of bytes) can be stored and retrieved using POST and GET requests. I will shorten my code and post it here if that would be helpful.

Thanks.

Re: Crash in vibe.d

Permalink: HTTP NNTP

Sönke Ludwig

Posted Sun, 11 Jan 2015 11:06:55 +0100 in reply to flamencofantasy

Am 06.10.2014 23:09, schrieb flamencofantasy:

warning: exec file is newer than core file.
[New Thread 31660]
[New Thread 31659]
[New Thread 31661]
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Core was generated by `./mq'.
Program terminated with signal 11, Segmentation fault.
#0 0x00000000007d0c98 in vibe.data.bson.BsonSerializer.endWriteDictionary!(CMD).endWriteDictionary (this=0x6852bf)
at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/data/bson.d:1375
1375 mdst.data[sh .. sh + 4] = toBsonData(cast(uint)(mdst.data.length - sh))[];

Assuming that the above is still accurate (the warning at the top could
indicate that the location below is wrong), this would definitely
indicate a bug in the BSON serialization code. I'll review that part of
the code to see if there is anything suspicious.

Hello again,

The previous post was from a core dump.

I was able to follow your instructions and here is the stack trace;

Program received signal SIGUSR1, User defined signal 1.
[Switching to Thread 0x7fff96ebf700 (LWP 29303)]
vibe.core.drivers.libevent2.levlockmutex (mode=0, lock=0x0)
 at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2.d:1287
1287 int levlockmutex(uint mode, void* lock)
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.132.el65.4.x8664 keyutils-libs-1.4-4.el6.x8664 krb5-libs-1.10.3-15.el65.1.x8664 libcomerr-1.41.12-18.el65.1.x8664 libselinux-2.0.94-5.3.el64.1.x8664 openssl-1.0.1e-16.el65.15.x8664 zlib-1.2.3-29.el6.x8664
(gdb) bt
#0 vibe.core.drivers.libevent2.levlock_mutex (mode=0, lock=0x0)
 at ../../../root/.dub/packages/vibe-d-0.7.21-rc.2/source/vibe/core/drivers/libevent2.d:1287

This looks like this is just a false alarm (SIGUSR1, AFAIK, is used by
the garbage collector to interrupt all threads during a collection). I
don't have the exact command at hand, but you can disable breaking on
SIGUSR1 and SIGUSR2 within GDB to ignore those.

My service is basically a queue where messages (arrays of bytes) can be stored and retrieved using POST and GET requests. I will shorten my code and post it here if that would be helpful.

A reproduction case would definitely be most helpful, especially for
debugging the segfault above, as it may prove necessary to inspect the
memory to find the root cause.