bosagora / agora

POC Node implementation for CoinNet
https://bosagora.io
MIT License
36 stars 22 forks source link

Vibe.d DNS is continuously spawning threads #2050

Open Geod24 opened 3 years ago

Geod24 commented 3 years ago

Vibe.d DNS resolution is the cause of hundreds of threads spawning and then dying, per second. This is expensive to us, as we're doing some allocations in module ctor, and overall it slows down the process quite a bit.

#0  0x00007f310f90c1a2 in pthread_create () from /lib/ld-musl-x86_64.so.1
#1  0x00007f310edd58cc in core.thread.osthread.Thread.start() () from /usr/lib/libdruntime-ldc-shared.so.96
#2  0x0000561738609a9d in eventcore.drivers.posix.dns.EventDriverDNS_GAI!(eventcore.drivers.posix.events.PosixEventDriverEvents!(eventcore.drivers.posix.epoll.EpollEventLoop, eventcore.drivers.posix.sockets.PosixEventDriverSockets!(eventcore.drivers.posix.epoll.EpollEventLoop).PosixEventDriverSockets).PosixEventDriverEvents, eventcore.drivers.posix.signals.SignalFDEventDriverSignals!(eventcore.drivers.posix.epoll.EpollEventLoop).SignalFDEventDriverSignals).EventDriverDNS_GAI.lookupHost(immutable(char)[], void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate).__lambda10() () at dns.d:121
#3  0x000056173860957b in eventcore.drivers.posix.dns.EventDriverDNS_GAI!(eventcore.drivers.posix.events.PosixEventDriverEvents!(eventcore.drivers.posix.epoll.EpollEventLoop, eventcore.drivers.posix.sockets.PosixEventDriverSockets!(eventcore.drivers.posix.epoll.EpollEventLoop).PosixEventDriverSockets).PosixEventDriverEvents, eventcore.drivers.posix.signals.SignalFDEventDriverSignals!(eventcore.drivers.posix.epoll.EpollEventLoop).SignalFDEventDriverSignals).EventDriverDNS_GAI.lookupHost(immutable(char)[], void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate) (this=0x7f31072a6900, name=..., on_lookup_finished=...) at dns.d:121
#4  0x00005617385e9140 in vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate).__lambda14(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate) (cb=...) at net.d:58
#5  0x00005617386020a3 in vibe.internal.async.asyncAwaitAny!(true, vibe.internal.async.Waitable!(void(eventcore.driver.TimerID) nothrow @safe delegate, vibe.internal.async.asyncAwaitAny!(true, vibe.internal.async.Waitable!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda15, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda16)).asyncAwaitAny(core.time.Duration, immutable(char)[]).__lambda4, vibe.internal.async.asyncAwaitAny!(true, vibe.internal.async.Waitable!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda15, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda16)).asyncAwaitAny(core.time.Duration, immutable(char)[]).__lambda5, vibe.internal.async.asyncAwaitAny!(true, vibe.internal.async.Waitable!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda15, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda16)).asyncAwaitAny(core.time.Duration, immutable(char)[]).__lambda6), vibe.internal.async.Waitable!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda15, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda16)).asyncAwaitAny(immutable(char)[]) () at async.d:218
#6  0x00005617385e5570 in vibe.internal.async.asyncAwaitAny!(true, vibe.internal.async.Waitable!(void(eventcore.driver.DNSLookupID, eventcore.driver.DNSStatus, scope eventcore.driver.RefAddress[]) nothrow @safe delegate, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda14, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda15, vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration).__lambda16)).asyncAwaitAny(core.time.Duration, immutable(char)[]) (timeout=..., func=...) at net.d:97
#7  0x00005617385e51c8 in vibe.core.net.resolveHost(immutable(char)[], ushort, bool, core.time.Duration) (host=...,
    address_family=0, use_dns=true, timeout=...) at net.d:73
#8  0x00005617385e4d3b in vibe.core.net.resolveHost(immutable(char)[], std.socket.AddressFamily, bool, core.time.Duration) (host=..., address_family=std.socket.UNSPEC, use_dns=true, timeout=...) at net.d:32
#9  0x00005617384d9d55 in vibe.http.client.HTTPClient.doRequest(scope void(vibe.http.client.HTTPClientRequest) delegate, ref bool, bool, std.datetime.systime.SysTime) (this=0x7f31097739a0, requester=...,
    close_conn=@0x7f30fcd47b27: false, confirmed_proxy_auth=false, connected_time=...) at client.d:705
#10 0x00005617384d7693 in vibe.http.client.HTTPClient.doRequestWithRetry(scope void(vibe.http.client.HTTPClientRequest) delegate, bool, out bool, out std.datetime.systime.SysTime) (this=0x7f31097739a0, requester=...,
    confirmed_proxy_auth=false, close_conn=@0x7f30fcd47b27: false, connected_time=...) at client.d:625
#11 0x00005617384d4f7d in vibe.http.client.HTTPClient.request(scope void(vibe.http.client.HTTPClientRequest) delegate)
    (this=0x7f31097739a0, requester=...) at client.d:597
#12 0x00005617384d43f4 in vibe.http.client.requestHTTP(vibe.inet.url.URL, scope void(scope vibe.http.client.HTTPClientRequest) delegate, const(vibe.http.client.HTTPClientSettings)) (url=..., requester=..., settings=0x7f3109748170)
    at client.d:85
#13 0x00005617384d1033 in vibe.web.rest.request(vibe.inet.url.URL, scope void(vibe.http.client.HTTPClientRequest) @safe delegate, scope void(vibe.http.client.HTTPClientRequest, scope vibe.core.stream.InputStream) @safe delegate, vibe.http
.common.HTTPMethod, immutable(char)[], scope ref const(vibe.utils.dictionarylist.DictionaryList!(immutable(char)[], false, 12uL, false).DictionaryList), immutable(char)[], immutable(char)[], ref vibe.utils.dictionarylist.DictionaryList!(immutable(char)[], false, 12uL, false).DictionaryList, ref vibe.utils.dictionarylist.DictionaryList!(immutable(char)[], false, 12uL, false).DictionaryList, in vibe.http.client.HTTPClientSettings) (base_url=..., request_filter=...,
    request_body_filter=..., verb=<optimized out>, path=..., hdrs=..., query=..., body_=..., reqReturnHdrs=...,
    optReturnHdrs=..., http_settings=0x7f3109748170) at rest.d:2021
#14 0x000056173805c4df in vibe.web.rest.executeClientMethod!(agora.api.handler.PreImage.PreImageReceivedHandler, 0, vibe.web.rest.RestInterfaceClient!(agora.api.handler.PreImage.PreImageReceivedHandler).RestInterfaceClient.__mixin19.pushPreImage(const(agora.consensus.data.PreImageInfo.PreImageInfo)).preimage).executeClientMethod(scope ref const(vibe.web.internal.rest.common.RestInterface!(agora.api.handler.PreImage.PreImageReceivedHandler).RestInterface), scope void(vibe.http.client.HTTPClientRequest) @safe delegate, scope void(vibe.http.client.HTTPClientRequest, scope vibe.core.stream.InputStream) @safe delegate) (intf=..., request_filter=..., request_body_filter=...)
    at /root/agora/source/agora/flash/api/FlashAPI.d:1928
#15 0x000056173805beeb in vibe.web.rest.RestInterfaceClient!(agora.api.handler.PreImage.PreImageReceivedHandler).RestInterfaceClient.__mixin19.pushPreImage(const(agora.consensus.data.PreImageInfo.PreImageInfo)) (this=0x7f310973c340,
    preimage=...) at /root/agora/submodules/vibe.d/utils/vibe/internal/meta/codegen.d-mixin-301:304
#16 0x0000561737fe1900 in agora.node.FullNode.FullNode.pushPreImage(const(agora.consensus.data.PreImageInfo.PreImageInfo)).__foreachbody2(ref immutable(char)[], ref agora.api.handler.PreImage.PreImageReceivedHandler).__lambda5() ()
    at /root/agora/source/agora/node/FullNode.d:924
#17 0x0000561738008f8c in vibe.core.task.TaskFuncInfo.set!(void() delegate).set(ref void() delegate).callDelegate(ref vibe.core.task.TaskFuncInfo) (tfi=...) at /root/agora/submodules/vibe-core/source/vibe/core/task.d:712
#18 0x00005617385fa8c2 in vibe.core.task.TaskFuncInfo.call() (this=0x0) at task.d:730
#19 0x00005617385fa00c in vibe.core.task.TaskFiber.run() (this=0x7f3109777600) at task.d:439
#20 0x00007f310edd4dbb in fiber_entryPoint () from /usr/lib/libdruntime-ldc-shared.so.96
#21 0x0000000000000000 in ?? ()
Geod24 commented 2 years ago

Cross ref:

mkykadir commented 2 years ago

This causes increasing memory allocations due to AddLogger mixin in some modules.

Following figure shows a memory allocation trend in Agora caused by this. memory allocation

First three peeks are caused due to AddLogger mixin and spawned threads. The last hill is caused due to my node couldn't be able to request from the peer and retried over 50 times.