On Sun, 27 Mar 2016 13:46:53 +0200, Sönke Ludwig wrote:

Am 22.03.2016 um 05:52 schrieb denizzzka:

With

settings.options |= HTTPServerOption.distribute;

sometimes (after ~3000 requests) server with my own HttpRequestHandler stucks on this state:

(gdb) bt
#0  0x00007f27be34c053 in epoll_wait () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f27bf3d8b08 in ?? () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#2  0x00007f27bf3c3d5a in event_base_loop () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#3  0x00000000007ee099 in vibe.core.drivers.libevent2.Libevent2Driver.runEventLoop() (this=0x7f27c017b600) at ../vibe.d/source/vibe/core/drivers/libevent2.d:196
#4  0x00000000007ea1b0 in vibe.core.core.runEventLoop() () at ../vibe.d/source/vibe/core/core.d:99
#5  0x000000000070e130 in pgator.app.loop() (methods=..., client=0x7f27c018aec0, cfg=...) at source/app.d:233
#6  0x000000000070de3a in D main (args=...) at source/app.d:135
#7  0x00000000008abbd7 in rt.dmain2._d_run_main() ()
#8  0x00000000008abb15 in rt.dmain2._d_run_main() ()
#9  0x00000000008abb93 in rt.dmain2._d_run_main() ()
#10 0x00000000008abb15 in rt.dmain2._d_run_main() ()
#11 0x00000000008aba72 in _d_run_main ()
#12 0x0000000000713b80 in main ()
(gdb)

What could be a reasons? There is a ways to debug this?

The stack trace looks good so far (the usual wait for new events). Do
the other threads have a similar trace?

Huh, I did not know that gdb is able to show all the threads!

(gdb) thread apply all bt

Thread 5 (Thread 0x7fef1b381700 (LWP 2296)):
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007fef21d58b82 in __GI___pthread_mutex_lock (mutex=0xc98500 <gc.gc.GC.mutexStorage()+16>) at ../nptl/pthread_mutex_lock.c:116
#2  0x00000000008a6929 in core.sync.mutex.Mutex.lock_nothrow() ()
#3  0x00000000008f189d in gc.gc.GCMutex.lock() ()
#4  0x00000000008f31fe in gc.gc.GC.query() ()
#5  0x00000000008a7caf in gc_query ()
#6  0x00000000008ada59 in _d_arrayappendcTX ()
#7  0x000000000083e633 in vibe.utils.array.__T8ArraySetTmZ.ArraySet.insert() (this=..., key=140630623776896) at ../vibe.d/source/vibe/utils/array.d:593
#8  0x00000000007eef63 in vibe.core.drivers.libevent2.Libevent2Driver.registerObject() (this=0x7fef231cc300, obj=0x7fe71e5ff080) at ../vibe.d/source/vibe/core/drivers/libevent2.d:570
#9  0x0000000000857f63 in vibe.core.drivers.libevent2.Libevent2Object.__ctor() (this=0x7fe71e5ff080, driver=0x7fef231cc300) at ../vibe.d/source/vibe/core/drivers/libevent2.d:618
#10 0x00000000007ef426 in vibe.core.drivers.libevent2.Libevent2ManualEvent.__ctor() (this=0x7fe71e5ff080, driver=0x7fef231cc300) at ../vibe.d/source/vibe/core/drivers/libevent2.d:650
#11 0x00000000007ee1ac in vibe.core.drivers.libevent2.Libevent2Driver.createManualEvent() (this=0x7fef231cc300) at ../vibe.d/source/vibe/core/drivers/libevent2.d:426
#12 0x000000000085f4a5 in vibe.core.sync.createManualEvent() () at ../vibe.d/source/vibe/core/sync.d:627
#13 0x000000000081a4d9 in vibe.core.sync.__T17TaskConditionImplVbi0TC4core4sync5mutex5MutexZ.TaskConditionImpl.setup() (this=..., mtx=0x7fe71e5fcf80) at ../vibe.d/source/vibe/core/sync.d:819
#14 0x0000000000813bb8 in vibe.core.sync.TaskCondition.__ctor() (this=0x7fe71e5ff000, mtx=0x7fe71e5fcf80) at ../vibe.d/source/vibe/core/sync.d:548
#15 0x00000000007e59ee in vibe.core.concurrency.VibedScheduler.newCondition() (this=0x7fef231a7060, m=0x7fe71e5fcf80) at ../vibe.d/source/vibe/core/concurrency.d:1229
#16 0x00000000008b6a54 in std.concurrency.MessageBox.__ctor() ()
#17 0x00000000008b61d7 in std.concurrency.thisTid() ()
#18 0x00000000008b6187 in std.concurrency.thisTid() ()
#19 0x00000000007e8b7a in vibe.core.core.CoreTask.run() (this=0x7fecc110b400) at ../vibe.d/source/vibe/core/core.d:1106
#20 0x00000000008f0c8e in core.thread.Fiber.run() ()
#21 0x00000000008f0a08 in fiber_entryPoint ()
#22 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7fef1c383700 (LWP 2294)):
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007fef21d58b82 in __GI___pthread_mutex_lock (mutex=0x7fef231a6210) at ../nptl/pthread_mutex_lock.c:116
#2  0x00000000008a6929 in core.sync.mutex.Mutex.lock_nothrow() ()
#3  0x00000000008a6911 in core.sync.mutex.Mutex.lock() ()
#4  0x00000000008aed4d in _d_monitorenter ()
#5  0x00000000007eefe8 in vibe.core.drivers.libevent2.Libevent2Driver.unregisterObject() (this=0x7fef231bc400, obj=0x7fe71d007d80) at ../vibe.d/source/vibe/core/drivers/libevent2.d:580
#6  0x0000000000857f95 in vibe.core.drivers.libevent2.Libevent2Object.__dtor() (this=0x7fe71d007d80) at ../vibe.d/source/vibe/core/drivers/libevent2.d:626
#7  0x00000000008abb17 in rt_finalize2 ()
#8  0x00000000008f9be2 in rt_finalizeFromGC ()
#9  0x00000000008f5db2 in gc.gc.Gcx.sweep() ()
#10 0x00000000008f6561 in gc.gc.Gcx.fullcollect() ()
#11 0x00000000008f45f7 in gc.gc.Gcx.smallAlloc() ()
#12 0x00000000008f20e5 in gc.gc.GC.malloc() ()
#13 0x00000000008a79bc in gc_malloc ()
#14 0x00000000008a836d in _aaGetY ()
#15 0x000000000078697a in vibe.data.json.__T9parseJsonTAyaZ.parseJson() (__HID153=0x7fea1f8ff8e0, filename=..., line=0x0, range=...) at ../vibe.d/source/vibe/data/json.d:1178
#16 0x0000000000774dff in vibe.http.server.handleRequest() (keep_alive=@0x7fea1f8ffb70: false, settings=@0x7fea1f8ffb68: 0x7fef2319fc00, listen_info=0x7fef231ae6c0, tcp_connection=0x7fef0c375850, http_stream=0x7fef0c375850)
    at ../vibe.d/source/vibe/http/server.d:1742
#17 0x00000000007738d0 in vibe.http.server.handleHTTPConnection() (listen_info=0x7fef231ae6c0, connection=0x7fef0c375850) at ../vibe.d/source/vibe/http/server.d:1535
#18 0x0000000000773281 in vibe.http.server.listenHTTPPlain() (this=0x7fef231aea80, conn=0x7fef0c375850) at ../vibe.d/source/vibe/http/server.d:1416
#19 0x000000000085874a in vibe.core.drivers.libevent2_tcp.ClientTask.execute() (this=...) at ../vibe.d/source/vibe/core/drivers/libevent2_tcp.d:610
#20 0x00000000007eb692 in vibe.core.core.__T16makeTaskFuncInfoTDFZvZ.makeTaskFuncInfo() (tfi=0x7fea1f8ffdf0) at ../vibe.d/source/vibe/core/core.d-mixin-500:500
#21 0x00000000007e8c00 in vibe.core.core.CoreTask.run() (this=0x7fee4ce5c800) at ../vibe.d/source/vibe/core/core.d:1114
#22 0x00000000008f0c8e in core.thread.Fiber.run() ()
#23 0x00000000008f0a08 in fiber_entryPoint ()
#24 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7fef1cb84700 (LWP 2293)):
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007fef21d58b82 in __GI___pthread_mutex_lock (mutex=0xc98500 <gc.gc.GC.mutexStorage()+16>) at ../nptl/pthread_mutex_lock.c:116
#2  0x00000000008a6929 in core.sync.mutex.Mutex.lock_nothrow() ()
#3  0x00000000008f189d in gc.gc.GCMutex.lock() ()
#4  0x00000000008f20aa in gc.gc.GC.malloc() ()
#5  0x00000000008a79bc in gc_malloc ()
#6  0x00000000008aa787 in _d_newclass ()
#7  0x00000000008b61cf in std.concurrency.thisTid() ()
---Type <return> to continue, or q <return> to quit---
#8  0x00000000008b6187 in std.concurrency.thisTid() ()
#9  0x00000000007e8b7a in vibe.core.core.CoreTask.run() (this=0x7fef23210c00) at ../vibe.d/source/vibe/core/core.d:1106
#10 0x00000000008f0c8e in core.thread.Fiber.run() ()
#11 0x00000000008f0a08 in fiber_entryPoint ()
#12 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fef1bb82700 (LWP 2295)):
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007fef21d58b82 in __GI___pthread_mutex_lock (mutex=0xc98500 <gc.gc.GC.mutexStorage()+16>) at ../nptl/pthread_mutex_lock.c:116
#2  0x00000000008a6929 in core.sync.mutex.Mutex.lock_nothrow() ()
#3  0x00000000008f189d in gc.gc.GCMutex.lock() ()
#4  0x00000000008f20aa in gc.gc.GC.malloc() ()
#5  0x00000000008a79bc in gc_malloc ()
#6  0x00000000008aa787 in _d_newclass ()
#7  0x000000000074bed0 in dpq2.connection.Connection.getResult() (this=0x7fef231b5000) at ../../dpq2/src/dpq2/connection.d:165
#8  0x0000000000748f45 in vibe.db.postgresql.__Conn.runStatementBlockingManner() (this=0x7fe71e5f8700) at ../vibe.d.db.postgresql/source/vibe/db/postgresql/package.d:161
#9  0x0000000000748cd2 in vibe.db.postgresql.__Conn.doQuery() (this=0x7fef231b5000, doesQueryAndCollectsResults=...) at ../vibe.d.db.postgresql/source/vibe/db/postgresql/package.d:126
#10 0x0000000000748d51 in vibe.db.postgresql.__Conn.runStatementBlockingManner() (this=0x7fef231b5000, sendsStatement=...) at ../vibe.d.db.postgresql/source/vibe/db/postgresql/package.d:134
#11 0x00000000007492fa in vibe.db.postgresql.__Conn.execPreparedStatement() (this=0x7fef231b5000, params=...) at ../vibe.d.db.postgresql/source/vibe/db/postgresql/package.d:223
#12 0x0000000000746d7b in pgator.sql_transaction.SQLTransaction.execBuiltIn() (this=..., prepared=...) at source/sql_transaction.d:88
#13 0x000000000074696d in pgator.sql_transaction.SQLTransaction.__ctor() (this=..., isReadOnly=false, client=0x7fef231aef40) at source/sql_transaction.d:29
#14 0x000000000070dac8 in pgator.app.execMethod() (__HID2=0x7fe9095ff840, rpcRequest=..., method=..., client=0x7fef231aef40) at source/app.d:294
#15 0x000000000070f7a1 in pgator.app.RpcRequest.performRpcRequest() (this=..., __HID8=0x7fe9095ffaf8, client=0x7fef231aef40, methods=...) at source/app.d:596
#16 0x000000000070ee89 in pgator.app.performRpcRequests() (this=0x7fee4cb75de0, __HID6=0x7fe9095ffb98) at source/app.d:497
#17 0x0000000000739409 in vibe.core.concurrency.__T5asyncTDFZS6pgator3app16RpcRequestResultZ.async() (callable=..., dst=...) at ../vibe.d/source/vibe/core/concurrency.d:1138
#18 0x000000000073aec8 in std.functional.__T13DelegateFakerTPFS4vibe5utils6memory53__T11FreeListRefTOS6pgator3app16RpcRequestResultVbi1Z11FreeListRefDFZS6pgator3app16RpcRequestResultZvZ.DelegateFaker.doIt() (this=..., a1=..., a0=...)
    at /usr/include/dmd/phobos/std/functional.d-mixin-1210:1221
#19 0x000000000073d164 in vibe.core.core.__T16makeTaskFuncInfoTDFS4vibe5utils6memory53__T11FreeListRefTOS6pgator3app16RpcRequestResultVbi1Z11FreeListRefDFZS6pgator3app16RpcRequestResultZvTS4vibe5utils6memory53__T11FreeListRefTOS6pgator3app16RpcRequestResultVbi1Z11FreeListRefTDFZS6pgator3app16RpcRequestResultZ.makeTaskFuncInfo() (tfi=0x7fe9095ffdf0) at ../vibe.d/source/vibe/core/core.d-mixin-500:500
#20 0x00000000007e8c00 in vibe.core.core.CoreTask.run() (this=0x7fecc0b18800) at ../vibe.d/source/vibe/core/core.d:1114
#21 0x00000000008f0c8e in core.thread.Fiber.run() ()
#22 0x00000000008f0a08 in fiber_entryPoint ()
#23 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fef232a0e80 (LWP 2290)):
#0  0x00007fef213784d3 in epoll_wait () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fef223fdb08 in ?? () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#2  0x00007fef223e8d5a in event_base_loop () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#3  0x00000000007ecac1 in vibe.core.drivers.libevent2.Libevent2Driver.runEventLoop() (this=0x7fef2319f600) at ../vibe.d/source/vibe/core/drivers/libevent2.d:196
#4  0x00000000007e8174 in vibe.core.core.runEventLoop() () at ../vibe.d/source/vibe/core/core.d:99
#5  0x000000000070cfa5 in pgator.app.loop() (methods=..., client=0x7fef231aef40, cfg=...) at source/app.d:235
#6  0x000000000070cca0 in D main (args=...) at source/app.d:137
#7  0x00000000008a9b4b in rt.dmain2._d_run_main() ()
#8  0x00000000008a9a89 in rt.dmain2._d_run_main() ()
#9  0x00000000008a9b07 in rt.dmain2._d_run_main() ()
#10 0x00000000008a9a89 in rt.dmain2._d_run_main() ()
#11 0x00000000008a99e6 in _d_run_main ()
#12 0x0000000000712a88 in main ()
(gdb) 

The best bet to find where a

task hangs is currently to set the log level to LogLevel.trace (or run
with --vvvv).

Tried, nothing strange isn't found

If that doesn't help, setting a task event callback and
logging from there would be a possibility.

Thanks, I'll try it